2024-08-29T23:18:04.795Z,1724973484.795 [Supervisor](DEBUG): Initializing supervisor.
2024-08-29T23:18:04.799Z,1724973484.799 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2024-08-29T23:18:04.799Z,1724973484.799 [SyncHandler](INFO): Protected caller Thread ID is 1067
2024-08-29T23:18:04.800Z,1724973484.800 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2024-08-29T23:18:04.801Z,1724973484.801 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2024-08-29T23:18:04.801Z,1724973484.801 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1068
2024-08-29T23:18:04.805Z,1724973484.805 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2024-08-29T23:18:04.822Z,1724973484.822 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2024-08-29T23:18:04.823Z,1724973484.823 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2024-08-29T23:18:04.824Z,1724973484.824 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1069
2024-08-29T23:18:04.828Z,1724973484.828 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2024-08-29T23:18:04.829Z,1724973484.829 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2024-08-29T23:18:04.829Z,1724973484.829 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1070
2024-08-29T23:18:04.831Z,1724973484.831 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2024-08-29T23:18:04.832Z,1724973484.832 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2024-08-29T23:18:04.833Z,1724973484.833 [logger ThreadHandler](INFO): Protected caller Thread ID is 1071
2024-08-29T23:18:04.836Z,1724973484.836 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2024-08-29T23:18:04.836Z,1724973484.836 [Supervisor](INFO): Looking for Config files in directory: Config/
2024-08-29T23:18:04.838Z,1724973484.838 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2024-08-29T23:18:04.945Z,1724973484.945 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2024-08-29T23:18:04.945Z,1724973484.945 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2024-08-29T23:18:05.190Z,1724973485.190 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2024-08-29T23:18:05.190Z,1724973485.190 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2024-08-29T23:18:05.466Z,1724973485.466 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2024-08-29T23:18:05.467Z,1724973485.467 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2024-08-29T23:18:05.586Z,1724973485.586 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2024-08-29T23:18:05.586Z,1724973485.586 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2024-08-29T23:18:06.356Z,1724973486.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2024-08-29T23:18:06.357Z,1724973486.357 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2024-08-29T23:18:06.926Z,1724973486.926 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2024-08-29T23:18:06.927Z,1724973486.927 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2024-08-29T23:18:07.548Z,1724973487.548 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2024-08-29T23:18:07.549Z,1724973487.549 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2024-08-29T23:18:07.983Z,1724973487.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2024-08-29T23:18:07.983Z,1724973487.983 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2024-08-29T23:18:08.338Z,1724973488.338 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2024-08-29T23:18:08.338Z,1724973488.338 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2024-08-29T23:18:08.736Z,1724973488.736 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2024-08-29T23:18:08.737Z,1724973488.737 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2024-08-29T23:18:08.980Z,1724973488.980 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2024-08-29T23:18:08.980Z,1724973488.980 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2024-08-29T23:18:09.132Z,1724973489.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2024-08-29T23:18:09.132Z,1724973489.132 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2024-08-29T23:18:09.224Z,1724973489.224 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2024-08-29T23:18:09.314Z,1724973489.314 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2024-08-29T23:18:09.512Z,1724973489.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2024-08-29T23:18:09.513Z,1724973489.513 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2024-08-29T23:18:09.757Z,1724973489.757 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2024-08-29T23:18:09.759Z,1724973489.759 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2024-08-29T23:18:09.760Z,1724973489.760 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2024-08-29T23:18:09.854Z,1724973489.854 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2024-08-29T23:18:10.127Z,1724973490.127 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2024-08-29T23:18:10.127Z,1724973490.127 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2024-08-29T23:18:10.232Z,1724973490.232 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2024-08-29T23:18:10.408Z,1724973490.408 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2024-08-29T23:18:10.518Z,1724973490.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2024-08-29T23:18:10.639Z,1724973490.639 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2024-08-29T23:18:10.762Z,1724973490.762 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2024-08-29T23:18:10.879Z,1724973490.879 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2024-08-29T23:18:11.051Z,1724973491.051 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2024-08-29T23:18:11.159Z,1724973491.159 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/workSite.cfg
2024-08-29T23:18:11.254Z,1724973491.254 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2024-08-29T23:18:11.362Z,1724973491.362 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2024-08-29T23:18:11.463Z,1724973491.463 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2024-08-29T23:18:11.463Z,1724973491.463 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2024-08-29T23:18:11.471Z,1724973491.471 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2024-08-29T23:18:11.643Z,1724973491.643 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2024-08-29T23:18:11.644Z,1724973491.644 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2024-08-29T23:18:11.802Z,1724973491.802 [BuoyancyServo] Loaded
2024-08-29T23:18:11.803Z,1724973491.803 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2024-08-29T23:18:11.825Z,1724973491.825 [ElevatorServo] Loaded
2024-08-29T23:18:11.826Z,1724973491.826 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2024-08-29T23:18:11.848Z,1724973491.848 [MassServo] Loaded
2024-08-29T23:18:11.848Z,1724973491.848 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2024-08-29T23:18:11.870Z,1724973491.870 [RudderServo] Loaded
2024-08-29T23:18:11.870Z,1724973491.870 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2024-08-29T23:18:11.887Z,1724973491.887 [ThrusterHE] Loaded
2024-08-29T23:18:11.887Z,1724973491.887 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2024-08-29T23:18:11.887Z,1724973491.887 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2024-08-29T23:18:11.888Z,1724973491.888 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2024-08-29T23:18:12.101Z,1724973492.101 [SBIT](DEBUG): Construct Startup Built In Test.
2024-08-29T23:18:12.115Z,1724973492.115 [SBIT] Loaded
2024-08-29T23:18:12.116Z,1724973492.116 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2024-08-29T23:18:12.118Z,1724973492.118 [IBIT](DEBUG): Construct Initiated Built In Test.
2024-08-29T23:18:12.139Z,1724973492.139 [IBIT] Loaded
2024-08-29T23:18:12.139Z,1724973492.139 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2024-08-29T23:18:12.145Z,1724973492.145 [CBIT](DEBUG): Construct Continuous Built In Test.
2024-08-29T23:18:12.364Z,1724973492.364 [CBIT] Loaded
2024-08-29T23:18:12.364Z,1724973492.364 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2024-08-29T23:18:12.365Z,1724973492.365 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2024-08-29T23:18:12.365Z,1724973492.365 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2024-08-29T23:18:12.548Z,1724973492.548 [CTD_Seabird] Loaded
2024-08-29T23:18:12.548Z,1724973492.548 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2024-08-29T23:18:12.549Z,1724973492.549 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406784E0
2024-08-29T23:18:12.549Z,1724973492.549 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1159
2024-08-29T23:18:12.584Z,1724973492.584 [ESPComponent] Loaded
2024-08-29T23:18:12.584Z,1724973492.584 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2024-08-29T23:18:12.606Z,1724973492.606 [PAR_Licor] Loaded
2024-08-29T23:18:12.606Z,1724973492.606 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2024-08-29T23:18:12.649Z,1724973492.649 [WetLabsBB2FL] Loaded
2024-08-29T23:18:12.649Z,1724973492.649 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2024-08-29T23:18:12.650Z,1724973492.650 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406A84E0
2024-08-29T23:18:12.650Z,1724973492.650 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1160
2024-08-29T23:18:12.651Z,1724973492.651 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2024-08-29T23:18:12.652Z,1724973492.652 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2024-08-29T23:18:12.701Z,1724973492.701 [DepthRateCalculator] Loaded
2024-08-29T23:18:12.702Z,1724973492.702 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2024-08-29T23:18:12.707Z,1724973492.707 [PitchRateCalculator] Loaded
2024-08-29T23:18:12.707Z,1724973492.707 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2024-08-29T23:18:12.717Z,1724973492.717 [SpeedCalculator] Loaded
2024-08-29T23:18:12.717Z,1724973492.717 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2024-08-29T23:18:12.722Z,1724973492.722 [YawRateCalculator] Loaded
2024-08-29T23:18:12.722Z,1724973492.722 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2024-08-29T23:18:12.742Z,1724973492.742 [ElevatorOffsetCalculator] Loaded
2024-08-29T23:18:12.742Z,1724973492.742 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2024-08-29T23:18:12.742Z,1724973492.742 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2024-08-29T23:18:12.743Z,1724973492.743 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2024-08-29T23:18:12.850Z,1724973492.850 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2024-08-29T23:18:12.850Z,1724973492.850 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2024-08-29T23:18:12.876Z,1724973492.876 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2024-08-29T23:18:12.877Z,1724973492.877 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2024-08-29T23:18:12.986Z,1724973492.986 [DeadReckonUsingMultipleVelocitySources] Loaded
2024-08-29T23:18:12.986Z,1724973492.986 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2024-08-29T23:18:12.000Z,1724973493.000 [NavChart] Loaded
2024-08-29T23:18:12.000Z,1724973493.000 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2024-08-29T23:18:13.006Z,1724973493.006 [UniversalFixResidualReporter] Loaded
2024-08-29T23:18:13.006Z,1724973493.006 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2024-08-29T23:18:13.006Z,1724973493.006 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2024-08-29T23:18:13.007Z,1724973493.007 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2024-08-29T23:18:13.456Z,1724973493.456 [AHRS_M2] Loaded
2024-08-29T23:18:13.456Z,1724973493.456 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2024-08-29T23:18:13.494Z,1724973493.494 [BackseatComponent] Loaded
2024-08-29T23:18:13.495Z,1724973493.495 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2024-08-29T23:18:13.496Z,1724973493.496 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A694E0
2024-08-29T23:18:13.496Z,1724973493.496 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1161
2024-08-29T23:18:13.499Z,1724973493.499 [LcmUniversalReporter] Loaded
2024-08-29T23:18:13.499Z,1724973493.499 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2024-08-29T23:18:14.237Z,1724973494.237 [BPC1] Loaded
2024-08-29T23:18:14.237Z,1724973494.237 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2024-08-29T23:18:14.326Z,1724973494.326 [DATMMP] Loaded
2024-08-29T23:18:14.327Z,1724973494.327 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2024-08-29T23:18:14.328Z,1724973494.328 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 40A9A4E0
2024-08-29T23:18:14.328Z,1724973494.328 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 1162
2024-08-29T23:18:14.398Z,1724973494.398 [DataOverHttps] Loaded
2024-08-29T23:18:14.399Z,1724973494.399 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2024-08-29T23:18:14.400Z,1724973494.400 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40ACA4E0
2024-08-29T23:18:14.400Z,1724973494.400 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1163
2024-08-29T23:18:14.423Z,1724973494.423 [Depth_Keller] Loaded
2024-08-29T23:18:14.423Z,1724973494.423 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2024-08-29T23:18:14.429Z,1724973494.429 [DropWeight] Loaded
2024-08-29T23:18:14.429Z,1724973494.429 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2024-08-29T23:18:14.469Z,1724973494.469 [DVL_micro] Loaded
2024-08-29T23:18:14.470Z,1724973494.470 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2024-08-29T23:18:14.531Z,1724973494.531 [NAL9602] Loaded
2024-08-29T23:18:14.531Z,1724973494.531 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2024-08-29T23:18:14.556Z,1724973494.556 [Onboard] Loaded
2024-08-29T23:18:14.556Z,1724973494.556 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2024-08-29T23:18:14.557Z,1724973494.557 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40AFA4E0
2024-08-29T23:18:14.558Z,1724973494.558 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1164
2024-08-29T23:18:14.572Z,1724973494.572 [Power24vConverter] Loaded
2024-08-29T23:18:14.572Z,1724973494.572 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2024-08-29T23:18:14.587Z,1724973494.587 [Radio_Surface] Loaded
2024-08-29T23:18:14.587Z,1724973494.587 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2024-08-29T23:18:14.588Z,1724973494.588 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40B2A4E0
2024-08-29T23:18:14.589Z,1724973494.589 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1165
2024-08-29T23:18:14.604Z,1724973494.604 [Sonardyne_Nano] Loaded
2024-08-29T23:18:14.604Z,1724973494.604 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2024-08-29T23:18:14.605Z,1724973494.605 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2024-08-29T23:18:14.606Z,1724973494.606 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2024-08-29T23:18:14.673Z,1724973494.673 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2024-08-29T23:18:14.674Z,1724973494.674 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2024-08-29T23:18:14.724Z,1724973494.724 [VerticalControl](DEBUG): Construct VerticalControl.
2024-08-29T23:18:14.775Z,1724973494.775 [VerticalControl] Loaded
2024-08-29T23:18:14.775Z,1724973494.775 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2024-08-29T23:18:14.778Z,1724973494.778 [HorizontalControl](DEBUG): Construct HorizontalControl.
2024-08-29T23:18:14.822Z,1724973494.822 [HorizontalControl] Loaded
2024-08-29T23:18:14.822Z,1724973494.822 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2024-08-29T23:18:14.825Z,1724973494.825 [SpeedControl](DEBUG): Construct SpeedControl.
2024-08-29T23:18:14.826Z,1724973494.826 [SpeedControl] Loaded
2024-08-29T23:18:14.827Z,1724973494.827 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2024-08-29T23:18:14.829Z,1724973494.829 [LoopControl](DEBUG): Construct LoopControl.
2024-08-29T23:18:14.830Z,1724973494.830 [LoopControl] Loaded
2024-08-29T23:18:14.830Z,1724973494.830 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2024-08-29T23:18:14.831Z,1724973494.831 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2024-08-29T23:18:14.831Z,1724973494.831 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2024-08-29T23:18:14.841Z,1724973494.841 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2024-08-29T23:18:14.842Z,1724973494.842 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2024-08-29T23:18:15.168Z,1724973495.168 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2024-08-29T23:18:15.174Z,1724973495.174 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2024-08-29T23:18:15.177Z,1724973495.177 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2024-08-29T23:18:15.188Z,1724973495.188 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2024-08-29T23:18:15.189Z,1724973495.189 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C524E0
2024-08-29T23:18:15.190Z,1724973495.190 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1166
2024-08-29T23:18:15.194Z,1724973495.194 [Supervisor](INFO): Main Thread ID is 824
2024-08-29T23:18:15.194Z,1724973495.194 [Supervisor](DEBUG): Running supervisor.
2024-08-29T23:18:15.195Z,1724973495.195 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1167
2024-08-29T23:18:15.195Z,1724973495.195 [CommandExec](INFO): Initializing the command executive.
2024-08-29T23:18:15.197Z,1724973495.197 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1168
2024-08-29T23:18:15.200Z,1724973495.200 [controlThread ThreadHandler](INFO): Handler Thread ID is 1169
2024-08-29T23:18:15.200Z,1724973495.200 [controlThread](DEBUG): Initializing ControlThread
2024-08-29T23:18:15.202Z,1724973495.202 [SBIT](INFO): Initialize SBIT Component.
2024-08-29T23:18:15.202Z,1724973495.202 [SBIT](IMPORTANT): git: 2024-08-28_A
2024-08-29T23:18:15.203Z,1724973495.203 [SBIT](INFO): git hash: 19b1c3b1e3952ad2aa64ad64d76ff1fa7009b665
2024-08-29T23:18:15.203Z,1724973495.203 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2024-08-29T23:18:15.204Z,1724973495.204 [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
2024-08-29T23:18:15.206Z,1724973495.206 [SBIT](INFO): Beginning SBIT in 88.000000 seconds.
2024-08-29T23:18:15.206Z,1724973495.206 [IBIT](INFO): Initialize IBIT Component.
2024-08-29T23:18:15.207Z,1724973495.207 [CBIT](DEBUG): Initialize CBIT Component.
2024-08-29T23:18:15.208Z,1724973495.208 [logger ThreadHandler](INFO): Handler Thread ID is 1170
2024-08-29T23:18:15.221Z,1724973495.221 [CBIT](DEBUG): Initialized mux pins.
2024-08-29T23:18:15.221Z,1724973495.221 [CBIT](DEBUG): Initializing the watchdog timer.
2024-08-29T23:18:15.233Z,1724973495.233 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1171
2024-08-29T23:18:15.234Z,1724973495.234 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2024-08-29T23:18:15.239Z,1724973495.239 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1173
2024-08-29T23:18:15.241Z,1724973495.241 [WetLabsBB2FL](INFO): Powering up
2024-08-29T23:18:15.243Z,1724973495.243 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1175
2024-08-29T23:18:15.245Z,1724973495.245 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2024-08-29T23:18:15.246Z,1724973495.246 [CBIT](DEBUG): Initializing heartbeat.
2024-08-29T23:18:15.260Z,1724973495.260 [DATMMP ThreadHandler](INFO): Handler Thread ID is 1176
2024-08-29T23:18:15.260Z,1724973495.260 [DATMMP](INFO): Start
2024-08-29T23:18:15.260Z,1724973495.260 [DATMMP](INFO): Powering up
2024-08-29T23:18:15.261Z,1724973495.261 [DATMMP](DEBUG): Initializing DATMMP.
2024-08-29T23:18:15.269Z,1724973495.269 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1178
2024-08-29T23:18:15.271Z,1724973495.271 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2024-08-29T23:18:15.281Z,1724973495.281 [Onboard ThreadHandler](INFO): Handler Thread ID is 1179
2024-08-29T23:18:15.299Z,1724973495.299 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1180
2024-08-29T23:18:15.317Z,1724973495.317 [CBIT](DEBUG): Deactivating GF circuits.
2024-08-29T23:18:15.317Z,1724973495.317 [CBIT](DEBUG): Deactivating emergency mode.
2024-08-29T23:18:15.319Z,1724973495.319 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1181
2024-08-29T23:18:15.322Z,1724973495.322 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2024-08-29T23:18:15.326Z,1724973495.326 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2024-08-29T23:18:15.344Z,1724973495.344 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2024-08-29T23:18:15.346Z,1724973495.346 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US1WC07M.000
2024-08-29T23:18:15.346Z,1724973495.346 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2024-08-29T23:18:15.347Z,1724973495.347 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2WC11M.000
2024-08-29T23:18:15.347Z,1724973495.347 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2024-08-29T23:18:15.349Z,1724973495.349 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US3CA52M.000
2024-08-29T23:18:15.349Z,1724973495.349 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2024-08-29T23:18:15.350Z,1724973495.350 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US5CA50M.000
2024-08-29T23:18:15.357Z,1724973495.357 [CBIT](DEBUG): Backplane powered.
2024-08-29T23:18:15.361Z,1724973495.361 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2024-08-29T23:18:15.362Z,1724973495.362 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2024-08-29T23:18:15.362Z,1724973495.362 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2024-08-29T23:18:15.362Z,1724973495.362 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2024-08-29T23:18:15.363Z,1724973495.363 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2024-08-29T23:18:15.364Z,1724973495.364 [NavChart](DEBUG): Initialize NavChart Navigation.
2024-08-29T23:18:15.364Z,1724973495.364 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2024-08-29T23:18:15.371Z,1724973495.371 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2024-08-29T23:18:15.373Z,1724973495.373 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2024-08-29T23:18:15.374Z,1724973495.374 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2024-08-29T23:18:15.374Z,1724973495.374 [LoopControl](DEBUG): Initialize LoopControlComponent.
2024-08-29T23:18:15.375Z,1724973495.375 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2024-08-29T23:18:15.376Z,1724973495.376 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2024-08-29T23:18:15.376Z,1724973495.376 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2024-08-29T23:18:15.377Z,1724973495.377 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2024-08-29T23:18:15.422Z,1724973495.422 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2024-08-29T23:18:15.427Z,1724973495.427 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2024-08-29T23:18:15.446Z,1724973495.446 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US5CA50M.000
2024-08-29T23:18:15.474Z,1724973495.474 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Startup {
behavior Guidance:GoToSurface {
run in progression
}
aggregate StartupSatComms {
run in sequence
readDatum {
timeout duration=P1M
Universal:latitude_fix
}
readDatum {
timeout duration=P1M
Universal:platform_communications
}
}
}
2024-08-29T23:18:15.475Z,1724973495.475 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2024-08-29T23:18:15.475Z,1724973495.475 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2024-08-29T23:18:15.476Z,1724973495.476 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2024-08-29T23:18:15.513Z,1724973495.513 [DATMMP](INFO): Starting
2024-08-29T23:18:15.705Z,1724973495.705 [Radio_Surface](INFO): Powering up
2024-08-29T23:18:15.765Z,1724973495.765 [DATMMP](INFO): Starting
2024-08-29T23:18:15.795Z,1724973495.795 [MissionManager](DEBUG): TethyslAPI: Missions/Default.tl translated into:
0
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2024-08-29T23:18:15.818Z,1724973495.818 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2024-08-29T23:18:15.819Z,1724973495.819 [Default:A.Wait](DEBUG): Construct Wait.
2024-08-29T23:18:15.822Z,1724973495.822 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2024-08-29T23:18:15.846Z,1724973495.846 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2024-08-29T23:18:15.848Z,1724973495.848 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2024-08-29T23:18:15.886Z,1724973495.886 [Default:E.Execute](DEBUG): Construct Execute.
2024-08-29T23:18:15.889Z,1724973495.889 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission Default {
arguments {
ElapsedSinceDefaultStarted = 0 minute
}
behavior Guidance:Wait {
"""
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
"""
run in sequence
set duration = 13 second
}
behavior Guidance:GoToSurface {
run in progression
}
aggregate CheckIn {
run in sequence repeat=288
readDatum id="Read_GPS" {
timeout duration=P5M
Universal:time_fix
}
readDatum id="Read_Iridium" {
timeout duration=P4H {
behavior Guidance:Execute {
run in sequence
set command = "Burn on"
}
syslog critical "Dropped weight due to communications timeout."
}
Universal:platform_communications
}
behavior Guidance:Wait {
run in sequence
set duration = 5 minute
}
assign in sequence ElapsedSinceDefaultStarted = elapsed ( Universal:mission_started )
syslog important "Default mission has been running for " + ElapsedSinceDefaultStarted~minute
}
syslog important "Restarting logs and Default mission."
behavior Guidance:Execute {
run in sequence
set command = "restart logs"
}
}
2024-08-29T23:18:15.901Z,1724973495.901 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,Sonardyne_Nano,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2024-08-29T23:18:15.922Z,1724973495.922 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2024-08-29T23:18:15.983Z,1724973495.983 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.444336 decibar, 0.000000 m
2024-08-29T23:18:15.986Z,1724973495.986 [Power24vConverter](INFO): Powering up.
2024-08-29T23:18:15.987Z,1724973495.987 [Sonardyne_Nano](INFO): Initializing.
2024-08-29T23:18:16.013Z,1724973496.013 [DepthRateCalculator](ERROR): Depth measurement is not active
2024-08-29T23:18:16.017Z,1724973496.017 [DATMMP](INFO): Starting
2024-08-29T23:18:16.032Z,1724973496.032 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2024-08-29T23:18:16.045Z,1724973496.045 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2024-08-29T23:18:16.046Z,1724973496.046 [ElevatorServo](DEBUG): Initializing EZServoServo.
2024-08-29T23:18:16.053Z,1724973496.053 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2024-08-29T23:18:16.054Z,1724973496.054 [MassServo](DEBUG): Initializing EZServoServo.
2024-08-29T23:18:16.061Z,1724973496.061 [MassServo](DEBUG): Initializing MassServo.
2024-08-29T23:18:16.062Z,1724973496.062 [RudderServo](DEBUG): Initializing EZServoServo.
2024-08-29T23:18:16.093Z,1724973496.093 [RudderServo](DEBUG): Initializing RudderServo.
2024-08-29T23:18:16.094Z,1724973496.094 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-08-29T23:18:16.113Z,1724973496.113 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-08-29T23:18:16.269Z,1724973496.269 [DATMMP](INFO): Starting
2024-08-29T23:18:16.521Z,1724973496.521 [DATMMP](INFO): Starting
2024-08-29T23:18:16.773Z,1724973496.773 [DATMMP](INFO): Starting
2024-08-29T23:18:17.025Z,1724973497.025 [DATMMP](INFO): Starting
2024-08-29T23:18:17.278Z,1724973497.278 [DATMMP](INFO): Starting
2024-08-29T23:18:17.349Z,1724973497.349 [WetLabsBB2FL](INFO): Powering down
2024-08-29T23:18:17.529Z,1724973497.529 [DATMMP](INFO): Starting
2024-08-29T23:18:17.781Z,1724973497.781 [DATMMP](INFO): Starting
2024-08-29T23:18:17.936Z,1724973497.936 [Sonardyne_Nano](ERROR): Failed to get valid response or reached max queue size, flushing UART
2024-08-29T23:18:18.033Z,1724973498.033 [DATMMP](INFO): Starting
2024-08-29T23:18:18.285Z,1724973498.285 [DATMMP](INFO): Starting
2024-08-29T23:18:18.537Z,1724973498.537 [DATMMP](INFO): Starting
2024-08-29T23:18:18.790Z,1724973498.790 [DATMMP](INFO): Starting
2024-08-29T23:18:19.041Z,1724973499.041 [DATMMP](INFO): Starting
2024-08-29T23:18:19.222Z,1724973499.222 [Sonardyne_Nano](IMPORTANT): Found beacon with acoustic ID 2213
2024-08-29T23:18:19.293Z,1724973499.293 [DATMMP](INFO): Starting
2024-08-29T23:18:19.545Z,1724973499.545 [DATMMP](INFO): Starting
2024-08-29T23:18:19.797Z,1724973499.797 [DATMMP](INFO): Starting
2024-08-29T23:18:20.050Z,1724973500.050 [DATMMP](INFO): Starting
2024-08-29T23:18:20.301Z,1724973500.301 [DATMMP](INFO): Starting
2024-08-29T23:18:20.553Z,1724973500.553 [DATMMP](INFO): Starting
2024-08-29T23:18:20.805Z,1724973500.805 [DATMMP](INFO): Starting
2024-08-29T23:18:21.057Z,1724973501.057 [DATMMP](INFO): Starting
2024-08-29T23:18:21.309Z,1724973501.309 [DATMMP](INFO): Starting
2024-08-29T23:18:21.561Z,1724973501.561 [DATMMP](INFO): Starting
2024-08-29T23:18:21.813Z,1724973501.813 [DATMMP](INFO): Starting
2024-08-29T23:18:22.066Z,1724973502.066 [DATMMP](INFO): Starting
2024-08-29T23:18:22.183Z,1724973502.183 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US5CA50M.000
2024-08-29T23:18:22.317Z,1724973502.317 [DATMMP](INFO): Starting
2024-08-29T23:18:22.569Z,1724973502.569 [DATMMP](INFO): Starting
2024-08-29T23:18:22.821Z,1724973502.821 [DATMMP](INFO): Starting
2024-08-29T23:18:23.073Z,1724973503.073 [DATMMP](INFO): Starting
2024-08-29T23:18:23.329Z,1724973503.329 [DATMMP](INFO): Starting
2024-08-29T23:18:23.581Z,1724973503.581 [DATMMP](INFO): Starting
2024-08-29T23:18:23.833Z,1724973503.833 [DATMMP](INFO): Starting
2024-08-29T23:18:24.085Z,1724973504.085 [DATMMP](INFO): Starting
2024-08-29T23:18:24.337Z,1724973504.337 [DATMMP](INFO): Starting
2024-08-29T23:18:24.589Z,1724973504.589 [DATMMP](INFO): Starting
2024-08-29T23:18:24.841Z,1724973504.841 [DATMMP](INFO): Starting
2024-08-29T23:18:25.093Z,1724973505.093 [DATMMP](INFO): Starting
2024-08-29T23:18:25.345Z,1724973505.345 [DATMMP](INFO): Starting
2024-08-29T23:18:25.597Z,1724973505.597 [DATMMP](INFO): Starting
2024-08-29T23:18:25.849Z,1724973505.849 [DATMMP](INFO): Starting
2024-08-29T23:18:26.101Z,1724973506.101 [DATMMP](INFO): Starting
2024-08-29T23:18:26.353Z,1724973506.353 [DATMMP](INFO): Starting
2024-08-29T23:18:26.606Z,1724973506.606 [DATMMP](INFO): Starting
2024-08-29T23:18:26.857Z,1724973506.857 [DATMMP](INFO): Starting
2024-08-29T23:18:27.109Z,1724973507.109 [DATMMP](INFO): Starting
2024-08-29T23:18:27.361Z,1724973507.361 [DATMMP](INFO): Starting
2024-08-29T23:18:27.362Z,1724973507.362 [DATMMP](INFO): DAT read:
2024-08-29T23:18:27.363Z,1724973507.363 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series
2024-08-29T23:18:27.613Z,1724973507.613 [DATMMP](INFO): Starting
2024-08-29T23:18:27.865Z,1724973507.865 [DATMMP](INFO): Starting
2024-08-29T23:18:28.117Z,1724973508.117 [DATMMP](INFO): Starting
2024-08-29T23:18:28.370Z,1724973508.370 [DATMMP](INFO): Starting
2024-08-29T23:18:28.621Z,1724973508.621 [DATMMP](INFO): Starting
2024-08-29T23:18:28.873Z,1724973508.873 [DATMMP](INFO): Starting
2024-08-29T23:18:28.874Z,1724973508.874 [DATMMP](INFO): DAT read: MF Frequency Band
2024-08-29T23:18:28.875Z,1724973508.875 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0
2024-08-29T23:18:28.876Z,1724973508.876 [DATMMP](INFO): DAT read: Jul 29 2000 23:18:23
2024-08-29T23:18:29.125Z,1724973509.125 [DATMMP](INFO): Starting
2024-08-29T23:18:29.377Z,1724973509.377 [DATMMP](INFO): Starting
2024-08-29T23:18:29.629Z,1724973509.629 [DATMMP](INFO): Starting
2024-08-29T23:18:29.881Z,1724973509.881 [DATMMP](INFO): Starting
2024-08-29T23:18:30.133Z,1724973510.133 [DATMMP](INFO): Starting
2024-08-29T23:18:30.134Z,1724973510.134 [DATMMP](INFO): DAT read: Features enabled [Bearing]
2024-08-29T23:18:30.135Z,1724973510.135 [DATMMP](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC
2024-08-29T23:18:30.135Z,1724973510.135 [DATMMP](INFO): commRate: 1200
2024-08-29T23:18:30.385Z,1724973510.385 [DATMMP](INFO): Starting
2024-08-29T23:18:30.637Z,1724973510.637 [DATMMP](INFO): Starting
2024-08-29T23:18:30.889Z,1724973510.889 [DATMMP](INFO): Starting
2024-08-29T23:18:31.141Z,1724973511.141 [DATMMP](INFO): Starting
2024-08-29T23:18:31.393Z,1724973511.393 [DATMMP](INFO): Starting
2024-08-29T23:18:31.645Z,1724973511.645 [DATMMP](INFO): Starting
2024-08-29T23:18:31.897Z,1724973511.897 [DATMMP](INFO): Starting
2024-08-29T23:18:32.149Z,1724973512.149 [DATMMP](INFO): Starting
2024-08-29T23:18:32.201Z,1724973512.201 [DATMMP](INFO): entering command mode
2024-08-29T23:18:32.401Z,1724973512.401 [DATMMP](INFO): Starting
2024-08-29T23:18:32.402Z,1724973512.402 [DATMMP](INFO): DAT read:
2024-08-29T23:18:32.402Z,1724973512.402 [DATMMP](INFO): DAT read: user:1>
2024-08-29T23:18:32.403Z,1724973512.403 [DATMMP](DEBUG): read user prompt 1: user:1>
2024-08-29T23:18:32.403Z,1724973512.403 [DATMMP](INFO): entering MMP mode
2024-08-29T23:18:32.653Z,1724973512.653 [DATMMP](INFO): Starting
2024-08-29T23:18:32.654Z,1724973512.654 [DATMMP](INFO): GSXN notify for xid: 0
2024-08-29T23:18:32.656Z,1724973512.656 [DATMMP](INFO): status rx: x1
2024-08-29T23:18:32.656Z,1724973512.656 [DATMMP](INFO): MMP status: 1: started
2024-08-29T23:18:32.656Z,1724973512.656 [DATMMP](INFO): Received message type: status
2024-08-29T23:18:32.656Z,1724973512.656 [DATMMP](INFO): Handled
2024-08-29T23:18:32.905Z,1724973512.905 [DATMMP](INFO): Starting
2024-08-29T23:18:32.906Z,1724973512.906 [DATMMP](INFO): Sent Tx Power Config 8
2024-08-29T23:18:32.907Z,1724973512.907 [DATMMP](INFO): Setting local address: 5
2024-08-29T23:18:32.909Z,1724973512.909 [DATMMP](INFO): Setting time to: 23:18:32 And date to:8/29/2024
2024-08-29T23:18:33.157Z,1724973513.157 [DATMMP](INFO): Starting
2024-08-29T23:18:33.158Z,1724973513.158 [DATMMP](INFO): GSXN notify for xid: 0
2024-08-29T23:18:33.158Z,1724973513.158 [DATMMP](INFO): mdmpower rx: x8 x0 x5 x0
2024-08-29T23:18:33.159Z,1724973513.159 [DATMMP](INFO): Received message type: mdmpower
2024-08-29T23:18:33.159Z,1724973513.159 [DATMMP](INFO): Handled
2024-08-29T23:18:33.409Z,1724973513.409 [DATMMP](INFO): Starting
2024-08-29T23:18:33.409Z,1724973513.409 [DATMMP](INFO): GSXN notify for xid: 10
2024-08-29T23:18:33.410Z,1724973513.410 [DATMMP](INFO): sreg_txpower rx: x8
2024-08-29T23:18:33.410Z,1724973513.410 [DATMMP](INFO): Received message type: sreg_txpower
2024-08-29T23:18:33.410Z,1724973513.410 [DATMMP](INFO): Match for : sreg_txpower
2024-08-29T23:18:33.411Z,1724973513.411 [DATMMP](INFO): ACK
2024-08-29T23:18:33.661Z,1724973513.661 [DATMMP](INFO): Starting
2024-08-29T23:18:33.662Z,1724973513.662 [DATMMP](INFO): GSXN notify for xid: 0
2024-08-29T23:18:33.663Z,1724973513.663 [DATMMP](INFO): mdmlocal rx: x5 x0 x0 x0
2024-08-29T23:18:33.663Z,1724973513.663 [DATMMP](INFO): Received message type: mdmlocal
2024-08-29T23:18:33.663Z,1724973513.663 [DATMMP](INFO): Handled
2024-08-29T23:18:33.913Z,1724973513.913 [DATMMP](INFO): Starting
2024-08-29T23:18:33.914Z,1724973513.914 [DATMMP](INFO): GSXN notify for xid: 11
2024-08-29T23:18:33.914Z,1724973513.914 [DATMMP](INFO): sreg_locaddr rx: x5
2024-08-29T23:18:33.914Z,1724973513.914 [DATMMP](INFO): Received message type: sreg_locaddr
2024-08-29T23:18:33.914Z,1724973513.914 [DATMMP](INFO): Match for : sreg_locaddr
2024-08-29T23:18:33.915Z,1724973513.915 [DATMMP](INFO): ACK
2024-08-29T23:18:34.165Z,1724973514.165 [DATMMP](INFO): Starting
2024-08-29T23:18:34.166Z,1724973514.166 [DATMMP](INFO): GSXN notify for xid: 12
2024-08-29T23:18:34.167Z,1724973514.167 [DATMMP](INFO): timedate rx: x0 x17 x12 x20 x7 x1D x7C x0
2024-08-29T23:18:34.167Z,1724973514.167 [DATMMP](INFO): Received message type: timedate
2024-08-29T23:18:34.167Z,1724973514.167 [DATMMP](INFO): Match for : timedate
2024-08-29T23:18:34.167Z,1724973514.167 [DATMMP](INFO): ACK
2024-08-29T23:18:34.417Z,1724973514.417 [DATMMP](INFO): Starting
2024-08-29T23:18:34.418Z,1724973514.418 [DATMMP](INFO): GSXN notify for xid: 0
2024-08-29T23:18:34.418Z,1724973514.418 [DATMMP](INFO): sys_verb rx: x0 x0 x0 x0
2024-08-29T23:18:34.419Z,1724973514.419 [DATMMP](INFO): Received message type: sys_verb
2024-08-29T23:18:34.419Z,1724973514.419 [DATMMP](INFO): Handled
2024-08-29T23:18:34.669Z,1724973514.669 [DATMMP](INFO): Starting
2024-08-29T23:18:34.670Z,1724973514.670 [DATMMP](INFO): GSXN notify for xid: 13
2024-08-29T23:18:34.670Z,1724973514.670 [DATMMP](INFO): sreg_verbosity rx: x0
2024-08-29T23:18:34.670Z,1724973514.670 [DATMMP](INFO): Received message type: sreg_verbosity
2024-08-29T23:18:34.671Z,1724973514.671 [DATMMP](INFO): Match for : sreg_verbosity
2024-08-29T23:18:34.671Z,1724973514.671 [DATMMP](INFO): ACK
2024-08-29T23:18:34.921Z,1724973514.921 [DATMMP](INFO): Starting
2024-08-29T23:18:34.922Z,1724973514.922 [DATMMP](INFO): GSXN notify for xid: 14
2024-08-29T23:18:34.922Z,1724973514.922 [DATMMP](INFO): version rx: x2 x5
2024-08-29T23:18:34.923Z,1724973514.923 [DATMMP](INFO): DatMMPVersion: 2.5
2024-08-29T23:18:34.923Z,1724973514.923 [DATMMP](INFO): Received message type: version
2024-08-29T23:18:34.923Z,1724973514.923 [DATMMP](INFO): Match for : version
2024-08-29T23:18:34.923Z,1724973514.923 [DATMMP](INFO): ACK
2024-08-29T23:18:34.923Z,1724973514.923 [DATMMP](INFO): in MMP mode: config complete going to runnable
2024-08-29T23:18:40.741Z,1724973520.741 [NavChartDb](INFO): # of records loaded: 5000
2024-08-29T23:18:44.611Z,1724973524.611 [NAL9602](INFO): Powering up NAL9602
2024-08-29T23:18:48.878Z,1724973528.878 [NavChartDb](INFO): # of records loaded: 10000
2024-08-29T23:18:49.290Z,1724973529.290 [DATMMP](INFO): GSXN notify for xid: 0
2024-08-29T23:18:49.291Z,1724973529.291 [DATMMP](INFO): timesync rx: x0 x1 x1 x0
2024-08-29T23:18:49.291Z,1724973529.291 [DATMMP](INFO): Received message type: timesync
2024-08-29T23:18:49.291Z,1724973529.291 [DATMMP](INFO): Handled
2024-08-29T23:18:55.515Z,1724973535.515 [NAL9602](INFO): NAL9602 initialized
2024-08-29T23:18:56.517Z,1724973536.517 [NavChartDb](INFO): # of records loaded: 15000
2024-08-29T23:18:59.126Z,1724973539.126 [DATMMP](INFO): GSXN notify for xid: 0
2024-08-29T23:18:59.127Z,1724973539.127 [DATMMP](INFO): timesync rx: x1 x0 x1 x0
2024-08-29T23:18:59.127Z,1724973539.127 [DATMMP](INFO): Received message type: timesync
2024-08-29T23:18:59.127Z,1724973539.127 [DATMMP](INFO): Handled
2024-08-29T23:19:04.584Z,1724973544.584 [NavChartDb](INFO): # of records loaded: 20000
2024-08-29T23:19:11.956Z,1724973551.956 [NavChartDb](INFO): # of records loaded: 25000
2024-08-29T23:19:19.431Z,1724973559.431 [NavChartDb](INFO): # of records loaded: 30000
2024-08-29T23:19:28.593Z,1724973568.593 [NavChartDb](INFO): # of records loaded: 35000
2024-08-29T23:19:38.590Z,1724973578.590 [NavChartDb](INFO): # of records loaded: 40000
2024-08-29T23:19:43.639Z,1724973583.639 [SBIT](IMPORTANT): Beginning Startup BIT
2024-08-29T23:19:43.652Z,1724973583.652 [CBIT](IMPORTANT): Beginning ground fault scan
2024-08-29T23:19:46.755Z,1724973586.755 [NavChartDb](INFO): # of records loaded: 45000
2024-08-29T23:19:54.577Z,1724973594.577 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.016796
CHAN A1 (24V): 0.002861
CHAN A2 (12V): -0.000341
CHAN A3 (5V): -0.009817
CHAN B0 (3.3V): -0.007850
CHAN B1 (3.15aV): -0.006778
CHAN B2 (3.15bV): -0.005988
CHAN B3 (GND): -0.009290
OPEN: 0.006981
Full Scale: +/- 1 mA
2024-08-29T23:19:55.279Z,1724973595.279 [NavChartDb](INFO): # of records loaded: 50000
2024-08-29T23:19:56.121Z,1724973596.121 [NAL9602](INFO): SBD MO Status=2, MOMSN=15967, MT Status=2, MTMSN=0
2024-08-29T23:19:56.121Z,1724973596.121 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-08-29T23:20:06.673Z,1724973606.673 [NavChartDb](INFO): # of records loaded: 55000
2024-08-29T23:20:08.443Z,1724973608.443 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US5CA50M.000
2024-08-29T23:20:13.345Z,1724973613.345 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US5CA50M.000
2024-08-29T23:20:18.108Z,1724973618.108 [NavChartDb](INFO): # of records loaded: 60000
2024-08-29T23:20:30.515Z,1724973630.515 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004096
2024-08-29T23:20:33.094Z,1724973633.094 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US5CA50M.000
2024-08-29T23:20:33.155Z,1724973633.155 [NavChartDb](INFO): # of records loaded: 62052
2024-08-29T23:20:33.160Z,1724973633.160 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US5CA50M.000
2024-08-29T23:20:33.197Z,1724973633.197 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US3CA52M.000
2024-08-29T23:20:36.663Z,1724973636.663 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US3CA52M.000
2024-08-29T23:20:37.788Z,1724973637.788 [SBIT](IMPORTANT): SBIT PASSED
2024-08-29T23:20:37.793Z,1724973637.793 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2024-08-29T23:20:37.794Z,1724973637.794 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=31 count;
2024-08-29T23:20:37.794Z,1724973637.794 [SBIT](IMPORTANT): CBIT.gf24Offset=180 microampere;
2024-08-29T23:20:37.795Z,1724973637.795 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;
2024-08-29T23:20:37.795Z,1724973637.795 [SBIT](IMPORTANT): DATMMP.loadAtStartup=1 bool;
2024-08-29T23:20:37.795Z,1724973637.795 [SBIT](IMPORTANT): DATMMP.simulateHardware=0 bool;
2024-08-29T23:20:37.795Z,1724973637.795 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=3 minute;
2024-08-29T23:20:37.795Z,1724973637.795 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=200 cubic_centimeter;
2024-08-29T23:20:37.795Z,1724973637.795 [SBIT](IMPORTANT): VerticalControl.massDefault=1.7 centimeter;
2024-08-29T23:20:38.175Z,1724973638.175 [MissionManager](IMPORTANT): Started mission Startup
2024-08-29T23:20:38.175Z,1724973638.175 [Startup] Running Loop=1
2024-08-29T23:20:38.176Z,1724973638.176 [Startup](DEBUG): Aggregate::initialize Startup
2024-08-29T23:20:38.176Z,1724973638.176 [Startup:A.GoToSurface] Running Loop=1
2024-08-29T23:20:38.176Z,1724973638.176 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-08-29T23:20:38.176Z,1724973638.176 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-08-29T23:20:38.201Z,1724973638.201 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-08-29T23:20:38.201Z,1724973638.201 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-08-29T23:20:38.202Z,1724973638.202 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-08-29T23:20:38.202Z,1724973638.202 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-08-29T23:20:38.202Z,1724973638.202 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-08-29T23:20:38.213Z,1724973638.213 [Startup:StartupSatComms] Running Loop=1
2024-08-29T23:20:38.213Z,1724973638.213 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2024-08-29T23:20:38.213Z,1724973638.213 [Startup:StartupSatComms:A] Running Loop=1
2024-08-29T23:20:38.562Z,1724973638.562 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2024-08-29T23:20:47.967Z,1724973647.967 [NavChartDb](INFO): # of records loaded: 5000
2024-08-29T23:20:57.158Z,1724973657.158 [BPC1](INFO): Calculating totals. Valid battery stick count: 27. Valid reserve battery stick count: 4.
2024-08-29T23:20:57.193Z,1724973657.193 [BPC1](INFO): Received data from all battery sticks.
2024-08-29T23:20:59.918Z,1724973659.918 [NavChartDb](INFO): # of records loaded: 10000
2024-08-29T23:21:03.365Z,1724973663.365 [NavChartDb](INFO): # of records loaded: 15000
2024-08-29T23:21:06.372Z,1724973666.372 [NavChartDb](INFO): # of records loaded: 20000
2024-08-29T23:21:11.208Z,1724973671.208 [NavChartDb](INFO): # of records loaded: 25000
2024-08-29T23:21:15.717Z,1724973675.717 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2024-08-29T23:21:15.717Z,1724973675.717 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2024-08-29T23:21:15.769Z,1724973675.769 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2024-08-29T23:21:15.924Z,1724973675.924 [NavChartDb](INFO): # of records loaded: 30000
2024-08-29T23:21:16.145Z,1724973676.145 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2024-08-29T23:21:16.149Z,1724973676.149 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2024-08-29T23:21:18.588Z,1724973678.588 [NavChartDb](INFO): # of records loaded: 35000
2024-08-29T23:21:22.189Z,1724973682.189 [NAL9602](INFO): SBD MO Status=0, MOMSN=15967, MT Status=0, MTMSN=0
2024-08-29T23:21:22.190Z,1724973682.190 [NAL9602](INFO): No messages in MT queue
2024-08-29T23:21:23.203Z,1724973683.203 [NavChartDb](INFO): # of records loaded: 40000
2024-08-29T23:21:29.453Z,1724973689.453 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232126.00,A,3648.16337,N,12147.25439,W,1.419,90.44,290824,,,A*4A
2024-08-29T23:21:29.460Z,1724973689.460 [NAL9602](INFO): GPS fix at 20240829T232126: (36.802723, -121.787573)
2024-08-29T23:21:29.482Z,1724973689.482 [Startup:StartupSatComms:A] Stopped
2024-08-29T23:21:29.482Z,1724973689.482 [Startup:StartupSatComms:B] Running Loop=1
2024-08-29T23:21:29.811Z,1724973689.811 [NavChartDb](INFO): # of records loaded: 45000
2024-08-29T23:21:29.930Z,1724973689.930 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-08-29T23:21:38.917Z,1724973698.917 [NavChartDb](INFO): # of records loaded: 50000
2024-08-29T23:21:45.579Z,1724973705.579 [NavChartDb](INFO): # of records loaded: 55000
2024-08-29T23:21:50.748Z,1724973710.748 [NavChartDb](INFO): # of records loaded: 60000
2024-08-29T23:21:52.061Z,1724973712.061 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:21:55.025Z,1724973715.025 [NavChartDb](INFO): # of records loaded: 65000
2024-08-29T23:22:01.207Z,1724973721.207 [NavChartDb](INFO): # of records loaded: 70000
2024-08-29T23:22:02.181Z,1724973722.181 [NAL9602](INFO): Not Powering down - fast GPS
2024-08-29T23:22:07.867Z,1724973727.867 [NavChartDb](INFO): # of records loaded: 75000
2024-08-29T23:22:15.283Z,1724973735.283 [NavChartDb](INFO): # of records loaded: 80000
2024-08-29T23:22:19.898Z,1724973739.898 [NavChartDb](INFO): # of records loaded: 85000
2024-08-29T23:22:23.194Z,1724973743.194 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:22:26.979Z,1724973746.979 [NavChartDb](INFO): # of records loaded: 90000
2024-08-29T23:22:29.691Z,1724973749.691 [Startup:StartupSatComms:B](INFO): Timed out from 2024-08-29T23:21:29.5Z
2024-08-29T23:22:29.691Z,1724973749.691 [Startup:StartupSatComms:B] Stopped
2024-08-29T23:22:29.691Z,1724973749.691 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2024-08-29T23:22:29.691Z,1724973749.691 [Startup:StartupSatComms] Stopped
2024-08-29T23:22:29.691Z,1724973749.691 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2024-08-29T23:22:29.692Z,1724973749.692 [Startup](INFO): Completed Startup
2024-08-29T23:22:29.692Z,1724973749.692 [MissionManager](INFO): Startup is completed.
2024-08-29T23:22:29.693Z,1724973749.693 [MissionManager](INFO): Uninitializing Mission Startup
2024-08-29T23:22:29.697Z,1724973749.697 [Startup] Stopped
2024-08-29T23:22:29.697Z,1724973749.697 [Startup](DEBUG): Aggregate::uninitialize Startup
2024-08-29T23:22:29.697Z,1724973749.697 [Startup:A.GoToSurface] Stopped
2024-08-29T23:22:29.697Z,1724973749.697 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-08-29T23:22:30.086Z,1724973750.086 [MissionManager](IMPORTANT): Started mission Default
2024-08-29T23:22:30.086Z,1724973750.086 [Default] Running Loop=1
2024-08-29T23:22:30.086Z,1724973750.086 [Default](DEBUG): Aggregate::initialize Default
2024-08-29T23:22:30.087Z,1724973750.087 [Default:B.GoToSurface] Running Loop=1
2024-08-29T23:22:30.087Z,1724973750.087 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-08-29T23:22:30.087Z,1724973750.087 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-08-29T23:22:30.087Z,1724973750.087 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-08-29T23:22:30.087Z,1724973750.087 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-08-29T23:22:30.088Z,1724973750.088 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-08-29T23:22:30.088Z,1724973750.088 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-08-29T23:22:30.088Z,1724973750.088 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-08-29T23:22:30.089Z,1724973750.089 [Default:A.Wait] Running Loop=1
2024-08-29T23:22:30.109Z,1724973750.109 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-08-29T23:22:33.238Z,1724973753.238 [NavChartDb](INFO): # of records loaded: 95000
2024-08-29T23:22:41.062Z,1724973761.062 [NavChartDb](INFO): # of records loaded: 100000
2024-08-29T23:22:43.419Z,1724973763.419 [Default:A.Wait](INFO): Done Waiting.
2024-08-29T23:22:43.419Z,1724973763.419 [Default:A.Wait] Stopped
2024-08-29T23:22:43.419Z,1724973763.419 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-08-29T23:22:43.811Z,1724973763.811 [Default:CheckIn] Running Loop=1
2024-08-29T23:22:43.811Z,1724973763.811 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-08-29T23:22:43.811Z,1724973763.811 [Default:CheckIn:Read_GPS] Running Loop=1
2024-08-29T23:22:44.222Z,1724973764.222 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2024-08-29T23:22:45.812Z,1724973765.812 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232242.00,A,3648.14163,N,12147.22832,W,0.311,55.77,290824,,,A*4D
2024-08-29T23:22:45.815Z,1724973765.815 [NAL9602](INFO): GPS fix at 20240829T232242: (36.802360, -121.787139)
2024-08-29T23:22:45.860Z,1724973765.860 [Default:CheckIn:Read_GPS] Stopped
2024-08-29T23:22:45.860Z,1724973765.860 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-08-29T23:22:46.253Z,1724973766.253 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-08-29T23:22:49.334Z,1724973769.334 [NavChartDb](INFO): # of records loaded: 105000
2024-08-29T23:22:54.333Z,1724973774.333 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:22:57.652Z,1724973777.652 [NavChartDb](INFO): # of records loaded: 110000
2024-08-29T23:23:04.940Z,1724973784.940 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US3CA52M.000
2024-08-29T23:23:05.998Z,1724973785.998 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US3CA52M.000
2024-08-29T23:23:08.457Z,1724973788.457 [NavChartDb](INFO): # of records loaded: 115000
2024-08-29T23:23:16.350Z,1724973796.350 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US3CA52M.000
2024-08-29T23:23:16.436Z,1724973796.436 [NavChartDb](INFO): # of records loaded: 117310
2024-08-29T23:23:16.440Z,1724973796.440 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US3CA52M.000
2024-08-29T23:23:16.453Z,1724973796.453 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US2WC11M.000
2024-08-29T23:23:18.743Z,1724973798.743 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US2WC11M.000
2024-08-29T23:23:25.462Z,1724973805.462 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:23:26.774Z,1724973806.774 [NavChartDb](INFO): # of records loaded: 5000
2024-08-29T23:23:31.486Z,1724973811.486 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.975479
2024-08-29T23:23:32.324Z,1724973812.324 [NAL9602](INFO): SBD MO Status=0, MOMSN=15968, MT Status=0, MTMSN=0
2024-08-29T23:23:32.324Z,1724973812.324 [NAL9602](INFO): No messages in MT queue
2024-08-29T23:23:33.544Z,1724973813.544 [NavChartDb](INFO): # of records loaded: 10000
2024-08-29T23:23:41.770Z,1724973821.770 [NavChartDb](INFO): # of records loaded: 15000
2024-08-29T23:23:50.312Z,1724973830.312 [NAL9602](INFO): SBD MO Status=1, MOMSN=15969, MT Status=0, MTMSN=0
2024-08-29T23:23:50.361Z,1724973830.361 [NAL9602](INFO): Sent 40 bytes from file Logs/20240829T230518/Courier0013.lzma
2024-08-29T23:23:50.362Z,1724973830.362 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:23:52.656Z,1724973832.656 [NavChartDb](INFO): # of records loaded: 20000
2024-08-29T23:24:00.625Z,1724973840.625 [NAL9602](INFO): SBD MO Status=1, MOMSN=15970, MT Status=0, MTMSN=0
2024-08-29T23:24:00.674Z,1724973840.674 [NAL9602](INFO): Sent 315 bytes from file Logs/20240829T231804/Courier0000.lzma
2024-08-29T23:24:00.674Z,1724973840.674 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:24:01.133Z,1724973841.133 [NavChartDb](INFO): # of records loaded: 25000
2024-08-29T23:24:02.609Z,1724973842.609 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:24:10.481Z,1724973850.481 [NavChartDb](INFO): # of records loaded: 30000
2024-08-29T23:24:16.592Z,1724973856.592 [NAL9602](INFO): SBD MO Status=1, MOMSN=15971, MT Status=0, MTMSN=0
2024-08-29T23:24:16.645Z,1724973856.645 [NAL9602](INFO): Sent 77 bytes from file Logs/20240829T231804/Courier0004.lzma
2024-08-29T23:24:16.646Z,1724973856.646 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:24:21.399Z,1724973861.399 [NavChartDb](INFO): # of records loaded: 35000
2024-08-29T23:24:26.407Z,1724973866.407 [NAL9602](INFO): SBD MO Status=1, MOMSN=15972, MT Status=0, MTMSN=0
2024-08-29T23:24:26.457Z,1724973866.457 [NAL9602](INFO): Sent 114 bytes from file Logs/20240829T230518/Express0014.lzma
2024-08-29T23:24:26.458Z,1724973866.458 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:24:32.706Z,1724973872.706 [NavChartDb](INFO): # of records loaded: 40000
2024-08-29T23:24:33.749Z,1724973873.749 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:24:35.786Z,1724973875.786 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US2WC11M.000
2024-08-29T23:24:36.633Z,1724973876.633 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US2WC11M.000
2024-08-29T23:24:43.745Z,1724973883.745 [NAL9602](INFO): SBD MO Status=1, MOMSN=15973, MT Status=0, MTMSN=0
2024-08-29T23:24:43.805Z,1724973883.805 [NAL9602](INFO): Sent 332 bytes from file Logs/20240829T231804/Express0001.lzma
2024-08-29T23:24:43.806Z,1724973883.806 [NAL9602](INFO): Packets left to send: 3
2024-08-29T23:24:49.429Z,1724973889.429 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002674
2024-08-29T23:24:53.372Z,1724973893.372 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US2WC11M.000
2024-08-29T23:24:53.496Z,1724973893.496 [NavChartDb](INFO): # of records loaded: 44941
2024-08-29T23:24:53.501Z,1724973893.501 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US2WC11M.000
2024-08-29T23:24:53.502Z,1724973893.502 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US1WC07M.000
2024-08-29T23:24:54.283Z,1724973894.283 [NAL9602](INFO): SBD MO Status=1, MOMSN=15974, MT Status=0, MTMSN=0
2024-08-29T23:24:54.340Z,1724973894.340 [NAL9602](INFO): Sent 332 bytes from file Logs/20240829T231804/Express0001.lzma
2024-08-29T23:24:54.340Z,1724973894.340 [NAL9602](INFO): Packets left to send: 2
2024-08-29T23:24:54.388Z,1724973894.388 [Default:CheckIn:Read_Iridium] Stopped
2024-08-29T23:24:54.388Z,1724973894.388 [Default:CheckIn:C.Wait] Running Loop=1
2024-08-29T23:24:54.389Z,1724973894.389 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-08-29T23:24:58.237Z,1724973898.237 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US1WC07M.000
2024-08-29T23:25:04.858Z,1724973904.858 [DataOverHttps](INFO): Sending 1071 bytes from file Logs/20240829T231804/Express0001.lzma
2024-08-29T23:25:06.863Z,1724973906.863 [DataOverHttps](INFO): Moved sent file to Logs/20240829T231804/Express0001.lzma.bak
2024-08-29T23:25:06.863Z,1724973906.863 [DataOverHttps](INFO): SBD MOMSN=23095642
2024-08-29T23:25:16.680Z,1724973916.680 [NavChartDb](INFO): # of records loaded: 5000
2024-08-29T23:25:24.970Z,1724973924.970 [NAL9602](INFO): Not Powering down - fast GPS
2024-08-29T23:25:27.260Z,1724973927.260 [NavChartDb](INFO): # of records loaded: 10000
2024-08-29T23:25:37.301Z,1724973937.301 [NavChartDb](INFO): # of records loaded: 15000
2024-08-29T23:25:50.362Z,1724973950.362 [NavChartDb](INFO): # of records loaded: 20000
2024-08-29T23:25:52.681Z,1724973952.681 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US1WC07M.000
2024-08-29T23:25:54.239Z,1724973954.239 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US1WC07M.000
2024-08-29T23:26:16.440Z,1724973976.440 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US1WC07M.000
2024-08-29T23:26:16.813Z,1724973976.813 [NavChartDb](INFO): # of records loaded: 24439
2024-08-29T23:26:16.822Z,1724973976.822 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US1WC07M.000
2024-08-29T23:26:18.443Z,1724973978.443 [NavChartDb](INFO): Creating index for soundings
2024-08-29T23:26:22.852Z,1724973982.852 [NavChartDb](INFO): Creating index for 0p0
2024-08-29T23:26:24.340Z,1724973984.340 [NavChartDb](INFO): Creating index for 1p8
2024-08-29T23:26:24.535Z,1724973984.535 [NavChartDb](INFO): Creating index for 3p6
2024-08-29T23:26:25.304Z,1724973985.304 [NavChartDb](INFO): Creating index for 5p4
2024-08-29T23:26:25.736Z,1724973985.736 [NavChartDb](INFO): Creating index for 9p1
2024-08-29T23:26:25.777Z,1724973985.777 [NavChartDb](INFO): Creating index for 10p9
2024-08-29T23:26:26.645Z,1724973986.645 [NavChartDb](INFO): Creating index for 18p2
2024-08-29T23:26:27.899Z,1724973987.899 [NavChartDb](INFO): Creating index for 36p5
2024-08-29T23:26:29.520Z,1724973989.520 [NavChartDb](INFO): Creating index for 54p8
2024-08-29T23:26:30.965Z,1724973990.965 [NavChartDb](INFO): Creating index for 73p1
2024-08-29T23:26:33.162Z,1724973993.162 [NavChartDb](INFO): Creating index for 91p4
2024-08-29T23:26:36.850Z,1724973996.850 [NavChartDb](INFO): Creating index for 182p8
2024-08-29T23:26:40.908Z,1724974000.908 [NavChartDb](INFO): Creating index for 365p7
2024-08-29T23:26:43.548Z,1724974003.548 [NavChartDb](INFO): Creating index for 548p6
2024-08-29T23:26:46.407Z,1724974006.407 [NavChartDb](INFO): Creating index for 731p5
2024-08-29T23:26:50.059Z,1724974010.059 [NavChartDb](INFO): Creating index for 914p4
2024-08-29T23:26:52.027Z,1724974012.027 [NavChartDb](INFO): Creating index for 1097p2
2024-08-29T23:26:53.123Z,1724974013.123 [NavChartDb](INFO): Creating index for 1280p1
2024-08-29T23:26:54.097Z,1724974014.097 [NavChartDb](INFO): Creating index for 1463p0
2024-08-29T23:26:54.901Z,1724974014.901 [NavChartDb](INFO): Creating index for 1645p9
2024-08-29T23:26:57.406Z,1724974017.406 [NavChartDb](INFO): Creating index for 1828p8
2024-08-29T23:26:58.861Z,1724974018.861 [NavChartDb](INFO): Creating index for 2011p6
2024-08-29T23:26:59.363Z,1724974019.363 [NavChartDb](INFO): Creating index for 2194p5
2024-08-29T23:26:59.816Z,1724974019.816 [NavChartDb](INFO): Creating index for 2377p4
2024-08-29T23:27:00.274Z,1724974020.274 [NavChartDb](INFO): Creating index for 2560p3
2024-08-29T23:27:01.310Z,1724974021.310 [NavChartDb](INFO): Creating index for 2743p2
2024-08-29T23:27:02.078Z,1724974022.078 [NavChartDb](INFO): Creating index for 2926p0
2024-08-29T23:27:02.680Z,1724974022.680 [NavChartDb](INFO): Creating index for 3108p9
2024-08-29T23:27:04.441Z,1724974024.441 [NavChartDb](INFO): Creating index for 3291p8
2024-08-29T23:27:05.819Z,1724974025.819 [NavChartDb](INFO): Creating index for 3474p7
2024-08-29T23:27:11.416Z,1724974031.416 [NavChartDb](INFO): Creating index for 3657p6
2024-08-29T23:29:54.900Z,1724974194.900 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-08-29T23:29:54.900Z,1724974194.900 [Default:CheckIn:C.Wait] Stopped
2024-08-29T23:29:54.900Z,1724974194.900 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-08-29T23:29:54.900Z,1724974194.900 [Default:CheckIn:D] Running Loop=1
2024-08-29T23:29:55.298Z,1724974195.298 [Default:CheckIn:D] Stopped
2024-08-29T23:29:55.298Z,1724974195.298 [Default:CheckIn:E] Running Loop=1
2024-08-29T23:29:55.691Z,1724974195.691 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.420197 min
2024-08-29T23:29:55.691Z,1724974195.691 [Default:CheckIn:E] Stopped
2024-08-29T23:29:55.691Z,1724974195.691 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-08-29T23:29:55.691Z,1724974195.691 [Default:CheckIn] Stopped
2024-08-29T23:29:55.691Z,1724974195.691 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-08-29T23:29:55.691Z,1724974195.691 [Default:CheckIn](INFO): Running loop #2
2024-08-29T23:29:55.691Z,1724974195.691 [Default:CheckIn] Running Loop=2
2024-08-29T23:29:55.691Z,1724974195.691 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-08-29T23:29:55.691Z,1724974195.691 [Default:CheckIn:Read_GPS] Running Loop=1
2024-08-29T23:29:57.717Z,1724974197.717 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,232957.00,A,3648.14872,N,12147.22562,W,0.933,34.98,290824,,,D*4A
2024-08-29T23:29:57.719Z,1724974197.719 [NAL9602](INFO): GPS fix at 20240829T232957: (36.802479, -121.787094)
2024-08-29T23:29:57.728Z,1724974197.728 [Default:CheckIn:Read_GPS] Stopped
2024-08-29T23:29:57.728Z,1724974197.728 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-08-29T23:30:12.485Z,1724974212.485 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:30:14.673Z,1724974214.673 [NAL9602](INFO): SBD MO Status=0, MOMSN=15975, MT Status=0, MTMSN=0
2024-08-29T23:30:14.673Z,1724974214.673 [NAL9602](INFO): No messages in MT queue
2024-08-29T23:30:43.617Z,1724974243.617 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:30:45.373Z,1724974245.373 [NAL9602](INFO): Not Powering down - fast GPS
2024-08-29T23:31:14.741Z,1724974274.741 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:31:45.865Z,1724974305.865 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:32:17.001Z,1724974337.001 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:32:21.019Z,1724974341.019 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.740234
2024-08-29T23:32:37.419Z,1724974357.419 [NAL9602](INFO): SBD MO Status=1, MOMSN=15976, MT Status=0, MTMSN=0
2024-08-29T23:32:37.469Z,1724974357.469 [NAL9602](INFO): Sent 77 bytes from file Logs/20240829T231804/Courier0007.lzma
2024-08-29T23:32:37.469Z,1724974357.469 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:32:45.651Z,1724974365.651 [NAL9602](INFO): SBD MO Status=1, MOMSN=15977, MT Status=0, MTMSN=0
2024-08-29T23:32:45.709Z,1724974365.709 [NAL9602](INFO): Sent 121 bytes from file Logs/20240829T231804/Express0005.lzma
2024-08-29T23:32:45.709Z,1724974365.709 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:32:52.161Z,1724974372.161 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:32:57.076Z,1724974377.076 [NAL9602](INFO): SBD MO Status=1, MOMSN=15978, MT Status=0, MTMSN=0
2024-08-29T23:32:57.129Z,1724974377.129 [NAL9602](INFO): Sent 240 bytes from file Logs/20240829T231804/Express0008.lzma
2024-08-29T23:32:57.129Z,1724974377.129 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:33:07.146Z,1724974387.146 [NAL9602](INFO): SBD MO Status=0, MOMSN=15979, MT Status=0, MTMSN=0
2024-08-29T23:33:07.223Z,1724974387.223 [Default:CheckIn:Read_Iridium] Stopped
2024-08-29T23:33:07.223Z,1724974387.223 [Default:CheckIn:C.Wait] Running Loop=1
2024-08-29T23:33:07.223Z,1724974387.223 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-08-29T23:33:23.289Z,1724974403.289 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:33:37.867Z,1724974417.867 [NAL9602](INFO): Not Powering down - fast GPS
2024-08-29T23:33:54.429Z,1724974434.429 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:34:25.557Z,1724974465.557 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:34:56.693Z,1724974496.693 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:35:27.821Z,1724974527.821 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:35:58.945Z,1724974558.945 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:36:30.073Z,1724974590.073 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:37:01.197Z,1724974621.197 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:37:32.353Z,1724974652.353 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:37:42.734Z,1724974662.734 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003195
2024-08-29T23:38:07.757Z,1724974687.757 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-08-29T23:38:07.757Z,1724974687.757 [Default:CheckIn:C.Wait] Stopped
2024-08-29T23:38:07.757Z,1724974687.757 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-08-29T23:38:07.758Z,1724974687.758 [Default:CheckIn:D] Running Loop=1
2024-08-29T23:38:08.163Z,1724974688.163 [Default:CheckIn:D] Stopped
2024-08-29T23:38:08.163Z,1724974688.163 [Default:CheckIn:E] Running Loop=1
2024-08-29T23:38:08.571Z,1724974688.571 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 15.634608 min
2024-08-29T23:38:08.571Z,1724974688.571 [Default:CheckIn:E] Stopped
2024-08-29T23:38:08.572Z,1724974688.572 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-08-29T23:38:08.572Z,1724974688.572 [Default:CheckIn] Stopped
2024-08-29T23:38:08.572Z,1724974688.572 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-08-29T23:38:08.572Z,1724974688.572 [Default:CheckIn](INFO): Running loop #3
2024-08-29T23:38:08.572Z,1724974688.572 [Default:CheckIn] Running Loop=3
2024-08-29T23:38:08.572Z,1724974688.572 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-08-29T23:38:08.572Z,1724974688.572 [Default:CheckIn:Read_GPS] Running Loop=1
2024-08-29T23:38:10.580Z,1724974690.580 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,233810.00,A,3648.27089,N,12147.13409,W,4.860,17.74,290824,,,A*4E
2024-08-29T23:38:10.582Z,1724974690.582 [NAL9602](INFO): GPS fix at 20240829T233810: (36.804515, -121.785568)
2024-08-29T23:38:10.615Z,1724974690.615 [Default:CheckIn:Read_GPS] Stopped
2024-08-29T23:38:10.615Z,1724974690.615 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-08-29T23:38:13.440Z,1724974693.440 [DataOverHttps](INFO): Sending 77 bytes from file Logs/20240829T231804/Courier0010.lzma
2024-08-29T23:38:14.563Z,1724974694.563 [DataOverHttps](INFO): Moved sent file to Logs/20240829T231804/Courier0010.lzma.bak
2024-08-29T23:38:14.563Z,1724974694.563 [DataOverHttps](INFO): SBD MOMSN=23095817
2024-08-29T23:38:32.445Z,1724974712.445 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20240829T231804/Express0011.lzma
2024-08-29T23:38:33.447Z,1724974713.447 [DataOverHttps](INFO): Moved sent file to Logs/20240829T231804/Express0011.lzma.bak
2024-08-29T23:38:33.447Z,1724974713.447 [DataOverHttps](INFO): SBD MOMSN=23095826
2024-08-29T23:38:38.211Z,1724974718.211 [Default:CheckIn:Read_Iridium] Stopped
2024-08-29T23:38:38.211Z,1724974718.211 [Default:CheckIn:C.Wait] Running Loop=1
2024-08-29T23:38:38.211Z,1724974718.211 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-08-29T23:38:45.070Z,1724974725.070 [NAL9602](INFO): SBD MO Status=2, MOMSN=15980, MT Status=2, MTMSN=0
2024-08-29T23:38:45.070Z,1724974725.070 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-08-29T23:39:27.779Z,1724974767.779 [DataOverHttps](IMPORTANT): SBD MTMSN=20240829T233927
2024-08-29T23:39:35.169Z,1724974775.169 [DataOverHttps](INFO): Received command: strobe off
2024-08-29T23:39:35.230Z,1724974775.230 [CommandExec](IMPORTANT): got command strobe off
2024-08-29T23:39:35.231Z,1724974775.231 [CommandExec](IMPORTANT): Deactivating strobe
2024-08-29T23:39:41.203Z,1724974781.203 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=15980, MT Status=1, MTMSN=4008
2024-08-29T23:39:41.203Z,1724974781.203 [NAL9602](INFO): Data available in MT queue
2024-08-29T23:39:41.689Z,1724974781.689 [NAL9602](INFO): Received command: strobe off
2024-08-29T23:39:41.782Z,1724974781.782 [CommandExec](IMPORTANT): got command strobe off
2024-08-29T23:39:41.783Z,1724974781.783 [CommandExec](IMPORTANT): Deactivating strobe
2024-08-29T23:40:12.313Z,1724974812.313 [NAL9602](INFO): Not Powering down - fast GPS
2024-08-29T23:41:30.922Z,1724974890.922 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:42:01.531Z,1724974921.531 [DataOverHttps](IMPORTANT): SBD MTMSN=20240829T234201
2024-08-29T23:42:14.037Z,1724974934.037 [DataOverHttps](INFO): Received command: load Transport/transit.tl;set transit.MissionTimeout 30 min;set transit.NeedCommsTime 20 min;set transit.Latitude 36.797 degree;set transit.Longitude -121.847 degree;run
2024-08-29T23:42:14.147Z,1724974934.147 [CommandExec](IMPORTANT): got command load ./Missions/Transport/transit.tl
2024-08-29T23:42:14.147Z,1724974934.147 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/transit.tl
2024-08-29T23:42:14.147Z,1724974934.147 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/transit.tl
2024-08-29T23:42:14.151Z,1724974934.151 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/transit.tl
2024-08-29T23:42:14.845Z,1724974934.845 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/transit.tl translated into:
60
30
NaN
NaN
0
0
10
1
20
1
7
1
2024-08-29T23:42:14.851Z,1724974934.851 [MissionManager](INFO): DefineArg transit.MissionTimeout = 60.000000 min
2024-08-29T23:42:14.854Z,1724974934.854 [MissionManager](INFO): DefineArg transit.NeedCommsTime = 30.000000 min
2024-08-29T23:42:14.856Z,1724974934.856 [MissionManager](INFO): DefineArg transit.Latitude = nan arcdeg
2024-08-29T23:42:14.889Z,1724974934.889 [MissionManager](INFO): DefineArg transit.Longitude = nan arcdeg
2024-08-29T23:42:14.898Z,1724974934.898 [MissionManager](INFO): DefineArg transit.Northings = 0.000000 m
2024-08-29T23:42:14.911Z,1724974934.911 [MissionManager](INFO): DefineArg transit.Eastings = 0.000000 m
2024-08-29T23:42:14.930Z,1724974934.930 [MissionManager](INFO): DefineArg transit.Depth = 10.000000 m
2024-08-29T23:42:14.936Z,1724974934.936 [MissionManager](INFO): DefineArg transit.Speed = 1.000000 m/s
2024-08-29T23:42:14.958Z,1724974934.958 [MissionManager](INFO): DefineArg transit.MaxDepth = 20.000000 m
2024-08-29T23:42:14.964Z,1724974934.964 [MissionManager](INFO): DefineArg transit.MinOffshore = 1.000000 km
2024-08-29T23:42:14.981Z,1724974934.981 [MissionManager](INFO): DefineArg transit.MinAltitude = 7.000000 m
2024-08-29T23:42:14.995Z,1724974934.995 [MissionManager](INFO): DefineArg transit.MassHold = 1 bool
2024-08-29T23:42:15.014Z,1724974935.014 [MissionManager](INFO): DefineArg transit.BuoyancyHold = 1 bool
2024-08-29T23:42:15.014Z,1724974935.014 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl
2024-08-29T23:42:15.014Z,1724974935.014 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl
2024-08-29T23:42:15.015Z,1724974935.015 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl
2024-08-29T23:42:15.328Z,1724974935.328 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/NeedComms.tl translated into:
1
10
20
NaN
1
1000
7
30
0
last time_fix was:
first GPS update timeout
Comms timed out after
minutes
second GPS update timeout
2024-08-29T23:42:15.334Z,1724974935.334 [MissionManager](INFO): DefineArg transit:NeedComms.DiveInterval = 1.000000 h
2024-08-29T23:42:15.337Z,1724974935.337 [MissionManager](INFO): DefineArg transit:NeedComms.WaitForPitchUp = 10.000000 min
2024-08-29T23:42:15.340Z,1724974935.340 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacePitch = 20.000000 arcdeg
2024-08-29T23:42:15.343Z,1724974935.343 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceDepthRate = nan m/s
2024-08-29T23:42:15.346Z,1724974935.346 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceSpeed = 1.000000 m/s
2024-08-29T23:42:15.349Z,1724974935.349 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacingTimeout = 1000.000000 s
2024-08-29T23:42:15.352Z,1724974935.352 [MissionManager](INFO): DefineArg transit:NeedComms.GPSTimeout = 7.000000 min
2024-08-29T23:42:15.354Z,1724974935.354 [MissionManager](INFO): DefineArg transit:NeedComms.CommsTimeout = 30.000000 min
2024-08-29T23:42:15.361Z,1724974935.361 [transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2024-08-29T23:42:15.419Z,1724974935.419 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl
2024-08-29T23:42:15.419Z,1724974935.419 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl
2024-08-29T23:42:15.421Z,1724974935.421 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl
2024-08-29T23:42:15.606Z,1724974935.606 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into:
5
0
200
2000
2024-08-29T23:42:15.616Z,1724974935.616 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinAltitude = 5.000000 m
2024-08-29T23:42:15.632Z,1724974935.632 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepthIgnore = 0.000000 m
2024-08-29T23:42:15.639Z,1724974935.639 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepth = 200.000000 m
2024-08-29T23:42:15.659Z,1724974935.659 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinOffshore = 2000.000000 m
2024-08-29T23:42:15.660Z,1724974935.660 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2024-08-29T23:42:15.672Z,1724974935.672 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2024-08-29T23:42:15.697Z,1724974935.697 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2024-08-29T23:42:15.725Z,1724974935.725 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2024-08-29T23:42:15.726Z,1724974935.726 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2024-08-29T23:42:15.727Z,1724974935.727 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2024-08-29T23:42:15.774Z,1724974935.774 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2024-08-29T23:42:15.779Z,1724974935.779 [MissionManager](INFO): DefineArg transit:BackseatDriver.EnableBackseat = 0 bool
2024-08-29T23:42:15.789Z,1724974935.789 [transit:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2024-08-29T23:42:15.792Z,1724974935.792 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl
2024-08-29T23:42:15.792Z,1724974935.792 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl
2024-08-29T23:42:15.798Z,1724974935.798 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl
2024-08-29T23:42:16.028Z,1724974936.028 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into:
99999
2024-08-29T23:42:16.046Z,1724974936.046 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleAll = 0 bool
2024-08-29T23:42:16.048Z,1724974936.048 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad1 = 0 bool
2024-08-29T23:42:16.056Z,1724974936.056 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad2 = 0 bool
2024-08-29T23:42:16.070Z,1724974936.070 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad3 = 0 bool
2024-08-29T23:42:16.074Z,1724974936.074 [MissionManager](INFO): DefineArg transit:PowerOnly.EnabledPowerOnly = 0 bool
2024-08-29T23:42:16.089Z,1724974936.089 [transit:PowerOnly:E.Wait](DEBUG): Construct Wait.
2024-08-29T23:42:16.091Z,1724974936.091 [transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2024-08-29T23:42:16.099Z,1724974936.099 [transit:MassHold.Pitch](DEBUG): Construct.
2024-08-29T23:42:16.116Z,1724974936.115 [transit:Transit:A.Pitch](DEBUG): Construct.
2024-08-29T23:42:16.130Z,1724974936.130 [transit:Transit:B.SetSpeed](DEBUG): Construct.
2024-08-29T23:42:16.137Z,1724974936.137 [transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2024-08-29T23:42:16.172Z,1724974936.172 [MissionManager](DEBUG):
# Copyright (c) 2024 MBARI
# MBARI Proprietary Information. Confidential. All Rights Reserved
# Unauthorized copying or distribution of this file via any medium is strictly
# prohibited.
#
# WARNING - This file contains information whose export is restricted by the
# Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as
# amended. Violations of these export laws are subject to severe civil and/or
# criminal penalties.
mission transit {
"""
Vehicle transits to desired waypoint and can be commanded to use/hold
mass or buoyancy.
"""
arguments {
MissionTimeout = 60 minute
"""
Maximum duration of mission
"""
NeedCommsTime = 30 minute
"""
How often to surface for commumications
"""
Latitude = NaN degree
"""
Latitude of waypoint to seek. If set to NaN, uses latitude at mission
initialization.
"""
Longitude = NaN degree
"""
Longitude of waypoint to seek. If set to NaN, uses longitude at mission
initialization.
"""
Northings = 0 meter
"""
Northward distance of the waypoint to seek. If combined with Latitude
and/or Longitude, this is an offset from the specified Latitude and/or
Longitude.
"""
Eastings = 0 meter
"""
Eastward distance of the waypoint to seek. If combined with Latitude
and/or Longitude, this is an offset from the specified Latitude and/or
Longitude.
"""
Depth = 10 meter
"""
Depth of flat and level flight during the mission.
"""
Speed = 1 meter_per_second
"""
Speed of vehicle (relative to water) during the mission.
"""
MaxDepth = 20 meter
"""
Maximum depth for the entire mission.
"""
MinOffshore = 1 kilometer
"""
Minimum distance offshore for the entire mission.
"""
MinAltitude = 7 meter
"""
Minimum height above the sea floor for the entire mission.
"""
MassHold = true
"""
Set to True in order to hold mass at default position, False to allow
mass to run on its own.
"""
BuoyancyHold = true
"""
Set to True in order to hold buoyancy at neutral position, False to
allow buoyancy to run on its own.
"""
}
timeout duration=MissionTimeout
insert id="NeedComms" Insert/NeedComms.tl
assign in sequence NeedComms:DiveInterval = NeedCommsTime
assign in sequence NeedComms:WaitForPitchUp = 1 second
insert Insert/StandardEnvelopes.tl
assign in sequence StandardEnvelopes:MinAltitude = MinAltitude
assign in sequence StandardEnvelopes:MaxDepth = MaxDepth
assign in sequence StandardEnvelopes:MinOffshore = MinOffshore
insert Insert/BackseatDriver.tl
insert Insert/PowerOnly.tl
behavior Guidance:Buoyancy id="BuoyancyHold" {
run while ( BuoyancyHold )
set position = Control:VerticalControl.buoyancyNeutral
}
behavior Guidance:Pitch id="MassHold" {
run while ( MassHold )
set massPosition = Control:VerticalControl.massDefault
}
aggregate Transit {
run in sequence
behavior Guidance:Pitch {
run in parallel
set depth = Depth
}
behavior Guidance:SetSpeed {
run in parallel
set speed = Speed
}
behavior Guidance:Waypoint id="Wpt1" {
run in sequence
set latitude = Latitude
set longitude = Longitude
set northingsDelta = Northings
set eastingsDelta = Eastings
}
call id="PhoneHome" refId="NeedComms"
}
}
2024-08-29T23:42:16.177Z,1724974936.177 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/transit.tl id=transit
2024-08-29T23:42:22.324Z,1724974942.324 [CommandExec](IMPORTANT): got command set transit.MissionTimeout 30 minute
2024-08-29T23:42:22.325Z,1724974942.325 [CommandExec](IMPORTANT): got command set transit.NeedCommsTime 20 minute
2024-08-29T23:42:22.326Z,1724974942.326 [CommandExec](IMPORTANT): got command set transit.Latitude 36.797 degree
2024-08-29T23:42:22.327Z,1724974942.327 [CommandExec](IMPORTANT): got command set transit.Longitude -121.847 degree
2024-08-29T23:42:22.327Z,1724974942.327 [CommandExec](IMPORTANT): got command run
2024-08-29T23:42:22.329Z,1724974942.329 [CommandExec](IMPORTANT): Running
2024-08-29T23:42:22.432Z,1724974942.432 [Default] Stopped
2024-08-29T23:42:22.432Z,1724974942.432 [Default](DEBUG): Aggregate::uninitialize Default
2024-08-29T23:42:22.432Z,1724974942.432 [Default:B.GoToSurface] Stopped
2024-08-29T23:42:22.433Z,1724974942.433 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-08-29T23:42:22.433Z,1724974942.433 [Default:CheckIn] Stopped
2024-08-29T23:42:22.433Z,1724974942.433 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-08-29T23:42:22.433Z,1724974942.433 [Default:CheckIn:C.Wait] Stopped
2024-08-29T23:42:22.434Z,1724974942.434 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-08-29T23:42:22.434Z,1724974942.434 [MissionManager](IMPORTANT): Started mission transit
2024-08-29T23:42:22.434Z,1724974942.434 [transit] Running Loop=1
2024-08-29T23:42:22.434Z,1724974942.434 [transit](DEBUG): Aggregate::initialize transit
2024-08-29T23:42:22.434Z,1724974942.434 [transit:StandardEnvelopes] Running Loop=1
2024-08-29T23:42:22.434Z,1724974942.434 [transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit:StandardEnvelopes
2024-08-29T23:42:22.434Z,1724974942.434 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2024-08-29T23:42:22.434Z,1724974942.434 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2024-08-29T23:42:22.435Z,1724974942.435 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2024-08-29T23:42:22.435Z,1724974942.435 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2024-08-29T23:42:22.435Z,1724974942.435 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2024-08-29T23:42:22.435Z,1724974942.435 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2024-08-29T23:42:22.435Z,1724974942.435 [transit:BackseatDriver] Running Loop=1
2024-08-29T23:42:22.435Z,1724974942.435 [transit:BackseatDriver](DEBUG): Aggregate::initialize transit:BackseatDriver
2024-08-29T23:42:22.435Z,1724974942.435 [transit:BackseatDriver:A.BackseatDriver] Running Loop=1
2024-08-29T23:42:22.435Z,1724974942.435 [transit:PowerOnly] Running Loop=1
2024-08-29T23:42:22.436Z,1724974942.436 [transit:PowerOnly](DEBUG): Aggregate::initialize transit:PowerOnly
2024-08-29T23:42:22.436Z,1724974942.436 [transit:PowerOnly:A] Running Loop=1
2024-08-29T23:42:22.436Z,1724974942.436 [transit:PowerOnly:B] Running Loop=1
2024-08-29T23:42:22.436Z,1724974942.436 [transit:PowerOnly:C] Running Loop=1
2024-08-29T23:42:22.436Z,1724974942.436 [transit:PowerOnly:D] Running Loop=1
2024-08-29T23:42:22.436Z,1724974942.436 [transit:PowerOnly:E.Wait] Running Loop=1
2024-08-29T23:42:22.436Z,1724974942.436 [transit:PowerOnly:E.Wait](DEBUG): Initialize Wait Component.
2024-08-29T23:42:22.436Z,1724974942.436 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2024-08-29T23:42:22.436Z,1724974942.436 [transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component.
2024-08-29T23:42:22.436Z,1724974942.436 [transit:MassHold.Pitch] Running Loop=1
2024-08-29T23:42:22.436Z,1724974942.436 [transit:MassHold.Pitch](DEBUG): Initialize.
2024-08-29T23:42:22.437Z,1724974942.437 [transit:B] Running Loop=1
2024-08-29T23:42:22.437Z,1724974942.437 [transit:MassHold.Pitch] Running Loop=1
2024-08-29T23:42:22.438Z,1724974942.438 [transit:BuoyancyHold.Buoyancy] Running Loop=1
2024-08-29T23:42:22.439Z,1724974942.439 [transit:PowerOnly] Running Loop=1
2024-08-29T23:42:22.441Z,1724974942.441 [transit:PowerOnly:D] Stopped
2024-08-29T23:42:22.441Z,1724974942.441 [transit:PowerOnly:C] Stopped
2024-08-29T23:42:22.441Z,1724974942.441 [transit:PowerOnly:B] Stopped
2024-08-29T23:42:22.442Z,1724974942.442 [transit:PowerOnly:A] Stopped
2024-08-29T23:42:22.442Z,1724974942.442 [transit:BackseatDriver] Running Loop=1
2024-08-29T23:42:22.444Z,1724974942.444 [transit:StandardEnvelopes] Running Loop=1
2024-08-29T23:42:22.444Z,1724974942.444 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2024-08-29T23:42:22.444Z,1724974942.444 [transit:StandardEnvelopes:C.OffshoreEnvelope](IMPORTANT): Offshore envelope ACTIVE
2024-08-29T23:42:22.453Z,1724974942.453 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2024-08-29T23:42:22.453Z,1724974942.453 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2024-08-29T23:42:22.454Z,1724974942.454 [transit:B] Stopped
2024-08-29T23:42:22.454Z,1724974942.454 [transit:C] Running Loop=1
2024-08-29T23:42:22.459Z,1724974942.459 [HorizontalControl](DEBUG): kpHeading = 0.400000
2024-08-29T23:42:22.459Z,1724974942.459 [HorizontalControl](DEBUG): kiHeading = 0.001000
2024-08-29T23:42:22.459Z,1724974942.459 [HorizontalControl](DEBUG): kdHeading = 0.050000
2024-08-29T23:42:22.860Z,1724974942.860 [transit:C] Stopped
2024-08-29T23:42:22.860Z,1724974942.860 [transit:E] Running Loop=1
2024-08-29T23:42:23.253Z,1724974943.253 [transit:E] Stopped
2024-08-29T23:42:23.253Z,1724974943.253 [transit:F] Running Loop=1
2024-08-29T23:42:23.739Z,1724974943.739 [transit:F] Stopped
2024-08-29T23:42:23.739Z,1724974943.739 [transit:G] Running Loop=1
2024-08-29T23:42:24.060Z,1724974944.060 [transit:G] Stopped
2024-08-29T23:42:24.060Z,1724974944.060 [transit:Transit] Running Loop=1
2024-08-29T23:42:24.060Z,1724974944.060 [transit:Transit](DEBUG): Aggregate::initialize transit:Transit
2024-08-29T23:42:24.061Z,1724974944.061 [transit:Transit:A.Pitch] Running Loop=1
2024-08-29T23:42:24.061Z,1724974944.061 [transit:Transit:A.Pitch](DEBUG): Initialize.
2024-08-29T23:42:24.061Z,1724974944.061 [transit:Transit:B.SetSpeed] Running Loop=1
2024-08-29T23:42:24.061Z,1724974944.061 [transit:Transit:B.SetSpeed](DEBUG): Initialize.
2024-08-29T23:42:24.061Z,1724974944.061 [transit:Transit:Wpt1.Waypoint] Running Loop=1
2024-08-29T23:42:24.061Z,1724974944.061 [transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent.
2024-08-29T23:42:24.063Z,1724974944.063 [transit:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.797001,-121.847000
2024-08-29T23:42:24.073Z,1724974944.073 [transit:StandardEnvelopes:A.AltitudeEnvelope](ERROR): Altitude Measurement is not Active.
2024-08-29T23:42:24.460Z,1724974944.460 [transit:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.797001,-121.847000
2024-08-29T23:42:24.462Z,1724974944.462 [transit:Transit:B.SetSpeed] Running Loop=1
2024-08-29T23:42:24.462Z,1724974944.462 [transit:Transit:A.Pitch] Running Loop=1
2024-08-29T23:45:05.069Z,1724975105.069 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:45:36.205Z,1724975136.205 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:46:07.329Z,1724975167.329 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:46:23.289Z,1724975183.289 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:23.705Z,1724975183.705 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:24.125Z,1724975184.125 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:24.481Z,1724975184.481 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:24.897Z,1724975184.897 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:25.309Z,1724975185.309 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:25.678Z,1724975185.678 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2024-08-29T23:46:25.679Z,1724975185.679 [ThrusterHE](INFO): Powering down
2024-08-29T23:46:26.479Z,1724975186.479 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-08-29T23:46:26.598Z,1724975186.598 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-08-29T23:46:32.609Z,1724975192.609 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:34.182Z,1724975194.182 [ThrusterHE](FAULT): Lock Detect. Motor stopped spinning or could not start spinning.
2024-08-29T23:46:34.182Z,1724975194.182 [ThrusterHE] Hardware Fault, FailCount= 1
2024-08-29T23:46:34.182Z,1724975194.182 [ThrusterHE](ERROR): Hardware Fault
2024-08-29T23:46:34.216Z,1724975194.216 [CBIT](ERROR): Hardware Fault in component: ThrusterHE
2024-08-29T23:46:34.549Z,1724975194.549 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2024-08-29T23:46:34.549Z,1724975194.549 [ThrusterHE](INFO): Powering down
2024-08-29T23:46:35.373Z,1724975195.373 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-08-29T23:46:35.494Z,1724975195.494 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-08-29T23:46:35.498Z,1724975195.498 [CBIT](INFO): Clearing failed state for component ThrusterHE
2024-08-29T23:46:35.498Z,1724975195.498 [ThrusterHE] No Fault, FailCount= 1
2024-08-29T23:46:38.457Z,1724975198.457 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:46:42.685Z,1724975202.685 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:43.073Z,1724975203.073 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:43.489Z,1724975203.489 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:43.893Z,1724975203.893 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:44.297Z,1724975204.297 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:44.689Z,1724975204.689 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:45.057Z,1724975205.057 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2024-08-29T23:46:45.058Z,1724975205.058 [ThrusterHE](INFO): Powering down
2024-08-29T23:46:45.875Z,1724975205.875 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-08-29T23:46:45.994Z,1724975205.994 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-08-29T23:46:53.593Z,1724975213.593 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:53.989Z,1724975213.989 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:54.385Z,1724975214.385 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:56.417Z,1724975216.417 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:56.841Z,1724975216.841 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:46:57.187Z,1724975217.187 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2024-08-29T23:46:57.187Z,1724975217.187 [ThrusterHE](INFO): Powering down
2024-08-29T23:46:57.982Z,1724975217.982 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-08-29T23:46:58.103Z,1724975218.103 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-08-29T23:47:06.525Z,1724975226.525 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:47:06.933Z,1724975226.933 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:47:07.313Z,1724975227.313 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:47:07.732Z,1724975227.732 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:47:08.149Z,1724975228.149 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:47:08.541Z,1724975228.541 [ThrusterHE](IMPORTANT): Status lock Detected.
2024-08-29T23:47:08.888Z,1724975228.888 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2024-08-29T23:47:08.888Z,1724975228.888 [ThrusterHE](INFO): Powering down
2024-08-29T23:47:09.581Z,1724975229.581 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:47:09.714Z,1724975229.714 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-08-29T23:47:09.834Z,1724975229.834 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-08-29T23:47:13.598Z,1724975233.598 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.743393
2024-08-29T23:48:05.326Z,1724975285.326 [CommandExec](IMPORTANT): got command stop
2024-08-29T23:48:05.326Z,1724975285.326 [CommandExec](IMPORTANT): Scheduling is paused
2024-08-29T23:48:05.327Z,1724975285.327 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2024-08-29T23:48:05.455Z,1724975285.455 [MissionManager](INFO): MissionManager is completed.
2024-08-29T23:48:05.455Z,1724975285.455 [MissionManager](INFO): Uninitializing Mission transit
2024-08-29T23:48:05.455Z,1724975285.455 [transit] Stopped
2024-08-29T23:48:05.455Z,1724975285.455 [transit](DEBUG): Aggregate::uninitialize transit
2024-08-29T23:48:05.455Z,1724975285.455 [transit:StandardEnvelopes] Stopped
2024-08-29T23:48:05.455Z,1724975285.455 [transit:StandardEnvelopes](DEBUG): Aggregate::uninitialize transit:StandardEnvelopes
2024-08-29T23:48:05.456Z,1724975285.456 [transit:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2024-08-29T23:48:05.456Z,1724975285.456 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2024-08-29T23:48:05.456Z,1724975285.456 [transit:StandardEnvelopes:B.DepthEnvelope] Stopped
2024-08-29T23:48:05.456Z,1724975285.456 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2024-08-29T23:48:05.456Z,1724975285.456 [transit:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2024-08-29T23:48:05.456Z,1724975285.456 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2024-08-29T23:48:05.456Z,1724975285.456 [transit:BackseatDriver] Stopped
2024-08-29T23:48:05.456Z,1724975285.456 [transit:BackseatDriver](DEBUG): Aggregate::uninitialize transit:BackseatDriver
2024-08-29T23:48:05.456Z,1724975285.456 [transit:BackseatDriver:A.BackseatDriver] Stopped
2024-08-29T23:48:05.456Z,1724975285.456 [transit:PowerOnly] Stopped
2024-08-29T23:48:05.456Z,1724975285.456 [transit:PowerOnly](DEBUG): Aggregate::uninitialize transit:PowerOnly
2024-08-29T23:48:05.456Z,1724975285.456 [transit:PowerOnly:E.Wait] Stopped
2024-08-29T23:48:05.456Z,1724975285.456 [transit:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component.
2024-08-29T23:48:05.457Z,1724975285.457 [transit:BuoyancyHold.Buoyancy] Stopped
2024-08-29T23:48:05.457Z,1724975285.457 [transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component.
2024-08-29T23:48:05.457Z,1724975285.457 [transit:MassHold.Pitch] Stopped
2024-08-29T23:48:05.457Z,1724975285.457 [transit:Transit] Stopped
2024-08-29T23:48:05.457Z,1724975285.457 [transit:Transit](DEBUG): Aggregate::uninitialize transit:Transit
2024-08-29T23:48:05.457Z,1724975285.457 [transit:Transit:A.Pitch] Stopped
2024-08-29T23:48:05.457Z,1724975285.457 [transit:Transit:B.SetSpeed] Stopped
2024-08-29T23:48:05.457Z,1724975285.457 [transit:Transit:B.SetSpeed](DEBUG): Uninitialize.
2024-08-29T23:48:05.457Z,1724975285.457 [transit:Transit:Wpt1.Waypoint] Stopped
2024-08-29T23:48:05.457Z,1724975285.457 [transit:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent.
2024-08-29T23:48:05.856Z,1724975285.856 [MissionManager](IMPORTANT): Started mission Default
2024-08-29T23:48:05.857Z,1724975285.857 [Default] Running Loop=1
2024-08-29T23:48:05.857Z,1724975285.857 [Default](DEBUG): Aggregate::initialize Default
2024-08-29T23:48:05.857Z,1724975285.857 [Default:B.GoToSurface] Running Loop=1
2024-08-29T23:48:05.857Z,1724975285.857 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-08-29T23:48:05.857Z,1724975285.857 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-08-29T23:48:05.858Z,1724975285.858 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-08-29T23:48:05.858Z,1724975285.858 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-08-29T23:48:05.858Z,1724975285.858 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-08-29T23:48:05.859Z,1724975285.859 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-08-29T23:48:05.859Z,1724975285.859 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-08-29T23:48:05.859Z,1724975285.859 [Default:A.Wait] Running Loop=1
2024-08-29T23:48:05.859Z,1724975285.859 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-08-29T23:48:10.841Z,1724975290.841 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:48:19.193Z,1724975299.193 [Default:A.Wait](INFO): Done Waiting.
2024-08-29T23:48:19.193Z,1724975299.193 [Default:A.Wait] Stopped
2024-08-29T23:48:19.193Z,1724975299.193 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-08-29T23:48:19.578Z,1724975299.578 [Default:CheckIn] Running Loop=1
2024-08-29T23:48:19.579Z,1724975299.579 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-08-29T23:48:19.579Z,1724975299.579 [Default:CheckIn:Read_GPS] Running Loop=1
2024-08-29T23:48:21.588Z,1724975301.588 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,234821.00,A,3648.39498,N,12147.98741,W,2.780,90.14,290824,,,D*47
2024-08-29T23:48:21.591Z,1724975301.591 [NAL9602](INFO): GPS fix at 20240829T234821: (36.806583, -121.799790)
2024-08-29T23:48:21.600Z,1724975301.600 [Default:CheckIn:Read_GPS] Stopped
2024-08-29T23:48:21.600Z,1724975301.600 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-08-29T23:48:41.965Z,1724975321.965 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:48:42.778Z,1724975322.778 [NAL9602](INFO): SBD MO Status=1, MOMSN=15981, MT Status=0, MTMSN=0
2024-08-29T23:48:42.827Z,1724975322.827 [NAL9602](INFO): Sent 76 bytes from file Logs/20240829T231804/Courier0013.lzma
2024-08-29T23:48:42.828Z,1724975322.828 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:48:58.288Z,1724975338.288 [NAL9602](INFO): SBD MO Status=2, MOMSN=15982, MT Status=2, MTMSN=0
2024-08-29T23:48:58.288Z,1724975338.288 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-08-29T23:49:13.089Z,1724975353.089 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:49:19.770Z,1724975359.770 [NAL9602](INFO): SBD MO Status=1, MOMSN=15982, MT Status=0, MTMSN=0
2024-08-29T23:49:19.817Z,1724975359.817 [NAL9602](INFO): Sent 332 bytes from file Logs/20240829T231804/Express0014.lzma
2024-08-29T23:49:19.817Z,1724975359.817 [NAL9602](INFO): Packets left to send: 2
2024-08-29T23:49:32.308Z,1724975372.308 [NAL9602](INFO): SBD MO Status=1, MOMSN=15983, MT Status=0, MTMSN=0
2024-08-29T23:49:32.365Z,1724975372.365 [NAL9602](INFO): Sent 332 bytes from file Logs/20240829T231804/Express0014.lzma
2024-08-29T23:49:32.365Z,1724975372.365 [NAL9602](INFO): Packets left to send: 1
2024-08-29T23:49:43.345Z,1724975383.345 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=15984, MT Status=1, MTMSN=4009
2024-08-29T23:49:43.400Z,1724975383.400 [NAL9602](INFO): Sent 159 bytes from file Logs/20240829T231804/Express0014.lzma
2024-08-29T23:49:43.400Z,1724975383.400 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:49:43.820Z,1724975383.820 [NAL9602](INFO): Received command: stop
2024-08-29T23:49:43.918Z,1724975383.918 [CommandExec](IMPORTANT): got command stop
2024-08-29T23:49:44.213Z,1724975384.213 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:49:59.842Z,1724975399.842 [NAL9602](INFO): SBD MO Status=0, MOMSN=15985, MT Status=0, MTMSN=0
2024-08-29T23:50:15.337Z,1724975415.337 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:50:18.678Z,1724975418.678 [NAL9602](INFO): SBD MO Status=1, MOMSN=15986, MT Status=0, MTMSN=0
2024-08-29T23:50:18.728Z,1724975418.728 [NAL9602](INFO): Sent 40 bytes from file Logs/20240829T231804/Courier0016.lzma
2024-08-29T23:50:18.729Z,1724975418.729 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:50:44.668Z,1724975444.668 [NAL9602](INFO): SBD MO Status=2, MOMSN=15987, MT Status=2, MTMSN=0
2024-08-29T23:50:44.669Z,1724975444.669 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-08-29T23:50:46.485Z,1724975446.485 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:51:03.402Z,1724975463.402 [NAL9602](INFO): SBD MO Status=1, MOMSN=15987, MT Status=0, MTMSN=0
2024-08-29T23:51:03.465Z,1724975463.465 [NAL9602](INFO): Sent 147 bytes from file Logs/20240829T231804/Express0017.lzma
2024-08-29T23:51:03.465Z,1724975463.465 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:51:11.896Z,1724975471.896 [NAL9602](INFO): SBD MO Status=0, MOMSN=15988, MT Status=0, MTMSN=0
2024-08-29T23:51:12.016Z,1724975472.016 [Default:CheckIn:Read_Iridium] Stopped
2024-08-29T23:51:12.017Z,1724975472.017 [Default:CheckIn:C.Wait] Running Loop=1
2024-08-29T23:51:12.017Z,1724975472.017 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-08-29T23:51:17.609Z,1724975477.609 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:51:42.672Z,1724975502.672 [NAL9602](INFO): Not Powering down - fast GPS
2024-08-29T23:51:48.741Z,1724975508.741 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:52:19.865Z,1724975539.865 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:52:50.990Z,1724975570.990 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:53:22.113Z,1724975602.113 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:53:53.238Z,1724975633.238 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:54:24.361Z,1724975664.361 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:54:55.485Z,1724975695.485 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:55:26.610Z,1724975726.610 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:55:52.675Z,1724975752.675 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,0021.30,000.00
2024-08-29T23:55:57.749Z,1724975757.749 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:56:12.498Z,1724975772.498 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-08-29T23:56:12.498Z,1724975772.498 [Default:CheckIn:C.Wait] Stopped
2024-08-29T23:56:12.498Z,1724975772.498 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-08-29T23:56:12.498Z,1724975772.498 [Default:CheckIn:D] Running Loop=1
2024-08-29T23:56:12.878Z,1724975772.878 [Default:CheckIn:D] Stopped
2024-08-29T23:56:12.878Z,1724975772.878 [Default:CheckIn:E] Running Loop=1
2024-08-29T23:56:13.286Z,1724975773.286 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.117015 min
2024-08-29T23:56:13.286Z,1724975773.286 [Default:CheckIn:E] Stopped
2024-08-29T23:56:13.287Z,1724975773.287 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-08-29T23:56:13.287Z,1724975773.287 [Default:CheckIn] Stopped
2024-08-29T23:56:13.287Z,1724975773.287 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-08-29T23:56:13.287Z,1724975773.287 [Default:CheckIn](INFO): Running loop #2
2024-08-29T23:56:13.287Z,1724975773.287 [Default:CheckIn] Running Loop=2
2024-08-29T23:56:13.287Z,1724975773.287 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-08-29T23:56:13.287Z,1724975773.287 [Default:CheckIn:Read_GPS] Running Loop=1
2024-08-29T23:56:15.302Z,1724975775.302 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,235614.00,A,3648.43478,N,12147.86142,W,0.836,50.88,290824,,,A*4B
2024-08-29T23:56:15.306Z,1724975775.306 [NAL9602](INFO): GPS fix at 20240829T235614: (36.807246, -121.797690)
2024-08-29T23:56:15.321Z,1724975775.321 [Default:CheckIn:Read_GPS] Stopped
2024-08-29T23:56:15.321Z,1724975775.321 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-08-29T23:56:28.873Z,1724975788.873 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2024-08-29T23:56:30.426Z,1724975790.426 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=15989, MT Status=1, MTMSN=4010
2024-08-29T23:56:30.481Z,1724975790.481 [NAL9602](INFO): Sent 77 bytes from file Logs/20240829T231804/Courier0019.lzma
2024-08-29T23:56:30.481Z,1724975790.481 [NAL9602](INFO): Packets left to send: 0
2024-08-29T23:56:30.905Z,1724975790.905 [NAL9602](INFO): Received command: restart logs