2024-08-21T16:14:37.001Z,1724256877.001 [Supervisor](DEBUG): Initializing supervisor.
2024-08-21T16:14:37.005Z,1724256877.005 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2024-08-21T16:14:37.006Z,1724256877.006 [SyncHandler](INFO): Protected caller Thread ID is 8950
2024-08-21T16:14:37.006Z,1724256877.006 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2024-08-21T16:14:37.007Z,1724256877.007 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2024-08-21T16:14:37.007Z,1724256877.007 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8951
2024-08-21T16:14:37.039Z,1724256877.039 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2024-08-21T16:14:37.128Z,1724256877.128 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2024-08-21T16:14:37.129Z,1724256877.129 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2024-08-21T16:14:37.129Z,1724256877.129 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 8952
2024-08-21T16:14:37.171Z,1724256877.171 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2024-08-21T16:14:37.172Z,1724256877.172 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2024-08-21T16:14:37.172Z,1724256877.172 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8953
2024-08-21T16:14:37.174Z,1724256877.174 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2024-08-21T16:14:37.186Z,1724256877.186 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2024-08-21T16:14:37.186Z,1724256877.186 [logger ThreadHandler](INFO): Protected caller Thread ID is 8954
2024-08-21T16:14:37.190Z,1724256877.190 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2024-08-21T16:14:37.190Z,1724256877.190 [Supervisor](INFO): Looking for Config files in directory: Config/
2024-08-21T16:14:37.192Z,1724256877.192 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2024-08-21T16:14:37.855Z,1724256877.855 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2024-08-21T16:14:37.856Z,1724256877.856 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2024-08-21T16:14:37.948Z,1724256877.948 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2024-08-21T16:14:38.308Z,1724256878.308 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2024-08-21T16:14:38.309Z,1724256878.309 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2024-08-21T16:14:38.433Z,1724256878.433 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2024-08-21T16:14:38.433Z,1724256878.433 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2024-08-21T16:14:38.657Z,1724256878.657 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2024-08-21T16:14:38.657Z,1724256878.657 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2024-08-21T16:14:39.213Z,1724256879.213 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2024-08-21T16:14:39.213Z,1724256879.213 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2024-08-21T16:14:39.512Z,1724256879.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2024-08-21T16:14:39.512Z,1724256879.512 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2024-08-21T16:14:39.748Z,1724256879.748 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2024-08-21T16:14:39.749Z,1724256879.749 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2024-08-21T16:14:39.951Z,1724256879.951 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2024-08-21T16:14:39.951Z,1724256879.951 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2024-08-21T16:14:40.064Z,1724256880.064 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2024-08-21T16:14:40.064Z,1724256880.064 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2024-08-21T16:14:40.324Z,1724256880.324 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2024-08-21T16:14:40.324Z,1724256880.324 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2024-08-21T16:14:40.759Z,1724256880.759 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2024-08-21T16:14:40.760Z,1724256880.760 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2024-08-21T16:14:40.854Z,1724256880.854 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2024-08-21T16:14:41.005Z,1724256881.005 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2024-08-21T16:14:41.006Z,1724256881.006 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2024-08-21T16:14:41.873Z,1724256881.873 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2024-08-21T16:14:41.873Z,1724256881.873 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2024-08-21T16:14:43.106Z,1724256883.106 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2024-08-21T16:14:43.108Z,1724256883.108 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2024-08-21T16:14:43.109Z,1724256883.109 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2024-08-21T16:14:43.337Z,1724256883.337 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2024-08-21T16:14:43.460Z,1724256883.460 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2024-08-21T16:14:43.573Z,1724256883.573 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2024-08-21T16:14:43.687Z,1724256883.687 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2024-08-21T16:14:43.963Z,1724256883.963 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2024-08-21T16:14:43.964Z,1724256883.964 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2024-08-21T16:14:44.091Z,1724256884.091 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2024-08-21T16:14:44.209Z,1724256884.209 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2024-08-21T16:14:44.350Z,1724256884.350 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2024-08-21T16:14:44.480Z,1724256884.480 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2024-08-21T16:14:44.580Z,1724256884.580 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2024-08-21T16:14:44.680Z,1724256884.680 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2024-08-21T16:14:44.802Z,1724256884.802 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2024-08-21T16:14:44.924Z,1724256884.924 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2024-08-21T16:14:45.160Z,1724256885.160 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2024-08-21T16:14:45.353Z,1724256885.353 [Supervisor](IMPORTANT): Reloading configuration overrides from Data/persisted.cfg
2024-08-21T16:14:45.361Z,1724256885.361 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2024-08-21T16:14:45.801Z,1724256885.801 [AHRS_M2] Loaded
2024-08-21T16:14:45.801Z,1724256885.801 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2024-08-21T16:14:45.839Z,1724256885.839 [BackseatComponent] Loaded
2024-08-21T16:14:45.839Z,1724256885.839 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2024-08-21T16:14:45.840Z,1724256885.840 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408044E0
2024-08-21T16:14:45.840Z,1724256885.840 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 9048
2024-08-21T16:14:45.843Z,1724256885.843 [LcmUniversalReporter] Loaded
2024-08-21T16:14:45.843Z,1724256885.843 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2024-08-21T16:14:46.631Z,1724256886.631 [BPC1] Loaded
2024-08-21T16:14:46.631Z,1724256886.631 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2024-08-21T16:14:46.703Z,1724256886.703 [DataOverHttps] Loaded
2024-08-21T16:14:46.704Z,1724256886.704 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2024-08-21T16:14:46.704Z,1724256886.704 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408344E0
2024-08-21T16:14:46.705Z,1724256886.705 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 9049
2024-08-21T16:14:46.726Z,1724256886.726 [DepthKeller33X] Loaded
2024-08-21T16:14:46.726Z,1724256886.726 [ComponentRegistry](DEBUG): SyncComponent "DepthKeller33X" handled in the control thread.
2024-08-21T16:14:46.731Z,1724256886.731 [DropWeight] Loaded
2024-08-21T16:14:46.731Z,1724256886.731 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2024-08-21T16:14:46.793Z,1724256886.793 [NAL9602] Loaded
2024-08-21T16:14:46.793Z,1724256886.793 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2024-08-21T16:14:46.822Z,1724256886.822 [Onboard] Loaded
2024-08-21T16:14:46.823Z,1724256886.823 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2024-08-21T16:14:46.824Z,1724256886.824 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408644E0
2024-08-21T16:14:46.824Z,1724256886.824 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 9050
2024-08-21T16:14:46.830Z,1724256886.829 [PowerOnly](INFO): Adding load control power supply at /dev/loadC2
2024-08-21T16:14:46.842Z,1724256886.842 [PowerOnly](INFO): Adding load control power supply at /dev/loadC6
2024-08-21T16:14:46.854Z,1724256886.854 [PowerOnly](INFO): Adding load control power supply at /dev/loadC4
2024-08-21T16:14:46.866Z,1724256886.866 [PowerOnly] Loaded
2024-08-21T16:14:46.866Z,1724256886.866 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2024-08-21T16:14:46.880Z,1724256886.880 [Power24vConverter] Loaded
2024-08-21T16:14:46.880Z,1724256886.880 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2024-08-21T16:14:46.895Z,1724256886.895 [Radio_Surface] Loaded
2024-08-21T16:14:46.896Z,1724256886.896 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2024-08-21T16:14:46.897Z,1724256886.897 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408944E0
2024-08-21T16:14:46.897Z,1724256886.897 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9051
2024-08-21T16:14:46.943Z,1724256886.943 [RDI_Pathfinder] Loaded
2024-08-21T16:14:46.943Z,1724256886.943 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2024-08-21T16:14:46.944Z,1724256886.944 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2024-08-21T16:14:46.944Z,1724256886.944 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2024-08-21T16:14:46.954Z,1724256886.954 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2024-08-21T16:14:46.955Z,1724256886.955 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2024-08-21T16:14:47.063Z,1724256887.063 [DeadReckonUsingMultipleVelocitySources] Loaded
2024-08-21T16:14:47.063Z,1724256887.063 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2024-08-21T16:14:47.076Z,1724256887.076 [NavChart] Loaded
2024-08-21T16:14:47.076Z,1724256887.076 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2024-08-21T16:14:47.082Z,1724256887.082 [UniversalFixResidualReporter] Loaded
2024-08-21T16:14:47.082Z,1724256887.082 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2024-08-21T16:14:47.082Z,1724256887.082 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2024-08-21T16:14:47.083Z,1724256887.083 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2024-08-21T16:14:47.189Z,1724256887.189 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2024-08-21T16:14:47.189Z,1724256887.189 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2024-08-21T16:14:47.320Z,1724256887.320 [BuoyancyServo] Loaded
2024-08-21T16:14:47.320Z,1724256887.320 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2024-08-21T16:14:47.344Z,1724256887.344 [ElevatorServo] Loaded
2024-08-21T16:14:47.344Z,1724256887.344 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2024-08-21T16:14:47.367Z,1724256887.367 [MassServo] Loaded
2024-08-21T16:14:47.367Z,1724256887.367 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2024-08-21T16:14:47.389Z,1724256887.389 [RudderServo] Loaded
2024-08-21T16:14:47.389Z,1724256887.389 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2024-08-21T16:14:47.406Z,1724256887.406 [ThrusterHE] Loaded
2024-08-21T16:14:47.406Z,1724256887.406 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2024-08-21T16:14:47.407Z,1724256887.407 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2024-08-21T16:14:47.407Z,1724256887.407 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2024-08-21T16:14:47.876Z,1724256887.876 [CTD_Seabird] Loaded
2024-08-21T16:14:47.877Z,1724256887.877 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2024-08-21T16:14:47.878Z,1724256887.878 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409E74E0
2024-08-21T16:14:47.878Z,1724256887.878 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 9052
2024-08-21T16:14:47.911Z,1724256887.911 [PAR_Licor] Loaded
2024-08-21T16:14:47.911Z,1724256887.911 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2024-08-21T16:14:47.992Z,1724256887.992 [WetLabsBB2FL] Loaded
2024-08-21T16:14:47.993Z,1724256887.993 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2024-08-21T16:14:47.994Z,1724256887.994 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A174E0
2024-08-21T16:14:47.994Z,1724256887.994 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 9053
2024-08-21T16:14:47.995Z,1724256887.995 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2024-08-21T16:14:47.995Z,1724256887.995 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2024-08-21T16:14:48.492Z,1724256888.492 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2024-08-21T16:14:48.493Z,1724256888.493 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2024-08-21T16:14:48.541Z,1724256888.541 [DepthRateCalculator] Loaded
2024-08-21T16:14:48.542Z,1724256888.542 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2024-08-21T16:14:48.547Z,1724256888.547 [PitchRateCalculator] Loaded
2024-08-21T16:14:48.547Z,1724256888.547 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2024-08-21T16:14:48.556Z,1724256888.556 [SpeedCalculator] Loaded
2024-08-21T16:14:48.556Z,1724256888.556 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2024-08-21T16:14:48.569Z,1724256888.569 [TempGradientCalculator] Loaded
2024-08-21T16:14:48.569Z,1724256888.569 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2024-08-21T16:14:48.584Z,1724256888.584 [VerticalHomogeneityIndexCalculator] Loaded
2024-08-21T16:14:48.584Z,1724256888.584 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2024-08-21T16:14:48.588Z,1724256888.588 [YawRateCalculator] Loaded
2024-08-21T16:14:48.589Z,1724256888.589 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2024-08-21T16:14:48.610Z,1724256888.610 [ElevatorOffsetCalculator] Loaded
2024-08-21T16:14:48.611Z,1724256888.611 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2024-08-21T16:14:48.611Z,1724256888.611 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2024-08-21T16:14:48.612Z,1724256888.612 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2024-08-21T16:14:48.746Z,1724256888.746 [SBIT](DEBUG): Construct Startup Built In Test.
2024-08-21T16:14:48.759Z,1724256888.759 [SBIT] Loaded
2024-08-21T16:14:48.759Z,1724256888.759 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2024-08-21T16:14:48.762Z,1724256888.762 [IBIT](DEBUG): Construct Initiated Built In Test.
2024-08-21T16:14:48.776Z,1724256888.776 [IBIT] Loaded
2024-08-21T16:14:48.776Z,1724256888.776 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2024-08-21T16:14:48.782Z,1724256888.782 [CBIT](DEBUG): Construct Continuous Built In Test.
2024-08-21T16:14:48.885Z,1724256888.885 [CBIT] Loaded
2024-08-21T16:14:48.885Z,1724256888.885 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2024-08-21T16:14:48.885Z,1724256888.885 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2024-08-21T16:14:48.886Z,1724256888.886 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2024-08-21T16:14:48.939Z,1724256888.939 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2024-08-21T16:14:48.940Z,1724256888.940 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2024-08-21T16:14:49.104Z,1724256889.104 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2024-08-21T16:14:49.105Z,1724256889.105 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2024-08-21T16:14:49.155Z,1724256889.155 [VerticalControl](DEBUG): Construct VerticalControl.
2024-08-21T16:14:49.204Z,1724256889.204 [VerticalControl] Loaded
2024-08-21T16:14:49.204Z,1724256889.204 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2024-08-21T16:14:49.207Z,1724256889.207 [HorizontalControl](DEBUG): Construct HorizontalControl.
2024-08-21T16:14:49.250Z,1724256889.250 [HorizontalControl] Loaded
2024-08-21T16:14:49.251Z,1724256889.251 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2024-08-21T16:14:49.253Z,1724256889.253 [SpeedControl](DEBUG): Construct SpeedControl.
2024-08-21T16:14:49.255Z,1724256889.255 [SpeedControl] Loaded
2024-08-21T16:14:49.255Z,1724256889.255 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2024-08-21T16:14:49.258Z,1724256889.258 [LoopControl](DEBUG): Construct LoopControl.
2024-08-21T16:14:49.258Z,1724256889.258 [LoopControl] Loaded
2024-08-21T16:14:49.258Z,1724256889.258 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2024-08-21T16:14:49.259Z,1724256889.259 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2024-08-21T16:14:49.259Z,1724256889.259 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2024-08-21T16:14:49.285Z,1724256889.285 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2024-08-21T16:14:49.292Z,1724256889.292 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2024-08-21T16:14:49.294Z,1724256889.294 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2024-08-21T16:14:49.306Z,1724256889.306 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2024-08-21T16:14:49.307Z,1724256889.307 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C074E0
2024-08-21T16:14:49.307Z,1724256889.307 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9054
2024-08-21T16:14:49.311Z,1724256889.311 [Supervisor](INFO): Main Thread ID is 8516
2024-08-21T16:14:49.312Z,1724256889.312 [Supervisor](DEBUG): Running supervisor.
2024-08-21T16:14:49.312Z,1724256889.312 [CommandExec ThreadHandler](INFO): Handler Thread ID is 9055
2024-08-21T16:14:49.313Z,1724256889.313 [CommandExec](INFO): Initializing the command executive.
2024-08-21T16:14:49.314Z,1724256889.314 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9056
2024-08-21T16:14:49.316Z,1724256889.316 [controlThread ThreadHandler](INFO): Handler Thread ID is 9057
2024-08-21T16:14:49.317Z,1724256889.317 [controlThread](DEBUG): Initializing ControlThread
2024-08-21T16:14:49.321Z,1724256889.321 [NavChart](DEBUG): Initialize NavChart Navigation.
2024-08-21T16:14:49.321Z,1724256889.321 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2024-08-21T16:14:49.327Z,1724256889.327 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2024-08-21T16:14:49.327Z,1724256889.327 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2024-08-21T16:14:49.327Z,1724256889.327 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2024-08-21T16:14:49.327Z,1724256889.327 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2024-08-21T16:14:49.328Z,1724256889.328 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2024-08-21T16:14:49.329Z,1724256889.329 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2024-08-21T16:14:49.329Z,1724256889.329 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2024-08-21T16:14:49.329Z,1724256889.329 [SBIT](INFO): Initialize SBIT Component.
2024-08-21T16:14:49.330Z,1724256889.330 [SBIT](IMPORTANT): git: 2024-05-22-5-gcd1858f91
2024-08-21T16:14:49.330Z,1724256889.330 [SBIT](INFO): git hash: cd1858f91ad007b0f5335e09bba474db3386574f
2024-08-21T16:14:49.330Z,1724256889.330 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2024-08-21T16:14:49.332Z,1724256889.332 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2024-08-21T16:14:49.333Z,1724256889.333 [SBIT](INFO): Beginning SBIT in 79.000000 seconds.
2024-08-21T16:14:49.333Z,1724256889.333 [IBIT](INFO): Initialize IBIT Component.
2024-08-21T16:14:49.335Z,1724256889.335 [CBIT](DEBUG): Initialize CBIT Component.
2024-08-21T16:14:49.336Z,1724256889.336 [logger ThreadHandler](INFO): Handler Thread ID is 9058
2024-08-21T16:14:49.346Z,1724256889.346 [CBIT](DEBUG): Initialized mux pins.
2024-08-21T16:14:49.346Z,1724256889.346 [CBIT](DEBUG): Initializing the watchdog timer.
2024-08-21T16:14:49.355Z,1724256889.355 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 9059
2024-08-21T16:14:49.367Z,1724256889.367 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 9060
2024-08-21T16:14:49.368Z,1724256889.368 [DataOverHttps](DEBUG): dashIP=128.128.181.226 starts with a digit so assuming it is a numeric IP
2024-08-21T16:14:49.370Z,1724256889.370 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2024-08-21T16:14:49.371Z,1724256889.371 [CBIT](DEBUG): Initializing heartbeat.
2024-08-21T16:14:49.387Z,1724256889.387 [Onboard ThreadHandler](INFO): Handler Thread ID is 9061
2024-08-21T16:14:49.404Z,1724256889.404 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9062
2024-08-21T16:14:49.427Z,1724256889.427 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 9063
2024-08-21T16:14:49.427Z,1724256889.427 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2024-08-21T16:14:49.432Z,1724256889.432 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 9065
2024-08-21T16:14:49.435Z,1724256889.435 [WetLabsBB2FL](INFO): Powering up
2024-08-21T16:14:49.436Z,1724256889.436 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9067
2024-08-21T16:14:49.439Z,1724256889.439 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MA23M.000
2024-08-21T16:14:49.439Z,1724256889.439 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MA23M.000
2024-08-21T16:14:49.439Z,1724256889.439 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MA43M.000
2024-08-21T16:14:49.439Z,1724256889.439 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MA43M.000
2024-08-21T16:14:49.439Z,1724256889.439 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3EC09M.000
2024-08-21T16:14:49.439Z,1724256889.439 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3EC09M.000
2024-08-21T16:14:49.440Z,1724256889.440 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3NY01M.000
2024-08-21T16:14:49.440Z,1724256889.440 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3NY01M.000
2024-08-21T16:14:49.440Z,1724256889.440 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2EC03M.000
2024-08-21T16:14:49.440Z,1724256889.440 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2EC03M.000
2024-08-21T16:14:49.440Z,1724256889.440 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2EC04M.000
2024-08-21T16:14:49.440Z,1724256889.440 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2EC04M.000
2024-08-21T16:14:49.442Z,1724256889.442 [CBIT](DEBUG): Deactivating GF circuits.
2024-08-21T16:14:49.442Z,1724256889.442 [CBIT](DEBUG): Deactivating emergency mode.
2024-08-21T16:14:49.482Z,1724256889.482 [CBIT](DEBUG): Backplane powered.
2024-08-21T16:14:49.483Z,1724256889.483 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2024-08-21T16:14:49.484Z,1724256889.484 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2024-08-21T16:14:49.485Z,1724256889.485 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2024-08-21T16:14:49.486Z,1724256889.486 [LoopControl](DEBUG): Initialize LoopControlComponent.
2024-08-21T16:14:49.486Z,1724256889.486 [MissionManager](IMPORTANT): Using TethysL tl-to-tx parser
2024-08-21T16:14:49.487Z,1724256889.487 [MissionManager](INFO): Loading Mission from file: Missions/Startup.tl
2024-08-21T16:14:49.487Z,1724256889.487 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Startup.tl
2024-08-21T16:14:49.488Z,1724256889.488 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Startup.tl
2024-08-21T16:14:49.535Z,1724256889.535 [MissionManager](DEBUG): TethyslAPI: Missions/Startup.tl translated into:
2024-08-21T16:14:49.540Z,1724256889.540 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2024-08-21T16:14:49.591Z,1724256889.591 [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-21T16:14:49.592Z,1724256889.592 [MissionManager](INFO): Loading Mission from file: Missions/Default.tl
2024-08-21T16:14:49.592Z,1724256889.592 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Default.tl
2024-08-21T16:14:49.593Z,1724256889.593 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Default.tl
2024-08-21T16:14:49.811Z,1724256889.811 [Radio_Surface](INFO): Powering up
2024-08-21T16:14:49.868Z,1724256889.868 [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-21T16:14:49.890Z,1724256889.890 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2024-08-21T16:14:49.891Z,1724256889.891 [Default:A.Wait](DEBUG): Construct Wait.
2024-08-21T16:14:49.893Z,1724256889.893 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2024-08-21T16:14:49.938Z,1724256889.938 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2024-08-21T16:14:49.941Z,1724256889.941 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2024-08-21T16:14:49.963Z,1724256889.963 [Default:E.Execute](DEBUG): Construct Execute.
2024-08-21T16:14:49.966Z,1724256889.966 [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-21T16:14:49.982Z,1724256889.982 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DepthKeller33X,DropWeight,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,PAR_Licor,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2024-08-21T16:14:49.994Z,1724256889.994 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2024-08-21T16:14:50.055Z,1724256890.055 [DepthKeller33X](INFO): Initializing.
2024-08-21T16:14:50.076Z,1724256890.076 [Power24vConverter](INFO): Powering up.
2024-08-21T16:14:50.077Z,1724256890.077 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2024-08-21T16:14:50.095Z,1724256890.095 [DepthRateCalculator](ERROR): Depth measurement is not active
2024-08-21T16:14:50.120Z,1724256890.120 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2024-08-21T16:14:50.127Z,1724256890.127 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2024-08-21T16:14:50.127Z,1724256890.127 [ElevatorServo](DEBUG): Initializing EZServoServo.
2024-08-21T16:14:50.135Z,1724256890.135 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2024-08-21T16:14:50.135Z,1724256890.135 [MassServo](DEBUG): Initializing EZServoServo.
2024-08-21T16:14:50.143Z,1724256890.143 [MassServo](DEBUG): Initializing MassServo.
2024-08-21T16:14:50.144Z,1724256890.144 [RudderServo](DEBUG): Initializing EZServoServo.
2024-08-21T16:14:50.151Z,1724256890.151 [RudderServo](DEBUG): Initializing RudderServo.
2024-08-21T16:14:50.151Z,1724256890.151 [ThrusterHE](DEBUG): Initializing EZServoServo.
2024-08-21T16:14:50.159Z,1724256890.159 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2024-08-21T16:14:50.440Z,1724256890.440 [DepthRateCalculator](ERROR): Depth measurement is not active
2024-08-21T16:14:50.807Z,1724256890.807 [DepthRateCalculator](ERROR): Depth measurement is not active
2024-08-21T16:14:51.207Z,1724256891.207 [DepthRateCalculator](ERROR): Depth measurement is not active
2024-08-21T16:14:51.647Z,1724256891.647 [DepthRateCalculator](ERROR): Depth measurement is not active
2024-08-21T16:14:52.046Z,1724256892.046 [WetLabsBB2FL](INFO): Powering down
2024-08-21T16:15:12.230Z,1724256912.230 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2024-08-21T16:15:12.230Z,1724256912.230 [RDI_Pathfinder] Communications Fault, FailCount= 1
2024-08-21T16:15:12.230Z,1724256912.230 [RDI_Pathfinder](ERROR): Communications Fault
2024-08-21T16:15:12.295Z,1724256912.295 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2024-08-21T16:15:12.704Z,1724256912.704 [RDI_Pathfinder](INFO): Powering down
2024-08-21T16:15:13.524Z,1724256913.524 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2024-08-21T16:15:13.524Z,1724256913.524 [RDI_Pathfinder] No Fault, FailCount= 1
2024-08-21T16:15:13.857Z,1724256913.857 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2024-08-21T16:15:17.076Z,1724256917.076 [NAL9602](INFO): Powering up NAL9602
2024-08-21T16:15:27.971Z,1724256927.971 [NAL9602](INFO): NAL9602 initialized
2024-08-21T16:15:36.078Z,1724256936.078 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2024-08-21T16:15:36.078Z,1724256936.078 [RDI_Pathfinder] Communications Fault, FailCount= 2
2024-08-21T16:15:36.078Z,1724256936.078 [RDI_Pathfinder](ERROR): Communications Fault
2024-08-21T16:15:36.101Z,1724256936.101 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2024-08-21T16:15:36.527Z,1724256936.527 [RDI_Pathfinder](INFO): Powering down
2024-08-21T16:15:37.288Z,1724256937.288 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2024-08-21T16:15:37.288Z,1724256937.288 [RDI_Pathfinder] No Fault, FailCount= 2
2024-08-21T16:15:37.669Z,1724256937.669 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2024-08-21T16:16:05.564Z,1724256965.564 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.00, 0.00, 0.00, 0.00
2024-08-21T16:16:06.369Z,1724256966.369 [NAL9602](INFO): SBD MO Status=2, MOMSN=46743, MT Status=2, MTMSN=0
2024-08-21T16:16:06.370Z,1724256966.370 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-08-21T16:16:08.820Z,1724256968.820 [SBIT](IMPORTANT): Beginning Startup BIT
2024-08-21T16:16:08.824Z,1724256968.824 [CBIT](IMPORTANT): Beginning ground fault scan
2024-08-21T16:16:14.853Z,1724256974.853 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,2408210956455+20.6, 0.0,1523.1, 0
2024-08-21T16:16:19.778Z,1724256979.778 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009363
CHAN A1 (24V): -0.028042
CHAN A2 (12V): -0.007050
CHAN A3 (5V): -0.002411
CHAN B0 (3.3V): 0.000290
CHAN B1 (3.15aV): 0.000299
CHAN B2 (3.15bV): 0.000246
CHAN B3 (GND): 0.002437
OPEN: 0.004647
Full Scale: +/- 1 mA
2024-08-21T16:16:24.557Z,1724256984.557 [NAL9602](INFO): SBD MO Status=2, MOMSN=46743, MT Status=2, MTMSN=0
2024-08-21T16:16:24.557Z,1724256984.557 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-08-21T16:16:33.019Z,1724256993.019 [NAL9602](INFO): SBD MO Status=0, MOMSN=46743, MT Status=0, MTMSN=0
2024-08-21T16:16:33.019Z,1724256993.019 [NAL9602](INFO): No messages in MT queue
2024-08-21T16:16:51.623Z,1724257011.623 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161650.00,A,4059.02549,N,07034.22650,W,5.229,100.61,210824,,,A*7F
2024-08-21T16:16:51.626Z,1724257011.626 [NAL9602](INFO): GPS fix at 20240821T161650: (40.983758, -70.570442)
2024-08-21T16:17:03.007Z,1724257023.007 [SBIT](IMPORTANT): SBIT PASSED
2024-08-21T16:17:03.007Z,1724257023.007 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2024-08-21T16:17:03.008Z,1724257023.008 [SBIT](IMPORTANT): CBIT.abortDepth=100 meter;
2024-08-21T16:17:03.008Z,1724257023.008 [SBIT](IMPORTANT): CBIT.stopDepth=80 meter;
2024-08-21T16:17:03.008Z,1724257023.008 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.050000 practical_salinity_unit;
2024-08-21T16:17:03.008Z,1724257023.008 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.500000 celsius;
2024-08-21T16:17:03.009Z,1724257023.009 [SBIT](IMPORTANT): RDI_PathfinderUp.loadAtStartup=0 bool;
2024-08-21T16:17:03.009Z,1724257023.009 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=265.936319 cubic_centimeter;
2024-08-21T16:17:03.009Z,1724257023.009 [SBIT](IMPORTANT): VerticalControl.massDefault=14.963524 millimeter;
2024-08-21T16:17:03.478Z,1724257023.478 [MissionManager](IMPORTANT): Started mission Startup
2024-08-21T16:17:03.479Z,1724257023.479 [Startup] Running Loop=1
2024-08-21T16:17:03.479Z,1724257023.479 [Startup](DEBUG): Aggregate::initialize Startup
2024-08-21T16:17:03.479Z,1724257023.479 [Startup:A.GoToSurface] Running Loop=1
2024-08-21T16:17:03.479Z,1724257023.479 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-08-21T16:17:03.479Z,1724257023.479 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-08-21T16:17:03.480Z,1724257023.480 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-08-21T16:17:03.480Z,1724257023.480 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-08-21T16:17:03.481Z,1724257023.481 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-08-21T16:17:03.481Z,1724257023.481 [Startup:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-08-21T16:17:03.481Z,1724257023.481 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-08-21T16:17:03.487Z,1724257023.487 [Startup:StartupSatComms] Running Loop=1
2024-08-21T16:17:03.487Z,1724257023.487 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2024-08-21T16:17:03.487Z,1724257023.487 [Startup:StartupSatComms:A] Running Loop=1
2024-08-21T16:17:03.899Z,1724257023.899 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2024-08-21T16:17:05.345Z,1724257025.345 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161704.00,A,4059.02171,N,07034.20112,W,4.821,103.38,210824,,,A*7F
2024-08-21T16:17:05.347Z,1724257025.347 [NAL9602](INFO): GPS fix at 20240821T161704: (40.983695, -70.570019)
2024-08-21T16:17:05.363Z,1724257025.363 [Startup:StartupSatComms:A] Stopped
2024-08-21T16:17:05.363Z,1724257025.363 [Startup:StartupSatComms:B] Running Loop=1
2024-08-21T16:17:05.819Z,1724257025.819 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-08-21T16:17:25.313Z,1724257045.313 [NAL9602](INFO): SBD MO Status=1, MOMSN=46744, MT Status=0, MTMSN=0
2024-08-21T16:17:25.371Z,1724257045.371 [NAL9602](INFO): Sent 63 bytes from file Logs/20240821T124245/Courier0115.lzma
2024-08-21T16:17:25.371Z,1724257045.371 [NAL9602](INFO): Packets left to send: 0
2024-08-21T16:17:35.941Z,1724257055.941 [NAL9602](INFO): SBD MO Status=1, MOMSN=46745, MT Status=0, MTMSN=0
2024-08-21T16:17:35.999Z,1724257055.999 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Courier0000.lzma
2024-08-21T16:17:35.999Z,1724257055.999 [NAL9602](INFO): Packets left to send: 1
2024-08-21T16:17:46.571Z,1724257066.571 [NAL9602](INFO): SBD MO Status=1, MOMSN=46746, MT Status=0, MTMSN=0
2024-08-21T16:17:46.619Z,1724257066.619 [NAL9602](INFO): Sent 68 bytes from file Logs/20240821T161436/Courier0000.lzma
2024-08-21T16:17:46.619Z,1724257066.619 [NAL9602](INFO): Packets left to send: 0
2024-08-21T16:17:55.849Z,1724257075.849 [NAL9602](INFO): SBD MO Status=1, MOMSN=46747, MT Status=0, MTMSN=0
2024-08-21T16:17:55.907Z,1724257075.907 [NAL9602](INFO): Sent 146 bytes from file Logs/20240821T124245/Express0116.lzma
2024-08-21T16:17:55.907Z,1724257075.907 [NAL9602](INFO): Packets left to send: 0
2024-08-21T16:18:00.352Z,1724257080.352 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing
2024-08-21T16:18:00.352Z,1724257080.352 [RDI_Pathfinder] Communications Fault, FailCount= 1
2024-08-21T16:18:00.352Z,1724257080.352 [RDI_Pathfinder](ERROR): Communications Fault
2024-08-21T16:18:00.378Z,1724257080.378 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2024-08-21T16:18:00.819Z,1724257080.819 [RDI_Pathfinder](INFO): Powering down
2024-08-21T16:18:01.571Z,1724257081.571 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2024-08-21T16:18:01.571Z,1724257081.571 [RDI_Pathfinder] No Fault, FailCount= 1
2024-08-21T16:18:01.937Z,1724257081.937 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2024-08-21T16:18:05.630Z,1724257085.630 [Startup:StartupSatComms:B](INFO): Timed out from 2024-08-21T16:17:05.4Z
2024-08-21T16:18:05.630Z,1724257085.630 [Startup:StartupSatComms:B] Stopped
2024-08-21T16:18:05.630Z,1724257085.630 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2024-08-21T16:18:05.630Z,1724257085.630 [Startup:StartupSatComms] Stopped
2024-08-21T16:18:05.630Z,1724257085.630 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2024-08-21T16:18:05.631Z,1724257085.631 [Startup](INFO): Completed Startup
2024-08-21T16:18:05.631Z,1724257085.631 [MissionManager](INFO): Startup is completed.
2024-08-21T16:18:05.632Z,1724257085.632 [MissionManager](INFO): Uninitializing Mission Startup
2024-08-21T16:18:05.632Z,1724257085.632 [Startup] Stopped
2024-08-21T16:18:05.632Z,1724257085.632 [Startup](DEBUG): Aggregate::uninitialize Startup
2024-08-21T16:18:05.632Z,1724257085.632 [Startup:A.GoToSurface] Stopped
2024-08-21T16:18:05.632Z,1724257085.632 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2024-08-21T16:18:05.996Z,1724257085.996 [MissionManager](IMPORTANT): Started mission Default
2024-08-21T16:18:05.997Z,1724257085.997 [Default] Running Loop=1
2024-08-21T16:18:05.997Z,1724257085.997 [Default](DEBUG): Aggregate::initialize Default
2024-08-21T16:18:05.997Z,1724257085.997 [Default:B.GoToSurface] Running Loop=1
2024-08-21T16:18:05.997Z,1724257085.997 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2024-08-21T16:18:05.997Z,1724257085.997 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2024-08-21T16:18:05.997Z,1724257085.997 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2024-08-21T16:18:05.998Z,1724257085.998 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2024-08-21T16:18:05.998Z,1724257085.998 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2024-08-21T16:18:05.998Z,1724257085.998 [Default:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2024-08-21T16:18:05.999Z,1724257085.999 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2024-08-21T16:18:05.999Z,1724257085.999 [Default:A.Wait] Running Loop=1
2024-08-21T16:18:05.999Z,1724257085.999 [Default:A.Wait](DEBUG): Initialize Wait Component.
2024-08-21T16:18:07.193Z,1724257087.193 [NAL9602](INFO): SBD MO Status=1, MOMSN=46748, MT Status=0, MTMSN=0
2024-08-21T16:18:07.255Z,1724257087.255 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Express0001.lzma
2024-08-21T16:18:07.255Z,1724257087.255 [NAL9602](INFO): Packets left to send: 5
2024-08-21T16:18:19.324Z,1724257099.324 [Default:A.Wait](INFO): Done Waiting.
2024-08-21T16:18:19.324Z,1724257099.324 [Default:A.Wait] Stopped
2024-08-21T16:18:19.324Z,1724257099.324 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2024-08-21T16:18:19.775Z,1724257099.775 [Default:CheckIn] Running Loop=1
2024-08-21T16:18:19.776Z,1724257099.776 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-08-21T16:18:19.776Z,1724257099.776 [Default:CheckIn:Read_GPS] Running Loop=1
2024-08-21T16:18:20.162Z,1724257100.162 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2024-08-21T16:18:21.746Z,1724257101.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161821.00,A,4058.99841,N,07034.10228,W,2.449,273.40,210824,,,A*78
2024-08-21T16:18:21.748Z,1724257101.748 [NAL9602](INFO): GPS fix at 20240821T161821: (40.983307, -70.568371)
2024-08-21T16:18:21.775Z,1724257101.775 [Default:CheckIn:Read_GPS] Stopped
2024-08-21T16:18:21.775Z,1724257101.775 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-08-21T16:18:22.192Z,1724257102.192 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2024-08-21T16:18:44.077Z,1724257124.077 [NAL9602](INFO): SBD MO Status=1, MOMSN=46749, MT Status=0, MTMSN=0
2024-08-21T16:18:44.139Z,1724257124.139 [NAL9602](INFO): Sent 72 bytes from file Logs/20240821T161436/Courier0004.lzma
2024-08-21T16:18:44.139Z,1724257124.139 [NAL9602](INFO): Packets left to send: 0
2024-08-21T16:18:53.417Z,1724257133.417 [NAL9602](INFO): SBD MO Status=1, MOMSN=46750, MT Status=0, MTMSN=0
2024-08-21T16:18:53.467Z,1724257133.467 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Express0001.lzma
2024-08-21T16:18:53.467Z,1724257133.467 [NAL9602](INFO): Packets left to send: 4
2024-08-21T16:19:03.217Z,1724257143.217 [NAL9602](INFO): SBD MO Status=1, MOMSN=46751, MT Status=0, MTMSN=0
2024-08-21T16:19:03.283Z,1724257143.283 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Express0001.lzma
2024-08-21T16:19:03.283Z,1724257143.283 [NAL9602](INFO): Packets left to send: 3
2024-08-21T16:19:10.420Z,1724257150.420 [NAL9602](INFO): SBD MO Status=1, MOMSN=46752, MT Status=0, MTMSN=0
2024-08-21T16:19:10.475Z,1724257150.475 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Express0001.lzma
2024-08-21T16:19:10.475Z,1724257150.475 [NAL9602](INFO): Packets left to send: 2
2024-08-21T16:19:20.489Z,1724257160.489 [NAL9602](INFO): SBD MO Status=1, MOMSN=46753, MT Status=0, MTMSN=0
2024-08-21T16:19:20.543Z,1724257160.543 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Express0001.lzma
2024-08-21T16:19:20.543Z,1724257160.543 [NAL9602](INFO): Packets left to send: 1
2024-08-21T16:19:28.664Z,1724257168.664 [NAL9602](INFO): SBD MO Status=1, MOMSN=46754, MT Status=0, MTMSN=0
2024-08-21T16:19:28.731Z,1724257168.731 [NAL9602](INFO): Sent 51 bytes from file Logs/20240821T161436/Express0001.lzma
2024-08-21T16:19:28.731Z,1724257168.731 [NAL9602](INFO): Packets left to send: 0
2024-08-21T16:19:36.269Z,1724257176.269 [NAL9602](INFO): SBD MO Status=1, MOMSN=46755, MT Status=0, MTMSN=0
2024-08-21T16:19:36.319Z,1724257176.319 [NAL9602](INFO): Sent 138 bytes from file Logs/20240821T161436/Express0005.lzma
2024-08-21T16:19:36.319Z,1724257176.319 [NAL9602](INFO): Packets left to send: 0
2024-08-21T16:19:45.505Z,1724257185.505 [NAL9602](INFO): SBD MO Status=0, MOMSN=46756, MT Status=0, MTMSN=0
2024-08-21T16:19:45.583Z,1724257185.583 [Default:CheckIn:Read_Iridium] Stopped
2024-08-21T16:19:45.583Z,1724257185.583 [Default:CheckIn:C.Wait] Running Loop=1
2024-08-21T16:19:45.583Z,1724257185.583 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-08-21T16:19:50.746Z,1724257190.746 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-31 in onboard configuration file).
2024-08-21T16:20:16.261Z,1724257216.261 [NAL9602](INFO): Not Powering down - fast GPS
2024-08-21T16:21:33.433Z,1724257293.433 [RDI_Pathfinder](ERROR): only read 0 of 4 data items for bottom velocity. Device response is::BS-32768,-32768,V
2024-08-21T16:21:35.130Z,1724257295.130 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout
2024-08-21T16:21:35.130Z,1724257295.130 [RDI_Pathfinder] Communications Fault, FailCount= 1
2024-08-21T16:21:35.131Z,1724257295.131 [RDI_Pathfinder](ERROR): Communications Fault
2024-08-21T16:21:35.173Z,1724257295.173 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder
2024-08-21T16:21:35.511Z,1724257295.511 [RDI_Pathfinder](INFO): Powering down
2024-08-21T16:21:36.272Z,1724257296.272 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder
2024-08-21T16:21:36.272Z,1724257296.272 [RDI_Pathfinder] No Fault, FailCount= 1
2024-08-21T16:21:36.631Z,1724257296.631 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2024-08-21T16:22:17.437Z,1724257337.437 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2024-08-21T16:22:17.441Z,1724257337.441 [BPC1](INFO): Received data from all battery sticks.
2024-08-21T16:22:20.563Z,1724257340.563 [CommandExec](IMPORTANT): got command ibit
2024-08-21T16:22:20.730Z,1724257340.730 [IBIT](IMPORTANT): Beginning Initiated BIT
2024-08-21T16:22:20.730Z,1724257340.730 [IBIT](IMPORTANT): Beginning control surface checks.
2024-08-21T16:22:20.733Z,1724257340.733 [CBIT](IMPORTANT): Beginning ground fault scan
2024-08-21T16:22:22.292Z,1724257342.292 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162221.00,A,4059.09062,N,07034.44592,W,4.024,284.75,210824,,,A*70
2024-08-21T16:22:22.294Z,1724257342.294 [NAL9602](INFO): GPS fix at 20240821T162221: (40.984844, -70.574099)
2024-08-21T16:22:31.616Z,1724257351.616 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009964
CHAN A1 (24V): -0.027667
CHAN A2 (12V): -0.007068
CHAN A3 (5V): -0.001669
CHAN B0 (3.3V): 0.000643
CHAN B1 (3.15aV): 0.000127
CHAN B2 (3.15bV): 0.000184
CHAN B3 (GND): 0.002277
OPEN: 0.004708
Full Scale: +/- 1 mA
2024-08-21T16:22:40.464Z,1724257360.464 [NAL9602](INFO): SBD MO Status=0, MOMSN=46757, MT Status=0, MTMSN=0
2024-08-21T16:22:40.464Z,1724257360.464 [NAL9602](INFO): No messages in MT queue
2024-08-21T16:22:41.687Z,1724257361.687 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162241.00,A,4059.09849,N,07034.47526,W,4.646,287.47,210824,,,A*7B
2024-08-21T16:22:41.689Z,1724257361.689 [NAL9602](INFO): GPS fix at 20240821T162241: (40.984975, -70.574588)
2024-08-21T16:22:44.909Z,1724257364.909 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162244.00,A,4059.09944,N,07034.47995,W,4.762,288.39,210824,,,A*77
2024-08-21T16:22:44.911Z,1724257364.911 [NAL9602](INFO): GPS fix at 20240821T162244: (40.984991, -70.574666)
2024-08-21T16:22:47.765Z,1724257367.765 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162247.00,A,4059.10058,N,07034.48416,W,3.829,291.13,210824,,,A*76
2024-08-21T16:22:47.768Z,1724257367.768 [NAL9602](INFO): GPS fix at 20240821T162247: (40.985010, -70.574736)
2024-08-21T16:22:50.978Z,1724257370.978 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162250.00,A,4059.10133,N,07034.48821,W,3.907,283.50,210824,,,A*7D
2024-08-21T16:22:50.980Z,1724257370.980 [NAL9602](INFO): GPS fix at 20240821T162250: (40.985022, -70.574804)
2024-08-21T16:22:53.194Z,1724257373.194 [CommandExec](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 300 revolution_per_minute
2024-08-21T16:22:53.199Z,1724257373.199 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread.
2024-08-21T16:22:53.551Z,1724257373.551 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DepthKeller33X,DropWeight,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,PAR_Licor,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2024-08-21T16:22:53.797Z,1724257373.797 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162253.00,A,4059.10268,N,07034.49264,W,4.529,292.06,210824,,,A*7D
2024-08-21T16:22:53.800Z,1724257373.800 [NAL9602](INFO): GPS fix at 20240821T162253: (40.985045, -70.574877)
2024-08-21T16:22:57.058Z,1724257377.058 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162256.00,A,4059.10338,N,07034.49597,W,3.382,290.34,210824,,,A*74
2024-08-21T16:22:57.060Z,1724257377.060 [NAL9602](INFO): GPS fix at 20240821T162256: (40.985056, -70.574933)
2024-08-21T16:22:59.873Z,1724257379.873 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162259.00,A,4059.10457,N,07034.49965,W,3.732,291.38,210824,,,A*76
2024-08-21T16:22:59.876Z,1724257379.876 [NAL9602](INFO): GPS fix at 20240821T162259: (40.985076, -70.574994)
2024-08-21T16:23:02.685Z,1724257382.685 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162302.00,A,4059.10581,N,07034.50376,W,4.199,292.05,210824,,,A*7E
2024-08-21T16:23:02.687Z,1724257382.687 [NAL9602](INFO): GPS fix at 20240821T162302: (40.985097, -70.575063)
2024-08-21T16:23:05.916Z,1724257385.916 [CommandExec](IMPORTANT): got command maintain clear
2024-08-21T16:23:05.941Z,1724257385.941 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162305.00,A,4059.10728,N,07034.50878,W,4.568,288.75,210824,,,A*7B
2024-08-21T16:23:05.944Z,1724257385.944 [NAL9602](INFO): GPS fix at 20240821T162305: (40.985121, -70.575146)
2024-08-21T16:23:06.092Z,1724257386.092 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DepthKeller33X,DropWeight,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,PAR_Licor,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2024-08-21T16:23:06.884Z,1724257386.884 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 40.985123 Longitude: -70.575150
2024-08-21T16:23:07.207Z,1724257387.207 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.492001
2024-08-21T16:23:07.207Z,1724257387.207 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2024-08-21T16:23:07.207Z,1724257387.207 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2024-08-21T16:23:07.577Z,1724257387.577 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2024-08-21T16:23:07.578Z,1724257387.578 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2024-08-21T16:23:07.578Z,1724257387.578 [IBIT](IMPORTANT): Pressure:6.015908 PSI
2024-08-21T16:23:07.578Z,1724257387.578 [IBIT](IMPORTANT): Humidity:10.499329 %
2024-08-21T16:23:07.957Z,1724257387.957 [IBIT](IMPORTANT): Vehicle Pitch:1.566754 degrees
2024-08-21T16:23:07.958Z,1724257387.958 [IBIT](IMPORTANT): Vehicle Roll:7.622557 degrees
2024-08-21T16:23:07.958Z,1724257387.958 [IBIT](IMPORTANT): Vehicle Heading:286.355011 degrees
2024-08-21T16:23:08.361Z,1724257388.361 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2024-08-21T16:23:08.361Z,1724257388.361 [IBIT](IMPORTANT): buoyancyNeutral: 265.936310 cc
2024-08-21T16:23:08.361Z,1724257388.361 [IBIT](IMPORTANT): massDefault: 1.496352 cm
2024-08-21T16:23:08.362Z,1724257388.362 [IBIT](IMPORTANT): stopDepth: 80.000000 m
2024-08-21T16:23:08.362Z,1724257388.362 [IBIT](IMPORTANT): abortDepth: 100.000000 m
2024-08-21T16:23:08.362Z,1724257388.362 [IBIT](IMPORTANT): IBIT PASSED
2024-08-21T16:23:18.815Z,1724257398.815 [CommandExec](IMPORTANT): got command failComponent
2024-08-21T16:23:18.815Z,1724257398.815 [CommandExec](IMPORTANT): Failed components:
2024-08-21T16:23:18.815Z,1724257398.815 [CommandExec](IMPORTANT): No failed Components.
2024-08-21T16:23:38.257Z,1724257418.257 [NAL9602](INFO): Not Powering down - fast GPS
2024-08-21T16:24:46.152Z,1724257486.152 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-08-21T16:24:46.152Z,1724257486.152 [Default:CheckIn:C.Wait] Stopped
2024-08-21T16:24:46.152Z,1724257486.152 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-08-21T16:24:46.152Z,1724257486.152 [Default:CheckIn:D] Running Loop=1
2024-08-21T16:24:46.564Z,1724257486.564 [Default:CheckIn:D] Stopped
2024-08-21T16:24:46.564Z,1724257486.564 [Default:CheckIn:E] Running Loop=1
2024-08-21T16:24:46.959Z,1724257486.959 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.676119 min
2024-08-21T16:24:46.959Z,1724257486.959 [Default:CheckIn:E] Stopped
2024-08-21T16:24:46.959Z,1724257486.959 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-08-21T16:24:46.959Z,1724257486.959 [Default:CheckIn] Stopped
2024-08-21T16:24:46.960Z,1724257486.960 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-08-21T16:24:46.960Z,1724257486.960 [Default:CheckIn](INFO): Running loop #2
2024-08-21T16:24:46.960Z,1724257486.960 [Default:CheckIn] Running Loop=2
2024-08-21T16:24:46.960Z,1724257486.960 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-08-21T16:24:46.960Z,1724257486.960 [Default:CheckIn:Read_GPS] Running Loop=1
2024-08-21T16:24:48.936Z,1724257488.936 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162448.00,A,4059.14940,N,07034.52958,W,5.968,74.75,210824,,,A*4C
2024-08-21T16:24:48.938Z,1724257488.938 [NAL9602](INFO): GPS fix at 20240821T162448: (40.985823, -70.575493)
2024-08-21T16:24:48.949Z,1724257488.949 [Default:CheckIn:Read_GPS] Stopped
2024-08-21T16:24:48.949Z,1724257488.949 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-08-21T16:25:12.469Z,1724257512.469 [NAL9602](INFO): SBD MO Status=1, MOMSN=46758, MT Status=0, MTMSN=0
2024-08-21T16:25:12.531Z,1724257512.531 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Courier0007.lzma
2024-08-21T16:25:12.531Z,1724257512.531 [NAL9602](INFO): Packets left to send: 1
2024-08-21T16:25:21.501Z,1724257521.501 [NAL9602](INFO): SBD MO Status=1, MOMSN=46759, MT Status=0, MTMSN=0
2024-08-21T16:25:21.551Z,1724257521.551 [NAL9602](INFO): Sent 18 bytes from file Logs/20240821T161436/Courier0007.lzma
2024-08-21T16:25:21.551Z,1724257521.551 [NAL9602](INFO): Packets left to send: 0
2024-08-21T16:25:30.392Z,1724257530.392 [NAL9602](INFO): SBD MO Status=1, MOMSN=46760, MT Status=0, MTMSN=0
2024-08-21T16:25:30.440Z,1724257530.440 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Express0008.lzma
2024-08-21T16:25:30.441Z,1724257530.441 [NAL9602](INFO): Packets left to send: 5
2024-08-21T16:25:41.268Z,1724257541.268 [NAL9602](INFO): SBD MO Status=1, MOMSN=46761, MT Status=0, MTMSN=0
2024-08-21T16:25:41.319Z,1724257541.319 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Express0008.lzma
2024-08-21T16:25:41.319Z,1724257541.319 [NAL9602](INFO): Packets left to send: 4
2024-08-21T16:25:52.511Z,1724257552.511 [NAL9602](INFO): SBD MO Status=1, MOMSN=46762, MT Status=0, MTMSN=0
2024-08-21T16:25:52.563Z,1724257552.563 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Express0008.lzma
2024-08-21T16:25:52.563Z,1724257552.563 [NAL9602](INFO): Packets left to send: 3
2024-08-21T16:26:04.920Z,1724257564.920 [NAL9602](INFO): SBD MO Status=1, MOMSN=46763, MT Status=0, MTMSN=0
2024-08-21T16:26:04.965Z,1724257564.965 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Express0008.lzma
2024-08-21T16:26:04.966Z,1724257564.966 [NAL9602](INFO): Packets left to send: 2
2024-08-21T16:26:16.389Z,1724257576.389 [NAL9602](INFO): SBD MO Status=1, MOMSN=46764, MT Status=0, MTMSN=0
2024-08-21T16:26:16.439Z,1724257576.439 [NAL9602](INFO): Sent 184 bytes from file Logs/20240821T161436/Express0008.lzma
2024-08-21T16:26:16.439Z,1724257576.439 [NAL9602](INFO): Packets left to send: 1
2024-08-21T16:26:24.001Z,1724257584.001 [NAL9602](INFO): SBD MO Status=1, MOMSN=46765, MT Status=0, MTMSN=0
2024-08-21T16:26:24.059Z,1724257584.059 [NAL9602](INFO): Sent 15 bytes from file Logs/20240821T161436/Express0008.lzma
2024-08-21T16:26:24.059Z,1724257584.059 [NAL9602](INFO): Packets left to send: 0
2024-08-21T16:26:41.163Z,1724257601.163 [NAL9602](INFO): SBD MO Status=2, MOMSN=46766, MT Status=2, MTMSN=0
2024-08-21T16:26:41.163Z,1724257601.163 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-08-21T16:26:57.229Z,1724257617.229 [NAL9602](INFO): SBD MO Status=2, MOMSN=46766, MT Status=2, MTMSN=0
2024-08-21T16:26:57.229Z,1724257617.229 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2024-08-21T16:27:16.173Z,1724257636.173 [NAL9602](INFO): SBD MO Status=0, MOMSN=46766, MT Status=0, MTMSN=0
2024-08-21T16:27:16.259Z,1724257636.259 [Default:CheckIn:Read_Iridium] Stopped
2024-08-21T16:27:16.259Z,1724257636.259 [Default:CheckIn:C.Wait] Running Loop=1
2024-08-21T16:27:16.259Z,1724257636.259 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2024-08-21T16:27:46.860Z,1724257666.860 [NAL9602](INFO): Not Powering down - fast GPS
2024-08-21T16:29:20.819Z,1724257760.819 [CommandExec](IMPORTANT): got command get height_above_sea_floor
2024-08-21T16:29:20.820Z,1724257760.820 [CommandExec](IMPORTANT): height_above_sea_floor 48.119999 m
2024-08-21T16:32:16.794Z,1724257936.794 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2024-08-21T16:32:16.794Z,1724257936.794 [Default:CheckIn:C.Wait] Stopped
2024-08-21T16:32:16.794Z,1724257936.794 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2024-08-21T16:32:16.795Z,1724257936.795 [Default:CheckIn:D] Running Loop=1
2024-08-21T16:32:17.159Z,1724257937.159 [Default:CheckIn:D] Stopped
2024-08-21T16:32:17.159Z,1724257937.159 [Default:CheckIn:E] Running Loop=1
2024-08-21T16:32:17.556Z,1724257937.556 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.186039 min
2024-08-21T16:32:17.556Z,1724257937.556 [Default:CheckIn:E] Stopped
2024-08-21T16:32:17.557Z,1724257937.557 [Default:CheckIn](INFO): Completed Default:CheckIn
2024-08-21T16:32:17.557Z,1724257937.557 [Default:CheckIn] Stopped
2024-08-21T16:32:17.557Z,1724257937.557 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2024-08-21T16:32:17.557Z,1724257937.557 [Default:CheckIn](INFO): Running loop #3
2024-08-21T16:32:17.557Z,1724257937.557 [Default:CheckIn] Running Loop=3
2024-08-21T16:32:17.557Z,1724257937.557 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2024-08-21T16:32:17.557Z,1724257937.557 [Default:CheckIn:Read_GPS] Running Loop=1
2024-08-21T16:32:19.568Z,1724257939.568 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163218.00,A,4059.24153,N,07034.08119,W,0.816,84.68,210824,,,A*4B
2024-08-21T16:32:19.571Z,1724257939.571 [NAL9602](INFO): GPS fix at 20240821T163218: (40.987359, -70.568020)
2024-08-21T16:32:19.582Z,1724257939.582 [Default:CheckIn:Read_GPS] Stopped
2024-08-21T16:32:19.582Z,1724257939.582 [Default:CheckIn:Read_Iridium] Running Loop=1
2024-08-21T16:32:36.681Z,1724257956.681 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=46767, MT Status=1, MTMSN=1772
2024-08-21T16:32:36.735Z,1724257956.735 [NAL9602](INFO): Sent 78 bytes from file Logs/20240821T161436/Courier0010.lzma
2024-08-21T16:32:36.735Z,1724257956.735 [NAL9602](INFO): Packets left to send: 0
2024-08-21T16:32:37.167Z,1724257957.167 [NAL9602](INFO): Received command: restart logs