2023-05-12T21:00:12.507Z,1683925212.507 [Supervisor](DEBUG): Initializing supervisor.
2023-05-12T21:00:12.511Z,1683925212.511 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-05-12T21:00:12.512Z,1683925212.512 [SyncHandler](INFO): Protected caller Thread ID is 831
2023-05-12T21:00:12.512Z,1683925212.512 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-05-12T21:00:12.513Z,1683925212.513 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-05-12T21:00:12.513Z,1683925212.513 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 832
2023-05-12T21:00:12.517Z,1683925212.517 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-05-12T21:00:12.535Z,1683925212.535 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-05-12T21:00:12.536Z,1683925212.536 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-05-12T21:00:12.536Z,1683925212.536 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 833
2023-05-12T21:00:12.540Z,1683925212.540 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-05-12T21:00:12.541Z,1683925212.541 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-05-12T21:00:12.541Z,1683925212.541 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 834
2023-05-12T21:00:12.543Z,1683925212.543 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-05-12T21:00:12.544Z,1683925212.544 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-05-12T21:00:12.545Z,1683925212.545 [logger ThreadHandler](INFO): Protected caller Thread ID is 835
2023-05-12T21:00:12.548Z,1683925212.548 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-05-12T21:00:12.549Z,1683925212.549 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-05-12T21:00:12.554Z,1683925212.554 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-05-12T21:00:12.650Z,1683925212.650 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-05-12T21:00:12.652Z,1683925212.652 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-05-12T21:00:12.864Z,1683925212.864 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-05-12T21:00:12.866Z,1683925212.866 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-05-12T21:00:13.115Z,1683925213.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-05-12T21:00:13.117Z,1683925213.117 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-05-12T21:00:13.223Z,1683925213.223 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-05-12T21:00:13.224Z,1683925213.224 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-05-12T21:00:13.913Z,1683925213.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-05-12T21:00:13.915Z,1683925213.915 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-05-12T21:00:14.379Z,1683925214.379 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-05-12T21:00:14.380Z,1683925214.380 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-05-12T21:00:14.877Z,1683925214.877 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-05-12T21:00:14.878Z,1683925214.878 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-05-12T21:00:15.280Z,1683925215.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-05-12T21:00:15.281Z,1683925215.281 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-05-12T21:00:15.598Z,1683925215.598 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-05-12T21:00:15.600Z,1683925215.600 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-05-12T21:00:16.237Z,1683925216.237 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-05-12T21:00:16.238Z,1683925216.238 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-05-12T21:00:16.796Z,1683925216.796 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-05-12T21:00:16.797Z,1683925216.797 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-05-12T21:00:16.937Z,1683925216.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-05-12T21:00:16.939Z,1683925216.939 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-05-12T21:00:17.020Z,1683925217.020 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-05-12T21:00:17.100Z,1683925217.100 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-05-12T21:00:17.279Z,1683925217.279 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-05-12T21:00:17.279Z,1683925217.279 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-05-12T21:00:17.495Z,1683925217.495 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-05-12T21:00:17.497Z,1683925217.497 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2023-05-12T21:00:17.500Z,1683925217.500 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2023-05-12T21:00:17.584Z,1683925217.584 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2023-05-12T21:00:17.845Z,1683925217.845 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-05-12T21:00:17.846Z,1683925217.846 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2023-05-12T21:00:17.944Z,1683925217.944 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2023-05-12T21:00:18.099Z,1683925218.099 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2023-05-12T21:00:18.273Z,1683925218.273 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2023-05-12T21:00:18.357Z,1683925218.357 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2023-05-12T21:00:18.465Z,1683925218.465 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2023-05-12T21:00:18.568Z,1683925218.568 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2023-05-12T21:00:18.721Z,1683925218.721 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2023-05-12T21:00:18.816Z,1683925218.816 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2023-05-12T21:00:18.913Z,1683925218.913 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-05-12T21:00:18.936Z,1683925218.936 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-05-12T21:00:19.123Z,1683925219.123 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-05-12T21:00:19.125Z,1683925219.125 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-05-12T21:00:19.313Z,1683925219.313 [BuoyancyServo] Loaded
2023-05-12T21:00:19.314Z,1683925219.314 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-05-12T21:00:19.335Z,1683925219.335 [ElevatorServo] Loaded
2023-05-12T21:00:19.335Z,1683925219.335 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-05-12T21:00:19.355Z,1683925219.355 [MassServo] Loaded
2023-05-12T21:00:19.355Z,1683925219.355 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-05-12T21:00:19.375Z,1683925219.375 [RudderServo] Loaded
2023-05-12T21:00:19.375Z,1683925219.375 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-05-12T21:00:19.391Z,1683925219.391 [ThrusterHE] Loaded
2023-05-12T21:00:19.391Z,1683925219.391 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-05-12T21:00:19.392Z,1683925219.392 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-05-12T21:00:19.394Z,1683925219.394 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-05-12T21:00:19.568Z,1683925219.568 [SBIT](DEBUG): Construct Startup Built In Test.
2023-05-12T21:00:19.583Z,1683925219.583 [SBIT] Loaded
2023-05-12T21:00:19.583Z,1683925219.583 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-05-12T21:00:19.586Z,1683925219.586 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-05-12T21:00:19.607Z,1683925219.607 [IBIT] Loaded
2023-05-12T21:00:19.608Z,1683925219.608 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-05-12T21:00:19.613Z,1683925219.613 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-05-12T21:00:19.831Z,1683925219.831 [CBIT] Loaded
2023-05-12T21:00:19.831Z,1683925219.831 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-05-12T21:00:19.832Z,1683925219.832 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-05-12T21:00:19.833Z,1683925219.833 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-05-12T21:00:20.048Z,1683925220.048 [CTD_Seabird] Loaded
2023-05-12T21:00:20.048Z,1683925220.048 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-05-12T21:00:20.049Z,1683925220.049 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406644E0
2023-05-12T21:00:20.049Z,1683925220.049 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 917
2023-05-12T21:00:20.081Z,1683925220.081 [ESPComponent] Loaded
2023-05-12T21:00:20.082Z,1683925220.082 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-05-12T21:00:20.102Z,1683925220.102 [PAR_Licor] Loaded
2023-05-12T21:00:20.102Z,1683925220.102 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-05-12T21:00:20.133Z,1683925220.133 [WetLabsBB2FL] Loaded
2023-05-12T21:00:20.133Z,1683925220.133 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-05-12T21:00:20.134Z,1683925220.134 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406944E0
2023-05-12T21:00:20.134Z,1683925220.134 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 918
2023-05-12T21:00:20.135Z,1683925220.135 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-05-12T21:00:20.136Z,1683925220.136 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-05-12T21:00:20.207Z,1683925220.207 [DepthRateCalculator] Loaded
2023-05-12T21:00:20.207Z,1683925220.207 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-05-12T21:00:20.212Z,1683925220.212 [PitchRateCalculator] Loaded
2023-05-12T21:00:20.213Z,1683925220.213 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-05-12T21:00:20.223Z,1683925220.223 [SpeedCalculator] Loaded
2023-05-12T21:00:20.223Z,1683925220.223 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-05-12T21:00:20.238Z,1683925220.238 [VerticalHomogeneityIndexCalculator] Loaded
2023-05-12T21:00:20.238Z,1683925220.238 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2023-05-12T21:00:20.243Z,1683925220.243 [YawRateCalculator] Loaded
2023-05-12T21:00:20.243Z,1683925220.243 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-05-12T21:00:20.262Z,1683925220.262 [ElevatorOffsetCalculator] Loaded
2023-05-12T21:00:20.263Z,1683925220.263 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-05-12T21:00:20.263Z,1683925220.263 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-05-12T21:00:20.264Z,1683925220.264 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-05-12T21:00:20.392Z,1683925220.392 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-05-12T21:00:20.393Z,1683925220.393 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-05-12T21:00:20.437Z,1683925220.437 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-05-12T21:00:20.437Z,1683925220.437 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-05-12T21:00:20.574Z,1683925220.574 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-05-12T21:00:20.575Z,1683925220.575 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-05-12T21:00:20.589Z,1683925220.589 [NavChart] Loaded
2023-05-12T21:00:20.589Z,1683925220.589 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-05-12T21:00:20.595Z,1683925220.595 [UniversalFixResidualReporter] Loaded
2023-05-12T21:00:20.595Z,1683925220.595 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-05-12T21:00:20.595Z,1683925220.595 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-05-12T21:00:20.596Z,1683925220.596 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-05-12T21:00:21.440Z,1683925221.440 [AHRS_M2] Loaded
2023-05-12T21:00:21.440Z,1683925221.440 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-05-12T21:00:21.689Z,1683925221.689 [BackseatComponent] Loaded
2023-05-12T21:00:21.689Z,1683925221.689 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-05-12T21:00:21.690Z,1683925221.690 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A3B4E0
2023-05-12T21:00:21.690Z,1683925221.690 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 919
2023-05-12T21:00:21.693Z,1683925221.693 [LcmUniversalReporter] Loaded
2023-05-12T21:00:21.693Z,1683925221.693 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-05-12T21:00:22.429Z,1683925222.429 [BPC1] Loaded
2023-05-12T21:00:22.429Z,1683925222.429 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-05-12T21:00:22.520Z,1683925222.520 [DAT] Loaded
2023-05-12T21:00:22.521Z,1683925222.521 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-05-12T21:00:22.522Z,1683925222.522 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40A6B4E0
2023-05-12T21:00:22.522Z,1683925222.522 [DAT ThreadHandler](INFO): Protected caller Thread ID is 920
2023-05-12T21:00:22.670Z,1683925222.670 [DataOverHttps] Loaded
2023-05-12T21:00:22.671Z,1683925222.671 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-05-12T21:00:22.672Z,1683925222.672 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A9B4E0
2023-05-12T21:00:22.672Z,1683925222.672 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 921
2023-05-12T21:00:22.693Z,1683925222.693 [Depth_Keller] Loaded
2023-05-12T21:00:22.693Z,1683925222.693 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-05-12T21:00:22.698Z,1683925222.698 [DropWeight] Loaded
2023-05-12T21:00:22.699Z,1683925222.699 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-05-12T21:00:22.738Z,1683925222.738 [DVL_micro] Loaded
2023-05-12T21:00:22.738Z,1683925222.738 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2023-05-12T21:00:22.798Z,1683925222.798 [NAL9602] Loaded
2023-05-12T21:00:22.799Z,1683925222.799 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-05-12T21:00:22.826Z,1683925222.826 [Onboard] Loaded
2023-05-12T21:00:22.827Z,1683925222.827 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-05-12T21:00:22.828Z,1683925222.828 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40ACB4E0
2023-05-12T21:00:22.828Z,1683925222.828 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 922
2023-05-12T21:00:22.841Z,1683925222.841 [Power24vConverter] Loaded
2023-05-12T21:00:22.841Z,1683925222.841 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-05-12T21:00:22.855Z,1683925222.855 [Radio_Surface] Loaded
2023-05-12T21:00:22.855Z,1683925222.855 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-05-12T21:00:22.856Z,1683925222.856 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AFB4E0
2023-05-12T21:00:22.856Z,1683925222.856 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 923
2023-05-12T21:00:22.857Z,1683925222.857 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-05-12T21:00:22.858Z,1683925222.858 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-05-12T21:00:23.701Z,1683925223.701 [StratificationFrontDetector](IMPORTANT): thresholdVTHI set to: 0.050012 degC
2023-05-12T21:00:23.701Z,1683925223.701 [StratificationFrontDetector](INFO): (re)initializing
2023-05-12T21:00:23.701Z,1683925223.701 [StratificationFrontDetector] Loaded
2023-05-12T21:00:23.701Z,1683925223.701 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2023-05-12T21:00:23.702Z,1683925223.702 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-05-12T21:00:23.702Z,1683925223.702 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-05-12T21:00:23.883Z,1683925223.883 [VerticalControl](DEBUG): Construct VerticalControl.
2023-05-12T21:00:23.934Z,1683925223.934 [VerticalControl] Loaded
2023-05-12T21:00:23.934Z,1683925223.934 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-05-12T21:00:23.937Z,1683925223.937 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-05-12T21:00:23.975Z,1683925223.975 [HorizontalControl] Loaded
2023-05-12T21:00:23.975Z,1683925223.975 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-05-12T21:00:23.978Z,1683925223.978 [SpeedControl](DEBUG): Construct SpeedControl.
2023-05-12T21:00:23.979Z,1683925223.979 [SpeedControl] Loaded
2023-05-12T21:00:23.979Z,1683925223.979 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-05-12T21:00:23.982Z,1683925223.982 [LoopControl](DEBUG): Construct LoopControl.
2023-05-12T21:00:23.983Z,1683925223.983 [LoopControl] Loaded
2023-05-12T21:00:23.983Z,1683925223.983 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-05-12T21:00:23.984Z,1683925223.984 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-05-12T21:00:23.984Z,1683925223.984 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-05-12T21:00:24.000Z,1683925224.000 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-05-12T21:00:24.001Z,1683925224.001 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-05-12T21:00:24.367Z,1683925224.367 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-05-12T21:00:24.374Z,1683925224.374 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-05-12T21:00:24.376Z,1683925224.376 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-05-12T21:00:24.387Z,1683925224.387 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-05-12T21:00:24.388Z,1683925224.388 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C014E0
2023-05-12T21:00:24.389Z,1683925224.389 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 924
2023-05-12T21:00:24.393Z,1683925224.393 [Supervisor](INFO): Main Thread ID is 824
2023-05-12T21:00:24.393Z,1683925224.393 [Supervisor](DEBUG): Running supervisor.
2023-05-12T21:00:24.394Z,1683925224.394 [CommandExec ThreadHandler](INFO): Handler Thread ID is 925
2023-05-12T21:00:24.395Z,1683925224.395 [CommandExec](INFO): Initializing the command executive.
2023-05-12T21:00:24.396Z,1683925224.396 [CommandLine ThreadHandler](INFO): Handler Thread ID is 926
2023-05-12T21:00:24.398Z,1683925224.398 [controlThread ThreadHandler](INFO): Handler Thread ID is 927
2023-05-12T21:00:24.399Z,1683925224.399 [controlThread](DEBUG): Initializing ControlThread
2023-05-12T21:00:24.400Z,1683925224.400 [SBIT](INFO): Initialize SBIT Component.
2023-05-12T21:00:24.401Z,1683925224.401 [SBIT](IMPORTANT): git: 2023-05-12
2023-05-12T21:00:24.401Z,1683925224.401 [SBIT](INFO): git hash: e578d619fb9973b827c94456cbab8bc18b161215
2023-05-12T21:00:24.401Z,1683925224.401 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-05-12T21:00:24.403Z,1683925224.403 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-05-12T21:00:24.404Z,1683925224.404 [SBIT](INFO): Beginning SBIT in 71.000000 seconds.
2023-05-12T21:00:24.404Z,1683925224.404 [IBIT](INFO): Initialize IBIT Component.
2023-05-12T21:00:24.405Z,1683925224.405 [CBIT](DEBUG): Initialize CBIT Component.
2023-05-12T21:00:24.406Z,1683925224.406 [logger ThreadHandler](INFO): Handler Thread ID is 928
2023-05-12T21:00:24.420Z,1683925224.420 [CBIT](DEBUG): Initialized mux pins.
2023-05-12T21:00:24.420Z,1683925224.420 [CBIT](DEBUG): Initializing the watchdog timer.
2023-05-12T21:00:24.432Z,1683925224.432 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 929
2023-05-12T21:00:24.433Z,1683925224.433 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-05-12T21:00:24.437Z,1683925224.437 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 931
2023-05-12T21:00:24.440Z,1683925224.440 [WetLabsBB2FL](INFO): Powering up
2023-05-12T21:00:24.441Z,1683925224.441 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 933
2023-05-12T21:00:24.444Z,1683925224.444 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-05-12T21:00:24.444Z,1683925224.444 [CBIT](DEBUG): Initializing heartbeat.
2023-05-12T21:00:24.458Z,1683925224.458 [DAT ThreadHandler](INFO): Handler Thread ID is 934
2023-05-12T21:00:24.459Z,1683925224.459 [DAT](INFO): Powering up
2023-05-12T21:00:24.459Z,1683925224.459 [DAT](DEBUG): Initializing DAT.
2023-05-12T21:00:24.465Z,1683925224.465 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 936
2023-05-12T21:00:24.466Z,1683925224.466 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-05-12T21:00:24.476Z,1683925224.476 [Onboard ThreadHandler](INFO): Handler Thread ID is 937
2023-05-12T21:00:24.494Z,1683925224.494 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 938
2023-05-12T21:00:24.512Z,1683925224.512 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 939
2023-05-12T21:00:24.516Z,1683925224.516 [CBIT](DEBUG): Deactivating GF circuits.
2023-05-12T21:00:24.516Z,1683925224.516 [CBIT](DEBUG): Deactivating emergency mode.
2023-05-12T21:00:24.522Z,1683925224.522 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-05-12T21:00:24.522Z,1683925224.522 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-05-12T21:00:24.522Z,1683925224.522 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-05-12T21:00:24.522Z,1683925224.522 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-05-12T21:00:24.522Z,1683925224.522 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-05-12T21:00:24.523Z,1683925224.523 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-05-12T21:00:24.523Z,1683925224.523 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-05-12T21:00:24.523Z,1683925224.523 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-05-12T21:00:24.523Z,1683925224.523 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA69M.000
2023-05-12T21:00:24.523Z,1683925224.523 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA69M.000
2023-05-12T21:00:24.556Z,1683925224.556 [CBIT](DEBUG): Backplane powered.
2023-05-12T21:00:24.560Z,1683925224.560 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-05-12T21:00:24.561Z,1683925224.561 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-05-12T21:00:24.561Z,1683925224.561 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-05-12T21:00:24.561Z,1683925224.561 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2023-05-12T21:00:24.562Z,1683925224.562 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-05-12T21:00:24.562Z,1683925224.562 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-05-12T21:00:24.563Z,1683925224.563 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-05-12T21:00:24.564Z,1683925224.564 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-05-12T21:00:24.574Z,1683925224.574 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-05-12T21:00:24.584Z,1683925224.584 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-05-12T21:00:24.585Z,1683925224.585 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-05-12T21:00:24.585Z,1683925224.585 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-05-12T21:00:24.586Z,1683925224.586 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-05-12T21:00:24.626Z,1683925224.626 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-12T21:00:24.668Z,1683925224.668 [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-05-12T21:00:24.669Z,1683925224.669 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-05-12T21:00:24.764Z,1683925224.764 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-05-12T21:00:24.765Z,1683925224.765 [Default:A.Wait](DEBUG): Construct Wait.
2023-05-12T21:00:24.767Z,1683925224.767 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-12T21:00:24.791Z,1683925224.791 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-05-12T21:00:24.817Z,1683925224.817 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-05-12T21:00:24.827Z,1683925224.827 [Default:E.Execute](DEBUG): Construct Execute.
2023-05-12T21:00:24.846Z,1683925224.846 [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-05-12T21:00:24.853Z,1683925224.853 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-05-12T21:00:24.897Z,1683925224.897 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-05-12T21:00:24.900Z,1683925224.900 [Radio_Surface](INFO): Powering up
2023-05-12T21:00:25.022Z,1683925225.022 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.444336 decibar, 0.000000 m
2023-05-12T21:00:25.024Z,1683925225.024 [Power24vConverter](INFO): Powering up.
2023-05-12T21:00:25.029Z,1683925225.029 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-05-12T21:00:25.093Z,1683925225.093 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-05-12T21:00:25.100Z,1683925225.100 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-05-12T21:00:25.101Z,1683925225.101 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-05-12T21:00:25.108Z,1683925225.108 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-05-12T21:00:25.109Z,1683925225.109 [MassServo](DEBUG): Initializing EZServoServo.
2023-05-12T21:00:25.116Z,1683925225.116 [MassServo](DEBUG): Initializing MassServo.
2023-05-12T21:00:25.117Z,1683925225.117 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-12T21:00:25.124Z,1683925225.124 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-12T21:00:25.125Z,1683925225.125 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-05-12T21:00:25.132Z,1683925225.132 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-05-12T21:00:26.548Z,1683925226.548 [WetLabsBB2FL](INFO): Powering down
2023-05-12T21:00:30.621Z,1683925230.621 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-05-12T21:00:36.304Z,1683925236.304 [DAT](INFO): DAT read: 

2023-05-12T21:00:36.306Z,1683925236.306 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-05-12T21:00:38.069Z,1683925238.069 [DAT](INFO): DAT read: MF Frequency Band

2023-05-12T21:00:38.070Z,1683925238.070 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-05-12T21:00:38.070Z,1683925238.070 [DAT](INFO): DAT read: May 12 2023 21:00:31 

2023-05-12T21:00:39.077Z,1683925239.077 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-05-12T21:00:39.079Z,1683925239.079 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC

2023-05-12T21:00:39.079Z,1683925239.079 [DAT](INFO): commRate: 1200
2023-05-12T21:00:41.156Z,1683925241.156 [DAT](INFO): entering command mode
2023-05-12T21:00:41.156Z,1683925241.156 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-12T21:00:41.345Z,1683925241.345 [DAT](INFO): DAT read: 

2023-05-12T21:00:41.345Z,1683925241.345 [DAT](INFO): DAT read: user:1>

2023-05-12T21:00:41.345Z,1683925241.345 [DAT](INFO): setting verbose to 3
2023-05-12T21:00:41.597Z,1683925241.597 [DAT](INFO): DAT read: user:1>

2023-05-12T21:00:41.598Z,1683925241.598 [DAT](INFO): DAT read: Verbose         | 3           

2023-05-12T21:00:41.598Z,1683925241.598 [DAT](INFO): set verbose to 3
2023-05-12T21:00:41.598Z,1683925241.598 [DAT](INFO): setting DatVerbose to 27440
2023-05-12T21:00:41.848Z,1683925241.848 [DAT](INFO): DAT read: user:2>

2023-05-12T21:00:41.849Z,1683925241.849 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-05-12T21:00:41.850Z,1683925241.850 [DAT](INFO): set DatVerbose to 27440
2023-05-12T21:00:41.850Z,1683925241.850 [DAT](INFO): setting transmit power to 8
2023-05-12T21:00:42.100Z,1683925242.100 [DAT](INFO): DAT read: user:3>

2023-05-12T21:00:42.101Z,1683925242.101 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-05-12T21:00:42.102Z,1683925242.102 [DAT](INFO): set transmit power to 8
2023-05-12T21:00:42.102Z,1683925242.102 [DAT](INFO): setting local address to 5
2023-05-12T21:00:42.353Z,1683925242.353 [DAT](INFO): DAT read: user:4>

2023-05-12T21:00:42.353Z,1683925242.353 [DAT](INFO): DAT read: LocalAddr       | 5           

2023-05-12T21:00:42.354Z,1683925242.354 [DAT](INFO): set local address to 5
2023-05-12T21:00:42.355Z,1683925242.355 [DAT](INFO): Setting time to: 21:0:42 And date to:5/12/2023
2023-05-12T21:00:42.604Z,1683925242.604 [DAT](INFO): DAT read: user:5>

2023-05-12T21:00:42.605Z,1683925242.605 [DAT](INFO): DAT read: Fri May 12, 2023  21:00:42  

2023-05-12T21:00:42.606Z,1683925242.606 [DAT](INFO): Local DAT time set to Fri May 12, 2023  21:00:42  

2023-05-12T21:00:53.170Z,1683925253.170 [NAL9602](INFO): Powering up NAL9602
2023-05-12T21:01:04.078Z,1683925264.078 [NAL9602](INFO): NAL9602 initialized
2023-05-12T21:01:36.018Z,1683925296.018 [SBIT](IMPORTANT): Beginning Startup BIT
2023-05-12T21:01:36.022Z,1683925296.022 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-12T21:01:47.352Z,1683925307.352 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005650
CHAN A1 (24V): 0.001960
CHAN A2 (12V): -0.005288
CHAN A3 (5V): -0.003364
CHAN B0 (3.3V): -0.001444
CHAN B1 (3.15aV): 0.000611
CHAN B2 (3.15bV): -0.001549
CHAN B3 (GND): -0.000839
OPEN: 0.012162
Full Scale: +/- 1 mA
2023-05-12T21:02:30.150Z,1683925350.150 [SBIT](IMPORTANT): SBIT PASSED
2023-05-12T21:02:30.150Z,1683925350.150 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-05-12T21:02:30.151Z,1683925350.151 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2023-05-12T21:02:30.151Z,1683925350.151 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=1 bool;

2023-05-12T21:02:30.151Z,1683925350.151 [SBIT](IMPORTANT): Depth_Keller.offset=-0.8 decibar;

2023-05-12T21:02:30.151Z,1683925350.151 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=4 minute;

2023-05-12T21:02:30.151Z,1683925350.151 [SBIT](IMPORTANT): ElevatorServo.offsetAngle=1 degree;

2023-05-12T21:02:30.151Z,1683925350.151 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_salinity_homogeneity_index 0.050000 practical_salinity_unit;

2023-05-12T21:02:30.152Z,1683925350.152 [SBIT](IMPORTANT): Express linearApproximation VerticalHomogeneityIndexCalculator.vertical_temperature_homogeneity_index 0.050000 celsius;

2023-05-12T21:02:30.152Z,1683925350.152 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff470nm;

2023-05-12T21:02:30.152Z,1683925350.152 [SBIT](IMPORTANT): Express none WetLabsBB2FL.BackscatteringCoeff650nm;

2023-05-12T21:02:30.152Z,1683925350.152 [SBIT](IMPORTANT): Express linearApproximation depth 5.000000 meter;

2023-05-12T21:02:30.152Z,1683925350.152 [SBIT](IMPORTANT): Express linearApproximation latitude 0.005000 degree;

2023-05-12T21:02:30.152Z,1683925350.152 [SBIT](IMPORTANT): Express linearApproximation longitude 0.005000 degree;

2023-05-12T21:02:30.153Z,1683925350.153 [SBIT](IMPORTANT): StratificationFrontDetector.loadAtStartup=1 bool;

2023-05-12T21:02:30.153Z,1683925350.153 [SBIT](IMPORTANT): StratificationFrontDetector.threshold_VTHI=0.05 celsius;

2023-05-12T21:02:30.153Z,1683925350.153 [SBIT](IMPORTANT): StratificationFrontDetector.verbosity=1 count;

2023-05-12T21:02:30.153Z,1683925350.153 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=191.501740 cubic_centimeter;

2023-05-12T21:02:30.153Z,1683925350.153 [SBIT](IMPORTANT): VerticalControl.massDefault=12.944775 millimeter;

2023-05-12T21:02:30.153Z,1683925350.153 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth3=20 meter;

2023-05-12T21:02:30.153Z,1683925350.153 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.depth4=30 meter;

2023-05-12T21:02:30.153Z,1683925350.153 [SBIT](IMPORTANT): VerticalHomogeneityIndexCalculator.loadAtStartup=1 bool;

2023-05-12T21:02:30.551Z,1683925350.551 [MissionManager](IMPORTANT): Started mission Startup
2023-05-12T21:02:30.551Z,1683925350.551 [Startup] Running Loop=1
2023-05-12T21:02:30.551Z,1683925350.551 [Startup](DEBUG): Aggregate::initialize Startup
2023-05-12T21:02:30.551Z,1683925350.551 [Startup:A.GoToSurface] Running Loop=1
2023-05-12T21:02:30.551Z,1683925350.551 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-12T21:02:30.552Z,1683925350.552 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-12T21:02:30.552Z,1683925350.552 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-12T21:02:30.553Z,1683925350.553 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-12T21:02:30.553Z,1683925350.553 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-12T21:02:30.554Z,1683925350.554 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-12T21:02:30.555Z,1683925350.555 [Startup:StartupSatComms] Running Loop=1
2023-05-12T21:02:30.555Z,1683925350.555 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-05-12T21:02:30.555Z,1683925350.555 [Startup:StartupSatComms:A] Running Loop=1
2023-05-12T21:02:30.950Z,1683925350.950 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-05-12T21:03:24.707Z,1683925404.707 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-05-12T21:03:24.707Z,1683925404.707 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-12T21:03:24.742Z,1683925404.742 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-12T21:03:25.098Z,1683925405.098 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-12T21:03:25.098Z,1683925405.098 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-05-12T21:03:30.747Z,1683925410.747 [Startup:StartupSatComms:A](INFO): Timed out from 2023-05-12T21:02:30.6Z
2023-05-12T21:03:30.747Z,1683925410.747 [Startup:StartupSatComms:A] Stopped
2023-05-12T21:03:30.747Z,1683925410.747 [Startup:StartupSatComms:B] Running Loop=1
2023-05-12T21:03:31.143Z,1683925411.143 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-12T21:03:58.702Z,1683925438.702 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004449
2023-05-12T21:04:06.325Z,1683925446.325 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230512T161716/Courier0088.lzma
2023-05-12T21:04:07.326Z,1683925447.326 [DataOverHttps](INFO): Moved sent file to Logs/20230512T161716/Courier0088.lzma.bak
2023-05-12T21:04:07.326Z,1683925447.326 [DataOverHttps](INFO): SBD MOMSN=18301277
2023-05-12T21:04:23.160Z,1683925463.160 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230512T161716/Courier0091.lzma
2023-05-12T21:04:24.162Z,1683925464.162 [DataOverHttps](INFO): Moved sent file to Logs/20230512T161716/Courier0091.lzma.bak
2023-05-12T21:04:24.162Z,1683925464.162 [DataOverHttps](INFO): SBD MOMSN=18301279
2023-05-12T21:04:30.954Z,1683925470.954 [Startup:StartupSatComms:B](INFO): Timed out from 2023-05-12T21:03:30.7Z
2023-05-12T21:04:30.954Z,1683925470.954 [Startup:StartupSatComms:B] Stopped
2023-05-12T21:04:30.955Z,1683925470.955 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-05-12T21:04:30.955Z,1683925470.955 [Startup:StartupSatComms] Stopped
2023-05-12T21:04:30.955Z,1683925470.955 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-05-12T21:04:30.956Z,1683925470.956 [Startup](INFO): Completed Startup
2023-05-12T21:04:30.956Z,1683925470.956 [MissionManager](INFO): Startup is completed.
2023-05-12T21:04:30.956Z,1683925470.956 [MissionManager](INFO): Uninitializing Mission Startup
2023-05-12T21:04:30.956Z,1683925470.956 [Startup] Stopped
2023-05-12T21:04:30.956Z,1683925470.956 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-05-12T21:04:30.956Z,1683925470.956 [Startup:A.GoToSurface] Stopped
2023-05-12T21:04:30.956Z,1683925470.956 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-12T21:04:31.367Z,1683925471.367 [MissionManager](IMPORTANT): Started mission Default
2023-05-12T21:04:31.367Z,1683925471.367 [Default] Running Loop=1
2023-05-12T21:04:31.367Z,1683925471.367 [Default](DEBUG): Aggregate::initialize Default
2023-05-12T21:04:31.367Z,1683925471.367 [Default:B.GoToSurface] Running Loop=1
2023-05-12T21:04:31.367Z,1683925471.367 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-12T21:04:31.368Z,1683925471.368 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-12T21:04:31.368Z,1683925471.368 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-12T21:04:31.368Z,1683925471.368 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-12T21:04:31.369Z,1683925471.369 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-12T21:04:31.369Z,1683925471.369 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-12T21:04:31.369Z,1683925471.369 [Default:A.Wait] Running Loop=1
2023-05-12T21:04:31.369Z,1683925471.369 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:04:43.107Z,1683925483.107 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20230512T210012/Courier0000.lzma
2023-05-12T21:04:44.112Z,1683925484.112 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0000.lzma.bak
2023-05-12T21:04:44.112Z,1683925484.112 [DataOverHttps](INFO): SBD MOMSN=18301284
2023-05-12T21:04:44.773Z,1683925484.773 [Default:A.Wait](INFO): Done Waiting.
2023-05-12T21:04:44.773Z,1683925484.773 [Default:A.Wait] Stopped
2023-05-12T21:04:44.773Z,1683925484.773 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:04:45.163Z,1683925485.163 [Default:CheckIn] Running Loop=1
2023-05-12T21:04:45.163Z,1683925485.163 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:04:45.163Z,1683925485.163 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:04:45.551Z,1683925485.551 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-05-12T21:05:00.083Z,1683925500.083 [DVL_micro](ERROR): only read 2 of 4 data items
2023-05-12T21:05:00.083Z,1683925500.083 [DVL_micro](ERROR): Failed to parse:
:BI,-00176,+00558+00000,A0000000.00,+00000000.00,+00000000.00,0000.20

2023-05-12T21:05:27.597Z,1683925527.597 [DVL_micro](ERROR): only read 3 of 4 data items
2023-05-12T21:05:27.597Z,1683925527.597 [DVL_micro](ERROR): Failed to parse:
:BI,-00212,+00380,00000,A
2023-05-12T21:06:06.779Z,1683925566.779 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-12T21:06:13.254Z,1683925573.254 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210558.00,A,3648.16373,N,12147.28134,W,0.097,299.55,120523,,,A*78
2023-05-12T21:06:13.258Z,1683925573.258 [NAL9602](INFO): GPS fix at 20230512T210558: (36.802729, -121.788022)
2023-05-12T21:06:13.268Z,1683925573.268 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:06:13.268Z,1683925573.268 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:06:13.692Z,1683925573.692 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-12T21:06:21.208Z,1683925581.208 [DataOverHttps](INFO): Sending 226 bytes from file Logs/20230512T210012/Courier0004.lzma
2023-05-12T21:06:22.209Z,1683925582.209 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0004.lzma.bak
2023-05-12T21:06:22.210Z,1683925582.210 [DataOverHttps](INFO): SBD MOMSN=18301292
2023-05-12T21:06:31.033Z,1683925591.033 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:06:31.033Z,1683925591.033 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+19.1,009.0,000
2023-05-12T21:06:41.937Z,1683925601.937 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20230512T161716/Express0086.lzma
2023-05-12T21:06:42.938Z,1683925602.938 [DataOverHttps](INFO): Moved sent file to Logs/20230512T161716/Express0086.lzma.bak
2023-05-12T21:06:42.938Z,1683925602.938 [DataOverHttps](INFO): SBD MOMSN=18301295
2023-05-12T21:06:45.676Z,1683925605.676 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:07:01.237Z,1683925621.237 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20230512T161716/Express0089.lzma
2023-05-12T21:07:02.238Z,1683925622.238 [DataOverHttps](INFO): Moved sent file to Logs/20230512T161716/Express0089.lzma.bak
2023-05-12T21:07:02.238Z,1683925622.238 [DataOverHttps](INFO): SBD MOMSN=18301299
2023-05-12T21:07:22.197Z,1683925642.197 [DataOverHttps](INFO): Sending 70 bytes from file Logs/20230512T161716/Express0092.lzma
2023-05-12T21:07:23.198Z,1683925643.198 [DataOverHttps](INFO): Moved sent file to Logs/20230512T161716/Express0092.lzma.bak
2023-05-12T21:07:23.198Z,1683925643.198 [DataOverHttps](INFO): SBD MOMSN=18301303
2023-05-12T21:07:39.438Z,1683925659.438 [DataOverHttps](INFO): Sending 1079 bytes from file Logs/20230512T210012/Express0001.lzma
2023-05-12T21:07:40.434Z,1683925660.434 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0001.lzma.bak
2023-05-12T21:07:40.434Z,1683925660.434 [DataOverHttps](INFO): SBD MOMSN=18301305
2023-05-12T21:07:56.548Z,1683925676.548 [DataOverHttps](INFO): Sending 312 bytes from file Logs/20230512T210012/Express0005.lzma
2023-05-12T21:07:57.549Z,1683925677.549 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0005.lzma.bak
2023-05-12T21:07:57.550Z,1683925677.550 [DataOverHttps](INFO): SBD MOMSN=18301337
2023-05-12T21:07:59.249Z,1683925679.249 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:07:59.249Z,1683925679.249 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:07:59.249Z,1683925679.249 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:08:00.037Z,1683925680.037 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:08:00.038Z,1683925680.038 [DVL_micro](ERROR): Failed to parse:
:TS,000000,35.0,+19.,1489.0,000
2023-05-12T21:08:29.947Z,1683925709.947 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:08:29.947Z,1683925709.947 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+19.1,089.0,000
2023-05-12T21:08:59.440Z,1683925739.440 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2023-05-12T21:08:59.443Z,1683925739.443 [BPC1](INFO): Received data from all battery sticks.
2023-05-12T21:09:30.136Z,1683925770.136 [DVL_micro](ERROR): Failed to parse:
:WI,+00000,+00000,+00000,+00000,I
2023-05-12T21:12:18.633Z,1683925938.633 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:12:18.633Z,1683925938.633 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+19.1,0000.0000
2023-05-12T21:12:36.454Z,1683925956.454 [DVL_micro](ERROR): Failed to parse:
:SA,-04.06,+05.86,049.6
2023-05-12T21:12:59.902Z,1683925979.902 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:12:59.902Z,1683925979.902 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:12:59.902Z,1683925979.902 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:12:59.902Z,1683925979.902 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:13:00.295Z,1683925980.295 [Default:CheckIn:D] Stopped
2023-05-12T21:13:00.295Z,1683925980.295 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:13:00.705Z,1683925980.705 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.482125 min 
2023-05-12T21:13:00.705Z,1683925980.705 [Default:CheckIn:E] Stopped
2023-05-12T21:13:00.705Z,1683925980.705 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:13:00.705Z,1683925980.705 [Default:CheckIn] Stopped
2023-05-12T21:13:00.705Z,1683925980.705 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:13:00.705Z,1683925980.705 [Default:CheckIn](INFO): Running loop #2
2023-05-12T21:13:00.705Z,1683925980.705 [Default:CheckIn] Running Loop=2
2023-05-12T21:13:00.705Z,1683925980.705 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:13:00.705Z,1683925980.705 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:13:02.714Z,1683925982.714 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211250.00,A,3648.16550,N,12147.28473,W,0.272,299.55,120523,,,A*7E
2023-05-12T21:13:02.717Z,1683925982.717 [NAL9602](INFO): GPS fix at 20230512T211250: (36.802758, -121.788079)
2023-05-12T21:13:02.744Z,1683925982.744 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:13:02.744Z,1683925982.744 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:13:13.287Z,1683925993.287 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20230512T210012/Courier0007.lzma
2023-05-12T21:13:14.292Z,1683925994.292 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0007.lzma.bak
2023-05-12T21:13:14.292Z,1683925994.292 [DataOverHttps](INFO): SBD MOMSN=18301381
2023-05-12T21:13:31.215Z,1683926011.215 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20230512T210012/Express0008.lzma
2023-05-12T21:13:32.218Z,1683926012.218 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0008.lzma.bak
2023-05-12T21:13:32.218Z,1683926012.218 [DataOverHttps](INFO): SBD MOMSN=18301384
2023-05-12T21:13:33.470Z,1683926013.470 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-12T21:13:33.552Z,1683926013.552 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-05-12T21:13:33.927Z,1683926013.927 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:13:33.927Z,1683926013.927 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:13:33.927Z,1683926013.927 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:13:50.532Z,1683926030.532 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:13:50.532Z,1683926030.532 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,00.0,1489.0,000
2023-05-12T21:14:11.073Z,1683926051.073 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,0000.20,000.00
2023-05-12T21:15:45.316Z,1683926145.316 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:15:45.316Z,1683926145.316 [DVL_micro](ERROR): Failed to parse:
:TS,000000000000+19.0,0000.0,1489.0,000
2023-05-12T21:16:58.513Z,1683926218.513 [DVL_micro](ERROR): only read 3 of 4 data items
2023-05-12T21:16:58.513Z,1683926218.513 [DVL_micro](ERROR): Failed to parse:
:BI,-00060,+00090,-00942,+

2023-05-12T21:17:19.705Z,1683926239.705 [CommandExec](IMPORTANT): got command failComponent
2023-05-12T21:17:19.705Z,1683926239.705 [CommandExec](IMPORTANT): Failed components:
2023-05-12T21:17:19.705Z,1683926239.705 [CommandExec](IMPORTANT): No failed Components.
2023-05-12T21:17:39.715Z,1683926259.715 [NAL9602](INFO): SBD MO Status=2, MOMSN=3657, MT Status=2, MTMSN=0
2023-05-12T21:17:39.715Z,1683926259.715 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-05-12T21:18:04.366Z,1683926284.366 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+0000000000000.00,9999.99,000.00
2023-05-12T21:18:05.574Z,1683926285.574 [NAL9602](INFO): SBD MO Status=2, MOMSN=3657, MT Status=2, MTMSN=0
2023-05-12T21:18:05.574Z,1683926285.574 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-05-12T21:18:05.974Z,1683926285.974 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-12T21:18:34.678Z,1683926314.678 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:18:34.678Z,1683926314.678 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:18:34.678Z,1683926314.678 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:18:34.678Z,1683926314.678 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:18:35.086Z,1683926315.086 [Default:CheckIn:D] Stopped
2023-05-12T21:18:35.086Z,1683926315.086 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:18:35.477Z,1683926315.477 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.061978 min 
2023-05-12T21:18:35.477Z,1683926315.477 [Default:CheckIn:E] Stopped
2023-05-12T21:18:35.477Z,1683926315.477 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:18:35.477Z,1683926315.477 [Default:CheckIn] Stopped
2023-05-12T21:18:35.477Z,1683926315.477 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:18:35.478Z,1683926315.478 [Default:CheckIn](INFO): Running loop #3
2023-05-12T21:18:35.478Z,1683926315.478 [Default:CheckIn] Running Loop=3
2023-05-12T21:18:35.478Z,1683926315.478 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:18:35.478Z,1683926315.478 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:18:37.491Z,1683926317.491 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211836.00,A,3648.16949,N,12147.28869,W,0.330,286.59,120523,,,A*72
2023-05-12T21:18:37.493Z,1683926317.493 [NAL9602](INFO): GPS fix at 20230512T211836: (36.802825, -121.788145)
2023-05-12T21:18:37.503Z,1683926317.503 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:18:37.503Z,1683926317.503 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:18:44.483Z,1683926324.483 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20230512T210012/Courier0010.lzma
2023-05-12T21:18:45.486Z,1683926325.486 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0010.lzma.bak
2023-05-12T21:18:45.486Z,1683926325.486 [DataOverHttps](INFO): SBD MOMSN=18301393
2023-05-12T21:19:04.204Z,1683926344.204 [DataOverHttps](INFO): Sending 280 bytes from file Logs/20230512T210012/Express0011.lzma
2023-05-12T21:19:05.206Z,1683926345.206 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0011.lzma.bak
2023-05-12T21:19:05.206Z,1683926345.206 [DataOverHttps](INFO): SBD MOMSN=18301396
2023-05-12T21:19:07.055Z,1683926347.055 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:19:07.055Z,1683926347.055 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:19:07.055Z,1683926347.055 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:19:10.291Z,1683926350.291 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:21:29.654Z,1683926489.654 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:21:29.654Z,1683926489.654 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+19.,1489.0,000
2023-05-12T21:24:07.647Z,1683926647.647 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:24:07.647Z,1683926647.647 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:24:07.647Z,1683926647.647 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:24:07.647Z,1683926647.647 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:24:08.063Z,1683926648.063 [Default:CheckIn:D] Stopped
2023-05-12T21:24:08.063Z,1683926648.063 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:24:08.450Z,1683926648.450 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.611593 min 
2023-05-12T21:24:08.451Z,1683926648.451 [Default:CheckIn:E] Stopped
2023-05-12T21:24:08.451Z,1683926648.451 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:24:08.451Z,1683926648.451 [Default:CheckIn] Stopped
2023-05-12T21:24:08.451Z,1683926648.451 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:24:08.451Z,1683926648.451 [Default:CheckIn](INFO): Running loop #4
2023-05-12T21:24:08.451Z,1683926648.451 [Default:CheckIn] Running Loop=4
2023-05-12T21:24:08.451Z,1683926648.451 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:24:08.451Z,1683926648.451 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:24:10.464Z,1683926650.464 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212409.00,A,3648.16802,N,12147.28201,W,0.136,328.40,120523,,,A*72
2023-05-12T21:24:10.467Z,1683926650.467 [NAL9602](INFO): GPS fix at 20230512T212409: (36.802800, -121.788033)
2023-05-12T21:24:10.477Z,1683926650.477 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:24:10.477Z,1683926650.477 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:24:17.360Z,1683926657.360 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230512T210012/Courier0013.lzma
2023-05-12T21:24:18.362Z,1683926658.362 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0013.lzma.bak
2023-05-12T21:24:18.362Z,1683926658.362 [DataOverHttps](INFO): SBD MOMSN=18301412
2023-05-12T21:24:38.047Z,1683926678.047 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230512T210012/Express0014.lzma
2023-05-12T21:24:39.050Z,1683926679.050 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0014.lzma.bak
2023-05-12T21:24:39.050Z,1683926679.050 [DataOverHttps](INFO): SBD MOMSN=18301415
2023-05-12T21:24:41.323Z,1683926681.323 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:24:41.324Z,1683926681.324 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:24:41.340Z,1683926681.340 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:24:46.958Z,1683926686.958 [DVL_micro](ERROR): only read 3 of 4 data items
2023-05-12T21:24:46.959Z,1683926686.959 [DVL_micro](ERROR): Failed to parse:
:BI,+01283,-00117,-01141I
2023-05-12T21:24:59.855Z,1683926699.855 [DVL_micro](ERROR): Failed to parse:
0000000000,35.0,+19.3,0000.0,1489.0,000
2023-05-12T21:27:04.338Z,1683926824.338 [NAL9602](INFO): SBD MO Status=2, MOMSN=3657, MT Status=2, MTMSN=0
2023-05-12T21:27:04.338Z,1683926824.338 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-05-12T21:27:18.482Z,1683926838.482 [NAL9602](INFO): SBD MO Status=2, MOMSN=3657, MT Status=2, MTMSN=0
2023-05-12T21:27:18.483Z,1683926838.483 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-05-12T21:27:41.510Z,1683926861.510 [NAL9602](INFO): SBD MO Status=2, MOMSN=3657, MT Status=2, MTMSN=0
2023-05-12T21:27:41.510Z,1683926861.510 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-05-12T21:28:32.504Z,1683926912.504 [DVL_micro](ERROR): Failed to parse::BD,+00000000.00,+00000000.00,+00000000.00,900.00
2023-05-12T21:29:13.306Z,1683926953.306 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-12T21:29:41.996Z,1683926981.996 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:29:41.996Z,1683926981.996 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:29:41.996Z,1683926981.996 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:29:41.996Z,1683926981.996 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:29:42.408Z,1683926982.408 [Default:CheckIn:D] Stopped
2023-05-12T21:29:42.408Z,1683926982.408 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:29:42.806Z,1683926982.806 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.184019 min 
2023-05-12T21:29:42.806Z,1683926982.806 [Default:CheckIn:E] Stopped
2023-05-12T21:29:42.807Z,1683926982.807 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:29:42.807Z,1683926982.807 [Default:CheckIn] Stopped
2023-05-12T21:29:42.807Z,1683926982.807 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:29:42.807Z,1683926982.807 [Default:CheckIn](INFO): Running loop #5
2023-05-12T21:29:42.807Z,1683926982.807 [Default:CheckIn] Running Loop=5
2023-05-12T21:29:42.807Z,1683926982.807 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:29:42.807Z,1683926982.807 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:29:44.814Z,1683926984.814 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212944.00,A,3648.16975,N,12147.28229,W,0.778,337.25,120523,,,A*7C
2023-05-12T21:29:44.817Z,1683926984.817 [NAL9602](INFO): GPS fix at 20230512T212944: (36.802829, -121.788038)
2023-05-12T21:29:44.827Z,1683926984.827 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:29:44.827Z,1683926984.827 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:29:52.215Z,1683926992.215 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20230512T210012/Courier0016.lzma
2023-05-12T21:29:53.218Z,1683926993.218 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0016.lzma.bak
2023-05-12T21:29:53.218Z,1683926993.218 [DataOverHttps](INFO): SBD MOMSN=18301426
2023-05-12T21:30:09.016Z,1683927009.016 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20230512T210012/Express0017.lzma
2023-05-12T21:30:10.018Z,1683927010.018 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0017.lzma.bak
2023-05-12T21:30:10.018Z,1683927010.018 [DataOverHttps](INFO): SBD MOMSN=18301433
2023-05-12T21:30:11.504Z,1683927011.504 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:30:11.504Z,1683927011.504 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:30:11.504Z,1683927011.504 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:30:17.546Z,1683927017.546 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:35:12.065Z,1683927312.065 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:35:12.065Z,1683927312.065 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:35:12.065Z,1683927312.065 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:35:12.065Z,1683927312.065 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:35:12.475Z,1683927312.476 [Default:CheckIn:D] Stopped
2023-05-12T21:35:12.476Z,1683927312.476 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:35:12.871Z,1683927312.871 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.685142 min 
2023-05-12T21:35:12.871Z,1683927312.871 [Default:CheckIn:E] Stopped
2023-05-12T21:35:12.871Z,1683927312.871 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:35:12.872Z,1683927312.872 [Default:CheckIn] Stopped
2023-05-12T21:35:12.872Z,1683927312.872 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:35:12.872Z,1683927312.872 [Default:CheckIn](INFO): Running loop #6
2023-05-12T21:35:12.872Z,1683927312.872 [Default:CheckIn] Running Loop=6
2023-05-12T21:35:12.872Z,1683927312.872 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:35:12.872Z,1683927312.872 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:35:14.899Z,1683927314.899 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213514.00,A,3648.14237,N,12147.22578,W,0.000,49.77,120523,,,D*42
2023-05-12T21:35:14.901Z,1683927314.901 [NAL9602](INFO): GPS fix at 20230512T213514: (36.802373, -121.787096)
2023-05-12T21:35:14.911Z,1683927314.911 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:35:14.911Z,1683927314.911 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:35:21.847Z,1683927321.847 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230512T210012/Courier0019.lzma
2023-05-12T21:35:22.850Z,1683927322.850 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0019.lzma.bak
2023-05-12T21:35:22.850Z,1683927322.850 [DataOverHttps](INFO): SBD MOMSN=18301437
2023-05-12T21:35:39.491Z,1683927339.491 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230512T210012/Express0020.lzma
2023-05-12T21:35:40.494Z,1683927340.494 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0020.lzma.bak
2023-05-12T21:35:40.494Z,1683927340.494 [DataOverHttps](INFO): SBD MOMSN=18301440
2023-05-12T21:35:41.962Z,1683927341.962 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:35:41.962Z,1683927341.962 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:35:41.962Z,1683927341.962 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:35:45.593Z,1683927345.593 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-12T21:35:45.676Z,1683927345.676 [NAL9602](ERROR): received: 
+CSQ:0

OK57, 2, 0, 0, 0

OK
2023-05-12T21:35:55.291Z,1683927355.291 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:35:55.291Z,1683927355.291 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+19.4,00000,000
2023-05-12T21:36:07.410Z,1683927367.410 [NAL9602](INFO): SBD MO Status=0, MOMSN=3657, MT Status=0, MTMSN=0
2023-05-12T21:36:07.410Z,1683927367.410 [NAL9602](INFO): No messages in MT queue
2023-05-12T21:36:38.109Z,1683927398.109 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:37:01.143Z,1683927421.143 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:37:01.144Z,1683927421.144 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+19.4,0000.0000
2023-05-12T21:39:35.467Z,1683927575.467 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2023-05-12T21:39:35.467Z,1683927575.467 [DVL_micro](ERROR): Failed to parse:
:TS0000000,35.0,+19.4,0000.0,1489.0,000
2023-05-12T21:40:42.547Z,1683927642.547 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:40:42.547Z,1683927642.547 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:40:42.547Z,1683927642.547 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:40:42.547Z,1683927642.547 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:40:42.955Z,1683927642.955 [Default:CheckIn:D] Stopped
2023-05-12T21:40:42.955Z,1683927642.955 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:40:43.367Z,1683927643.367 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.193140 min 
2023-05-12T21:40:43.368Z,1683927643.368 [Default:CheckIn:E] Stopped
2023-05-12T21:40:43.368Z,1683927643.368 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:40:43.368Z,1683927643.368 [Default:CheckIn] Stopped
2023-05-12T21:40:43.368Z,1683927643.368 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:40:43.368Z,1683927643.368 [Default:CheckIn](INFO): Running loop #7
2023-05-12T21:40:43.368Z,1683927643.368 [Default:CheckIn] Running Loop=7
2023-05-12T21:40:43.368Z,1683927643.368 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:40:43.369Z,1683927643.369 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:40:45.395Z,1683927645.395 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214044.00,A,3648.14977,N,12147.21931,W,1.089,67.14,120523,,,D*41
2023-05-12T21:40:45.398Z,1683927645.398 [NAL9602](INFO): GPS fix at 20230512T214044: (36.802496, -121.786989)
2023-05-12T21:40:45.407Z,1683927645.407 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:40:45.407Z,1683927645.407 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:40:53.452Z,1683927653.452 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20230512T210012/Courier0022.lzma
2023-05-12T21:40:54.454Z,1683927654.454 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0022.lzma.bak
2023-05-12T21:40:54.454Z,1683927654.454 [DataOverHttps](INFO): SBD MOMSN=18301457
2023-05-12T21:41:13.340Z,1683927673.340 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20230512T210012/Express0023.lzma
2023-05-12T21:41:14.342Z,1683927674.342 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0023.lzma.bak
2023-05-12T21:41:14.342Z,1683927674.342 [DataOverHttps](INFO): SBD MOMSN=18301460
2023-05-12T21:41:16.131Z,1683927676.131 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:41:16.131Z,1683927676.131 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:41:16.131Z,1683927676.131 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:41:44.793Z,1683927704.793 [NAL9602](INFO): SBD MO Status=0, MOMSN=3658, MT Status=0, MTMSN=0
2023-05-12T21:41:44.794Z,1683927704.794 [NAL9602](INFO): No messages in MT queue
2023-05-12T21:42:15.497Z,1683927735.497 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:43:20.555Z,1683927800.555 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 807
2023-05-12T21:43:20.561Z,1683927800.561 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2023-05-12T21:46:16.698Z,1683927976.698 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:46:16.698Z,1683927976.698 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:46:16.698Z,1683927976.698 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:46:16.699Z,1683927976.699 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:46:17.099Z,1683927977.099 [Default:CheckIn:D] Stopped
2023-05-12T21:46:17.099Z,1683927977.099 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:46:17.530Z,1683927977.530 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.762203 min 
2023-05-12T21:46:17.530Z,1683927977.530 [Default:CheckIn:E] Stopped
2023-05-12T21:46:17.530Z,1683927977.530 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:46:17.530Z,1683927977.530 [Default:CheckIn] Stopped
2023-05-12T21:46:17.530Z,1683927977.530 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:46:17.530Z,1683927977.530 [Default:CheckIn](INFO): Running loop #8
2023-05-12T21:46:17.530Z,1683927977.530 [Default:CheckIn] Running Loop=8
2023-05-12T21:46:17.530Z,1683927977.530 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:46:17.531Z,1683927977.531 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:46:19.533Z,1683927979.533 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214618.00,A,3648.15227,N,12147.22200,W,0.019,167.85,120523,,,D*7A
2023-05-12T21:46:19.535Z,1683927979.535 [NAL9602](INFO): GPS fix at 20230512T214618: (36.802538, -121.787033)
2023-05-12T21:46:19.545Z,1683927979.545 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:46:19.546Z,1683927979.546 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:46:28.499Z,1683927988.499 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230512T210012/Courier0025.lzma
2023-05-12T21:46:29.953Z,1683927989.953 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0025.lzma.bak
2023-05-12T21:46:29.954Z,1683927989.954 [DataOverHttps](INFO): SBD MOMSN=18301473
2023-05-12T21:46:37.848Z,1683927997.848 [NAL9602](INFO): SBD MO Status=0, MOMSN=3659, MT Status=0, MTMSN=0
2023-05-12T21:46:37.852Z,1683927997.852 [NAL9602](INFO): No messages in MT queue
2023-05-12T21:46:48.588Z,1683928008.588 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230512T210012/Express0026.lzma
2023-05-12T21:46:49.590Z,1683928009.590 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0026.lzma.bak
2023-05-12T21:46:49.590Z,1683928009.590 [DataOverHttps](INFO): SBD MOMSN=18301481
2023-05-12T21:46:51.117Z,1683928011.117 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:46:51.117Z,1683928011.117 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:46:51.117Z,1683928011.117 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:47:08.478Z,1683928028.478 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:47:18.593Z,1683928038.593 [DVL_micro](ERROR): Failed to parse:
:SA,-02.30,-00.82,176.2
2023-05-12T21:48:33.021Z,1683928113.021 [DataOverHttps](IMPORTANT): SBD MTMSN=20230512T214832
2023-05-12T21:48:41.420Z,1683928121.420 [DataOverHttps](INFO): Received command: ibit
2023-05-12T21:48:41.429Z,1683928121.429 [CommandExec](IMPORTANT): got command ibit
2023-05-12T21:48:41.479Z,1683928121.479 [IBIT](IMPORTANT): Beginning Initiated BIT
2023-05-12T21:48:41.479Z,1683928121.479 [IBIT](IMPORTANT): Beginning control surface checks.
2023-05-12T21:48:41.483Z,1683928121.483 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-12T21:48:42.421Z,1683928122.421 [DataOverHttps](IMPORTANT): SBD MTMSN=20230512T214841
2023-05-12T21:48:43.075Z,1683928123.075 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214842.00,A,3648.15135,N,12147.22070,W,0.097,167.85,120523,,,D*78
2023-05-12T21:48:43.077Z,1683928123.077 [NAL9602](INFO): GPS fix at 20230512T214842: (36.802523, -121.787012)
2023-05-12T21:48:50.056Z,1683928130.056 [DataOverHttps](INFO): Received command: ibit
2023-05-12T21:48:50.105Z,1683928130.105 [CommandExec](IMPORTANT): got command ibit
2023-05-12T21:48:52.386Z,1683928132.386 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.042285
CHAN A1 (24V): 0.032697
CHAN A2 (12V): -0.021696
CHAN A3 (5V): -0.038386
CHAN B0 (3.3V): -0.020436
CHAN B1 (3.15aV): -0.009512
CHAN B2 (3.15bV): -0.004821
CHAN B3 (GND): -0.019712
OPEN: 0.007842
Full Scale: +/- 1 mA
2023-05-12T21:49:09.760Z,1683928149.760 [NAL9602](INFO): SBD MO Status=0, MOMSN=3660, MT Status=0, MTMSN=0
2023-05-12T21:49:09.760Z,1683928149.760 [NAL9602](INFO): No messages in MT queue
2023-05-12T21:49:10.962Z,1683928150.962 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214910.00,A,3648.15143,N,12147.22101,W,0.019,167.85,120523,,,A*7B
2023-05-12T21:49:10.965Z,1683928150.965 [NAL9602](INFO): GPS fix at 20230512T214910: (36.802524, -121.787017)
2023-05-12T21:49:14.269Z,1683928154.269 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214913.00,A,3648.15140,N,12147.22105,W,0.039,167.85,120523,,,A*7D
2023-05-12T21:49:14.271Z,1683928154.271 [NAL9602](INFO): GPS fix at 20230512T214913: (36.802523, -121.787018)
2023-05-12T21:49:17.039Z,1683928157.039 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214916.00,A,3648.15130,N,12147.22104,W,0.078,167.85,120523,,,A*7B
2023-05-12T21:49:17.045Z,1683928157.045 [NAL9602](INFO): GPS fix at 20230512T214916: (36.802522, -121.787017)
2023-05-12T21:49:19.858Z,1683928159.858 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214919.00,A,3648.15121,N,12147.22100,W,0.039,167.85,120523,,,A*75
2023-05-12T21:49:19.860Z,1683928159.860 [NAL9602](INFO): GPS fix at 20230512T214919: (36.802520, -121.787017)
2023-05-12T21:49:23.084Z,1683928163.084 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214922.00,A,3648.15115,N,12147.22088,W,0.058,167.85,120523,,,A*7C
2023-05-12T21:49:23.086Z,1683928163.086 [NAL9602](INFO): GPS fix at 20230512T214922: (36.802519, -121.787015)
2023-05-12T21:49:25.911Z,1683928165.911 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214925.00,A,3648.15107,N,12147.22088,W,0.019,167.85,120523,,,A*7D
2023-05-12T21:49:25.913Z,1683928165.913 [NAL9602](INFO): GPS fix at 20230512T214925: (36.802518, -121.787015)
2023-05-12T21:49:27.570Z,1683928167.570 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802517 Longitude: -121.787018
2023-05-12T21:49:27.955Z,1683928167.955 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 15.541000
2023-05-12T21:49:27.955Z,1683928167.955 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2023-05-12T21:49:27.956Z,1683928167.956 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2023-05-12T21:49:28.346Z,1683928168.346 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2023-05-12T21:49:28.346Z,1683928168.346 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2023-05-12T21:49:28.347Z,1683928168.347 [IBIT](IMPORTANT): Pressure:9.638187 PSI
2023-05-12T21:49:28.347Z,1683928168.347 [IBIT](IMPORTANT): Humidity:6.781834 %
2023-05-12T21:49:28.760Z,1683928168.760 [IBIT](IMPORTANT): Vehicle Pitch:-2.169929 degrees
2023-05-12T21:49:28.761Z,1683928168.761 [IBIT](IMPORTANT): Vehicle  Roll:-0.103697 degrees
2023-05-12T21:49:28.761Z,1683928168.761 [IBIT](IMPORTANT): Vehicle  Heading:201.752441 degrees
2023-05-12T21:49:29.151Z,1683928169.151 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2023-05-12T21:49:29.151Z,1683928169.151 [IBIT](IMPORTANT): buoyancyNeutral: 191.501740 cc
2023-05-12T21:49:29.152Z,1683928169.152 [IBIT](IMPORTANT): massDefault: 1.294477 cm
2023-05-12T21:49:29.152Z,1683928169.152 [IBIT](IMPORTANT): stopDepth: 50.000000 m
2023-05-12T21:49:29.152Z,1683928169.152 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2023-05-12T21:49:29.152Z,1683928169.152 [IBIT](IMPORTANT): IBIT PASSED
2023-05-12T21:49:58.633Z,1683928198.633 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:51:51.830Z,1683928311.830 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:51:51.830Z,1683928311.830 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:51:51.830Z,1683928311.830 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:51:51.830Z,1683928311.830 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:51:52.226Z,1683928312.226 [Default:CheckIn:D] Stopped
2023-05-12T21:51:52.226Z,1683928312.226 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:51:52.597Z,1683928312.597 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 47.347640 min 
2023-05-12T21:51:52.597Z,1683928312.597 [Default:CheckIn:E] Stopped
2023-05-12T21:51:52.597Z,1683928312.597 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:51:52.597Z,1683928312.597 [Default:CheckIn] Stopped
2023-05-12T21:51:52.597Z,1683928312.597 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:51:52.597Z,1683928312.597 [Default:CheckIn](INFO): Running loop #9
2023-05-12T21:51:52.597Z,1683928312.597 [Default:CheckIn] Running Loop=9
2023-05-12T21:51:52.597Z,1683928312.597 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:51:52.598Z,1683928312.598 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:51:54.598Z,1683928314.598 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215153.00,A,3648.17548,N,12147.19712,W,4.860,52.14,120523,,,D*4C
2023-05-12T21:51:54.601Z,1683928314.601 [NAL9602](INFO): GPS fix at 20230512T215153: (36.802925, -121.786619)
2023-05-12T21:51:54.627Z,1683928314.627 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:51:54.627Z,1683928314.627 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:52:01.883Z,1683928321.883 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20230512T210012/Courier0028.lzma
2023-05-12T21:52:02.886Z,1683928322.886 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0028.lzma.bak
2023-05-12T21:52:02.886Z,1683928322.886 [DataOverHttps](INFO): SBD MOMSN=18301521
2023-05-12T21:52:19.549Z,1683928339.549 [DataOverHttps](INFO): Sending 821 bytes from file Logs/20230512T210012/Express0029.lzma
2023-05-12T21:52:20.550Z,1683928340.550 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0029.lzma.bak
2023-05-12T21:52:20.550Z,1683928340.550 [DataOverHttps](INFO): SBD MOMSN=18301524
2023-05-12T21:52:21.269Z,1683928341.269 [NAL9602](INFO): SBD MO Status=2, MOMSN=3661, MT Status=2, MTMSN=0
2023-05-12T21:52:21.269Z,1683928341.269 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-05-12T21:52:40.271Z,1683928360.271 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20230512T210012/Express0032.lzma
2023-05-12T21:52:41.274Z,1683928361.274 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0032.lzma.bak
2023-05-12T21:52:41.274Z,1683928361.274 [DataOverHttps](INFO): SBD MOMSN=18301552
2023-05-12T21:52:43.115Z,1683928363.115 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:52:43.115Z,1683928363.115 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:52:43.116Z,1683928363.116 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:52:48.357Z,1683928368.357 [NAL9602](INFO): SBD MO Status=2, MOMSN=3661, MT Status=2, MTMSN=0
2023-05-12T21:52:48.357Z,1683928368.357 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2023-05-12T21:52:57.647Z,1683928377.647 [NAL9602](INFO): SBD MO Status=0, MOMSN=3661, MT Status=0, MTMSN=0
2023-05-12T21:52:57.647Z,1683928377.647 [NAL9602](INFO): No messages in MT queue
2023-05-12T21:53:28.352Z,1683928408.352 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T21:55:01.286Z,1683928501.286 [DVL_micro](ERROR): Failed to parse:
:B,-00110,-00851,+00000,I
2023-05-12T21:57:43.715Z,1683928663.715 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-12T21:57:43.715Z,1683928663.715 [Default:CheckIn:C.Wait] Stopped
2023-05-12T21:57:43.715Z,1683928663.715 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T21:57:43.715Z,1683928663.715 [Default:CheckIn:D] Running Loop=1
2023-05-12T21:57:44.114Z,1683928664.114 [Default:CheckIn:D] Stopped
2023-05-12T21:57:44.114Z,1683928664.114 [Default:CheckIn:E] Running Loop=1
2023-05-12T21:57:44.517Z,1683928664.517 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 53.212443 min 
2023-05-12T21:57:44.517Z,1683928664.517 [Default:CheckIn:E] Stopped
2023-05-12T21:57:44.517Z,1683928664.517 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-12T21:57:44.517Z,1683928664.517 [Default:CheckIn] Stopped
2023-05-12T21:57:44.518Z,1683928664.518 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T21:57:44.518Z,1683928664.518 [Default:CheckIn](INFO): Running loop #10
2023-05-12T21:57:44.518Z,1683928664.518 [Default:CheckIn] Running Loop=10
2023-05-12T21:57:44.518Z,1683928664.518 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T21:57:44.518Z,1683928664.518 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T21:57:46.527Z,1683928666.527 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215745.00,A,3648.45662,N,12147.34101,W,7.076,237.87,120523,,,D*7D
2023-05-12T21:57:46.530Z,1683928666.530 [NAL9602](INFO): GPS fix at 20230512T215745: (36.807610, -121.789017)
2023-05-12T21:57:46.539Z,1683928666.539 [Default:CheckIn:Read_GPS] Stopped
2023-05-12T21:57:46.540Z,1683928666.540 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-12T21:57:53.851Z,1683928673.851 [DataOverHttps](INFO): Sending 76 bytes from file Logs/20230512T210012/Courier0034.lzma
2023-05-12T21:57:54.854Z,1683928674.854 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Courier0034.lzma.bak
2023-05-12T21:57:54.854Z,1683928674.854 [DataOverHttps](INFO): SBD MOMSN=18301569
2023-05-12T21:58:01.087Z,1683928681.087 [NAL9602](INFO): SBD MO Status=0, MOMSN=3662, MT Status=0, MTMSN=0
2023-05-12T21:58:01.087Z,1683928681.087 [NAL9602](INFO): No messages in MT queue
2023-05-12T21:58:10.743Z,1683928690.743 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20230512T210012/Express0035.lzma
2023-05-12T21:58:11.742Z,1683928691.742 [DataOverHttps](INFO): Moved sent file to Logs/20230512T210012/Express0035.lzma.bak
2023-05-12T21:58:11.742Z,1683928691.742 [DataOverHttps](INFO): SBD MOMSN=18301573
2023-05-12T21:58:13.212Z,1683928693.212 [Default:CheckIn:Read_Iridium] Stopped
2023-05-12T21:58:13.212Z,1683928693.212 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-12T21:58:13.212Z,1683928693.212 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-12T21:58:31.786Z,1683928711.786 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T22:01:23.210Z,1683928883.210 [DataOverHttps](IMPORTANT): SBD MTMSN=20230512T220122
2023-05-12T22:01:30.688Z,1683928890.688 [DataOverHttps](INFO): Received command: configSet CBIT.stopDepth 210 meter persist;configSet DAT.loadAtStartup 0 bool persist;configSet DATMMP.loadAtStartup 1 bool persist;configSet DATMMP.simulateHardware 0 bool persist;restart app
2023-05-12T22:01:31.693Z,1683928891.693 [CommandExec](IMPORTANT): got command configSet CBIT.stopDepth 210 meter persist
2023-05-12T22:01:31.697Z,1683928891.697 [CommandExec](IMPORTANT): got command configSet DAT.loadAtStartup 0 bool persist
2023-05-12T22:01:31.698Z,1683928891.698 [CommandExec](IMPORTANT): configSet DAT.loadAtStartup requires a restart to take effect.
2023-05-12T22:01:31.700Z,1683928891.700 [CommandExec](IMPORTANT): got command configSet DATMMP.loadAtStartup 1 bool persist
2023-05-12T22:01:31.701Z,1683928891.701 [CommandExec](IMPORTANT): configSet DATMMP.loadAtStartup requires a restart to take effect.
2023-05-12T22:01:31.703Z,1683928891.703 [CommandExec](IMPORTANT): got command configSet DATMMP.simulateHardware 0 bool persist
2023-05-12T22:01:31.706Z,1683928891.706 [CommandExec](IMPORTANT): got command restart application
2023-05-12T22:01:32.708Z,1683928892.708 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2023-05-12T22:01:32.708Z,1683928892.708 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:32.709Z,1683928892.709 [CommandExec](INFO): Uninitializing the command executive.
2023-05-12T22:01:32.709Z,1683928892.709 [CommandExec](INFO): Uninitializing the command scheduler.
2023-05-12T22:01:32.709Z,1683928892.709 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:32.804Z,1683928892.804 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-05-12T22:01:32.804Z,1683928892.804 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-05-12T22:01:32.804Z,1683928892.804 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:32.805Z,1683928892.805 [NavChartDb](INFO): Join timeout helper Thread ID is 1259
2023-05-12T22:01:32.944Z,1683928892.944 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:32.944Z,1683928892.944 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:32.952Z,1683928892.952 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-05-12T22:01:32.952Z,1683928892.952 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:32.953Z,1683928892.953 [Radio_Surface](INFO): Join timeout helper Thread ID is 1260
2023-05-12T22:01:33.060Z,1683928893.060 [Radio_Surface](INFO): Powering down
2023-05-12T22:01:33.061Z,1683928893.061 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:33.061Z,1683928893.061 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:33.072Z,1683928893.072 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-05-12T22:01:33.072Z,1683928893.072 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:33.072Z,1683928893.072 [Onboard](INFO): Join timeout helper Thread ID is 1261
2023-05-12T22:01:33.696Z,1683928893.696 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-05-12T22:01:36.420Z,1683928896.420 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:36.420Z,1683928896.420 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.428Z,1683928896.428 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-05-12T22:01:36.428Z,1683928896.428 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.428Z,1683928896.428 [DataOverHttps](INFO): Join timeout helper Thread ID is 1262
2023-05-12T22:01:36.708Z,1683928896.708 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:36.708Z,1683928896.708 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.723Z,1683928896.723 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2023-05-12T22:01:36.723Z,1683928896.723 [DAT ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.723Z,1683928896.723 [DAT](INFO): Join timeout helper Thread ID is 1263
2023-05-12T22:01:36.908Z,1683928896.908 [DAT](INFO): Powering down
2023-05-12T22:01:36.981Z,1683928896.981 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:36.981Z,1683928896.981 [DAT](INFO): Powering down
2023-05-12T22:01:36.982Z,1683928896.982 [DAT ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.993Z,1683928896.993 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-05-12T22:01:36.993Z,1683928896.993 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:36.993Z,1683928896.993 [BackseatComponent](INFO): Join timeout helper Thread ID is 1264
2023-05-12T22:01:37.028Z,1683928897.028 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:37.028Z,1683928897.028 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:37.037Z,1683928897.037 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-05-12T22:01:37.037Z,1683928897.037 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:37.037Z,1683928897.037 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1265
2023-05-12T22:01:37.208Z,1683928897.208 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:37.208Z,1683928897.208 [WetLabsBB2FL](INFO): Powering down
2023-05-12T22:01:37.209Z,1683928897.209 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:37.225Z,1683928897.225 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-05-12T22:01:37.225Z,1683928897.225 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:37.225Z,1683928897.225 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1266
2023-05-12T22:01:37.984Z,1683928897.984 [CTD_Seabird](INFO): Powering down
2023-05-12T22:01:37.996Z,1683928897.996 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:38.001Z,1683928898.001 [CTD_Seabird](INFO): Powering down
2023-05-12T22:01:38.012Z,1683928898.012 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.017Z,1683928898.017 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-05-12T22:01:38.017Z,1683928898.017 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.017Z,1683928898.017 [logger](INFO): Join timeout helper Thread ID is 1267
2023-05-12T22:01:38.028Z,1683928898.028 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:38.029Z,1683928898.029 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.037Z,1683928898.037 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-05-12T22:01:38.037Z,1683928898.037 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.037Z,1683928898.037 [CommandLine](INFO): Join timeout helper Thread ID is 1268
2023-05-12T22:01:38.116Z,1683928898.116 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:38.116Z,1683928898.116 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.125Z,1683928898.125 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-05-12T22:01:38.125Z,1683928898.125 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.125Z,1683928898.125 [CommandExec](INFO): Join timeout helper Thread ID is 1269
2023-05-12T22:01:38.126Z,1683928898.126 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-05-12T22:01:38.126Z,1683928898.126 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.127Z,1683928898.127 [controlThread](INFO): Join timeout helper Thread ID is 1270
2023-05-12T22:01:38.400Z,1683928898.400 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-12T22:01:38.400Z,1683928898.400 [controlThread](DEBUG): Uninitializing ControlThread
2023-05-12T22:01:38.402Z,1683928898.402 [AHRS_M2](INFO): Powering down
2023-05-12T22:01:38.544Z,1683928898.544 [DVL_micro](INFO): Powering down
2023-05-12T22:01:38.545Z,1683928898.545 [NAL9602](INFO): Powering down
2023-05-12T22:01:38.547Z,1683928898.547 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-05-12T22:01:38.547Z,1683928898.547 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-05-12T22:01:38.548Z,1683928898.548 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-05-12T22:01:38.549Z,1683928898.549 [MissionManager](INFO): Uninitializing Mission Default
2023-05-12T22:01:38.549Z,1683928898.549 [Default] Stopped
2023-05-12T22:01:38.549Z,1683928898.549 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-12T22:01:38.549Z,1683928898.549 [Default:B.GoToSurface] Stopped
2023-05-12T22:01:38.549Z,1683928898.549 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-12T22:01:38.549Z,1683928898.549 [Default:CheckIn] Stopped
2023-05-12T22:01:38.549Z,1683928898.549 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-12T22:01:38.549Z,1683928898.549 [Default:CheckIn:C.Wait] Stopped
2023-05-12T22:01:38.550Z,1683928898.550 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T22:01:38.552Z,1683928898.552 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-05-12T22:01:38.553Z,1683928898.553 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-05-12T22:01:38.553Z,1683928898.553 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-05-12T22:01:38.553Z,1683928898.553 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-05-12T22:01:38.553Z,1683928898.553 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-05-12T22:01:38.554Z,1683928898.554 [BuoyancyServo](INFO): Powering down
2023-05-12T22:01:38.568Z,1683928898.568 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-05-12T22:01:38.568Z,1683928898.568 [ElevatorServo](INFO): Powering down
2023-05-12T22:01:38.569Z,1683928898.569 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-05-12T22:01:38.569Z,1683928898.569 [MassServo](INFO): Powering down
2023-05-12T22:01:38.570Z,1683928898.570 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-12T22:01:38.570Z,1683928898.570 [RudderServo](INFO): Powering down
2023-05-12T22:01:38.571Z,1683928898.571 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-05-12T22:01:38.571Z,1683928898.571 [ThrusterHE](INFO): Powering down
2023-05-12T22:01:38.572Z,1683928898.572 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-05-12T22:01:38.572Z,1683928898.572 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-05-12T22:01:38.573Z,1683928898.573 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-05-12T22:01:38.573Z,1683928898.573 [CBIT](DEBUG): Powering off loads.
2023-05-12T22:01:38.584Z,1683928898.584 [CBIT](DEBUG): Disabling WDT.
2023-05-12T22:01:38.596Z,1683928898.596 [CBIT](DEBUG): Opening all GF detection circuits.
2023-05-12T22:01:38.597Z,1683928898.597 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.634Z,1683928898.634 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.640Z,1683928898.640 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.669Z,1683928898.669 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.671Z,1683928898.671 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.679Z,1683928898.679 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.685Z,1683928898.685 [DAT ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.727Z,1683928898.727 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.777Z,1683928898.777 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-12T22:01:38.847Z,1683928898.847 [logger ThreadHandler](INFO): Thread cancelled.