2023-08-04T20:08:32.586Z,1691179712.586 [Supervisor](DEBUG): Initializing supervisor.
2023-08-04T20:08:32.591Z,1691179712.591 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-08-04T20:08:32.591Z,1691179712.591 [SyncHandler](INFO): Protected caller Thread ID is 9889
2023-08-04T20:08:32.592Z,1691179712.592 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-08-04T20:08:32.593Z,1691179712.593 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-08-04T20:08:32.593Z,1691179712.593 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 9890
2023-08-04T20:08:32.597Z,1691179712.597 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-08-04T20:08:32.615Z,1691179712.615 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-08-04T20:08:32.616Z,1691179712.616 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-08-04T20:08:32.616Z,1691179712.616 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 9891
2023-08-04T20:08:32.620Z,1691179712.620 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-08-04T20:08:32.621Z,1691179712.621 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-08-04T20:08:32.622Z,1691179712.622 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 9892
2023-08-04T20:08:32.624Z,1691179712.624 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-08-04T20:08:32.624Z,1691179712.624 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-08-04T20:08:32.625Z,1691179712.625 [logger ThreadHandler](INFO): Protected caller Thread ID is 9893
2023-08-04T20:08:32.628Z,1691179712.628 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-08-04T20:08:32.629Z,1691179712.629 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-08-04T20:08:32.631Z,1691179712.631 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-08-04T20:08:32.727Z,1691179712.727 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-08-04T20:08:32.727Z,1691179712.727 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-08-04T20:08:33.396Z,1691179713.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-08-04T20:08:33.397Z,1691179713.397 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-08-04T20:08:33.608Z,1691179713.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-08-04T20:08:33.609Z,1691179713.609 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-08-04T20:08:33.688Z,1691179713.688 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-08-04T20:08:33.816Z,1691179713.816 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-08-04T20:08:33.817Z,1691179713.817 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-08-04T20:08:33.898Z,1691179713.898 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-08-04T20:08:34.004Z,1691179714.004 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-08-04T20:08:34.005Z,1691179714.005 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-08-04T20:08:34.371Z,1691179714.372 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-08-04T20:08:34.372Z,1691179714.372 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-08-04T20:08:34.837Z,1691179714.837 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-08-04T20:08:34.838Z,1691179714.838 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-08-04T20:08:35.048Z,1691179715.048 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-08-04T20:08:35.049Z,1691179715.049 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-08-04T20:08:35.232Z,1691179715.232 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-08-04T20:08:35.233Z,1691179715.233 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-08-04T20:08:35.726Z,1691179715.726 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-08-04T20:08:35.726Z,1691179715.726 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-08-04T20:08:36.002Z,1691179716.002 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-08-04T20:08:36.003Z,1691179716.003 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-08-04T20:08:36.219Z,1691179716.219 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-08-04T20:08:36.220Z,1691179716.220 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-08-04T20:08:36.591Z,1691179716.591 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-08-04T20:08:36.591Z,1691179716.591 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-08-04T20:08:36.912Z,1691179716.912 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-08-04T20:08:36.915Z,1691179716.915 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2023-08-04T20:08:36.916Z,1691179716.916 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2023-08-04T20:08:37.000Z,1691179717.000 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2023-08-04T20:08:37.162Z,1691179717.162 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2023-08-04T20:08:37.265Z,1691179717.265 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2023-08-04T20:08:37.443Z,1691179717.443 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2023-08-04T20:08:37.736Z,1691179717.736 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2023-08-04T20:08:37.930Z,1691179717.930 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2023-08-04T20:08:38.529Z,1691179718.529 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-08-04T20:08:38.529Z,1691179718.529 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2023-08-04T20:08:38.624Z,1691179718.624 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2023-08-04T20:08:38.722Z,1691179718.722 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2023-08-04T20:08:38.859Z,1691179718.859 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2023-08-04T20:08:38.960Z,1691179718.960 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-08-04T20:08:38.970Z,1691179718.970 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-08-04T20:08:39.068Z,1691179719.068 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-08-04T20:08:39.069Z,1691179719.069 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-08-04T20:08:39.119Z,1691179719.119 [VerticalControl](DEBUG): Construct VerticalControl.
2023-08-04T20:08:39.178Z,1691179719.178 [VerticalControl] Loaded
2023-08-04T20:08:39.178Z,1691179719.178 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-08-04T20:08:39.181Z,1691179719.181 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-08-04T20:08:39.221Z,1691179719.221 [HorizontalControl] Loaded
2023-08-04T20:08:39.222Z,1691179719.222 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-08-04T20:08:39.224Z,1691179719.224 [SpeedControl](DEBUG): Construct SpeedControl.
2023-08-04T20:08:39.227Z,1691179719.227 [SpeedControl] Loaded
2023-08-04T20:08:39.227Z,1691179719.227 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-08-04T20:08:39.230Z,1691179719.230 [LoopControl](DEBUG): Construct LoopControl.
2023-08-04T20:08:39.230Z,1691179719.230 [LoopControl] Loaded
2023-08-04T20:08:39.230Z,1691179719.230 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-08-04T20:08:39.231Z,1691179719.231 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-08-04T20:08:39.231Z,1691179719.231 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-08-04T20:08:39.280Z,1691179719.280 [DepthRateCalculator] Loaded
2023-08-04T20:08:39.281Z,1691179719.281 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-08-04T20:08:39.285Z,1691179719.285 [PitchRateCalculator] Loaded
2023-08-04T20:08:39.286Z,1691179719.286 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-08-04T20:08:39.295Z,1691179719.295 [SpeedCalculator] Loaded
2023-08-04T20:08:39.296Z,1691179719.296 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-08-04T20:08:39.300Z,1691179719.300 [YawRateCalculator] Loaded
2023-08-04T20:08:39.300Z,1691179719.300 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-08-04T20:08:39.318Z,1691179719.318 [ElevatorOffsetCalculator] Loaded
2023-08-04T20:08:39.318Z,1691179719.318 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-08-04T20:08:39.319Z,1691179719.319 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-08-04T20:08:39.319Z,1691179719.319 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-08-04T20:08:39.347Z,1691179719.347 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-08-04T20:08:39.347Z,1691179719.347 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-08-04T20:08:39.403Z,1691179719.403 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-08-04T20:08:39.403Z,1691179719.403 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-08-04T20:08:39.710Z,1691179719.710 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-08-04T20:08:39.711Z,1691179719.711 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-08-04T20:08:39.855Z,1691179719.855 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-08-04T20:08:39.855Z,1691179719.855 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-08-04T20:08:40.280Z,1691179720.280 [AHRS_M2] Loaded
2023-08-04T20:08:40.280Z,1691179720.280 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-08-04T20:08:40.315Z,1691179720.315 [BackseatComponent] Loaded
2023-08-04T20:08:40.315Z,1691179720.315 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-08-04T20:08:40.316Z,1691179720.316 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 4098F4E0
2023-08-04T20:08:40.317Z,1691179720.317 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 9975
2023-08-04T20:08:40.320Z,1691179720.320 [LcmUniversalReporter] Loaded
2023-08-04T20:08:40.320Z,1691179720.320 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-08-04T20:08:41.120Z,1691179721.120 [BPC1] Loaded
2023-08-04T20:08:41.120Z,1691179721.120 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-08-04T20:08:41.191Z,1691179721.191 [DataOverHttps] Loaded
2023-08-04T20:08:41.192Z,1691179721.192 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-08-04T20:08:41.192Z,1691179721.192 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409BF4E0
2023-08-04T20:08:41.193Z,1691179721.193 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 9976
2023-08-04T20:08:41.213Z,1691179721.213 [Depth_Keller] Loaded
2023-08-04T20:08:41.214Z,1691179721.214 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-08-04T20:08:41.218Z,1691179721.218 [DropWeight] Loaded
2023-08-04T20:08:41.219Z,1691179721.219 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-08-04T20:08:41.280Z,1691179721.280 [NAL9602] Loaded
2023-08-04T20:08:41.281Z,1691179721.281 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-08-04T20:08:41.310Z,1691179721.310 [Onboard] Loaded
2023-08-04T20:08:41.310Z,1691179721.310 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-08-04T20:08:41.311Z,1691179721.311 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409EF4E0
2023-08-04T20:08:41.312Z,1691179721.312 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 9977
2023-08-04T20:08:41.318Z,1691179721.318 [PowerOnly](INFO): Adding load control power supply at /dev/loadB1
2023-08-04T20:08:41.329Z,1691179721.329 [PowerOnly] Loaded
2023-08-04T20:08:41.329Z,1691179721.329 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2023-08-04T20:08:41.341Z,1691179721.341 [Power24vConverter] Loaded
2023-08-04T20:08:41.341Z,1691179721.341 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-08-04T20:08:41.354Z,1691179721.354 [Radio_Surface] Loaded
2023-08-04T20:08:41.354Z,1691179721.354 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-08-04T20:08:41.355Z,1691179721.355 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A1F4E0
2023-08-04T20:08:41.355Z,1691179721.355 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9978
2023-08-04T20:08:41.400Z,1691179721.400 [RDI_Pathfinder] Loaded
2023-08-04T20:08:41.400Z,1691179721.400 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2023-08-04T20:08:41.491Z,1691179721.491 [DAT] Loaded
2023-08-04T20:08:41.491Z,1691179721.491 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-08-04T20:08:41.492Z,1691179721.492 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A4F4E0
2023-08-04T20:08:41.493Z,1691179721.493 [DAT ThreadHandler](INFO): Protected caller Thread ID is 9979
2023-08-04T20:08:41.493Z,1691179721.493 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-08-04T20:08:41.494Z,1691179721.494 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-08-04T20:08:41.604Z,1691179721.604 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-08-04T20:08:41.604Z,1691179721.604 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-08-04T20:08:41.618Z,1691179721.618 [NavChart] Loaded
2023-08-04T20:08:41.618Z,1691179721.618 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-08-04T20:08:41.624Z,1691179721.624 [UniversalFixResidualReporter] Loaded
2023-08-04T20:08:41.624Z,1691179721.624 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-08-04T20:08:41.625Z,1691179721.625 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-08-04T20:08:41.625Z,1691179721.625 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-08-04T20:08:41.761Z,1691179721.761 [SBIT](DEBUG): Construct Startup Built In Test.
2023-08-04T20:08:41.770Z,1691179721.770 [SBIT] Loaded
2023-08-04T20:08:41.770Z,1691179721.770 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-08-04T20:08:41.773Z,1691179721.773 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-08-04T20:08:41.785Z,1691179721.785 [IBIT] Loaded
2023-08-04T20:08:41.785Z,1691179721.785 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-08-04T20:08:41.791Z,1691179721.791 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-08-04T20:08:41.894Z,1691179721.894 [CBIT] Loaded
2023-08-04T20:08:41.894Z,1691179721.894 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-08-04T20:08:41.895Z,1691179721.895 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-08-04T20:08:41.895Z,1691179721.895 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-08-04T20:08:42.021Z,1691179722.021 [BuoyancyServo] Loaded
2023-08-04T20:08:42.022Z,1691179722.022 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-08-04T20:08:42.042Z,1691179722.042 [ElevatorServo] Loaded
2023-08-04T20:08:42.042Z,1691179722.042 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-08-04T20:08:42.062Z,1691179722.062 [MassServo] Loaded
2023-08-04T20:08:42.062Z,1691179722.062 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-08-04T20:08:42.080Z,1691179722.080 [RudderServo] Loaded
2023-08-04T20:08:42.080Z,1691179722.080 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-08-04T20:08:42.097Z,1691179722.097 [ThrusterServo] Loaded
2023-08-04T20:08:42.098Z,1691179722.098 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2023-08-04T20:08:42.098Z,1691179722.098 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-08-04T20:08:42.099Z,1691179722.099 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-08-04T20:08:42.109Z,1691179722.109 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-08-04T20:08:42.109Z,1691179722.109 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-08-04T20:08:42.292Z,1691179722.292 [CTD_Seabird] Loaded
2023-08-04T20:08:42.292Z,1691179722.292 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-08-04T20:08:42.293Z,1691179722.293 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B9A4E0
2023-08-04T20:08:42.294Z,1691179722.294 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 9980
2023-08-04T20:08:42.314Z,1691179722.314 [PAR_Licor] Loaded
2023-08-04T20:08:42.314Z,1691179722.314 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-08-04T20:08:42.354Z,1691179722.354 [WetLabsBB2FL] Loaded
2023-08-04T20:08:42.354Z,1691179722.354 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-08-04T20:08:42.355Z,1691179722.355 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40BCA4E0
2023-08-04T20:08:42.356Z,1691179722.356 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 9981
2023-08-04T20:08:42.375Z,1691179722.375 [WetLabsUBAT] Loaded
2023-08-04T20:08:42.375Z,1691179722.375 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2023-08-04T20:08:42.376Z,1691179722.376 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40BFA4E0
2023-08-04T20:08:42.377Z,1691179722.377 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 9982
2023-08-04T20:08:42.377Z,1691179722.377 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-08-04T20:08:42.384Z,1691179722.384 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-08-04T20:08:42.386Z,1691179722.386 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-08-04T20:08:42.398Z,1691179722.398 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-08-04T20:08:42.399Z,1691179722.399 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C2A4E0
2023-08-04T20:08:42.399Z,1691179722.399 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9983
2023-08-04T20:08:42.404Z,1691179722.404 [Supervisor](INFO): Main Thread ID is 9888
2023-08-04T20:08:42.404Z,1691179722.404 [Supervisor](DEBUG): Running supervisor.
2023-08-04T20:08:42.404Z,1691179722.404 [CommandExec ThreadHandler](INFO): Handler Thread ID is 9984
2023-08-04T20:08:42.405Z,1691179722.405 [CommandExec](INFO): Initializing the command executive.
2023-08-04T20:08:42.407Z,1691179722.407 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9985
2023-08-04T20:08:42.409Z,1691179722.409 [controlThread ThreadHandler](INFO): Handler Thread ID is 9986
2023-08-04T20:08:42.409Z,1691179722.409 [controlThread](DEBUG): Initializing ControlThread
2023-08-04T20:08:42.410Z,1691179722.410 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-08-04T20:08:42.412Z,1691179722.412 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-08-04T20:08:42.413Z,1691179722.413 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-08-04T20:08:42.413Z,1691179722.413 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-08-04T20:08:42.413Z,1691179722.413 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-08-04T20:08:42.414Z,1691179722.414 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-08-04T20:08:42.414Z,1691179722.414 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-08-04T20:08:42.415Z,1691179722.415 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-08-04T20:08:42.415Z,1691179722.415 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-08-04T20:08:42.420Z,1691179722.420 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-08-04T20:08:42.421Z,1691179722.421 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-08-04T20:08:42.421Z,1691179722.421 [SBIT](INFO): Initialize SBIT Component.
2023-08-04T20:08:42.422Z,1691179722.422 [SBIT](IMPORTANT): git: 2023-08-02-8-ga2b2183f7
2023-08-04T20:08:42.422Z,1691179722.422 [SBIT](INFO): git hash: a2b2183f71e07b707bfeaaf571c74c3561721119
2023-08-04T20:08:42.422Z,1691179722.422 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-08-04T20:08:42.423Z,1691179722.423 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-08-04T20:08:42.424Z,1691179722.424 [SBIT](INFO): Beginning SBIT in 45.000000 seconds.
2023-08-04T20:08:42.425Z,1691179722.425 [IBIT](INFO): Initialize IBIT Component.
2023-08-04T20:08:42.426Z,1691179722.426 [CBIT](DEBUG): Initialize CBIT Component.
2023-08-04T20:08:42.427Z,1691179722.427 [logger ThreadHandler](INFO): Handler Thread ID is 9987
2023-08-04T20:08:42.438Z,1691179722.438 [CBIT](DEBUG): Initialized mux pins.
2023-08-04T20:08:42.438Z,1691179722.438 [CBIT](DEBUG): Initializing the watchdog timer.
2023-08-04T20:08:42.446Z,1691179722.446 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 9988
2023-08-04T20:08:42.458Z,1691179722.458 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 9989
2023-08-04T20:08:42.459Z,1691179722.459 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-08-04T20:08:42.462Z,1691179722.462 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-08-04T20:08:42.463Z,1691179722.463 [CBIT](FAULT): Found backtrace file:
1691024331.563915 [CBIT]: Backtrace:
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x1b01c8]
./bin/LRAUV(_ZN7PCaller10PThreadRunEPv+0xc8) [0x1afc14]

1691024332.167789 [CBIT]: Backtrace:
./bin/LRAUV(_ZN7PCaller20DefaultSignalHandlerEiP7siginfoPv+0x20) [0x1b01c8]
./bin/LRAUV(_ZN7PCaller10PThreadRunEPv+0xc8) [0x1afc14]


2023-08-04T20:08:42.466Z,1691179722.466 [CBIT](FAULT): Renaming backtrace file to Data/backtrace12
2023-08-04T20:08:42.467Z,1691179722.467 [CBIT](DEBUG): Initializing heartbeat.
2023-08-04T20:08:42.470Z,1691179722.470 [Onboard ThreadHandler](INFO): Handler Thread ID is 9990
2023-08-04T20:08:42.484Z,1691179722.484 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9991
2023-08-04T20:08:42.494Z,1691179722.494 [DAT ThreadHandler](INFO): Handler Thread ID is 9992
2023-08-04T20:08:42.495Z,1691179722.495 [DAT](INFO): Powering up
2023-08-04T20:08:42.495Z,1691179722.495 [DAT](DEBUG): Initializing DAT.
2023-08-04T20:08:42.497Z,1691179722.497 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 9994
2023-08-04T20:08:42.498Z,1691179722.498 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 9995
2023-08-04T20:08:42.501Z,1691179722.501 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 9996
2023-08-04T20:08:42.514Z,1691179722.514 [WetLabsBB2FL](INFO): Powering up
2023-08-04T20:08:42.522Z,1691179722.522 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-08-04T20:08:42.538Z,1691179722.538 [CBIT](DEBUG): Deactivating GF circuits.
2023-08-04T20:08:42.538Z,1691179722.538 [CBIT](DEBUG): Deactivating emergency mode.
2023-08-04T20:08:42.578Z,1691179722.578 [CBIT](DEBUG): Backplane powered.
2023-08-04T20:08:42.611Z,1691179722.611 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-08-04T20:08:42.626Z,1691179722.626 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9997
2023-08-04T20:08:42.629Z,1691179722.629 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-08-04T20:08:42.630Z,1691179722.630 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-08-04T20:08:42.630Z,1691179722.630 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-08-04T20:08:42.630Z,1691179722.630 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-08-04T20:08:42.630Z,1691179722.630 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-08-04T20:08:42.631Z,1691179722.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-08-04T20:08:42.631Z,1691179722.631 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-08-04T20:08:42.631Z,1691179722.631 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-08-04T20:08:42.652Z,1691179722.652 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-08-04T20:08:42.669Z,1691179722.669 [WetLabsUBAT](INFO): Powering up
2023-08-04T20:08:42.773Z,1691179722.773 [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-08-04T20:08:42.774Z,1691179722.774 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-08-04T20:08:42.856Z,1691179722.856 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-08-04T20:08:42.866Z,1691179722.866 [Default:A.Wait](DEBUG): Construct Wait.
2023-08-04T20:08:42.868Z,1691179722.868 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-08-04T20:08:42.894Z,1691179722.894 [Radio_Surface](INFO): Powering up
2023-08-04T20:08:42.946Z,1691179722.946 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-08-04T20:08:42.949Z,1691179722.949 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-08-04T20:08:42.971Z,1691179722.971 [Default:E.Execute](DEBUG): Construct Execute.
2023-08-04T20:08:42.979Z,1691179722.979 [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-08-04T20:08:42.984Z,1691179722.984 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-08-04T20:08:43.030Z,1691179723.030 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-08-04T20:08:43.091Z,1691179723.091 [Depth_Keller](ERROR): Pressure or depth reading out of range: -1.000394 decibar, -0.993016 m
2023-08-04T20:08:43.093Z,1691179723.093 [PowerOnly](INFO): Powering up loadControl
2023-08-04T20:08:43.110Z,1691179723.110 [Power24vConverter](INFO): Powering up.
2023-08-04T20:08:43.111Z,1691179723.111 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2023-08-04T20:08:43.124Z,1691179723.124 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-08-04T20:08:43.163Z,1691179723.163 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-08-04T20:08:43.170Z,1691179723.170 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-08-04T20:08:43.171Z,1691179723.171 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-08-04T20:08:43.178Z,1691179723.178 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-08-04T20:08:43.179Z,1691179723.179 [MassServo](DEBUG): Initializing EZServoServo.
2023-08-04T20:08:43.186Z,1691179723.186 [MassServo](DEBUG): Initializing MassServo.
2023-08-04T20:08:43.187Z,1691179723.187 [RudderServo](DEBUG): Initializing EZServoServo.
2023-08-04T20:08:43.194Z,1691179723.194 [RudderServo](DEBUG): Initializing RudderServo.
2023-08-04T20:08:43.195Z,1691179723.195 [ThrusterServo](DEBUG): Initializing EZServoServo.
2023-08-04T20:08:43.202Z,1691179723.202 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2023-08-04T20:08:45.114Z,1691179725.114 [WetLabsBB2FL](INFO): Powering down
2023-08-04T20:08:50.530Z,1691179730.530 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2023-08-04T20:08:51.942Z,1691179731.942 [WetLabsUBAT](INFO): Powering down
2023-08-04T20:08:56.358Z,1691179736.358 [DAT](INFO): DAT read: 

2023-08-04T20:08:56.360Z,1691179736.360 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-08-04T20:08:56.792Z,1691179736.792 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004548
2023-08-04T20:08:58.123Z,1691179738.123 [DAT](INFO): DAT read: MF Frequency Band

2023-08-04T20:08:58.124Z,1691179738.124 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-08-04T20:08:58.124Z,1691179738.124 [DAT](INFO): DAT read: Aug  3 2023 00:55:22 

2023-08-04T20:08:59.131Z,1691179739.131 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-08-04T20:08:59.132Z,1691179739.132 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-08-04T20:08:59.132Z,1691179739.132 [DAT](INFO): commRate: 800
2023-08-04T20:09:01.198Z,1691179741.198 [DAT](INFO): entering command mode
2023-08-04T20:09:01.398Z,1691179741.398 [DAT](INFO): DAT read: 

2023-08-04T20:09:01.399Z,1691179741.399 [DAT](INFO): DAT read: user:1>

2023-08-04T20:09:01.399Z,1691179741.399 [DAT](INFO): setting verbose to 3
2023-08-04T20:09:01.650Z,1691179741.650 [DAT](INFO): DAT read: user:1>

2023-08-04T20:09:01.651Z,1691179741.651 [DAT](INFO): DAT read: Verbose         | 3           

2023-08-04T20:09:01.652Z,1691179741.652 [DAT](INFO): set verbose to 3
2023-08-04T20:09:01.652Z,1691179741.652 [DAT](INFO): setting DatVerbose to 27440
2023-08-04T20:09:01.902Z,1691179741.902 [DAT](INFO): DAT read: user:2>

2023-08-04T20:09:01.903Z,1691179741.903 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-08-04T20:09:01.904Z,1691179741.904 [DAT](INFO): set DatVerbose to 27440
2023-08-04T20:09:01.904Z,1691179741.904 [DAT](INFO): setting transmit power to 8
2023-08-04T20:09:02.155Z,1691179742.155 [DAT](INFO): DAT read: user:3>

2023-08-04T20:09:02.156Z,1691179742.156 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-08-04T20:09:02.156Z,1691179742.156 [DAT](INFO): set transmit power to 8
2023-08-04T20:09:02.156Z,1691179742.156 [DAT](INFO): setting local address to 10
2023-08-04T20:09:02.407Z,1691179742.407 [DAT](INFO): DAT read: user:4>

2023-08-04T20:09:02.407Z,1691179742.407 [DAT](INFO): DAT read: LocalAddr       | 10          

2023-08-04T20:09:02.408Z,1691179742.408 [DAT](INFO): set local address to 10
2023-08-04T20:09:02.409Z,1691179742.409 [DAT](INFO): Setting time to: 20:9:2 And date to:8/4/2023
2023-08-04T20:09:02.660Z,1691179742.660 [DAT](INFO): DAT read: user:5>

2023-08-04T20:09:02.663Z,1691179742.663 [DAT](INFO): DAT read: Fri Aug 4, 2023  20:09:02  

2023-08-04T20:09:02.663Z,1691179742.663 [DAT](INFO): Local DAT time set to Fri Aug 4, 2023  20:09:02  

2023-08-04T20:09:11.331Z,1691179751.331 [NAL9602](INFO): Powering up NAL9602
2023-08-04T20:09:22.239Z,1691179762.239 [NAL9602](INFO): NAL9602 initialized
2023-08-04T20:09:27.933Z,1691179767.933 [SBIT](IMPORTANT): Beginning Startup BIT
2023-08-04T20:09:27.971Z,1691179767.971 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T20:09:38.931Z,1691179778.931 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009210
CHAN A1 (24V): 0.001951
CHAN A2 (12V): -0.007812
CHAN A3 (5V): -0.002857
CHAN B0 (3.3V): -0.000516
CHAN B1 (3.15aV): -0.000470
CHAN B2 (3.15bV): 0.000370
CHAN B3 (GND): 0.001798
OPEN: 0.005215
Full Scale: +/- 1 mA
2023-08-04T20:10:21.659Z,1691179821.659 [SBIT](IMPORTANT): SBIT PASSED
2023-08-04T20:10:21.659Z,1691179821.659 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-08-04T20:10:21.660Z,1691179821.660 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2023-08-04T20:10:21.661Z,1691179821.661 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2023-08-04T20:10:21.661Z,1691179821.661 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2023-08-04T20:10:21.661Z,1691179821.661 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=10 ampere_hour;

2023-08-04T20:10:21.661Z,1691179821.661 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=11.5 volt;

2023-08-04T20:10:21.661Z,1691179821.661 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=242.547845 cubic_centimeter;

2023-08-04T20:10:21.661Z,1691179821.661 [SBIT](IMPORTANT): VerticalControl.massDefault=6.326399 millimeter;

2023-08-04T20:10:21.661Z,1691179821.661 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool;

2023-08-04T20:10:22.048Z,1691179822.048 [MissionManager](IMPORTANT): Started mission Startup
2023-08-04T20:10:22.048Z,1691179822.048 [Startup] Running Loop=1
2023-08-04T20:10:22.048Z,1691179822.048 [Startup](DEBUG): Aggregate::initialize Startup
2023-08-04T20:10:22.048Z,1691179822.048 [Startup:A.GoToSurface] Running Loop=1
2023-08-04T20:10:22.048Z,1691179822.048 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-08-04T20:10:22.049Z,1691179822.049 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-08-04T20:10:22.050Z,1691179822.050 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-08-04T20:10:22.050Z,1691179822.050 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-08-04T20:10:22.050Z,1691179822.050 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-08-04T20:10:22.051Z,1691179822.051 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-08-04T20:10:22.052Z,1691179822.052 [Startup:StartupSatComms] Running Loop=1
2023-08-04T20:10:22.052Z,1691179822.052 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-08-04T20:10:22.052Z,1691179822.052 [Startup:StartupSatComms:A] Running Loop=1
2023-08-04T20:10:22.445Z,1691179822.445 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-08-04T20:11:22.236Z,1691179882.236 [Startup:StartupSatComms:A](INFO): Timed out from 2023-08-04T20:10:22.1Z
2023-08-04T20:11:22.236Z,1691179882.236 [Startup:StartupSatComms:A] Stopped
2023-08-04T20:11:22.236Z,1691179882.236 [Startup:StartupSatComms:B] Running Loop=1
2023-08-04T20:11:22.768Z,1691179882.768 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-08-04T20:11:32.546Z,1691179892.546 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230804T200832/Courier0000.lzma
2023-08-04T20:11:33.548Z,1691179893.548 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0000.lzma.bak
2023-08-04T20:11:33.548Z,1691179893.548 [DataOverHttps](INFO): SBD MOMSN=18518473
2023-08-04T20:11:42.768Z,1691179902.768 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-08-04T20:11:42.768Z,1691179902.768 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-08-04T20:11:42.796Z,1691179902.796 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-08-04T20:11:43.168Z,1691179903.168 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-08-04T20:11:43.168Z,1691179903.168 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-08-04T20:11:49.601Z,1691179909.601 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230802T232958/Express0029.lzma
2023-08-04T20:11:50.605Z,1691179910.605 [DataOverHttps](INFO): Moved sent file to Logs/20230802T232958/Express0029.lzma.bak
2023-08-04T20:11:50.606Z,1691179910.606 [DataOverHttps](INFO): SBD MOMSN=18518478
2023-08-04T20:12:07.075Z,1691179927.075 [DataOverHttps](INFO): Sending 1037 bytes from file Logs/20230804T200832/Express0001.lzma
2023-08-04T20:12:08.087Z,1691179928.087 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0001.lzma.bak
2023-08-04T20:12:08.088Z,1691179928.088 [DataOverHttps](INFO): SBD MOMSN=18518480
2023-08-04T20:12:09.424Z,1691179929.424 [Startup:StartupSatComms:B] Stopped
2023-08-04T20:12:09.424Z,1691179929.424 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-08-04T20:12:09.424Z,1691179929.424 [Startup:StartupSatComms] Stopped
2023-08-04T20:12:09.424Z,1691179929.424 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-08-04T20:12:09.425Z,1691179929.425 [Startup](INFO): Completed Startup
2023-08-04T20:12:09.425Z,1691179929.425 [MissionManager](INFO): Startup is completed.
2023-08-04T20:12:09.425Z,1691179929.425 [MissionManager](INFO): Uninitializing Mission Startup
2023-08-04T20:12:09.425Z,1691179929.425 [Startup] Stopped
2023-08-04T20:12:09.425Z,1691179929.425 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-08-04T20:12:09.426Z,1691179929.426 [Startup:A.GoToSurface] Stopped
2023-08-04T20:12:09.426Z,1691179929.426 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-08-04T20:12:09.816Z,1691179929.816 [MissionManager](IMPORTANT): Started mission Default
2023-08-04T20:12:09.816Z,1691179929.816 [Default] Running Loop=1
2023-08-04T20:12:09.817Z,1691179929.817 [Default](DEBUG): Aggregate::initialize Default
2023-08-04T20:12:09.817Z,1691179929.817 [Default:B.GoToSurface] Running Loop=1
2023-08-04T20:12:09.817Z,1691179929.817 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-08-04T20:12:09.817Z,1691179929.817 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-08-04T20:12:09.817Z,1691179929.817 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-08-04T20:12:09.830Z,1691179929.830 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-08-04T20:12:09.830Z,1691179929.830 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-08-04T20:12:09.830Z,1691179929.830 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-08-04T20:12:09.831Z,1691179929.831 [Default:A.Wait] Running Loop=1
2023-08-04T20:12:09.831Z,1691179929.831 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-08-04T20:12:23.149Z,1691179943.149 [Default:A.Wait](INFO): Done Waiting.
2023-08-04T20:12:23.149Z,1691179943.149 [Default:A.Wait] Stopped
2023-08-04T20:12:23.149Z,1691179943.149 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T20:12:23.557Z,1691179943.557 [Default:CheckIn] Running Loop=1
2023-08-04T20:12:23.557Z,1691179943.557 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T20:12:23.557Z,1691179943.557 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T20:12:23.965Z,1691179943.965 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-08-04T20:14:25.559Z,1691180065.559 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T20:14:43.746Z,1691180083.746 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-08-04T20:14:43.746Z,1691180083.746 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-08-04T20:14:43.781Z,1691180083.781 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-08-04T20:14:44.161Z,1691180084.161 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-08-04T20:14:44.161Z,1691180084.161 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-08-04T20:16:09.790Z,1691180169.790 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-08-04T20:16:09.794Z,1691180169.794 [BPC1](INFO): Received data from all battery sticks.
2023-08-04T20:17:23.732Z,1691180243.732 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-08-04T20:12:23.6Z
2023-08-04T20:17:23.732Z,1691180243.732 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T20:17:23.732Z,1691180243.732 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T20:17:24.136Z,1691180244.136 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-08-04T20:17:32.149Z,1691180252.149 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20230804T200832/Courier0004.lzma
2023-08-04T20:17:33.152Z,1691180253.152 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0004.lzma.bak
2023-08-04T20:17:33.152Z,1691180253.152 [DataOverHttps](INFO): SBD MOMSN=18518547
2023-08-04T20:17:44.805Z,1691180264.805 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-08-04T20:17:44.805Z,1691180264.805 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-08-04T20:17:44.824Z,1691180264.824 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-08-04T20:17:45.173Z,1691180265.173 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-08-04T20:17:45.173Z,1691180265.173 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-08-04T20:17:49.161Z,1691180269.161 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20230804T200832/Express0005.lzma
2023-08-04T20:17:50.163Z,1691180270.163 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0005.lzma.bak
2023-08-04T20:17:50.164Z,1691180270.164 [DataOverHttps](INFO): SBD MOMSN=18518549
2023-08-04T20:17:51.624Z,1691180271.624 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T20:17:51.624Z,1691180271.624 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T20:17:51.624Z,1691180271.624 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T20:17:53.074Z,1691180273.074 [CommandExec](IMPORTANT): got command failComponent
2023-08-04T20:17:53.075Z,1691180273.075 [CommandExec](IMPORTANT): Failed components:
2023-08-04T20:17:53.075Z,1691180273.075 [CommandExec](IMPORTANT): No failed Components.
2023-08-04T20:18:56.692Z,1691180336.692 [RDI_Pathfinder](ERROR): only read 1 of 4 data items for water velocity. Device response is::WS,-32768,-,-32768,-32768,V
2023-08-04T20:19:20.139Z,1691180360.139 [CommandExec](IMPORTANT): got command gfscan
2023-08-04T20:19:20.155Z,1691180360.155 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T20:19:24.119Z,1691180364.119 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-08-04T20:19:24.119Z,1691180364.119 [NAL9602] Data Fault, FailCount= 1
2023-08-04T20:19:24.119Z,1691180364.119 [NAL9602](ERROR): Data Fault
2023-08-04T20:19:24.179Z,1691180364.179 [CBIT](ERROR): Data Fault in component: NAL9602
2023-08-04T20:19:24.516Z,1691180364.516 [NAL9602](INFO): Powering down
2023-08-04T20:19:25.352Z,1691180365.352 [CBIT](INFO): Clearing failed state for component NAL9602
2023-08-04T20:19:25.352Z,1691180365.352 [NAL9602] No Fault, FailCount= 1
2023-08-04T20:19:31.035Z,1691180371.035 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008595
CHAN A1 (24V): 0.001607
CHAN A2 (12V): -0.007704
CHAN A3 (5V): -0.002563
CHAN B0 (3.3V): 0.000199
CHAN B1 (3.15aV): -0.000231
CHAN B2 (3.15bV): 0.000183
CHAN B3 (GND): 0.001807
OPEN: 0.005338
Full Scale: +/- 1 mA
2023-08-04T20:19:54.823Z,1691180394.823 [NAL9602](INFO): Powering up NAL9602
2023-08-04T20:20:04.305Z,1691180404.305 [CommandExec](IMPORTANT): got command get Onboard.Pressure pound_per_square_inch
2023-08-04T20:20:04.306Z,1691180404.306 [CommandExec](IMPORTANT): Onboard.Pressure 7.891306 psi
2023-08-04T20:20:05.731Z,1691180405.731 [NAL9602](INFO): NAL9602 initialized
2023-08-04T20:20:45.744Z,1691180445.744 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-08-04T20:20:45.744Z,1691180445.744 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-08-04T20:20:45.755Z,1691180445.755 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-08-04T20:20:46.175Z,1691180446.175 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-08-04T20:20:46.175Z,1691180446.175 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-08-04T20:20:56.514Z,1691180456.514 [CommandExec](IMPORTANT): got command get Onboard.Humidity
2023-08-04T20:20:56.515Z,1691180456.515 [CommandExec](IMPORTANT): Onboard.Humidity 24.075205 %
2023-08-04T20:22:52.223Z,1691180572.223 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T20:22:52.223Z,1691180572.223 [Default:CheckIn:C.Wait] Stopped
2023-08-04T20:22:52.223Z,1691180572.223 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T20:22:52.223Z,1691180572.223 [Default:CheckIn:D] Running Loop=1
2023-08-04T20:22:52.620Z,1691180572.620 [Default:CheckIn:D] Stopped
2023-08-04T20:22:52.620Z,1691180572.620 [Default:CheckIn:E] Running Loop=1
2023-08-04T20:22:53.041Z,1691180573.041 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.713391 min 
2023-08-04T20:22:53.041Z,1691180573.041 [Default:CheckIn:E] Stopped
2023-08-04T20:22:53.041Z,1691180573.041 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T20:22:53.042Z,1691180573.042 [Default:CheckIn] Stopped
2023-08-04T20:22:53.042Z,1691180573.042 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T20:22:53.042Z,1691180573.042 [Default:CheckIn](INFO): Running loop #2
2023-08-04T20:22:53.042Z,1691180573.042 [Default:CheckIn] Running Loop=2
2023-08-04T20:22:53.042Z,1691180573.042 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T20:22:53.042Z,1691180573.042 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T20:23:46.777Z,1691180626.777 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-08-04T20:23:46.777Z,1691180626.777 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-08-04T20:23:46.808Z,1691180626.808 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-08-04T20:23:47.176Z,1691180627.176 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-08-04T20:23:47.177Z,1691180627.177 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-08-04T20:26:47.746Z,1691180807.746 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-08-04T20:26:47.746Z,1691180807.746 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-08-04T20:26:47.760Z,1691180807.760 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-08-04T20:26:48.169Z,1691180808.169 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-08-04T20:26:48.169Z,1691180808.169 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2023-08-04T20:27:53.211Z,1691180873.211 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-08-04T20:22:53.0Z
2023-08-04T20:27:53.211Z,1691180873.211 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T20:27:53.211Z,1691180873.211 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T20:28:00.093Z,1691180880.093 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230804T200832/Courier0007.lzma
2023-08-04T20:28:01.095Z,1691180881.095 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0007.lzma.bak
2023-08-04T20:28:01.096Z,1691180881.096 [DataOverHttps](INFO): SBD MOMSN=18518571
2023-08-04T20:28:17.514Z,1691180897.514 [DataOverHttps](INFO): Sending 510 bytes from file Logs/20230804T200832/Express0008.lzma
2023-08-04T20:28:18.515Z,1691180898.515 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0008.lzma.bak
2023-08-04T20:28:18.516Z,1691180898.516 [DataOverHttps](INFO): SBD MOMSN=18518574
2023-08-04T20:28:19.883Z,1691180899.883 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T20:28:19.883Z,1691180899.883 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T20:28:19.883Z,1691180899.883 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T20:29:48.759Z,1691180988.759 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2023-08-04T20:29:48.759Z,1691180988.759 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-08-04T20:29:48.770Z,1691180988.770 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-08-04T20:29:49.163Z,1691180989.163 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-08-04T20:29:49.163Z,1691180989.163 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2023-08-04T20:30:07.307Z,1691181007.307 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-08-04T20:30:07.307Z,1691181007.307 [NAL9602] Data Fault, FailCount= 2
2023-08-04T20:30:07.307Z,1691181007.307 [NAL9602](ERROR): Data Fault
2023-08-04T20:30:07.326Z,1691181007.326 [CBIT](ERROR): Data Fault in component: NAL9602
2023-08-04T20:30:07.707Z,1691181007.707 [NAL9602](INFO): Powering down
2023-08-04T20:30:08.587Z,1691181008.587 [CBIT](INFO): Clearing failed state for component NAL9602
2023-08-04T20:30:08.587Z,1691181008.587 [NAL9602] No Fault, FailCount= 2
2023-08-04T20:30:38.011Z,1691181038.011 [NAL9602](INFO): Powering up NAL9602
2023-08-04T20:30:48.917Z,1691181048.917 [NAL9602](INFO): NAL9602 initialized
2023-08-04T20:31:11.854Z,1691181071.854 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:31:13.862Z,1691181073.862 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.242447
2023-08-04T20:31:46.994Z,1691181106.994 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:32:22.134Z,1691181142.134 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:32:49.743Z,1691181169.743 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2023-08-04T20:32:49.743Z,1691181169.743 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-08-04T20:32:49.755Z,1691181169.755 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-08-04T20:32:50.164Z,1691181170.164 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-08-04T20:32:50.164Z,1691181170.164 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2023-08-04T20:32:57.282Z,1691181177.282 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:33:20.444Z,1691181200.444 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T20:33:20.444Z,1691181200.444 [Default:CheckIn:C.Wait] Stopped
2023-08-04T20:33:20.445Z,1691181200.445 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T20:33:20.445Z,1691181200.445 [Default:CheckIn:D] Running Loop=1
2023-08-04T20:33:20.896Z,1691181200.896 [Default:CheckIn:D] Stopped
2023-08-04T20:33:20.896Z,1691181200.896 [Default:CheckIn:E] Running Loop=1
2023-08-04T20:33:21.271Z,1691181201.271 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.184654 min 
2023-08-04T20:33:21.271Z,1691181201.271 [Default:CheckIn:E] Stopped
2023-08-04T20:33:21.272Z,1691181201.272 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T20:33:21.272Z,1691181201.272 [Default:CheckIn] Stopped
2023-08-04T20:33:21.272Z,1691181201.272 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T20:33:21.272Z,1691181201.272 [Default:CheckIn](INFO): Running loop #3
2023-08-04T20:33:21.272Z,1691181201.272 [Default:CheckIn] Running Loop=3
2023-08-04T20:33:21.272Z,1691181201.272 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T20:33:21.272Z,1691181201.272 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T20:33:32.422Z,1691181212.422 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:34:07.562Z,1691181247.562 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:34:42.702Z,1691181282.702 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:35:17.850Z,1691181317.850 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:35:50.751Z,1691181350.751 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2023-08-04T20:35:50.751Z,1691181350.751 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-08-04T20:35:50.786Z,1691181350.786 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-08-04T20:35:51.173Z,1691181351.173 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-08-04T20:35:51.173Z,1691181351.173 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2023-08-04T20:35:52.998Z,1691181352.998 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:36:28.150Z,1691181388.150 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:37:03.290Z,1691181423.290 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:37:38.434Z,1691181458.434 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:38:13.574Z,1691181493.574 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:38:21.424Z,1691181501.424 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-08-04T20:33:21.3Z
2023-08-04T20:38:21.424Z,1691181501.424 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T20:38:21.424Z,1691181501.424 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T20:38:39.669Z,1691181519.669 [NAL9602](INFO): SBD MO Status=1, MOMSN=29168, MT Status=0, MTMSN=0
2023-08-04T20:38:39.718Z,1691181519.718 [NAL9602](INFO): Sent 39 bytes from file Logs/20230804T200832/Courier0010.lzma
2023-08-04T20:38:39.718Z,1691181519.718 [NAL9602](INFO): Packets left to send: 0
2023-08-04T20:38:48.746Z,1691181528.746 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:38:49.049Z,1691181529.049 [NAL9602](INFO): SBD MO Status=1, MOMSN=29169, MT Status=0, MTMSN=0
2023-08-04T20:38:49.098Z,1691181529.098 [NAL9602](INFO): Sent 151 bytes from file Logs/20230804T200832/Express0011.lzma
2023-08-04T20:38:49.098Z,1691181529.098 [NAL9602](INFO): Packets left to send: 0
2023-08-04T20:38:51.877Z,1691181531.877 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2023-08-04T20:38:51.877Z,1691181531.877 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-08-04T20:38:51.888Z,1691181531.888 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-08-04T20:38:52.298Z,1691181532.298 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-08-04T20:38:52.298Z,1691181532.298 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2023-08-04T20:38:56.725Z,1691181536.725 [NAL9602](INFO): SBD MO Status=0, MOMSN=29170, MT Status=0, MTMSN=0
2023-08-04T20:38:56.824Z,1691181536.824 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T20:38:56.825Z,1691181536.825 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T20:38:56.825Z,1691181536.825 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T20:39:23.898Z,1691181563.898 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:39:29.074Z,1691181569.074 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,   +10,  -14,A
2023-08-04T20:39:36.721Z,1691181576.721 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203935.00,A,3648.16561,N,12147.28004,W,0.058,0.00,040823,,,A*71
2023-08-04T20:39:36.724Z,1691181576.724 [NAL9602](INFO): GPS fix at 20230804T203935: (36.802760, -121.788001)
2023-08-04T20:39:59.050Z,1691181599.050 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:40:09.447Z,1691181609.447 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T20:40:34.190Z,1691181634.190 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:41:09.330Z,1691181669.330 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:41:44.470Z,1691181704.470 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:42:19.610Z,1691181739.610 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:42:54.750Z,1691181774.750 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:43:29.902Z,1691181809.902 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:43:57.333Z,1691181837.333 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T20:43:57.334Z,1691181837.334 [Default:CheckIn:C.Wait] Stopped
2023-08-04T20:43:57.334Z,1691181837.334 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T20:43:57.334Z,1691181837.334 [Default:CheckIn:D] Running Loop=1
2023-08-04T20:43:57.773Z,1691181837.773 [Default:CheckIn:D] Stopped
2023-08-04T20:43:57.773Z,1691181837.773 [Default:CheckIn:E] Running Loop=1
2023-08-04T20:43:58.155Z,1691181838.155 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.799272 min 
2023-08-04T20:43:58.156Z,1691181838.156 [Default:CheckIn:E] Stopped
2023-08-04T20:43:58.156Z,1691181838.156 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T20:43:58.156Z,1691181838.156 [Default:CheckIn] Stopped
2023-08-04T20:43:58.156Z,1691181838.156 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T20:43:58.156Z,1691181838.156 [Default:CheckIn](INFO): Running loop #4
2023-08-04T20:43:58.156Z,1691181838.156 [Default:CheckIn] Running Loop=4
2023-08-04T20:43:58.156Z,1691181838.156 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T20:43:58.156Z,1691181838.156 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T20:44:00.133Z,1691181840.133 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204358.00,A,3648.16992,N,12147.28242,W,1.575,50.95,040823,,,A*45
2023-08-04T20:44:00.135Z,1691181840.135 [NAL9602](INFO): GPS fix at 20230804T204358: (36.802832, -121.788040)
2023-08-04T20:44:00.198Z,1691181840.198 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T20:44:00.198Z,1691181840.198 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T20:44:05.055Z,1691181845.055 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:44:40.214Z,1691181880.214 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:45:15.362Z,1691181915.362 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:45:50.518Z,1691181950.518 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:46:06.284Z,1691181966.284 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T20:46:06.284Z,1691181966.284 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T20:46:19.716Z,1691181979.716 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T20:46:19.716Z,1691181979.716 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T20:46:25.666Z,1691181985.666 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:46:58.734Z,1691182018.734 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003097
2023-08-04T20:47:06.638Z,1691182026.638 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20230804T200832/Courier0013.lzma
2023-08-04T20:47:07.639Z,1691182027.639 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0013.lzma.bak
2023-08-04T20:47:07.640Z,1691182027.640 [DataOverHttps](INFO): SBD MOMSN=18518668
2023-08-04T20:47:25.562Z,1691182045.562 [DataOverHttps](INFO): Sending 259 bytes from file Logs/20230804T200832/Express0014.lzma
2023-08-04T20:47:26.564Z,1691182046.564 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0014.lzma.bak
2023-08-04T20:47:26.564Z,1691182046.564 [DataOverHttps](INFO): SBD MOMSN=18518671
2023-08-04T20:47:28.015Z,1691182048.015 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T20:47:28.015Z,1691182048.015 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T20:47:28.015Z,1691182048.015 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T20:47:29.207Z,1691182049.207 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T20:47:44.378Z,1691182064.378 [CommandExec](IMPORTANT): got command gfscan
2023-08-04T20:47:44.607Z,1691182064.607 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T20:47:55.512Z,1691182075.512 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.000796
CHAN A1 (24V): 0.015641
CHAN A2 (12V): 0.001001
CHAN A3 (5V): 0.001094
CHAN B0 (3.3V): 0.002683
CHAN B1 (3.15aV): 0.002347
CHAN B2 (3.15bV): 0.002293
CHAN B3 (GND): 0.002016
OPEN: 0.006482
Full Scale: +/- 1 mA
2023-08-04T20:49:57.603Z,1691182197.603 [DataOverHttps](IMPORTANT): SBD MTMSN=20230804T204956
2023-08-04T20:50:05.274Z,1691182205.274 [DataOverHttps](INFO): Received command: run Maintenance/tank_ballast_and_trim.tl
2023-08-04T20:50:05.357Z,1691182205.357 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/tank_ballast_and_trim.tl
2023-08-04T20:50:05.357Z,1691182205.357 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/tank_ballast_and_trim.tl
2023-08-04T20:50:05.358Z,1691182205.358 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file ./Missions/Maintenance/tank_ballast_and_trim.tx
2023-08-04T20:50:05.427Z,1691182205.427 [MissionManager](INFO): DefineArg ballast_and_trim.MissionTimeout = 120.000000 min
2023-08-04T20:50:05.430Z,1691182205.430 [MissionManager](INFO): DefineArg ballast_and_trim.SkipComms = 0 bool
2023-08-04T20:50:05.433Z,1691182205.433 [MissionManager](INFO): DefineArg ballast_and_trim.Depth1 = 7.000000 m
2023-08-04T20:50:05.436Z,1691182205.436 [MissionManager](INFO): DefineArg ballast_and_trim.Depth2 = nan m
2023-08-04T20:50:05.439Z,1691182205.439 [MissionManager](INFO): DefineArg ballast_and_trim.DepthDeadband = 0.100000 m
2023-08-04T20:50:05.441Z,1691182205.441 [MissionManager](INFO): DefineArg ballast_and_trim.SurfaceThreshold = 2.500000 m
2023-08-04T20:50:05.444Z,1691182205.444 [MissionManager](INFO): DefineArg ballast_and_trim.MaxWaitOnSurface = 20.000000 min
2023-08-04T20:50:05.447Z,1691182205.447 [MissionManager](INFO): DefineArg ballast_and_trim.SettleTime = 10.000000 min
2023-08-04T20:50:05.450Z,1691182205.450 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationTimeout = 45.000000 min
2023-08-04T20:50:05.453Z,1691182205.453 [MissionManager](INFO): DefineArg ballast_and_trim.MinEstimationTime = 10.000000 min
2023-08-04T20:50:05.472Z,1691182205.472 [MissionManager](INFO): DefineArg ballast_and_trim.MassEstimationErrorBound = 0.250000 mm
2023-08-04T20:50:05.475Z,1691182205.475 [MissionManager](INFO): DefineArg ballast_and_trim.BuoyEstimationErrorBound = 15.000000 cc
2023-08-04T20:50:05.486Z,1691182205.486 [MissionManager](INFO): DefineArg ballast_and_trim.EstimationConfidence = 99.900002 %
2023-08-04T20:50:05.489Z,1691182205.489 [MissionManager](INFO): DefineArg ballast_and_trim.WaitToFloat = 5.000000 min
2023-08-04T20:50:05.489Z,1691182205.489 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/Science.tl
2023-08-04T20:50:05.494Z,1691182205.494 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/Science.tx
2023-08-04T20:50:06.145Z,1691182206.145 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectChlActive = 0 bool
2023-08-04T20:50:06.149Z,1691182206.149 [MissionManager](INFO): DefineArg ballast_and_trim:Science.TimeWindowPeakReport = nan min
2023-08-04T20:50:06.152Z,1691182206.152 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestChlPeakReportActive = 0 bool
2023-08-04T20:50:06.154Z,1691182206.154 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestSaltPeakReportActive = 0 bool
2023-08-04T20:50:06.157Z,1691182206.157 [MissionManager](INFO): DefineArg ballast_and_trim:Science.HighestOilPeakReportActive = 0 bool
2023-08-04T20:50:06.159Z,1691182206.159 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PatchTracking = 0 bool
2023-08-04T20:50:06.162Z,1691182206.162 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DetectTrough = 0 bool
2023-08-04T20:50:06.165Z,1691182206.165 [MissionManager](INFO): DefineArg ballast_and_trim:Science.FilterWidthHorizontal = 3.000000 count
2023-08-04T20:50:06.188Z,1691182206.188 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesSlidingwindow = 100.000000 count
2023-08-04T20:50:06.192Z,1691182206.192 [MissionManager](INFO): DefineArg ballast_and_trim:Science.OffPeakFractionHorizontal = 80.000000 %
2023-08-04T20:50:06.202Z,1691182206.202 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectNO3Active = 0 bool
2023-08-04T20:50:06.205Z,1691182206.205 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectOilActive = 0 bool
2023-08-04T20:50:06.212Z,1691182206.212 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectFDOMActive = 0 bool
2023-08-04T20:50:06.216Z,1691182206.216 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDetectSalinityActive = 0 bool
2023-08-04T20:50:06.226Z,1691182206.226 [MissionManager](INFO): DefineArg ballast_and_trim:Science.UpwardDerivativeOfTemperatureActive = 0 bool
2023-08-04T20:50:06.234Z,1691182206.234 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledAanderaaO2 = 0 bool
2023-08-04T20:50:06.237Z,1691182206.237 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledNeilBrown = 0 bool
2023-08-04T20:50:06.245Z,1691182206.245 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledSeabird = 1 bool
2023-08-04T20:50:06.260Z,1691182206.260 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsBB2FL = 1 bool
2023-08-04T20:50:06.268Z,1691182206.268 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsSeaOWL_UV_A = 0 bool
2023-08-04T20:50:06.271Z,1691182206.271 [MissionManager](INFO): DefineArg ballast_and_trim:Science.EnabledWetLabsUBAT = 1 bool
2023-08-04T20:50:06.290Z,1691182206.290 [MissionManager](INFO): DefineArg ballast_and_trim:Science.LowPassWindowLength = 20.000000 count
2023-08-04T20:50:06.298Z,1691182206.298 [MissionManager](INFO): DefineArg ballast_and_trim:Science.MedianFilterLen = 5.000000 count
2023-08-04T20:50:06.300Z,1691182206.300 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakShallowBound = nan m
2023-08-04T20:50:06.304Z,1691182206.304 [MissionManager](INFO): DefineArg ballast_and_trim:Science.PeakDeepBound = nan m
2023-08-04T20:50:06.314Z,1691182206.314 [MissionManager](INFO): DefineArg ballast_and_trim:Science.DepChangeThreshForAttitudeFlip = 2.000000 m
2023-08-04T20:50:06.317Z,1691182206.317 [MissionManager](INFO): DefineArg ballast_and_trim:Science.ChlThreshTriggerActive = 0 bool
2023-08-04T20:50:06.324Z,1691182206.324 [MissionManager](INFO): DefineArg ballast_and_trim:Science.ChlLowerThresh = nan ug/l
2023-08-04T20:50:06.328Z,1691182206.328 [MissionManager](INFO): DefineArg ballast_and_trim:Science.ChlUpperThresh = nan ug/l
2023-08-04T20:50:06.340Z,1691182206.340 [MissionManager](INFO): DefineArg ballast_and_trim:Science.NumProfilesThresh = 5.000000 count
2023-08-04T20:50:06.344Z,1691182206.344 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChl = nan ug/l
2023-08-04T20:50:06.391Z,1691182206.391 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlDepth = nan m
2023-08-04T20:50:06.399Z,1691182206.399 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlTemperature = nan degC
2023-08-04T20:50:06.418Z,1691182206.418 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLatitude = nan arcdeg
2023-08-04T20:50:06.421Z,1691182206.421 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakChlLongitude = nan arcdeg
2023-08-04T20:50:06.432Z,1691182206.432 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3 = nan umol/l
2023-08-04T20:50:06.436Z,1691182206.436 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Depth = nan m
2023-08-04T20:50:06.448Z,1691182206.448 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Latitude = nan arcdeg
2023-08-04T20:50:06.455Z,1691182206.455 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakNO3Longitude = nan arcdeg
2023-08-04T20:50:06.462Z,1691182206.462 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOil = nan kg/m3
2023-08-04T20:50:06.465Z,1691182206.465 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilDepth = nan m
2023-08-04T20:50:06.476Z,1691182206.476 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLatitude = nan arcdeg
2023-08-04T20:50:06.479Z,1691182206.479 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakOilLongitude = nan arcdeg
2023-08-04T20:50:06.486Z,1691182206.486 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOM = nan ppb
2023-08-04T20:50:06.489Z,1691182206.489 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMDepth = nan m
2023-08-04T20:50:06.502Z,1691182206.502 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMTemperature = nan degC
2023-08-04T20:50:06.505Z,1691182206.505 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLatitude = nan arcdeg
2023-08-04T20:50:06.518Z,1691182206.518 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakFDOMLongitude = nan arcdeg
2023-08-04T20:50:06.521Z,1691182206.521 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchFDOMDistance = nan m
2023-08-04T20:50:06.528Z,1691182206.528 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSalt = nan psu
2023-08-04T20:50:06.532Z,1691182206.532 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltDepth = nan m
2023-08-04T20:50:06.543Z,1691182206.543 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltTemperature = nan degC
2023-08-04T20:50:06.550Z,1691182206.550 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLatitude = nan arcdeg
2023-08-04T20:50:06.558Z,1691182206.558 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PeakSaltLongitude = nan arcdeg
2023-08-04T20:50:06.561Z,1691182206.561 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChl = nan ug/l
2023-08-04T20:50:06.568Z,1691182206.568 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDepth = nan m
2023-08-04T20:50:06.575Z,1691182206.575 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLatitude = nan arcdeg
2023-08-04T20:50:06.586Z,1691182206.586 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlLongitude = nan arcdeg
2023-08-04T20:50:06.598Z,1691182206.598 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchChlDistance = nan m
2023-08-04T20:50:06.601Z,1691182206.601 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSalt = nan psu
2023-08-04T20:50:06.608Z,1691182206.608 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDepth = nan m
2023-08-04T20:50:06.612Z,1691182206.612 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLatitude = nan arcdeg
2023-08-04T20:50:06.623Z,1691182206.623 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltLongitude = nan arcdeg
2023-08-04T20:50:06.631Z,1691182206.631 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchSaltDistance = nan m
2023-08-04T20:50:06.638Z,1691182206.638 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOil = nan psu
2023-08-04T20:50:06.641Z,1691182206.641 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDepth = nan m
2023-08-04T20:50:06.652Z,1691182206.652 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLatitude = nan arcdeg
2023-08-04T20:50:06.656Z,1691182206.656 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilLongitude = nan arcdeg
2023-08-04T20:50:06.671Z,1691182206.671 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.PatchOilDistance = nan m
2023-08-04T20:50:06.678Z,1691182206.678 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.TriggeredOnChl = 0 bool
2023-08-04T20:50:06.681Z,1691182206.681 [MissionManager](INFO): DefineOutput ballast_and_trim:Science.ChlTriggering = nan ug/l
2023-08-04T20:50:06.745Z,1691182206.745 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-08-04T20:50:06.816Z,1691182206.816 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2023-08-04T20:50:06.855Z,1691182206.855 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-08-04T20:50:06.869Z,1691182206.869 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-08-04T20:50:06.935Z,1691182206.935 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2023-08-04T20:50:06.973Z,1691182206.973 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-08-04T20:50:07.001Z,1691182207.001 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth.
2023-08-04T20:50:07.025Z,1691182207.025 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Construct PeakDetectHorizontal.
2023-08-04T20:50:07.061Z,1691182207.061 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect](DEBUG): Construct ValueDetect.
2023-08-04T20:50:07.076Z,1691182207.076 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2023-08-04T20:50:07.076Z,1691182207.076 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/BackseatDriver.tx
2023-08-04T20:50:07.107Z,1691182207.107 [MissionManager](INFO): DefineArg ballast_and_trim:BackseatDriver.EnableBackseat = 0 bool
2023-08-04T20:50:07.114Z,1691182207.114 [ballast_and_trim:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2023-08-04T20:50:07.117Z,1691182207.117 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BallastAndTrim.tl
2023-08-04T20:50:07.122Z,1691182207.122 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/BallastAndTrim.tx
2023-08-04T20:50:07.385Z,1691182207.385 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepth = 25.000000 m
2023-08-04T20:50:07.393Z,1691182207.393 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSpeed = 0.000000 m/s
2023-08-04T20:50:07.400Z,1691182207.400 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthRate = 0.400000 m/s
2023-08-04T20:50:07.414Z,1691182207.414 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachPitchLimit = 20.000000 arcdeg
2023-08-04T20:50:07.422Z,1691182207.422 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachSettleTimePreDive = 0.000000 min
2023-08-04T20:50:07.425Z,1691182207.425 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = 20.000000 min
2023-08-04T20:50:07.432Z,1691182207.432 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = 10.000000 min
2023-08-04T20:50:07.435Z,1691182207.435 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = 45.000000 min
2023-08-04T20:50:07.446Z,1691182207.446 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = 10.000000 min
2023-08-04T20:50:07.449Z,1691182207.449 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = 0.250000 mm
2023-08-04T20:50:07.456Z,1691182207.456 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = 15.000000 cc
2023-08-04T20:50:07.461Z,1691182207.461 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = 99.900002 %
2023-08-04T20:50:07.476Z,1691182207.476 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = 1.000000 m
2023-08-04T20:50:07.483Z,1691182207.483 [MissionManager](INFO): DefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertMassDeadband = 0.250000 mm
2023-08-04T20:50:07.515Z,1691182207.515 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Construct.
2023-08-04T20:50:07.536Z,1691182207.536 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Construct Buoyancy.
2023-08-04T20:50:07.551Z,1691182207.551 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Construct.
2023-08-04T20:50:07.610Z,1691182207.610 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Construct Wait.
2023-08-04T20:50:07.622Z,1691182207.622 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Construct.
2023-08-04T20:50:07.625Z,1691182207.625 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Construct.
2023-08-04T20:50:07.658Z,1691182207.658 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch:A_Timeout:B.Execute](DEBUG): Construct Execute.
2023-08-04T20:50:07.661Z,1691182207.661 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Construct.
2023-08-04T20:50:07.668Z,1691182207.668 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Construct.
2023-08-04T20:50:07.689Z,1691182207.689 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Construct Wait.
2023-08-04T20:50:07.715Z,1691182207.715 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](DEBUG): Construct BallastAndTrim.
2023-08-04T20:50:07.756Z,1691182207.756 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertDepthDeadband = reader:ballast_and_trim.DepthDeadband
2023-08-04T20:50:07.762Z,1691182207.762 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertApproachDepthTimeout = reader:ballast_and_trim.MaxWaitOnSurface
2023-08-04T20:50:07.764Z,1691182207.764 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.InsertSettleTime = reader:ballast_and_trim.SettleTime
2023-08-04T20:50:07.770Z,1691182207.770 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstTimeout = reader:ballast_and_trim.EstimationTimeout
2023-08-04T20:50:07.772Z,1691182207.772 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MinEstTime = reader:ballast_and_trim.MinEstimationTime
2023-08-04T20:50:07.778Z,1691182207.778 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.MassEstErrorBound = reader:ballast_and_trim.MassEstimationErrorBound
2023-08-04T20:50:07.782Z,1691182207.782 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.BuoyEstErrorBound = reader:ballast_and_trim.BuoyEstimationErrorBound
2023-08-04T20:50:07.784Z,1691182207.784 [MissionManager](INFO): RedefineArg ballast_and_trim:RunBallastAndTrim:BallastAndTrim.EstConfidence = reader:ballast_and_trim.EstimationConfidence
2023-08-04T20:50:07.809Z,1691182207.809 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Construct Buoyancy.
2023-08-04T20:50:07.820Z,1691182207.820 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Construct Wait.
2023-08-04T20:50:07.877Z,1691182207.877 [MissionManager](DEBUG): 
mission ballast_and_trim {
  arguments {
    MissionTimeout = 120 minute
      """
      Maximum duration of mission
      """

    SkipComms = false
      """
      Skip communications at start of mission.
      """

    Depth1 = 7 meter

    Depth2 = NaN meter

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

    SurfaceThreshold = 2.5 meter
      """
      Surface threshold depth.
      """

    MaxWaitOnSurface = 20 minute
      """
      Maximum wait time for the vehicle to go under the surface (i.e., reach
      the surface threshold depth).
      """

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

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

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

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

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

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

    WaitToFloat = 5 minute
  }

  timeout duration=MissionTimeout

  insert Insert/Science.tl

  insert Insert/BackseatDriver.tl

  aggregate RunBallastAndTrim {
    run in sequence

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

    aggregate Depth1 {
      run in sequence

      break if ( isNaN ( Depth1 ) )

      assign in sequence BallastAndTrim:InsertDepth = Depth1

      call refId="BallastAndTrim"
    }

    aggregate Depth2 {
      run in sequence

      break if ( isNaN ( Depth2 ) )

      assign in sequence BallastAndTrim:InsertDepth = Depth1

      call refId="BallastAndTrim"
    }
  }

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

    run in sequence

    break if (
      Universal:depth < Control:VerticalControl.surfaceThreshold
    )

    behavior Guidance:Buoyancy {
      run in parallel

      set position = Control:VerticalControl.buoyancyDefault
    }

    behavior Guidance:Wait {
      run in sequence

      set duration = WaitToFloat
    }
  }
}


2023-08-04T20:50:07.890Z,1691182207.890 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/tank_ballast_and_trim.tl
2023-08-04T20:50:08.003Z,1691182208.003 [Default] Stopped
2023-08-04T20:50:08.003Z,1691182208.003 [Default](DEBUG): Aggregate::uninitialize Default
2023-08-04T20:50:08.003Z,1691182208.003 [Default:B.GoToSurface] Stopped
2023-08-04T20:50:08.003Z,1691182208.003 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-08-04T20:50:08.003Z,1691182208.003 [Default:CheckIn] Stopped
2023-08-04T20:50:08.003Z,1691182208.003 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T20:50:08.003Z,1691182208.003 [Default:CheckIn:C.Wait] Stopped
2023-08-04T20:50:08.004Z,1691182208.004 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T20:50:08.004Z,1691182208.004 [MissionManager](IMPORTANT): Started mission ballast_and_trim
2023-08-04T20:50:08.004Z,1691182208.004 [ballast_and_trim] Running Loop=1
2023-08-04T20:50:08.004Z,1691182208.004 [ballast_and_trim](DEBUG): Aggregate::initialize ballast_and_trim
2023-08-04T20:50:08.004Z,1691182208.004 [ballast_and_trim:Science] Running Loop=1
2023-08-04T20:50:08.004Z,1691182208.004 [ballast_and_trim:Science](DEBUG): Aggregate::initialize ballast_and_trim:Science
2023-08-04T20:50:08.004Z,1691182208.004 [ballast_and_trim:Science:A] Running Loop=1
2023-08-04T20:50:08.004Z,1691182208.004 [ballast_and_trim:Science:B] Running Loop=1
2023-08-04T20:50:08.004Z,1691182208.004 [ballast_and_trim:Science:C] Running Loop=1
2023-08-04T20:50:08.004Z,1691182208.004 [ballast_and_trim:Science:D] Running Loop=1
2023-08-04T20:50:08.005Z,1691182208.005 [ballast_and_trim:Science:E] Running Loop=1
2023-08-04T20:50:08.005Z,1691182208.005 [ballast_and_trim:Science:F] Running Loop=1
2023-08-04T20:50:08.005Z,1691182208.005 [ballast_and_trim:Science:Read_Oil] Running Loop=1
2023-08-04T20:50:08.005Z,1691182208.005 [ballast_and_trim:Science:PeakDetectChl] Running Loop=1
2023-08-04T20:50:08.005Z,1691182208.005 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectChl
2023-08-04T20:50:08.005Z,1691182208.005 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1
2023-08-04T20:50:08.005Z,1691182208.005 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-08-04T20:50:08.011Z,1691182208.011 [ballast_and_trim:Science:HighestChlPeakReport] Running Loop=1
2023-08-04T20:50:08.012Z,1691182208.012 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestChlPeakReport
2023-08-04T20:50:08.012Z,1691182208.012 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Running Loop=1
2023-08-04T20:50:08.012Z,1691182208.012 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2023-08-04T20:50:08.012Z,1691182208.012 [ballast_and_trim:Science:PeakDetectNO3] Running Loop=1
2023-08-04T20:50:08.012Z,1691182208.012 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectNO3
2023-08-04T20:50:08.012Z,1691182208.012 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1
2023-08-04T20:50:08.013Z,1691182208.013 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-08-04T20:50:08.015Z,1691182208.015 [ballast_and_trim:Science:PeakDetectOil] Running Loop=1
2023-08-04T20:50:08.015Z,1691182208.015 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectOil
2023-08-04T20:50:08.015Z,1691182208.015 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Running Loop=1
2023-08-04T20:50:08.015Z,1691182208.015 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-08-04T20:50:08.017Z,1691182208.017 [ballast_and_trim:Science:HighestOilPeakReport] Running Loop=1
2023-08-04T20:50:08.017Z,1691182208.017 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestOilPeakReport
2023-08-04T20:50:08.026Z,1691182208.026 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Running Loop=1
2023-08-04T20:50:08.026Z,1691182208.026 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2023-08-04T20:50:08.026Z,1691182208.026 [ballast_and_trim:Science:PeakDetectFDOM] Running Loop=1
2023-08-04T20:50:08.026Z,1691182208.026 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectFDOM
2023-08-04T20:50:08.026Z,1691182208.026 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Running Loop=1
2023-08-04T20:50:08.027Z,1691182208.027 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-08-04T20:50:08.028Z,1691182208.028 [ballast_and_trim:Science:PeakDetectSalinity] Running Loop=1
2023-08-04T20:50:08.028Z,1691182208.028 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::initialize ballast_and_trim:Science:PeakDetectSalinity
2023-08-04T20:50:08.028Z,1691182208.028 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Running Loop=1
2023-08-04T20:50:08.028Z,1691182208.028 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Initialize.
2023-08-04T20:50:08.031Z,1691182208.031 [ballast_and_trim:Science:HighestSaltPeakReport] Running Loop=1
2023-08-04T20:50:08.031Z,1691182208.031 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::initialize ballast_and_trim:Science:HighestSaltPeakReport
2023-08-04T20:50:08.031Z,1691182208.031 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Running Loop=1
2023-08-04T20:50:08.032Z,1691182208.032 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](INFO): Initialize.
2023-08-04T20:50:08.032Z,1691182208.032 [ballast_and_trim:Science:ChlThreshTrigger] Running Loop=1
2023-08-04T20:50:08.032Z,1691182208.032 [ballast_and_trim:Science:ChlThreshTrigger](DEBUG): Aggregate::initialize ballast_and_trim:Science:ChlThreshTrigger
2023-08-04T20:50:08.032Z,1691182208.032 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect] Running Loop=1
2023-08-04T20:50:08.032Z,1691182208.032 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect](INFO): Initialize.
2023-08-04T20:50:08.033Z,1691182208.033 [ballast_and_trim:Science:OceanCurrent] Running Loop=1
2023-08-04T20:50:08.033Z,1691182208.033 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::initialize ballast_and_trim:Science:OceanCurrent
2023-08-04T20:50:08.033Z,1691182208.033 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2023-08-04T20:50:08.033Z,1691182208.033 [ballast_and_trim:Science:OceanCurrent:A.](INFO): Initializing CurrentEstimator.
2023-08-04T20:50:08.033Z,1691182208.033 [ballast_and_trim:BackseatDriver] Running Loop=1
2023-08-04T20:50:08.033Z,1691182208.033 [ballast_and_trim:BackseatDriver](DEBUG): Aggregate::initialize ballast_and_trim:BackseatDriver
2023-08-04T20:50:08.042Z,1691182208.042 [ballast_and_trim:BackseatDriver:A.BackseatDriver] Running Loop=1
2023-08-04T20:50:08.042Z,1691182208.042 [ballast_and_trim:RunBallastAndTrim] Running Loop=1
2023-08-04T20:50:08.042Z,1691182208.042 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim
2023-08-04T20:50:08.042Z,1691182208.042 [ballast_and_trim:RunBallastAndTrim:Depth1] Running Loop=1
2023-08-04T20:50:08.042Z,1691182208.042 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1
2023-08-04T20:50:08.042Z,1691182208.042 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Running Loop=1
2023-08-04T20:50:08.043Z,1691182208.043 [ballast_and_trim:RunBallastAndTrim:Depth1:A] Stopped
2023-08-04T20:50:08.043Z,1691182208.043 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Running Loop=1
2023-08-04T20:50:08.043Z,1691182208.043 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2023-08-04T20:50:08.043Z,1691182208.043 [ballast_and_trim:BackseatDriver] Running Loop=1
2023-08-04T20:50:08.044Z,1691182208.044 [ballast_and_trim:Science] Running Loop=1
2023-08-04T20:50:08.045Z,1691182208.045 [ballast_and_trim:Science:ChlThreshTrigger] Stopped
2023-08-04T20:50:08.045Z,1691182208.045 [ballast_and_trim:Science:ChlThreshTrigger](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:ChlThreshTrigger
2023-08-04T20:50:08.045Z,1691182208.045 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect] Stopped
2023-08-04T20:50:08.045Z,1691182208.045 [ballast_and_trim:Science:ChlThreshTrigger:A.ValueDetect](DEBUG): Uninitialize.
2023-08-04T20:50:08.045Z,1691182208.045 [ballast_and_trim:Science:HighestSaltPeakReport] Stopped
2023-08-04T20:50:08.045Z,1691182208.045 [ballast_and_trim:Science:HighestSaltPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestSaltPeakReport
2023-08-04T20:50:08.045Z,1691182208.045 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal] Stopped
2023-08-04T20:50:08.045Z,1691182208.045 [ballast_and_trim:Science:HighestSaltPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2023-08-04T20:50:08.045Z,1691182208.045 [ballast_and_trim:Science:PeakDetectSalinity] Stopped
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:PeakDetectSalinity](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectSalinity
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth] Stopped
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:PeakDetectSalinity:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:PeakDetectFDOM] Stopped
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:PeakDetectFDOM](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectFDOM
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth] Stopped
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:PeakDetectFDOM:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:HighestOilPeakReport] Stopped
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:HighestOilPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestOilPeakReport
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal] Stopped
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:HighestOilPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2023-08-04T20:50:08.050Z,1691182208.050 [ballast_and_trim:Science:PeakDetectOil] Stopped
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:PeakDetectOil](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectOil
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth] Stopped
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:PeakDetectOil:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:PeakDetectNO3] Stopped
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:PeakDetectNO3](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectNO3
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:HighestChlPeakReport] Stopped
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:HighestChlPeakReport](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:HighestChlPeakReport
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal] Stopped
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:HighestChlPeakReport:A.PeakDetectHorizontal](DEBUG): Uninitialize.
2023-08-04T20:50:08.051Z,1691182208.051 [ballast_and_trim:Science:PeakDetectChl] Stopped
2023-08-04T20:50:08.052Z,1691182208.052 [ballast_and_trim:Science:PeakDetectChl](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:PeakDetectChl
2023-08-04T20:50:08.052Z,1691182208.052 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped
2023-08-04T20:50:08.052Z,1691182208.052 [ballast_and_trim:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize.
2023-08-04T20:50:08.052Z,1691182208.052 [ballast_and_trim:Science:OceanCurrent:A.] Running Loop=1
2023-08-04T20:50:08.052Z,1691182208.052 [ballast_and_trim:Science:Read_Oil] Stopped
2023-08-04T20:50:08.052Z,1691182208.052 [ballast_and_trim:Science:F] Running Loop=1
2023-08-04T20:50:08.054Z,1691182208.054 [ballast_and_trim:Science:F](DEBUG): Initialize ReadDataComponent to sense WetLabsUBAT.average_bioluminescence
2023-08-04T20:50:08.054Z,1691182208.054 [ballast_and_trim:Science:E] Running Loop=1
2023-08-04T20:50:08.055Z,1691182208.055 [ballast_and_trim:Science:E](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water
2023-08-04T20:50:08.055Z,1691182208.055 [ballast_and_trim:Science:D] Stopped
2023-08-04T20:50:08.055Z,1691182208.055 [ballast_and_trim:Science:C] Running Loop=1
2023-08-04T20:50:08.055Z,1691182208.055 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_temperature
2023-08-04T20:50:08.056Z,1691182208.056 [ballast_and_trim:Science:C](DEBUG): Initialize ReadDataComponent to sense CTD_Seabird.sea_water_salinity
2023-08-04T20:50:08.056Z,1691182208.056 [ballast_and_trim:Science:B] Running Loop=1
2023-08-04T20:50:08.057Z,1691182208.057 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature
2023-08-04T20:50:08.057Z,1691182208.057 [ballast_and_trim:Science:B](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity
2023-08-04T20:50:08.058Z,1691182208.058 [ballast_and_trim:Science:A] Stopped
2023-08-04T20:50:08.392Z,1691182208.392 [WetLabsBB2FL](INFO): Powering up
2023-08-04T20:50:08.410Z,1691182208.410 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Running Loop=1
2023-08-04T20:50:08.410Z,1691182208.410 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2023-08-04T20:50:08.411Z,1691182208.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2023-08-04T20:50:08.411Z,1691182208.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2023-08-04T20:50:08.411Z,1691182208.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2023-08-04T20:50:08.411Z,1691182208.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2023-08-04T20:50:08.411Z,1691182208.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2023-08-04T20:50:08.411Z,1691182208.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Running Loop=1
2023-08-04T20:50:08.413Z,1691182208.413 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F](INFO): Going to target depth. Speed set to 0.000000 m/s 
2023-08-04T20:50:08.413Z,1691182208.413 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:F] Stopped
2023-08-04T20:50:08.413Z,1691182208.413 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Running Loop=1
2023-08-04T20:50:08.413Z,1691182208.413 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2023-08-04T20:50:08.413Z,1691182208.413 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2023-08-04T20:50:08.413Z,1691182208.413 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Running Loop=1
2023-08-04T20:50:08.418Z,1691182208.418 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2023-08-04T20:50:08.418Z,1691182208.418 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Running Loop=1
2023-08-04T20:50:08.418Z,1691182208.418 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point](DEBUG): Initialize.
2023-08-04T20:50:08.418Z,1691182208.418 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Running Loop=1
2023-08-04T20:50:08.418Z,1691182208.418 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-08-04T20:50:08.418Z,1691182208.418 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Running Loop=1
2023-08-04T20:50:08.418Z,1691182208.418 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch](DEBUG): Initialize.
2023-08-04T20:50:08.419Z,1691182208.419 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Running Loop=1
2023-08-04T20:50:08.419Z,1691182208.419 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2023-08-04T20:50:08.419Z,1691182208.419 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Running Loop=1
2023-08-04T20:50:08.419Z,1691182208.419 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Running Loop=1
2023-08-04T20:50:08.419Z,1691182208.419 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Running Loop=1
2023-08-04T20:50:08.419Z,1691182208.419 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Running Loop=1
2023-08-04T20:50:08.420Z,1691182208.420 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Running Loop=1
2023-08-04T20:50:08.420Z,1691182208.420 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Running Loop=1
2023-08-04T20:50:08.571Z,1691182208.571 [WetLabsUBAT](INFO): Powering up
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A](INFO): Waiting for 0.000000 min while pumping down to neutral.
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:A] Stopped
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Running Loop=1
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Initialize Wait Component.
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold] Stopped
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:A.Point] Stopped
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy] Stopped
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:B.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ActuatorHold:C.Pitch] Stopped
2023-08-04T20:50:08.820Z,1691182208.820 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Running Loop=1
2023-08-04T20:50:09.223Z,1691182209.223 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](INFO): Done Waiting.
2023-08-04T20:50:09.223Z,1691182209.223 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait] Stopped
2023-08-04T20:50:09.223Z,1691182209.223 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive:B.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T20:50:09.223Z,1691182209.223 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2023-08-04T20:50:09.223Z,1691182209.223 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive] Stopped
2023-08-04T20:50:09.223Z,1691182209.223 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:WaitPreDive
2023-08-04T20:50:09.223Z,1691182209.223 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Running Loop=1
2023-08-04T20:50:09.223Z,1691182209.223 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2023-08-04T20:50:09.223Z,1691182209.223 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2023-08-04T20:50:09.224Z,1691182209.224 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Initialize.
2023-08-04T20:50:09.224Z,1691182209.224 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Running Loop=1
2023-08-04T20:50:09.631Z,1691182209.631 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Running Loop=1
2023-08-04T20:50:09.632Z,1691182209.632 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A](INFO): Moving to 7.000000 m 
2023-08-04T20:50:09.632Z,1691182209.632 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:A] Stopped
2023-08-04T20:50:09.632Z,1691182209.632 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Running Loop=1
2023-08-04T20:50:09.632Z,1691182209.632 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch](DEBUG): Initialize.
2023-08-04T20:50:11.867Z,1691182211.867 [CTD_Seabird](ERROR): Failed to parse device response: <!--startlogging-->
2023-08-04T20:50:17.742Z,1691182217.742 [WetLabsUBAT](FAULT): Failed to acquire vaid data. Device message size is undefined.
2023-08-04T20:50:17.742Z,1691182217.742 [WetLabsUBAT] Data Fault, FailCount= 1
2023-08-04T20:50:17.742Z,1691182217.742 [WetLabsUBAT](ERROR): Data Fault
2023-08-04T20:50:17.779Z,1691182217.779 [CBIT](ERROR): Data Fault in component: WetLabsUBAT
2023-08-04T20:50:18.247Z,1691182218.247 [WetLabsUBAT](INFO): Powering down
2023-08-04T20:50:19.379Z,1691182219.379 [CBIT](INFO): Clearing failed state for component WetLabsUBAT
2023-08-04T20:50:19.379Z,1691182219.379 [WetLabsUBAT] No Fault, FailCount= 1
2023-08-04T20:50:19.459Z,1691182219.459 [WetLabsUBAT](INFO): Powering up
2023-08-04T20:50:29.647Z,1691182229.647 [WetLabsUBAT](FAULT): UBAT flow rate is below the specified threshold of 0.05 l/s.
2023-08-04T20:51:09.819Z,1691182269.819 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,-32768,32768,V
2023-08-04T20:51:39.590Z,1691182299.590 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:51:43.606Z,1691182303.606 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.246895
2023-08-04T20:52:14.138Z,1691182334.138 [Radio_Surface](INFO): Powering down
2023-08-04T20:52:14.734Z,1691182334.734 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T20:52:15.739Z,1691182335.739 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-08-04T20:52:49.019Z,1691182369.019 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2023-08-04T20:53:06.173Z,1691182386.173 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:C.Pitch] Stopped
2023-08-04T20:53:06.173Z,1691182386.173 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2023-08-04T20:53:06.174Z,1691182386.174 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth] Stopped
2023-08-04T20:53:06.174Z,1691182386.174 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth
2023-08-04T20:53:06.174Z,1691182386.174 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed] Stopped
2023-08-04T20:53:06.174Z,1691182386.174 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:ApproachDepth:B.SetSpeed](DEBUG): Uninitialize.
2023-08-04T20:53:06.174Z,1691182386.174 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2023-08-04T20:53:06.174Z,1691182386.174 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth] Stopped
2023-08-04T20:53:06.175Z,1691182386.175 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth
2023-08-04T20:53:06.175Z,1691182386.175 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:GoToTargetDepth:A] Stopped
2023-08-04T20:53:06.175Z,1691182386.175 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Running Loop=1
2023-08-04T20:53:06.175Z,1691182386.175 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2023-08-04T20:53:06.175Z,1691182386.175 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2023-08-04T20:53:06.175Z,1691182386.175 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Initialize.
2023-08-04T20:53:06.175Z,1691182386.175 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2023-08-04T20:53:06.175Z,1691182386.175 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch](DEBUG): Initialize.
2023-08-04T20:53:06.175Z,1691182386.175 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Running Loop=1
2023-08-04T20:53:06.612Z,1691182386.612 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C](INFO): Waiting for the vehicle to settle. Depth = 7.030292 m 
2023-08-04T20:53:06.612Z,1691182386.612 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:C] Stopped
2023-08-04T20:53:06.612Z,1691182386.612 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Running Loop=1
2023-08-04T20:53:06.612Z,1691182386.612 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Initialize Wait Component.
2023-08-04T20:53:06.612Z,1691182386.612 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Running Loop=1
2023-08-04T20:53:06.613Z,1691182386.613 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Running Loop=1
2023-08-04T20:53:52.244Z,1691182432.244 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for altitude. Device response is::BD,       -0.50,       -0.09,   
2023-08-04T20:55:32.429Z,1691182532.429 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for water velocity. Device response is::WS,-3276800, 10.12
2023-08-04T20:58:50.078Z,1691182730.078 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for water velocity. Device response is::WS,-3276,-32768,V
2023-08-04T20:59:38.068Z,1691182778.068 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,   +0,   -23,A
2023-08-04T21:00:41.626Z,1691182841.626 [DAT](INFO): DAT read: user:6>Rx Time:21:00:40.7279

2023-08-04T21:00:42.134Z,1691182842.134 [DAT](INFO): DAT read: 21:00:40.7279 LVL= 32144, 32753, 32754, 32755, AGC= 29, IDX= 356, 0.34,-0.508, 0.472, 0.906, 0.563, PHS=-1.037,-0.062, 0.415, RAW= 251.2,  10.7, CAL= 251.9,  10.0, ROT= 258.1, -10.0

2023-08-04T21:00:42.135Z,1691182842.135 [DAT](INFO): got valid direction response:
 21:00:40.7279 LVL= 32144, 32753, 32754, 32755, AGC= 29, IDX= 356, 0.34,-0.508, 0.472, 0.906, 0.563, PHS=-1.037,-0.062, 0.415, RAW= 251.2,  10.7, CAL= 251.9,  10.0, ROT= 258.1, -10.0

2023-08-04T21:00:42.136Z,1691182842.136 [DAT](INFO): DAT read: 

2023-08-04T21:00:42.137Z,1691182842.137 [DAT](INFO): DAT read: $Packet for address 20

2023-08-04T21:00:42.137Z,1691182842.137 [DAT](INFO): received a packet notification
2023-08-04T21:00:42.150Z,1691182842.150 [DAT](INFO): #Rx 1: Read direction message, but no range.
2023-08-04T21:00:42.151Z,1691182842.151 [DAT](INFO): direction in FSK: [-0.203071,-0.963643,0.173648]
2023-08-04T21:00:55.239Z,1691182855.239 [DAT](INFO): DAT read: Rx Time:21:00:54.2782

2023-08-04T21:00:55.240Z,1691182855.240 [DAT](INFO): Rx dataTimestamp_ set to:1691182854.278198
2023-08-04T21:00:55.240Z,1691182855.240 [DAT](INFO): received an acoustic signal
2023-08-04T21:00:55.747Z,1691182855.747 [DAT](INFO): DAT read: 21:00:54.2782 LVL= 30448, 32753, 32754, 32755, AGC= 30, IDX= 471,-0.49,-1.596, 0.080,-0.056,-0.106, PHS=-1.456, 0.215, 0.122, RAW= 272.8,  13.7, CAL= 273.2,  16.2, ROT= 236.8, -16.2

2023-08-04T21:00:55.748Z,1691182855.748 [DAT](INFO): got valid direction response:
 21:00:54.2782 LVL= 30448, 32753, 32754, 32755, AGC= 30, IDX= 471,-0.49,-1.596, 0.080,-0.056,-0.106, PHS=-1.456, 0.215, 0.122, RAW= 272.8,  13.7, CAL= 273.2,  16.2, ROT= 236.8, -16.2

2023-08-04T21:00:55.749Z,1691182855.749 [DAT](INFO): DAT read: 

2023-08-04T21:00:55.749Z,1691182855.749 [DAT](INFO): DAT read: $Packet for address 20

2023-08-04T21:00:55.750Z,1691182855.750 [DAT](INFO): received a packet notification
2023-08-04T21:00:55.762Z,1691182855.762 [DAT](INFO): #Rx 2: Read direction message, but no range.
2023-08-04T21:00:55.763Z,1691182855.763 [DAT](INFO): direction in FSK: [-0.525821,-0.803540,0.278991]
2023-08-04T21:02:38.915Z,1691182958.915 [DAT](INFO): DAT read: Rx Time:21:02:37.8294

2023-08-04T21:02:38.917Z,1691182958.917 [DAT](INFO): Rx dataTimestamp_ set to:1691182957.829399
2023-08-04T21:02:38.917Z,1691182958.917 [DAT](INFO): received an acoustic signal
2023-08-04T21:02:39.420Z,1691182959.420 [DAT](INFO): DAT read: 

2023-08-04T21:02:39.423Z,1691182959.423 [DAT](INFO): DAT read: $Packet for address 20

2023-08-04T21:02:39.424Z,1691182959.424 [DAT](INFO): received a packet notification
2023-08-04T21:02:50.267Z,1691182970.267 [DAT](INFO): DAT read: Rx Time:21:02:49.3297

2023-08-04T21:02:50.268Z,1691182970.268 [DAT](INFO): Rx dataTimestamp_ set to:1691182969.329700
2023-08-04T21:02:50.268Z,1691182970.268 [DAT](INFO): received an acoustic signal
2023-08-04T21:02:50.777Z,1691182970.777 [DAT](INFO): DAT read: 21:02:49.3297 LVL= 32752, 32753, 31298, 32755, AGC= 26, IDX= 466, 0.14, 0.454,-0.270, 1.394, 0.208, PHS= 0.279,-0.449, 1.258, RAW= 184.8, -14.5, CAL= 186.4, -14.2, ROT= 323.6,  14.2

2023-08-04T21:02:50.782Z,1691182970.782 [DAT](INFO): got valid direction response:
 21:02:49.3297 LVL= 32752, 32753, 31298, 32755, AGC= 26, IDX= 466, 0.14, 0.454,-0.270, 1.394, 0.208, PHS= 0.279,-0.449, 1.258, RAW= 184.8, -14.5, CAL= 186.4, -14.2, ROT= 323.6,  14.2

2023-08-04T21:02:50.782Z,1691182970.782 [DAT](INFO): DAT read: 

2023-08-04T21:02:50.783Z,1691182970.783 [DAT](INFO): DAT read: $Packet for address 20

2023-08-04T21:02:50.783Z,1691182970.783 [DAT](INFO): received a packet notification
2023-08-04T21:02:50.794Z,1691182970.794 [DAT](INFO): #Rx 3: Read direction message, but no range.
2023-08-04T21:02:50.795Z,1691182970.795 [DAT](INFO): direction in FSK: [0.780301,-0.575287,-0.245307]
2023-08-04T21:03:06.999Z,1691182986.999 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](INFO): Done Waiting.
2023-08-04T21:03:06.999Z,1691182986.999 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait] Stopped
2023-08-04T21:03:06.999Z,1691182986.999 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:D.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T21:03:06.000Z,1691182987.000 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Running Loop=1
2023-08-04T21:03:07.356Z,1691182987.356 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E](INFO): Running ballast and trim. Depth = 6.793868 m 
2023-08-04T21:03:07.357Z,1691182987.357 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:E] Stopped
2023-08-04T21:03:07.357Z,1691182987.357 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Running Loop=1
2023-08-04T21:03:07.357Z,1691182987.357 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Initializing BallastAndTrim.
2023-08-04T21:04:05.411Z,1691183045.411 [DAT](INFO): DAT read: Rx Time:21:04:04.3304

2023-08-04T21:04:05.412Z,1691183045.412 [DAT](INFO): Rx dataTimestamp_ set to:1691183044.330400
2023-08-04T21:04:05.413Z,1691183045.413 [DAT](INFO): received an acoustic signal
2023-08-04T21:04:05.914Z,1691183045.914 [DAT](INFO): DAT read: 

2023-08-04T21:04:05.915Z,1691183045.915 [DAT](INFO): DAT read: $Packet for address 20

2023-08-04T21:04:05.916Z,1691183045.916 [DAT](INFO): received a packet notification
2023-08-04T21:05:07.975Z,1691183107.975 [DAT](INFO): DAT read: Rx Time:21:05:06.9778

2023-08-04T21:05:07.976Z,1691183107.977 [DAT](INFO): Rx dataTimestamp_ set to:1691183106.977800
2023-08-04T21:05:07.977Z,1691183107.977 [DAT](INFO): received an acoustic signal
2023-08-04T21:05:08.483Z,1691183108.483 [DAT](INFO): DAT read: 21:05:06.9778 LVL= 28480, 29041, 32754, 32755, AGC= 26, IDX= 468,-0.07, 0.233, 0.322, 1.459, 0.034, PHS= 0.233, 0.317, 1.497, RAW= 213.4, -30.6, CAL= 213.6, -30.5, ROT= 296.4,  30.5

2023-08-04T21:05:08.484Z,1691183108.484 [DAT](INFO): got valid direction response:
 21:05:06.9778 LVL= 28480, 29041, 32754, 32755, AGC= 26, IDX= 468,-0.07, 0.233, 0.322, 1.459, 0.034, PHS= 0.233, 0.317, 1.497, RAW= 213.4, -30.6, CAL= 213.6, -30.5, ROT= 296.4,  30.5

2023-08-04T21:05:08.484Z,1691183108.484 [DAT](INFO): DAT read: 

2023-08-04T21:05:08.485Z,1691183108.485 [DAT](INFO): DAT read: $Packet for address 20

2023-08-04T21:05:08.489Z,1691183108.489 [DAT](INFO): received a packet notification
2023-08-04T21:05:08.502Z,1691183108.502 [DAT](INFO): #Rx 4: Read direction message, but no range.
2023-08-04T21:05:08.503Z,1691183108.503 [DAT](INFO): direction in FSK: [0.383111,-0.771771,-0.507538]
2023-08-04T21:05:22.367Z,1691183122.367 [DAT](INFO): DAT read: Rx Time:21:05:21.3370

2023-08-04T21:05:22.368Z,1691183122.368 [DAT](INFO): Rx dataTimestamp_ set to:1691183121.337000
2023-08-04T21:05:22.368Z,1691183122.368 [DAT](INFO): received an acoustic signal
2023-08-04T21:05:22.871Z,1691183122.871 [DAT](INFO): DAT read: 

2023-08-04T21:05:22.872Z,1691183122.872 [DAT](INFO): DAT read: $Packet for address 20

2023-08-04T21:05:22.873Z,1691183122.873 [DAT](INFO): received a packet notification
2023-08-04T21:17:05.486Z,1691183825.486 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2023-08-04T21:19:11.360Z,1691183951.360 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. Device response is::WD,     ,        +0.00,        +0.00,  20.00,1429.02
2023-08-04T21:21:12.156Z,1691184072.156 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,    +3,    +2, 
2023-08-04T21:21:56.374Z,1691184116.374 [WetLabsUBAT](ERROR): Failed to parse incomplete device message.
2023-08-04T21:23:38.827Z,1691184218.827 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-08-04T21:23:38.838Z,1691184218.838 [BPC1](INFO): Received data from all battery sticks.
2023-08-04T21:24:18.411Z,1691184258.411 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BallastAndTrim completed. Estimation time: 21.18 minutes.
2023-08-04T21:24:18.412Z,1691184258.412 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated buoyancyNeutral: 279.462762 +/- 14.999514 cc (conf. level 99.90%, sigma: 25.884318 cc).
2023-08-04T21:24:18.413Z,1691184258.413 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Estimated massDefault: 6.724128 +/- 0.225375 mm (conf. level 99.90%, sigma: 0.388924 mm).
2023-08-04T21:24:18.414Z,1691184258.414 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Changing persisted config values to: 279.462762 cc buoyancy neutral and 6.724128 mm mass default
2023-08-04T21:24:18.420Z,1691184258.420 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-08-04T21:24:18.421Z,1691184258.421 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2023-08-04T21:24:18.421Z,1691184258.421 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): CBIT.gf24Offset=143 microampere;

2023-08-04T21:24:18.421Z,1691184258.421 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 0.300000 liter_per_second;

2023-08-04T21:24:18.421Z,1691184258.421 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): IBIT.batteryCapacityThreshold=10 ampere_hour;

2023-08-04T21:24:18.421Z,1691184258.421 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): IBIT.batteryVoltageThreshold=11.5 volt;

2023-08-04T21:24:18.421Z,1691184258.421 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.buoyancyNeutral=279.462762 cubic_centimeter;

2023-08-04T21:24:18.422Z,1691184258.422 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): VerticalControl.massDefault=6.724128 millimeter;

2023-08-04T21:24:18.422Z,1691184258.422 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool;

2023-08-04T21:24:18.422Z,1691184258.422 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.] Stopped
2023-08-04T21:24:18.422Z,1691184258.422 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:F.](INFO): Uninitializing BallastAndTrim.
2023-08-04T21:24:18.423Z,1691184258.423 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2023-08-04T21:24:18.423Z,1691184258.423 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth] Stopped
2023-08-04T21:24:18.423Z,1691184258.423 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth
2023-08-04T21:24:18.423Z,1691184258.423 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed] Stopped
2023-08-04T21:24:18.424Z,1691184258.424 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:A.SetSpeed](DEBUG): Uninitialize.
2023-08-04T21:24:18.424Z,1691184258.424 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:BallastAndTrimAtTargetDepth:B.Pitch] Stopped
2023-08-04T21:24:18.425Z,1691184258.425 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2023-08-04T21:24:18.425Z,1691184258.425 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim] Stopped
2023-08-04T21:24:18.425Z,1691184258.425 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:BallastAndTrim
2023-08-04T21:24:18.425Z,1691184258.425 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:A] Stopped
2023-08-04T21:24:18.425Z,1691184258.425 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:B] Stopped
2023-08-04T21:24:18.425Z,1691184258.425 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:C] Stopped
2023-08-04T21:24:18.425Z,1691184258.425 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:D] Stopped
2023-08-04T21:24:18.425Z,1691184258.425 [ballast_and_trim:RunBallastAndTrim:BallastAndTrim:E] Stopped
2023-08-04T21:24:18.844Z,1691184258.844 [ballast_and_trim:RunBallastAndTrim:Depth1:B](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1:B
2023-08-04T21:24:18.844Z,1691184258.844 [ballast_and_trim:RunBallastAndTrim:Depth1:B] Stopped
2023-08-04T21:24:18.844Z,1691184258.844 [ballast_and_trim:RunBallastAndTrim:Depth1:B](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1:B
2023-08-04T21:24:18.844Z,1691184258.844 [ballast_and_trim:RunBallastAndTrim:Depth1](INFO): Completed ballast_and_trim:RunBallastAndTrim:Depth1
2023-08-04T21:24:18.844Z,1691184258.844 [ballast_and_trim:RunBallastAndTrim:Depth1] Stopped
2023-08-04T21:24:18.845Z,1691184258.845 [ballast_and_trim:RunBallastAndTrim:Depth1](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth1
2023-08-04T21:24:18.845Z,1691184258.845 [ballast_and_trim:RunBallastAndTrim:Depth2] Running Loop=1
2023-08-04T21:24:18.845Z,1691184258.845 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::initialize ballast_and_trim:RunBallastAndTrim:Depth2
2023-08-04T21:24:18.845Z,1691184258.845 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Running Loop=1
2023-08-04T21:24:19.215Z,1691184259.215 [ballast_and_trim:RunBallastAndTrim:Depth2] Stopped
2023-08-04T21:24:19.215Z,1691184259.215 [ballast_and_trim:RunBallastAndTrim:Depth2](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim:Depth2
2023-08-04T21:24:19.215Z,1691184259.215 [ballast_and_trim:RunBallastAndTrim:Depth2:A] Stopped
2023-08-04T21:24:19.215Z,1691184259.215 [ballast_and_trim:RunBallastAndTrim](INFO): Completed ballast_and_trim:RunBallastAndTrim
2023-08-04T21:24:19.216Z,1691184259.216 [ballast_and_trim:RunBallastAndTrim] Stopped
2023-08-04T21:24:19.216Z,1691184259.216 [ballast_and_trim:RunBallastAndTrim](DEBUG): Aggregate::uninitialize ballast_and_trim:RunBallastAndTrim
2023-08-04T21:24:19.216Z,1691184259.216 [ballast_and_trim:Float_Up] Running Loop=1
2023-08-04T21:24:19.216Z,1691184259.216 [ballast_and_trim:Float_Up](DEBUG): Aggregate::initialize ballast_and_trim:Float_Up
2023-08-04T21:24:19.216Z,1691184259.216 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2023-08-04T21:24:19.216Z,1691184259.216 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Initialize Buoyancy Component.
2023-08-04T21:24:19.216Z,1691184259.216 [ballast_and_trim:Float_Up:B.Wait] Running Loop=1
2023-08-04T21:24:19.216Z,1691184259.216 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Initialize Wait Component.
2023-08-04T21:24:19.682Z,1691184259.682 [ballast_and_trim:Float_Up:A.Buoyancy] Running Loop=1
2023-08-04T21:25:59.418Z,1691184359.418 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,23080413265729,35.0, +21.3,   0.0,1521.71
2023-08-04T21:26:19.639Z,1691184379.639 [ballast_and_trim:Float_Up] Stopped
2023-08-04T21:26:19.639Z,1691184379.639 [ballast_and_trim:Float_Up](DEBUG): Aggregate::uninitialize ballast_and_trim:Float_Up
2023-08-04T21:26:19.639Z,1691184379.639 [ballast_and_trim:Float_Up:A.Buoyancy] Stopped
2023-08-04T21:26:19.640Z,1691184379.640 [ballast_and_trim:Float_Up:A.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2023-08-04T21:26:19.640Z,1691184379.640 [ballast_and_trim:Float_Up:B.Wait] Stopped
2023-08-04T21:26:19.640Z,1691184379.640 [ballast_and_trim:Float_Up:B.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T21:26:19.643Z,1691184379.643 [ballast_and_trim](INFO): Completed ballast_and_trim
2023-08-04T21:26:19.643Z,1691184379.643 [MissionManager](INFO): ballast_and_trim is completed.
2023-08-04T21:26:19.643Z,1691184379.643 [MissionManager](INFO): Uninitializing Mission ballast_and_trim
2023-08-04T21:26:19.643Z,1691184379.643 [ballast_and_trim] Stopped
2023-08-04T21:26:19.643Z,1691184379.643 [ballast_and_trim](DEBUG): Aggregate::uninitialize ballast_and_trim
2023-08-04T21:26:19.643Z,1691184379.643 [ballast_and_trim:Science] Stopped
2023-08-04T21:26:19.643Z,1691184379.643 [ballast_and_trim:Science](DEBUG): Aggregate::uninitialize ballast_and_trim:Science
2023-08-04T21:26:19.643Z,1691184379.643 [ballast_and_trim:Science:B] Stopped
2023-08-04T21:26:19.643Z,1691184379.643 [ballast_and_trim:Science:C] Stopped
2023-08-04T21:26:19.643Z,1691184379.643 [ballast_and_trim:Science:E] Stopped
2023-08-04T21:26:19.643Z,1691184379.643 [ballast_and_trim:Science:F] Stopped
2023-08-04T21:26:19.643Z,1691184379.643 [ballast_and_trim:Science:OceanCurrent] Stopped
2023-08-04T21:26:19.644Z,1691184379.644 [ballast_and_trim:Science:OceanCurrent](DEBUG): Aggregate::uninitialize ballast_and_trim:Science:OceanCurrent
2023-08-04T21:26:19.644Z,1691184379.644 [ballast_and_trim:Science:OceanCurrent:A.] Stopped
2023-08-04T21:26:19.644Z,1691184379.644 [ballast_and_trim:BackseatDriver] Stopped
2023-08-04T21:26:19.644Z,1691184379.644 [ballast_and_trim:BackseatDriver](DEBUG): Aggregate::uninitialize ballast_and_trim:BackseatDriver
2023-08-04T21:26:19.644Z,1691184379.644 [ballast_and_trim:BackseatDriver:A.BackseatDriver] Stopped
2023-08-04T21:26:19.915Z,1691184379.915 [WetLabsUBAT](INFO): Powering down
2023-08-04T21:26:20.033Z,1691184380.033 [MissionManager](IMPORTANT): Started mission Default
2023-08-04T21:26:20.033Z,1691184380.033 [Default] Running Loop=1
2023-08-04T21:26:20.034Z,1691184380.034 [Default](DEBUG): Aggregate::initialize Default
2023-08-04T21:26:20.034Z,1691184380.034 [Default:B.GoToSurface] Running Loop=1
2023-08-04T21:26:20.034Z,1691184380.034 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-08-04T21:26:20.034Z,1691184380.034 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-08-04T21:26:20.034Z,1691184380.034 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-08-04T21:26:20.035Z,1691184380.035 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-08-04T21:26:20.035Z,1691184380.035 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-08-04T21:26:20.035Z,1691184380.035 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-08-04T21:26:20.036Z,1691184380.036 [Default:A.Wait] Running Loop=1
2023-08-04T21:26:20.036Z,1691184380.036 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-08-04T21:26:20.106Z,1691184380.106 [WetLabsBB2FL](INFO): Powering down
2023-08-04T21:26:20.226Z,1691184380.226 [Radio_Surface](INFO): Powering up
2023-08-04T21:26:26.218Z,1691184386.218 [DataOverHttps](INFO): Radio surface powered ON.
2023-08-04T21:26:33.360Z,1691184393.360 [Default:A.Wait](INFO): Done Waiting.
2023-08-04T21:26:33.360Z,1691184393.360 [Default:A.Wait] Stopped
2023-08-04T21:26:33.360Z,1691184393.360 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T21:26:33.785Z,1691184393.785 [Default:CheckIn] Running Loop=1
2023-08-04T21:26:33.785Z,1691184393.785 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T21:26:33.786Z,1691184393.786 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T21:26:56.354Z,1691184416.354 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T21:27:31.494Z,1691184451.494 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T21:28:06.642Z,1691184486.642 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T21:28:41.798Z,1691184521.798 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T21:29:16.938Z,1691184556.938 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2023-08-04T21:29:50.778Z,1691184590.778 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002991
2023-08-04T21:29:56.619Z,1691184596.619 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA,  0.00,  96.00,  96.19,  47.92
2023-08-04T21:31:18.977Z,1691184678.977 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:31:18.978Z,1691184678.978 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:31:33.951Z,1691184693.951 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-08-04T21:26:33.8Z
2023-08-04T21:31:33.951Z,1691184693.951 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T21:31:33.952Z,1691184693.952 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T21:31:38.359Z,1691184698.359 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T21:31:41.345Z,1691184701.345 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20230804T200832/Courier0016.lzma
2023-08-04T21:31:42.347Z,1691184702.347 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0016.lzma.bak
2023-08-04T21:31:42.348Z,1691184702.348 [DataOverHttps](INFO): SBD MOMSN=18518997
2023-08-04T21:31:59.120Z,1691184719.120 [DataOverHttps](INFO): Sending 1549 bytes from file Logs/20230804T200832/Express0017.lzma
2023-08-04T21:32:00.119Z,1691184720.119 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0017.lzma.bak
2023-08-04T21:32:00.120Z,1691184720.120 [DataOverHttps](INFO): SBD MOMSN=18518999
2023-08-04T21:32:01.871Z,1691184721.871 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T21:32:01.871Z,1691184721.871 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T21:32:01.871Z,1691184721.871 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T21:32:09.067Z,1691184729.067 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T21:36:19.483Z,1691184979.483 [DataOverHttps](IMPORTANT): SBD MTMSN=20230804T213618
2023-08-04T21:36:30.625Z,1691184990.625 [DataOverHttps](INFO): Received command: gfscan
2023-08-04T21:36:30.635Z,1691184990.635 [CommandExec](IMPORTANT): got command gfscan
2023-08-04T21:36:30.961Z,1691184990.961 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T21:36:41.924Z,1691185001.924 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.006448
CHAN A1 (24V): 0.025158
CHAN A2 (12V): 0.006127
CHAN A3 (5V): 0.003475
CHAN B0 (3.3V): 0.004054
CHAN B1 (3.15aV): 0.003168
CHAN B2 (3.15bV): 0.003656
CHAN B3 (GND): 0.002615
OPEN: 0.007203
Full Scale: +/- 1 mA
2023-08-04T21:37:02.446Z,1691185022.446 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T21:37:02.446Z,1691185022.446 [Default:CheckIn:C.Wait] Stopped
2023-08-04T21:37:02.446Z,1691185022.446 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T21:37:02.446Z,1691185022.446 [Default:CheckIn:D] Running Loop=1
2023-08-04T21:37:02.872Z,1691185022.872 [Default:CheckIn:D] Stopped
2023-08-04T21:37:02.873Z,1691185022.873 [Default:CheckIn:E] Running Loop=1
2023-08-04T21:37:03.280Z,1691185023.280 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.713973 min 
2023-08-04T21:37:03.280Z,1691185023.280 [Default:CheckIn:E] Stopped
2023-08-04T21:37:03.280Z,1691185023.280 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T21:37:03.280Z,1691185023.280 [Default:CheckIn] Stopped
2023-08-04T21:37:03.280Z,1691185023.280 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T21:37:03.281Z,1691185023.281 [Default:CheckIn](INFO): Running loop #2
2023-08-04T21:37:03.281Z,1691185023.281 [Default:CheckIn] Running Loop=2
2023-08-04T21:37:03.281Z,1691185023.281 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T21:37:03.281Z,1691185023.281 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T21:37:04.860Z,1691185024.860 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-08-04T21:37:04.860Z,1691185024.860 [NAL9602] Data Fault, FailCount= 3
2023-08-04T21:37:04.860Z,1691185024.860 [NAL9602](ERROR): Data Fault
2023-08-04T21:37:04.964Z,1691185024.964 [CBIT](ERROR): Data Fault in component: NAL9602
2023-08-04T21:37:05.258Z,1691185025.258 [NAL9602](INFO): Powering down
2023-08-04T21:37:06.111Z,1691185026.111 [CBIT](INFO): Clearing failed state for component NAL9602
2023-08-04T21:37:06.111Z,1691185026.111 [NAL9602] No Fault, FailCount= 3
2023-08-04T21:37:35.563Z,1691185055.563 [NAL9602](INFO): Powering up NAL9602
2023-08-04T21:37:40.824Z,1691185060.824 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,23080413383867,3,V
2023-08-04T21:37:46.471Z,1691185066.471 [NAL9602](INFO): NAL9602 initialized
2023-08-04T21:39:08.104Z,1691185148.104 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS-32768,V
2023-08-04T21:39:28.685Z,1691185168.685 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:39:28.685Z,1691185168.685 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:39:48.883Z,1691185188.883 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:39:48.883Z,1691185188.883 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:40:42.216Z,1691185242.216 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:40:42.217Z,1691185242.217 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:41:27.057Z,1691185287.057 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:41:27.057Z,1691185287.057 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:42:03.460Z,1691185323.460 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-08-04T21:37:03.3Z
2023-08-04T21:42:03.460Z,1691185323.460 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T21:42:03.460Z,1691185323.460 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T21:42:11.598Z,1691185331.598 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230804T200832/Courier0022.lzma
2023-08-04T21:42:12.600Z,1691185332.600 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0022.lzma.bak
2023-08-04T21:42:12.600Z,1691185332.600 [DataOverHttps](INFO): SBD MOMSN=18519050
2023-08-04T21:42:33.006Z,1691185353.006 [DataOverHttps](INFO): Sending 443 bytes from file Logs/20230804T200832/Express0023.lzma
2023-08-04T21:42:34.008Z,1691185354.008 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0023.lzma.bak
2023-08-04T21:42:34.008Z,1691185354.008 [DataOverHttps](INFO): SBD MOMSN=18519052
2023-08-04T21:42:49.955Z,1691185369.955 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T21:42:50.325Z,1691185370.325 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230804T200832/Express0026.lzma
2023-08-04T21:42:51.328Z,1691185371.328 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0026.lzma.bak
2023-08-04T21:42:51.328Z,1691185371.328 [DataOverHttps](INFO): SBD MOMSN=18519061
2023-08-04T21:42:52.799Z,1691185372.799 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T21:42:52.799Z,1691185372.799 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T21:42:52.800Z,1691185372.800 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T21:43:20.658Z,1691185400.658 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T21:47:53.415Z,1691185673.415 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T21:47:53.415Z,1691185673.415 [Default:CheckIn:C.Wait] Stopped
2023-08-04T21:47:53.415Z,1691185673.415 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T21:47:53.415Z,1691185673.415 [Default:CheckIn:D] Running Loop=1
2023-08-04T21:47:53.790Z,1691185673.790 [Default:CheckIn:D] Stopped
2023-08-04T21:47:53.790Z,1691185673.790 [Default:CheckIn:E] Running Loop=1
2023-08-04T21:47:54.192Z,1691185674.192 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.562608 min 
2023-08-04T21:47:54.192Z,1691185674.192 [Default:CheckIn:E] Stopped
2023-08-04T21:47:54.192Z,1691185674.192 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T21:47:54.192Z,1691185674.192 [Default:CheckIn] Stopped
2023-08-04T21:47:54.192Z,1691185674.192 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T21:47:54.192Z,1691185674.192 [Default:CheckIn](INFO): Running loop #3
2023-08-04T21:47:54.192Z,1691185674.192 [Default:CheckIn] Running Loop=3
2023-08-04T21:47:54.192Z,1691185674.192 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T21:47:54.192Z,1691185674.192 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T21:47:55.799Z,1691185675.799 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-08-04T21:47:55.799Z,1691185675.799 [NAL9602] Data Fault, FailCount= 4
2023-08-04T21:47:55.799Z,1691185675.799 [NAL9602](ERROR): Data Fault
2023-08-04T21:47:55.820Z,1691185675.820 [CBIT](ERROR): Data Fault in component: NAL9602
2023-08-04T21:47:56.199Z,1691185676.199 [NAL9602](INFO): Powering down
2023-08-04T21:47:57.032Z,1691185677.032 [CBIT](INFO): Clearing failed state for component NAL9602
2023-08-04T21:47:57.032Z,1691185677.032 [NAL9602] No Fault, FailCount= 4
2023-08-04T21:48:26.555Z,1691185706.555 [NAL9602](INFO): Powering up NAL9602
2023-08-04T21:48:37.489Z,1691185717.489 [NAL9602](INFO): NAL9602 initialized
2023-08-04T21:49:34.025Z,1691185774.025 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:49:34.025Z,1691185774.025 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:49:55.440Z,1691185795.440 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:49:55.440Z,1691185795.440 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:50:26.953Z,1691185826.953 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:50:26.953Z,1691185826.953 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:51:11.796Z,1691185871.796 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:51:11.797Z,1691185871.797 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:51:29.172Z,1691185889.172 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:51:29.172Z,1691185889.172 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:51:50.980Z,1691185910.980 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:51:50.980Z,1691185910.980 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:52:54.458Z,1691185974.458 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-08-04T21:47:54.2Z
2023-08-04T21:52:54.458Z,1691185974.458 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T21:52:54.460Z,1691185974.460 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T21:53:02.041Z,1691185982.041 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230804T200832/Courier0028.lzma
2023-08-04T21:53:03.044Z,1691185983.044 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0028.lzma.bak
2023-08-04T21:53:03.044Z,1691185983.044 [DataOverHttps](INFO): SBD MOMSN=18519085
2023-08-04T21:53:19.982Z,1691185999.982 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20230804T200832/Express0029.lzma
2023-08-04T21:53:20.983Z,1691186000.983 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0029.lzma.bak
2023-08-04T21:53:20.984Z,1691186000.984 [DataOverHttps](INFO): SBD MOMSN=18519087
2023-08-04T21:53:22.737Z,1691186002.737 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T21:53:22.737Z,1691186002.737 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T21:53:22.737Z,1691186002.737 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T21:53:41.275Z,1691186021.275 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T21:54:11.987Z,1691186051.987 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T21:54:27.825Z,1691186067.825 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,    -4,   +1,A
2023-08-04T21:58:23.466Z,1691186303.466 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T21:58:23.466Z,1691186303.466 [Default:CheckIn:C.Wait] Stopped
2023-08-04T21:58:23.466Z,1691186303.466 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T21:58:23.466Z,1691186303.466 [Default:CheckIn:D] Running Loop=1
2023-08-04T21:58:23.819Z,1691186303.819 [Default:CheckIn:D] Stopped
2023-08-04T21:58:23.819Z,1691186303.819 [Default:CheckIn:E] Running Loop=1
2023-08-04T21:58:24.222Z,1691186304.222 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 32.063096 min 
2023-08-04T21:58:24.223Z,1691186304.223 [Default:CheckIn:E] Stopped
2023-08-04T21:58:24.223Z,1691186304.223 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T21:58:24.223Z,1691186304.223 [Default:CheckIn] Stopped
2023-08-04T21:58:24.223Z,1691186304.223 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T21:58:24.223Z,1691186304.223 [Default:CheckIn](INFO): Running loop #4
2023-08-04T21:58:24.223Z,1691186304.223 [Default:CheckIn] Running Loop=4
2023-08-04T21:58:24.223Z,1691186304.223 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T21:58:24.223Z,1691186304.223 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T21:58:26.245Z,1691186306.245 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215824.00,A,3648.16120,N,12147.27839,W,0.214,311.06,040823,,,A*70
2023-08-04T21:58:26.247Z,1691186306.247 [NAL9602](INFO): GPS fix at 20230804T215824: (36.802687, -121.787973)
2023-08-04T21:58:26.324Z,1691186306.324 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T21:58:26.324Z,1691186306.324 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T21:58:33.777Z,1691186313.777 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0031.lzma
2023-08-04T21:58:34.779Z,1691186314.779 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0031.lzma.bak
2023-08-04T21:58:34.780Z,1691186314.780 [DataOverHttps](INFO): SBD MOMSN=18519108
2023-08-04T21:58:51.417Z,1691186331.417 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230804T200832/Express0032.lzma
2023-08-04T21:58:52.420Z,1691186332.420 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0032.lzma.bak
2023-08-04T21:58:52.420Z,1691186332.420 [DataOverHttps](INFO): SBD MOMSN=18519111
2023-08-04T21:58:53.960Z,1691186333.960 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T21:58:53.960Z,1691186333.960 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T21:58:53.960Z,1691186333.960 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T21:58:56.741Z,1691186336.741 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-08-04T21:58:56.818Z,1691186336.818 [NAL9602](ERROR): received: 
+CSQ:0

OK171, 2, 0, 0, 0

OK
2023-08-04T21:59:21.365Z,1691186361.365 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:59:21.365Z,1691186361.365 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T21:59:54.541Z,1691186394.541 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T21:59:54.541Z,1691186394.541 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:00:36.125Z,1691186436.125 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T22:00:36.125Z,1691186436.125 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:02:49.433Z,1691186569.433 [RDI_Pathfinder](ERROR): DVL BIT error. See manual. Result code: 100
Device respsone is::TS,23080414034728,35.0, +21.5,   0.0,1525.67, 100.35
2023-08-04T22:03:24.641Z,1691186604.641 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD,       -2.06,        +2.54, .00
2023-08-04T22:03:28.207Z,1691186608.207 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T22:03:54.478Z,1691186634.478 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:03:54.478Z,1691186634.478 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:03:54.479Z,1691186634.479 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:03:54.479Z,1691186634.479 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:03:54.894Z,1691186634.894 [Default:CheckIn:D] Stopped
2023-08-04T22:03:54.894Z,1691186634.894 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:03:55.315Z,1691186635.315 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.581014 min 
2023-08-04T22:03:55.315Z,1691186635.315 [Default:CheckIn:E] Stopped
2023-08-04T22:03:55.315Z,1691186635.315 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:03:55.315Z,1691186635.315 [Default:CheckIn] Stopped
2023-08-04T22:03:55.316Z,1691186635.316 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:03:55.316Z,1691186635.316 [Default:CheckIn](INFO): Running loop #5
2023-08-04T22:03:55.316Z,1691186635.316 [Default:CheckIn] Running Loop=5
2023-08-04T22:03:55.316Z,1691186635.316 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:03:55.316Z,1691186635.316 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:03:57.301Z,1691186637.301 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220356.00,A,3648.16606,N,12147.28320,W,0.603,142.92,040823,,,A*7C
2023-08-04T22:03:57.303Z,1691186637.303 [NAL9602](INFO): GPS fix at 20230804T220356: (36.802768, -121.788053)
2023-08-04T22:03:57.366Z,1691186637.366 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:03:57.366Z,1691186637.366 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:04:04.785Z,1691186644.785 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0034.lzma
2023-08-04T22:04:05.787Z,1691186645.787 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0034.lzma.bak
2023-08-04T22:04:05.788Z,1691186645.788 [DataOverHttps](INFO): SBD MOMSN=18519118
2023-08-04T22:04:22.762Z,1691186662.762 [DataOverHttps](INFO): Sending 210 bytes from file Logs/20230804T200832/Express0035.lzma
2023-08-04T22:04:23.764Z,1691186663.764 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0035.lzma.bak
2023-08-04T22:04:23.764Z,1691186663.764 [DataOverHttps](INFO): SBD MOMSN=18519125
2023-08-04T22:04:25.681Z,1691186665.681 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:04:25.681Z,1691186665.681 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:04:25.681Z,1691186665.681 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T22:04:29.715Z,1691186669.715 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T22:09:26.331Z,1691186966.331 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:09:26.331Z,1691186966.331 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:09:26.331Z,1691186966.331 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:09:26.332Z,1691186966.332 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:09:26.745Z,1691186966.745 [Default:CheckIn:D] Stopped
2023-08-04T22:09:26.745Z,1691186966.745 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:09:27.162Z,1691186967.162 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.111857 min 
2023-08-04T22:09:27.162Z,1691186967.162 [Default:CheckIn:E] Stopped
2023-08-04T22:09:27.162Z,1691186967.162 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:09:27.162Z,1691186967.162 [Default:CheckIn] Stopped
2023-08-04T22:09:27.162Z,1691186967.162 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:09:27.163Z,1691186967.163 [Default:CheckIn](INFO): Running loop #6
2023-08-04T22:09:27.163Z,1691186967.163 [Default:CheckIn] Running Loop=6
2023-08-04T22:09:27.163Z,1691186967.163 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:09:27.163Z,1691186967.163 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:09:29.148Z,1691186969.148 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220928.00,A,3648.16846,N,12147.28218,W,0.117,108.37,040823,,,A*7C
2023-08-04T22:09:29.150Z,1691186969.150 [NAL9602](INFO): GPS fix at 20230804T220928: (36.802808, -121.788036)
2023-08-04T22:09:29.162Z,1691186969.162 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:09:29.162Z,1691186969.162 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:09:37.401Z,1691186977.401 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0037.lzma
2023-08-04T22:09:38.404Z,1691186978.404 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0037.lzma.bak
2023-08-04T22:09:38.404Z,1691186978.404 [DataOverHttps](INFO): SBD MOMSN=18519132
2023-08-04T22:09:54.762Z,1691186994.762 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230804T200832/Express0038.lzma
2023-08-04T22:09:55.764Z,1691186995.764 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0038.lzma.bak
2023-08-04T22:09:55.764Z,1691186995.764 [DataOverHttps](INFO): SBD MOMSN=18519138
2023-08-04T22:09:57.447Z,1691186997.447 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:09:57.447Z,1691186997.447 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:09:57.448Z,1691186997.448 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T22:09:59.851Z,1691186999.851 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-08-04T22:09:59.930Z,1691186999.930 [NAL9602](ERROR): received: 
+CSQ:0

OK171, 2, 0, 0, 0

OK
2023-08-04T22:14:31.438Z,1691187271.438 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T22:14:58.114Z,1691187298.114 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:14:58.114Z,1691187298.114 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:14:58.114Z,1691187298.114 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:14:58.114Z,1691187298.114 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:14:58.523Z,1691187298.523 [Default:CheckIn:D] Stopped
2023-08-04T22:14:58.523Z,1691187298.523 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:14:58.931Z,1691187298.931 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.641496 min 
2023-08-04T22:14:58.931Z,1691187298.931 [Default:CheckIn:E] Stopped
2023-08-04T22:14:58.931Z,1691187298.931 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:14:58.931Z,1691187298.931 [Default:CheckIn] Stopped
2023-08-04T22:14:58.931Z,1691187298.931 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:14:58.932Z,1691187298.932 [Default:CheckIn](INFO): Running loop #7
2023-08-04T22:14:58.932Z,1691187298.932 [Default:CheckIn] Running Loop=7
2023-08-04T22:14:58.932Z,1691187298.932 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:14:58.932Z,1691187298.932 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:15:00.936Z,1691187300.936 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221500.00,A,3648.16896,N,12147.28474,W,0.097,108.37,040823,,,A*73
2023-08-04T22:15:00.949Z,1691187300.949 [NAL9602](INFO): GPS fix at 20230804T221500: (36.802816, -121.788079)
2023-08-04T22:15:00.961Z,1691187300.961 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:15:00.961Z,1691187300.961 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:15:08.557Z,1691187308.557 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0040.lzma
2023-08-04T22:15:09.563Z,1691187309.563 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0040.lzma.bak
2023-08-04T22:15:09.563Z,1691187309.563 [DataOverHttps](INFO): SBD MOMSN=18519144
2023-08-04T22:15:25.938Z,1691187325.938 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230804T200832/Express0041.lzma
2023-08-04T22:15:26.940Z,1691187326.940 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0041.lzma.bak
2023-08-04T22:15:26.940Z,1691187326.940 [DataOverHttps](INFO): SBD MOMSN=18519151
2023-08-04T22:15:28.419Z,1691187328.419 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:15:28.419Z,1691187328.419 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:15:28.419Z,1691187328.419 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T22:15:33.661Z,1691187333.661 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T22:20:29.074Z,1691187629.074 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:20:29.074Z,1691187629.074 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:20:29.074Z,1691187629.074 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:20:29.075Z,1691187629.075 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:20:29.479Z,1691187629.479 [Default:CheckIn:D] Stopped
2023-08-04T22:20:29.479Z,1691187629.479 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:20:29.906Z,1691187629.906 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.157434 min 
2023-08-04T22:20:29.906Z,1691187629.906 [Default:CheckIn:E] Stopped
2023-08-04T22:20:29.906Z,1691187629.906 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:20:29.906Z,1691187629.906 [Default:CheckIn] Stopped
2023-08-04T22:20:29.906Z,1691187629.906 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:20:29.906Z,1691187629.906 [Default:CheckIn](INFO): Running loop #8
2023-08-04T22:20:29.906Z,1691187629.906 [Default:CheckIn] Running Loop=8
2023-08-04T22:20:29.907Z,1691187629.907 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:20:29.907Z,1691187629.907 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:20:31.889Z,1691187631.889 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222031.00,A,3648.16862,N,12147.28320,W,0.136,108.37,040823,,,A*70
2023-08-04T22:20:31.891Z,1691187631.891 [NAL9602](INFO): GPS fix at 20230804T222031: (36.802810, -121.788053)
2023-08-04T22:20:31.943Z,1691187631.943 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:20:31.943Z,1691187631.943 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:20:39.865Z,1691187639.865 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0043.lzma
2023-08-04T22:20:40.867Z,1691187640.867 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0043.lzma.bak
2023-08-04T22:20:40.868Z,1691187640.868 [DataOverHttps](INFO): SBD MOMSN=18519158
2023-08-04T22:20:57.249Z,1691187657.249 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230804T200832/Express0044.lzma
2023-08-04T22:20:58.252Z,1691187658.252 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0044.lzma.bak
2023-08-04T22:20:58.252Z,1691187658.252 [DataOverHttps](INFO): SBD MOMSN=18519164
2023-08-04T22:20:59.804Z,1691187659.804 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:20:59.804Z,1691187659.804 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:20:59.804Z,1691187659.804 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T22:21:02.595Z,1691187662.595 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-08-04T22:21:02.678Z,1691187662.678 [NAL9602](ERROR): received: 
+CSQ:0

OK171, 2, 0, 0, 0

OK
2023-08-04T22:24:11.324Z,1691187851.324 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T22:24:11.324Z,1691187851.324 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:25:21.628Z,1691187921.628 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T22:25:21.628Z,1691187921.628 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:25:34.555Z,1691187934.555 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T22:26:00.420Z,1691187960.420 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:26:00.420Z,1691187960.420 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:26:00.420Z,1691187960.420 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:26:00.420Z,1691187960.420 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:26:00.831Z,1691187960.831 [Default:CheckIn:D] Stopped
2023-08-04T22:26:00.831Z,1691187960.831 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:26:01.246Z,1691187961.246 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.679960 min 
2023-08-04T22:26:01.246Z,1691187961.246 [Default:CheckIn:E] Stopped
2023-08-04T22:26:01.247Z,1691187961.247 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:26:01.247Z,1691187961.247 [Default:CheckIn] Stopped
2023-08-04T22:26:01.247Z,1691187961.247 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:26:01.247Z,1691187961.247 [Default:CheckIn](INFO): Running loop #9
2023-08-04T22:26:01.247Z,1691187961.247 [Default:CheckIn] Running Loop=9
2023-08-04T22:26:01.247Z,1691187961.247 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:26:01.247Z,1691187961.247 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:26:03.241Z,1691187963.241 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222602.00,A,3648.17074,N,12147.28248,W,0.078,0.00,040823,,,A*71
2023-08-04T22:26:03.243Z,1691187963.243 [NAL9602](INFO): GPS fix at 20230804T222602: (36.802846, -121.788041)
2023-08-04T22:26:03.255Z,1691187963.255 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:26:03.255Z,1691187963.255 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:26:10.977Z,1691187970.977 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0046.lzma
2023-08-04T22:26:11.980Z,1691187971.980 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0046.lzma.bak
2023-08-04T22:26:11.980Z,1691187971.980 [DataOverHttps](INFO): SBD MOMSN=18519185
2023-08-04T22:26:31.339Z,1691187991.339 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230804T200832/Express0047.lzma
2023-08-04T22:26:32.340Z,1691187992.340 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0047.lzma.bak
2023-08-04T22:26:32.340Z,1691187992.340 [DataOverHttps](INFO): SBD MOMSN=18519192
2023-08-04T22:26:34.030Z,1691187994.030 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:26:34.030Z,1691187994.030 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:26:34.030Z,1691187994.030 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T22:26:35.631Z,1691187995.631 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T22:31:05.165Z,1691188265.165 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2023-08-04T22:31:05.168Z,1691188265.168 [BPC1](INFO): Received data from all battery sticks.
2023-08-04T22:31:34.666Z,1691188294.666 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:31:34.666Z,1691188294.666 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:31:34.666Z,1691188294.666 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:31:34.666Z,1691188294.666 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:31:35.075Z,1691188295.075 [Default:CheckIn:D] Stopped
2023-08-04T22:31:35.075Z,1691188295.075 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:31:35.481Z,1691188295.481 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.250684 min 
2023-08-04T22:31:35.481Z,1691188295.481 [Default:CheckIn:E] Stopped
2023-08-04T22:31:35.481Z,1691188295.481 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:31:35.481Z,1691188295.481 [Default:CheckIn] Stopped
2023-08-04T22:31:35.481Z,1691188295.481 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:31:35.486Z,1691188295.486 [Default:CheckIn](INFO): Running loop #10
2023-08-04T22:31:35.486Z,1691188295.486 [Default:CheckIn] Running Loop=10
2023-08-04T22:31:35.486Z,1691188295.486 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:31:35.486Z,1691188295.486 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:31:37.485Z,1691188297.485 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223136.00,A,3648.17012,N,12147.28031,W,0.544,25.54,040823,,,A*40
2023-08-04T22:31:37.487Z,1691188297.487 [NAL9602](INFO): GPS fix at 20230804T223136: (36.802835, -121.788005)
2023-08-04T22:31:37.528Z,1691188297.528 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:31:37.529Z,1691188297.529 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:31:44.845Z,1691188304.845 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20230804T200832/Courier0049.lzma
2023-08-04T22:31:45.848Z,1691188305.848 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0049.lzma.bak
2023-08-04T22:31:45.848Z,1691188305.848 [DataOverHttps](INFO): SBD MOMSN=18519201
2023-08-04T22:32:02.281Z,1691188322.281 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230804T200832/Express0050.lzma
2023-08-04T22:32:03.284Z,1691188323.284 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0050.lzma.bak
2023-08-04T22:32:03.284Z,1691188323.284 [DataOverHttps](INFO): SBD MOMSN=18519204
2023-08-04T22:32:04.967Z,1691188324.967 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:32:04.967Z,1691188324.967 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:32:04.967Z,1691188324.967 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T22:32:08.196Z,1691188328.196 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-08-04T22:32:08.274Z,1691188328.274 [NAL9602](ERROR): received: 
+CSQ:1

OK171, 2, 0, 0, 0

OK
2023-08-04T22:32:45.352Z,1691188365.352 [NAL9602](INFO): SBD MO Status=2, MOMSN=29171, MT Status=2, MTMSN=0
2023-08-04T22:32:45.352Z,1691188365.352 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:33:27.368Z,1691188407.368 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=29171, MT Status=1, MTMSN=1543
2023-08-04T22:33:27.368Z,1691188407.368 [NAL9602](INFO): Data available in MT queue
2023-08-04T22:33:27.870Z,1691188407.870 [NAL9602](INFO): Received command: gfscan
2023-08-04T22:33:27.879Z,1691188407.879 [CommandExec](IMPORTANT): got command gfscan
2023-08-04T22:33:27.912Z,1691188407.912 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T22:33:38.723Z,1691188418.723 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.005147
CHAN A1 (24V): 0.024282
CHAN A2 (12V): 0.004285
CHAN A3 (5V): 0.001980
CHAN B0 (3.3V): 0.003481
CHAN B1 (3.15aV): 0.003295
CHAN B2 (3.15bV): 0.002718
CHAN B3 (GND): 0.001533
OPEN: 0.006692
Full Scale: +/- 1 mA
2023-08-04T22:33:58.475Z,1691188438.475 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T22:37:05.621Z,1691188625.621 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:37:05.621Z,1691188625.621 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:37:05.621Z,1691188625.621 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:37:05.622Z,1691188625.622 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:37:05.985Z,1691188625.985 [Default:CheckIn:D] Stopped
2023-08-04T22:37:05.985Z,1691188625.985 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:37:06.395Z,1691188626.395 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.765861 min 
2023-08-04T22:37:06.395Z,1691188626.395 [Default:CheckIn:E] Stopped
2023-08-04T22:37:06.395Z,1691188626.395 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:37:06.395Z,1691188626.395 [Default:CheckIn] Stopped
2023-08-04T22:37:06.395Z,1691188626.395 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:37:06.395Z,1691188626.395 [Default:CheckIn](INFO): Running loop #11
2023-08-04T22:37:06.395Z,1691188626.395 [Default:CheckIn] Running Loop=11
2023-08-04T22:37:06.395Z,1691188626.395 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:37:06.396Z,1691188626.396 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:37:08.402Z,1691188628.402 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223707.00,A,3648.17140,N,12147.28058,W,0.272,25.54,040823,,,A*4F
2023-08-04T22:37:08.404Z,1691188628.404 [NAL9602](INFO): GPS fix at 20230804T223707: (36.802857, -121.788010)
2023-08-04T22:37:08.416Z,1691188628.416 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:37:08.416Z,1691188628.416 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:37:16.513Z,1691188636.513 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0052.lzma
2023-08-04T22:37:17.519Z,1691188637.519 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0052.lzma.bak
2023-08-04T22:37:17.519Z,1691188637.519 [DataOverHttps](INFO): SBD MOMSN=18519215
2023-08-04T22:37:33.810Z,1691188653.810 [DataOverHttps](INFO): Sending 361 bytes from file Logs/20230804T200832/Express0053.lzma
2023-08-04T22:37:34.812Z,1691188654.812 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0053.lzma.bak
2023-08-04T22:37:34.812Z,1691188654.812 [DataOverHttps](INFO): SBD MOMSN=18519221
2023-08-04T22:37:36.314Z,1691188656.314 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:37:36.314Z,1691188656.314 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:37:36.315Z,1691188656.315 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T22:41:55.643Z,1691188915.643 [NAL9602](INFO): SBD MO Status=2, MOMSN=29172, MT Status=2, MTMSN=0
2023-08-04T22:41:55.643Z,1691188915.643 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:42:06.563Z,1691188926.563 [NAL9602](INFO): SBD MO Status=0, MOMSN=29172, MT Status=0, MTMSN=0
2023-08-04T22:42:06.564Z,1691188926.564 [NAL9602](INFO): No messages in MT queue
2023-08-04T22:42:36.871Z,1691188956.871 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:42:36.871Z,1691188956.871 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:42:36.871Z,1691188956.871 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:42:36.871Z,1691188956.871 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:42:37.267Z,1691188957.267 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T22:42:37.280Z,1691188957.280 [Default:CheckIn:D] Stopped
2023-08-04T22:42:37.280Z,1691188957.280 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:42:37.708Z,1691188957.708 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.287435 min 
2023-08-04T22:42:37.708Z,1691188957.708 [Default:CheckIn:E] Stopped
2023-08-04T22:42:37.708Z,1691188957.708 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:42:37.708Z,1691188957.708 [Default:CheckIn] Stopped
2023-08-04T22:42:37.709Z,1691188957.709 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:42:37.709Z,1691188957.709 [Default:CheckIn](INFO): Running loop #12
2023-08-04T22:42:37.709Z,1691188957.709 [Default:CheckIn] Running Loop=12
2023-08-04T22:42:37.709Z,1691188957.709 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:42:37.709Z,1691188957.709 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:42:39.689Z,1691188959.689 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224239.00,A,3648.16614,N,12147.27998,W,0.194,8.89,040823,,,A*79
2023-08-04T22:42:39.691Z,1691188959.691 [NAL9602](INFO): GPS fix at 20230804T224239: (36.802769, -121.788000)
2023-08-04T22:42:39.750Z,1691188959.750 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:42:39.751Z,1691188959.751 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:42:48.317Z,1691188968.317 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230804T200832/Courier0055.lzma
2023-08-04T22:42:49.320Z,1691188969.320 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0055.lzma.bak
2023-08-04T22:42:49.320Z,1691188969.320 [DataOverHttps](INFO): SBD MOMSN=18519231
2023-08-04T22:43:03.956Z,1691188983.956 [NAL9602](INFO): SBD MO Status=2, MOMSN=29173, MT Status=2, MTMSN=0
2023-08-04T22:43:03.956Z,1691188983.956 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:43:05.576Z,1691188985.576 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20230804T200832/Express0056.lzma
2023-08-04T22:43:06.572Z,1691188986.572 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0056.lzma.bak
2023-08-04T22:43:06.572Z,1691188986.572 [DataOverHttps](INFO): SBD MOMSN=18519237
2023-08-04T22:43:08.046Z,1691188988.046 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:43:08.046Z,1691188988.046 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:43:08.046Z,1691188988.046 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T22:43:50.843Z,1691189030.843 [NAL9602](INFO): SBD MO Status=0, MOMSN=29173, MT Status=0, MTMSN=0
2023-08-04T22:43:50.843Z,1691189030.843 [NAL9602](INFO): No messages in MT queue
2023-08-04T22:44:21.589Z,1691189061.589 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T22:48:08.629Z,1691189288.629 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:48:08.629Z,1691189288.629 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:48:08.629Z,1691189288.629 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:48:08.630Z,1691189288.630 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:48:09.026Z,1691189289.026 [Default:CheckIn:D] Stopped
2023-08-04T22:48:09.026Z,1691189289.026 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:48:09.430Z,1691189289.430 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 81.816545 min 
2023-08-04T22:48:09.430Z,1691189289.430 [Default:CheckIn:E] Stopped
2023-08-04T22:48:09.431Z,1691189289.431 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:48:09.431Z,1691189289.431 [Default:CheckIn] Stopped
2023-08-04T22:48:09.431Z,1691189289.431 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:48:09.431Z,1691189289.431 [Default:CheckIn](INFO): Running loop #13
2023-08-04T22:48:09.431Z,1691189289.431 [Default:CheckIn] Running Loop=13
2023-08-04T22:48:09.431Z,1691189289.431 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:48:09.431Z,1691189289.431 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:48:11.437Z,1691189291.437 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224810.00,A,3648.16783,N,12147.28154,W,0.117,8.70,040823,,,A*7D
2023-08-04T22:48:11.447Z,1691189291.447 [NAL9602](INFO): GPS fix at 20230804T224810: (36.802797, -121.788026)
2023-08-04T22:48:11.459Z,1691189291.459 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:48:11.459Z,1691189291.459 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:48:23.697Z,1691189303.697 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0058.lzma
2023-08-04T22:48:24.700Z,1691189304.700 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0058.lzma.bak
2023-08-04T22:48:24.700Z,1691189304.700 [DataOverHttps](INFO): SBD MOMSN=18519247
2023-08-04T22:48:42.482Z,1691189322.482 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20230804T200832/Express0059.lzma
2023-08-04T22:48:43.484Z,1691189323.484 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0059.lzma.bak
2023-08-04T22:48:43.484Z,1691189323.484 [DataOverHttps](INFO): SBD MOMSN=18519253
2023-08-04T22:48:45.046Z,1691189325.046 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:48:45.046Z,1691189325.046 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:48:45.046Z,1691189325.046 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T22:49:56.528Z,1691189396.528 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T22:49:56.528Z,1691189396.528 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:50:45.820Z,1691189445.820 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T22:50:45.820Z,1691189445.820 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:51:11.268Z,1691189471.268 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T22:51:11.269Z,1691189471.269 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:53:16.128Z,1691189596.128 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T22:53:16.128Z,1691189596.128 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T22:53:16.527Z,1691189596.527 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T22:53:45.673Z,1691189625.673 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:53:45.673Z,1691189625.673 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:53:45.673Z,1691189625.673 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:53:45.678Z,1691189625.678 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:53:46.038Z,1691189626.038 [Default:CheckIn:D] Stopped
2023-08-04T22:53:46.038Z,1691189626.038 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:53:46.447Z,1691189626.447 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.433407 min 
2023-08-04T22:53:46.447Z,1691189626.447 [Default:CheckIn:E] Stopped
2023-08-04T22:53:46.447Z,1691189626.447 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:53:46.447Z,1691189626.447 [Default:CheckIn] Stopped
2023-08-04T22:53:46.447Z,1691189626.447 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:53:46.447Z,1691189626.447 [Default:CheckIn](INFO): Running loop #14
2023-08-04T22:53:46.447Z,1691189626.447 [Default:CheckIn] Running Loop=14
2023-08-04T22:53:46.447Z,1691189626.447 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:53:46.448Z,1691189626.448 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:53:48.449Z,1691189628.449 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225347.00,A,3648.16423,N,12147.28319,W,0.253,215.48,040823,,,A*71
2023-08-04T22:53:48.451Z,1691189628.451 [NAL9602](INFO): GPS fix at 20230804T225347: (36.802737, -121.788053)
2023-08-04T22:53:48.483Z,1691189628.483 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:53:48.483Z,1691189628.483 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:53:56.389Z,1691189636.389 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0061.lzma
2023-08-04T22:53:57.392Z,1691189637.392 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0061.lzma.bak
2023-08-04T22:53:57.392Z,1691189637.392 [DataOverHttps](INFO): SBD MOMSN=18519259
2023-08-04T22:54:13.814Z,1691189653.814 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230804T200832/Express0062.lzma
2023-08-04T22:54:14.816Z,1691189654.816 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0062.lzma.bak
2023-08-04T22:54:14.816Z,1691189654.816 [DataOverHttps](INFO): SBD MOMSN=18519265
2023-08-04T22:54:16.339Z,1691189656.339 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:54:16.339Z,1691189656.339 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:54:16.339Z,1691189656.339 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T22:54:20.387Z,1691189660.387 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T22:59:16.979Z,1691189956.979 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T22:59:16.979Z,1691189956.979 [Default:CheckIn:C.Wait] Stopped
2023-08-04T22:59:16.979Z,1691189956.979 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T22:59:16.979Z,1691189956.979 [Default:CheckIn:D] Running Loop=1
2023-08-04T22:59:17.366Z,1691189957.366 [Default:CheckIn:D] Stopped
2023-08-04T22:59:17.366Z,1691189957.366 [Default:CheckIn:E] Running Loop=1
2023-08-04T22:59:17.794Z,1691189957.794 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 92.955542 min 
2023-08-04T22:59:17.794Z,1691189957.794 [Default:CheckIn:E] Stopped
2023-08-04T22:59:17.794Z,1691189957.794 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T22:59:17.795Z,1691189957.795 [Default:CheckIn] Stopped
2023-08-04T22:59:17.795Z,1691189957.795 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T22:59:17.795Z,1691189957.795 [Default:CheckIn](INFO): Running loop #15
2023-08-04T22:59:17.795Z,1691189957.795 [Default:CheckIn] Running Loop=15
2023-08-04T22:59:17.795Z,1691189957.795 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T22:59:17.795Z,1691189957.795 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T22:59:19.781Z,1691189959.781 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225919.00,A,3648.16621,N,12147.27887,W,0.350,173.93,040823,,,A*74
2023-08-04T22:59:19.783Z,1691189959.783 [NAL9602](INFO): GPS fix at 20230804T225919: (36.802770, -121.787981)
2023-08-04T22:59:19.831Z,1691189959.831 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T22:59:19.831Z,1691189959.831 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T22:59:26.993Z,1691189966.993 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0064.lzma
2023-08-04T22:59:27.996Z,1691189967.996 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0064.lzma.bak
2023-08-04T22:59:27.996Z,1691189967.996 [DataOverHttps](INFO): SBD MOMSN=18519280
2023-08-04T22:59:44.345Z,1691189984.345 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20230804T200832/Express0065.lzma
2023-08-04T22:59:45.348Z,1691189985.348 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0065.lzma.bak
2023-08-04T22:59:45.348Z,1691189985.348 [DataOverHttps](INFO): SBD MOMSN=18519283
2023-08-04T22:59:46.880Z,1691189986.880 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T22:59:46.880Z,1691189986.880 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T22:59:46.880Z,1691189986.880 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T23:00:26.910Z,1691190026.910 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T23:00:26.910Z,1691190026.910 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T23:01:35.965Z,1691190095.965 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T23:01:35.965Z,1691190095.965 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T23:01:53.340Z,1691190113.340 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T23:01:53.340Z,1691190113.340 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T23:02:10.306Z,1691190130.306 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T23:02:10.306Z,1691190130.306 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T23:02:45.080Z,1691190165.080 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T23:02:45.080Z,1691190165.080 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T23:04:22.451Z,1691190262.451 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T23:04:47.502Z,1691190287.502 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T23:04:47.502Z,1691190287.502 [Default:CheckIn:C.Wait] Stopped
2023-08-04T23:04:47.502Z,1691190287.502 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T23:04:47.503Z,1691190287.503 [Default:CheckIn:D] Running Loop=1
2023-08-04T23:04:47.962Z,1691190287.962 [Default:CheckIn:D] Stopped
2023-08-04T23:04:47.962Z,1691190287.962 [Default:CheckIn:E] Running Loop=1
2023-08-04T23:04:48.329Z,1691190288.329 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 98.465470 min 
2023-08-04T23:04:48.329Z,1691190288.329 [Default:CheckIn:E] Stopped
2023-08-04T23:04:48.329Z,1691190288.329 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T23:04:48.330Z,1691190288.330 [Default:CheckIn] Stopped
2023-08-04T23:04:48.330Z,1691190288.330 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T23:04:48.330Z,1691190288.330 [Default:CheckIn](INFO): Running loop #16
2023-08-04T23:04:48.330Z,1691190288.330 [Default:CheckIn] Running Loop=16
2023-08-04T23:04:48.330Z,1691190288.330 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T23:04:48.330Z,1691190288.330 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T23:04:50.321Z,1691190290.321 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230449.00,A,3648.16294,N,12147.28503,W,0.039,173.93,040823,,,A*70
2023-08-04T23:04:50.323Z,1691190290.323 [NAL9602](INFO): GPS fix at 20230804T230449: (36.802716, -121.788084)
2023-08-04T23:04:50.351Z,1691190290.351 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T23:04:50.351Z,1691190290.351 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T23:04:58.141Z,1691190298.141 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0067.lzma
2023-08-04T23:04:59.144Z,1691190299.144 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0067.lzma.bak
2023-08-04T23:04:59.144Z,1691190299.144 [DataOverHttps](INFO): SBD MOMSN=18519292
2023-08-04T23:05:15.738Z,1691190315.738 [DataOverHttps](INFO): Sending 203 bytes from file Logs/20230804T200832/Express0068.lzma
2023-08-04T23:05:16.740Z,1691190316.740 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0068.lzma.bak
2023-08-04T23:05:16.740Z,1691190316.740 [DataOverHttps](INFO): SBD MOMSN=18519296
2023-08-04T23:05:18.210Z,1691190318.210 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T23:05:18.210Z,1691190318.210 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T23:05:18.211Z,1691190318.211 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T23:05:22.635Z,1691190322.635 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T23:08:59.567Z,1691190539.567 [CommandExec](IMPORTANT): got command gfscan
2023-08-04T23:08:59.736Z,1691190539.736 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T23:09:10.574Z,1691190550.574 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.006957
CHAN A1 (24V): 0.024952
CHAN A2 (12V): 0.005390
CHAN A3 (5V): 0.002970
CHAN B0 (3.3V): 0.003809
CHAN B1 (3.15aV): 0.003975
CHAN B2 (3.15bV): 0.004324
CHAN B3 (GND): 0.001981
OPEN: 0.006719
Full Scale: +/- 1 mA
2023-08-04T23:10:18.877Z,1691190618.877 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T23:10:18.877Z,1691190618.877 [Default:CheckIn:C.Wait] Stopped
2023-08-04T23:10:18.877Z,1691190618.877 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T23:10:18.878Z,1691190618.878 [Default:CheckIn:D] Running Loop=1
2023-08-04T23:10:19.250Z,1691190619.250 [Default:CheckIn:D] Stopped
2023-08-04T23:10:19.250Z,1691190619.250 [Default:CheckIn:E] Running Loop=1
2023-08-04T23:10:19.725Z,1691190619.725 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 103.986938 min 
2023-08-04T23:10:19.725Z,1691190619.725 [Default:CheckIn:E] Stopped
2023-08-04T23:10:19.725Z,1691190619.725 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T23:10:19.725Z,1691190619.725 [Default:CheckIn] Stopped
2023-08-04T23:10:19.725Z,1691190619.725 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T23:10:19.726Z,1691190619.726 [Default:CheckIn](INFO): Running loop #17
2023-08-04T23:10:19.726Z,1691190619.726 [Default:CheckIn] Running Loop=17
2023-08-04T23:10:19.726Z,1691190619.726 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T23:10:19.726Z,1691190619.726 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T23:10:21.698Z,1691190621.698 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231020.00,A,3648.16600,N,12147.28284,W,0.097,173.93,040823,,,A*7F
2023-08-04T23:10:21.700Z,1691190621.700 [NAL9602](INFO): GPS fix at 20230804T231020: (36.802767, -121.788047)
2023-08-04T23:10:21.988Z,1691190621.988 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T23:10:21.988Z,1691190621.988 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T23:10:31.053Z,1691190631.053 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0070.lzma
2023-08-04T23:10:32.056Z,1691190632.056 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0070.lzma.bak
2023-08-04T23:10:32.056Z,1691190632.056 [DataOverHttps](INFO): SBD MOMSN=18519306
2023-08-04T23:10:48.666Z,1691190648.666 [DataOverHttps](INFO): Sending 332 bytes from file Logs/20230804T200832/Express0071.lzma
2023-08-04T23:10:49.668Z,1691190649.668 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0071.lzma.bak
2023-08-04T23:10:49.668Z,1691190649.668 [DataOverHttps](INFO): SBD MOMSN=18519309
2023-08-04T23:10:51.204Z,1691190651.204 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T23:10:51.204Z,1691190651.204 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T23:10:51.204Z,1691190651.204 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T23:10:52.367Z,1691190652.367 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-08-04T23:10:52.446Z,1691190652.446 [NAL9602](ERROR): received: 
+CSQ:0

OK174, 2, 0, 0, 0

OK
2023-08-04T23:13:22.248Z,1691190802.248 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T23:13:22.248Z,1691190802.248 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T23:15:24.256Z,1691190924.256 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T23:15:51.766Z,1691190951.766 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T23:15:51.767Z,1691190951.767 [Default:CheckIn:C.Wait] Stopped
2023-08-04T23:15:51.767Z,1691190951.767 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T23:15:51.767Z,1691190951.767 [Default:CheckIn:D] Running Loop=1
2023-08-04T23:15:52.164Z,1691190952.164 [Default:CheckIn:D] Stopped
2023-08-04T23:15:52.164Z,1691190952.164 [Default:CheckIn:E] Running Loop=1
2023-08-04T23:15:52.593Z,1691190952.593 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 109.535506 min 
2023-08-04T23:15:52.593Z,1691190952.593 [Default:CheckIn:E] Stopped
2023-08-04T23:15:52.593Z,1691190952.593 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T23:15:52.593Z,1691190952.593 [Default:CheckIn] Stopped
2023-08-04T23:15:52.593Z,1691190952.593 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T23:15:52.593Z,1691190952.593 [Default:CheckIn](INFO): Running loop #18
2023-08-04T23:15:52.593Z,1691190952.593 [Default:CheckIn] Running Loop=18
2023-08-04T23:15:52.594Z,1691190952.594 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T23:15:52.594Z,1691190952.594 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T23:15:54.595Z,1691190954.595 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,231553.00,A,3648.16478,N,12147.27865,W,0.156,65.21,040823,,,A*4A
2023-08-04T23:15:54.601Z,1691190954.601 [NAL9602](INFO): GPS fix at 20230804T231553: (36.802746, -121.787977)
2023-08-04T23:15:54.663Z,1691190954.663 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T23:15:54.663Z,1691190954.663 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T23:16:02.173Z,1691190962.173 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0073.lzma
2023-08-04T23:16:03.176Z,1691190963.176 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0073.lzma.bak
2023-08-04T23:16:03.176Z,1691190963.176 [DataOverHttps](INFO): SBD MOMSN=18519329
2023-08-04T23:16:23.610Z,1691190983.610 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230804T200832/Express0074.lzma
2023-08-04T23:16:24.612Z,1691190984.612 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0074.lzma.bak
2023-08-04T23:16:24.612Z,1691190984.612 [DataOverHttps](INFO): SBD MOMSN=18519332
2023-08-04T23:16:26.527Z,1691190986.527 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T23:16:26.549Z,1691190986.549 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T23:16:26.549Z,1691190986.549 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T23:16:26.549Z,1691190986.549 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T23:17:03.748Z,1691191023.748 [RDI_Pathfinder](ERROR): only read 1 of 4 data items for bottom velocity. Device response is::BS,   +15,   
2023-08-04T23:18:37.928Z,1691191117.928 [CommandExec](IMPORTANT): got command gfscan
2023-08-04T23:18:37.962Z,1691191117.962 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T23:18:48.799Z,1691191128.799 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.006862
CHAN A1 (24V): 0.025193
CHAN A2 (12V): 0.005442
CHAN A3 (5V): 0.003481
CHAN B0 (3.3V): 0.004546
CHAN B1 (3.15aV): 0.003588
CHAN B2 (3.15bV): 0.003503
CHAN B3 (GND): 0.001995
OPEN: 0.007051
Full Scale: +/- 1 mA
2023-08-04T23:18:57.107Z,1691191137.107 [CommandExec](IMPORTANT): got command gfscan
2023-08-04T23:18:57.303Z,1691191137.303 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T23:19:08.188Z,1691191148.188 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.006556
CHAN A1 (24V): 0.025124
CHAN A2 (12V): 0.005315
CHAN A3 (5V): 0.003055
CHAN B0 (3.3V): 0.003400
CHAN B1 (3.15aV): 0.003105
CHAN B2 (3.15bV): 0.002627
CHAN B3 (GND): 0.002063
OPEN: 0.006865
Full Scale: +/- 1 mA
2023-08-04T23:19:31.691Z,1691191171.691 [CommandExec](IMPORTANT): got command gfscan
2023-08-04T23:19:32.028Z,1691191172.028 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T23:19:42.930Z,1691191182.930 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.006103
CHAN A1 (24V): 0.025209
CHAN A2 (12V): 0.005433
CHAN A3 (5V): 0.002751
CHAN B0 (3.3V): 0.004328
CHAN B1 (3.15aV): 0.003474
CHAN B2 (3.15bV): 0.002767
CHAN B3 (GND): 0.002365
OPEN: 0.006795
Full Scale: +/- 1 mA
2023-08-04T23:21:27.176Z,1691191287.176 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T23:21:27.176Z,1691191287.176 [Default:CheckIn:C.Wait] Stopped
2023-08-04T23:21:27.176Z,1691191287.176 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T23:21:27.177Z,1691191287.177 [Default:CheckIn:D] Running Loop=1
2023-08-04T23:21:27.559Z,1691191287.559 [Default:CheckIn:D] Stopped
2023-08-04T23:21:27.559Z,1691191287.559 [Default:CheckIn:E] Running Loop=1
2023-08-04T23:21:27.962Z,1691191287.962 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.125423 min 
2023-08-04T23:21:27.962Z,1691191287.962 [Default:CheckIn:E] Stopped
2023-08-04T23:21:27.962Z,1691191287.962 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T23:21:27.962Z,1691191287.962 [Default:CheckIn] Stopped
2023-08-04T23:21:27.963Z,1691191287.963 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T23:21:27.963Z,1691191287.963 [Default:CheckIn](INFO): Running loop #19
2023-08-04T23:21:27.963Z,1691191287.963 [Default:CheckIn] Running Loop=19
2023-08-04T23:21:27.963Z,1691191287.963 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T23:21:27.963Z,1691191287.963 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T23:21:29.969Z,1691191289.969 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232129.00,A,3648.16231,N,12147.27770,W,0.233,65.21,040823,,,A*40
2023-08-04T23:21:29.971Z,1691191289.971 [NAL9602](INFO): GPS fix at 20230804T232129: (36.802705, -121.787962)
2023-08-04T23:21:29.983Z,1691191289.983 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T23:21:29.984Z,1691191289.984 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T23:21:33.879Z,1691191293.879 [CommandExec](IMPORTANT): got command gfscan
2023-08-04T23:21:34.061Z,1691191294.061 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T23:21:38.454Z,1691191298.454 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0076.lzma
2023-08-04T23:21:39.456Z,1691191299.456 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0076.lzma.bak
2023-08-04T23:21:39.456Z,1691191299.456 [DataOverHttps](INFO): SBD MOMSN=18519344
2023-08-04T23:21:44.971Z,1691191304.971 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.006473
CHAN A1 (24V): 0.025364
CHAN A2 (12V): 0.005474
CHAN A3 (5V): 0.003832
CHAN B0 (3.3V): 0.004410
CHAN B1 (3.15aV): 0.003445
CHAN B2 (3.15bV): 0.003613
CHAN B3 (GND): 0.002127
OPEN: 0.006959
Full Scale: +/- 1 mA
2023-08-04T23:21:56.202Z,1691191316.202 [DataOverHttps](INFO): Sending 415 bytes from file Logs/20230804T200832/Express0077.lzma
2023-08-04T23:21:57.204Z,1691191317.204 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0077.lzma.bak
2023-08-04T23:21:57.204Z,1691191317.204 [DataOverHttps](INFO): SBD MOMSN=18519347
2023-08-04T23:21:58.682Z,1691191318.682 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T23:21:58.682Z,1691191318.682 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T23:21:58.682Z,1691191318.682 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T23:22:00.675Z,1691191320.675 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-08-04T23:22:00.754Z,1691191320.754 [NAL9602](ERROR): received: 
+CSQ:0

OK174, 2, 0, 0, 0

OK
2023-08-04T23:24:40.352Z,1691191480.352 [NAL9602](INFO): SBD MO Status=2, MOMSN=29174, MT Status=2, MTMSN=0
2023-08-04T23:24:40.352Z,1691191480.352 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-08-04T23:26:32.283Z,1691191592.283 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-08-04T23:26:59.334Z,1691191619.334 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-08-04T23:26:59.334Z,1691191619.334 [Default:CheckIn:C.Wait] Stopped
2023-08-04T23:26:59.334Z,1691191619.334 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T23:26:59.334Z,1691191619.334 [Default:CheckIn:D] Running Loop=1
2023-08-04T23:26:59.766Z,1691191619.766 [Default:CheckIn:D] Stopped
2023-08-04T23:26:59.766Z,1691191619.766 [Default:CheckIn:E] Running Loop=1
2023-08-04T23:27:00.163Z,1691191620.163 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 120.662215 min 
2023-08-04T23:27:00.163Z,1691191620.163 [Default:CheckIn:E] Stopped
2023-08-04T23:27:00.163Z,1691191620.163 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-08-04T23:27:00.163Z,1691191620.163 [Default:CheckIn] Stopped
2023-08-04T23:27:00.163Z,1691191620.163 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T23:27:00.164Z,1691191620.164 [Default:CheckIn](INFO): Running loop #20
2023-08-04T23:27:00.164Z,1691191620.164 [Default:CheckIn] Running Loop=20
2023-08-04T23:27:00.164Z,1691191620.164 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-08-04T23:27:00.164Z,1691191620.164 [Default:CheckIn:Read_GPS] Running Loop=1
2023-08-04T23:27:02.153Z,1691191622.153 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232701.00,A,3648.16478,N,12147.28088,W,0.058,65.21,040823,,,A*47
2023-08-04T23:27:02.155Z,1691191622.155 [NAL9602](INFO): GPS fix at 20230804T232701: (36.802746, -121.788015)
2023-08-04T23:27:02.234Z,1691191622.234 [Default:CheckIn:Read_GPS] Stopped
2023-08-04T23:27:02.234Z,1691191622.234 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-08-04T23:27:09.585Z,1691191629.585 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20230804T200832/Courier0079.lzma
2023-08-04T23:27:10.588Z,1691191630.588 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Courier0079.lzma.bak
2023-08-04T23:27:10.588Z,1691191630.588 [DataOverHttps](INFO): SBD MOMSN=18519365
2023-08-04T23:27:27.294Z,1691191647.294 [DataOverHttps](INFO): Sending 394 bytes from file Logs/20230804T200832/Express0080.lzma
2023-08-04T23:27:28.296Z,1691191648.296 [DataOverHttps](INFO): Moved sent file to Logs/20230804T200832/Express0080.lzma.bak
2023-08-04T23:27:28.296Z,1691191648.296 [DataOverHttps](INFO): SBD MOMSN=18519369
2023-08-04T23:27:29.731Z,1691191649.731 [Default:CheckIn:Read_Iridium] Stopped
2023-08-04T23:27:29.731Z,1691191649.731 [Default:CheckIn:C.Wait] Running Loop=1
2023-08-04T23:27:29.731Z,1691191649.731 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-08-04T23:27:34.563Z,1691191654.563 [NAL9602](INFO): Not Powering down - fast GPS
2023-08-04T23:27:37.147Z,1691191657.147 [DataOverHttps](IMPORTANT): SBD MTMSN=20230804T232736
2023-08-04T23:27:45.109Z,1691191665.109 [DataOverHttps](INFO): Received command: configSet CBIT.gfScanTimeout 5 minute persist;restart app
2023-08-04T23:27:45.428Z,1691191665.428 [CommandExec](IMPORTANT): got command configSet CBIT.gfScanTimeout 5 minute persist
2023-08-04T23:27:45.431Z,1691191665.431 [CommandExec](IMPORTANT): got command restart application
2023-08-04T23:27:45.541Z,1691191665.541 [CBIT](IMPORTANT): Beginning ground fault scan
2023-08-04T23:27:46.434Z,1691191666.434 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2023-08-04T23:27:46.434Z,1691191666.434 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:46.434Z,1691191666.434 [CommandExec](INFO): Uninitializing the command executive.
2023-08-04T23:27:46.434Z,1691191666.434 [CommandExec](INFO): Uninitializing the command scheduler.
2023-08-04T23:27:46.434Z,1691191666.434 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:46.502Z,1691191666.502 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-08-04T23:27:46.502Z,1691191666.502 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-08-04T23:27:46.503Z,1691191666.503 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:46.503Z,1691191666.503 [NavChartDb](INFO): Join timeout helper Thread ID is 1033
2023-08-04T23:27:46.830Z,1691191666.830 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:46.830Z,1691191666.830 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:46.842Z,1691191666.842 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2023-08-04T23:27:46.842Z,1691191666.842 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:46.843Z,1691191666.843 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 1034
2023-08-04T23:27:47.202Z,1691191667.202 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:47.202Z,1691191667.202 [WetLabsUBAT](INFO): Powering down
2023-08-04T23:27:47.203Z,1691191667.203 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:47.210Z,1691191667.210 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-08-04T23:27:47.210Z,1691191667.210 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:47.210Z,1691191667.210 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1035
2023-08-04T23:27:47.386Z,1691191667.386 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:47.387Z,1691191667.387 [WetLabsBB2FL](INFO): Powering down
2023-08-04T23:27:47.389Z,1691191667.389 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:47.402Z,1691191667.402 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-08-04T23:27:47.402Z,1691191667.402 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:47.402Z,1691191667.402 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1036
2023-08-04T23:27:47.910Z,1691191667.910 [CTD_Seabird](INFO): Powering down
2023-08-04T23:27:47.922Z,1691191667.922 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:47.922Z,1691191667.922 [CTD_Seabird](INFO): Powering down
2023-08-04T23:27:47.934Z,1691191667.934 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:47.934Z,1691191667.934 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2023-08-04T23:27:47.934Z,1691191667.934 [DAT ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:47.935Z,1691191667.935 [DAT](INFO): Join timeout helper Thread ID is 1037
2023-08-04T23:27:48.062Z,1691191668.062 [DAT](INFO): Powering down
2023-08-04T23:27:48.130Z,1691191668.130 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:48.130Z,1691191668.130 [DAT](INFO): Powering down
2023-08-04T23:27:48.131Z,1691191668.131 [DAT ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:48.135Z,1691191668.135 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-08-04T23:27:48.135Z,1691191668.135 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:48.135Z,1691191668.135 [Radio_Surface](INFO): Join timeout helper Thread ID is 1038
2023-08-04T23:27:48.426Z,1691191668.426 [Radio_Surface](INFO): Powering down
2023-08-04T23:27:48.427Z,1691191668.427 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:48.427Z,1691191668.427 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:48.442Z,1691191668.442 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-08-04T23:27:48.442Z,1691191668.442 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:48.443Z,1691191668.443 [Onboard](INFO): Join timeout helper Thread ID is 1039
2023-08-04T23:27:49.122Z,1691191669.122 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-08-04T23:27:52.582Z,1691191672.582 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:52.582Z,1691191672.582 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:52.602Z,1691191672.602 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-08-04T23:27:52.602Z,1691191672.602 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:52.603Z,1691191672.603 [DataOverHttps](INFO): Join timeout helper Thread ID is 1040
2023-08-04T23:27:53.139Z,1691191673.139 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:53.140Z,1691191673.140 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.166Z,1691191673.166 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-08-04T23:27:53.167Z,1691191673.167 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.167Z,1691191673.167 [BackseatComponent](INFO): Join timeout helper Thread ID is 1041
2023-08-04T23:27:53.174Z,1691191673.174 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:53.174Z,1691191673.174 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.190Z,1691191673.190 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-08-04T23:27:53.190Z,1691191673.190 [logger ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.191Z,1691191673.191 [logger](INFO): Join timeout helper Thread ID is 1042
2023-08-04T23:27:53.194Z,1691191673.194 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:53.194Z,1691191673.194 [logger ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.203Z,1691191673.203 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-08-04T23:27:53.203Z,1691191673.203 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.204Z,1691191673.204 [CommandLine](INFO): Join timeout helper Thread ID is 1043
2023-08-04T23:27:53.278Z,1691191673.278 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:53.278Z,1691191673.278 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.282Z,1691191673.282 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-08-04T23:27:53.282Z,1691191673.282 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.283Z,1691191673.283 [CommandExec](INFO): Join timeout helper Thread ID is 1044
2023-08-04T23:27:53.284Z,1691191673.284 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-08-04T23:27:53.284Z,1691191673.284 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.284Z,1691191673.284 [controlThread](INFO): Join timeout helper Thread ID is 1045
2023-08-04T23:27:53.554Z,1691191673.554 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-08-04T23:27:53.554Z,1691191673.554 [controlThread](DEBUG): Uninitializing ControlThread
2023-08-04T23:27:53.554Z,1691191673.554 [AHRS_M2](INFO): Powering down
2023-08-04T23:27:53.626Z,1691191673.626 [NAL9602](INFO): Powering down
2023-08-04T23:27:53.698Z,1691191673.698 [RDI_Pathfinder](INFO): Powering down
2023-08-04T23:27:53.699Z,1691191673.699 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-08-04T23:27:53.700Z,1691191673.700 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-08-04T23:27:53.700Z,1691191673.700 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-08-04T23:27:53.701Z,1691191673.701 [MissionManager](INFO): Uninitializing Mission Default
2023-08-04T23:27:53.701Z,1691191673.701 [Default] Stopped
2023-08-04T23:27:53.701Z,1691191673.701 [Default](DEBUG): Aggregate::uninitialize Default
2023-08-04T23:27:53.701Z,1691191673.701 [Default:B.GoToSurface] Stopped
2023-08-04T23:27:53.701Z,1691191673.701 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-08-04T23:27:53.701Z,1691191673.701 [Default:CheckIn] Stopped
2023-08-04T23:27:53.702Z,1691191673.702 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-08-04T23:27:53.702Z,1691191673.702 [Default:CheckIn:C.Wait] Stopped
2023-08-04T23:27:53.702Z,1691191673.702 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-08-04T23:27:53.704Z,1691191673.704 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-08-04T23:27:53.705Z,1691191673.705 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-08-04T23:27:53.705Z,1691191673.705 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-08-04T23:27:53.706Z,1691191673.706 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-08-04T23:27:53.706Z,1691191673.706 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-08-04T23:27:53.706Z,1691191673.706 [BuoyancyServo](INFO): Powering down
2023-08-04T23:27:53.718Z,1691191673.718 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-08-04T23:27:53.718Z,1691191673.718 [ElevatorServo](INFO): Powering down
2023-08-04T23:27:53.719Z,1691191673.719 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-08-04T23:27:53.719Z,1691191673.719 [MassServo](INFO): Powering down
2023-08-04T23:27:53.720Z,1691191673.720 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-08-04T23:27:53.720Z,1691191673.720 [RudderServo](INFO): Powering down
2023-08-04T23:27:53.721Z,1691191673.721 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2023-08-04T23:27:53.721Z,1691191673.721 [ThrusterServo](INFO): Powering down
2023-08-04T23:27:53.722Z,1691191673.722 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-08-04T23:27:53.722Z,1691191673.722 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-08-04T23:27:53.722Z,1691191673.722 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-08-04T23:27:53.722Z,1691191673.722 [CBIT](DEBUG): Powering off loads.
2023-08-04T23:27:53.733Z,1691191673.733 [CBIT](DEBUG): Disabling WDT.
2023-08-04T23:27:53.745Z,1691191673.745 [CBIT](DEBUG): Opening all GF detection circuits.
2023-08-04T23:27:53.746Z,1691191673.746 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.804Z,1691191673.804 [DAT ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.812Z,1691191673.812 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.815Z,1691191673.815 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.821Z,1691191673.821 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.864Z,1691191673.864 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.922Z,1691191673.922 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.924Z,1691191673.924 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.927Z,1691191673.927 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:53.935Z,1691191673.935 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-08-04T23:27:54.008Z,1691191674.008 [logger ThreadHandler](INFO): Thread cancelled.