2022-01-23T20:11:24.597Z,1642968684.597 [Supervisor](DEBUG): Initializing supervisor.
2022-01-23T20:11:24.602Z,1642968684.602 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-01-23T20:11:24.602Z,1642968684.602 [SyncHandler](INFO): Protected caller Thread ID is 1986
2022-01-23T20:11:24.602Z,1642968684.602 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-01-23T20:11:24.603Z,1642968684.603 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-01-23T20:11:24.604Z,1642968684.604 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1987
2022-01-23T20:11:24.608Z,1642968684.608 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-01-23T20:11:24.626Z,1642968684.626 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-01-23T20:11:24.627Z,1642968684.627 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-01-23T20:11:24.627Z,1642968684.627 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1988
2022-01-23T20:11:24.631Z,1642968684.631 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-01-23T20:11:24.632Z,1642968684.632 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-01-23T20:11:24.633Z,1642968684.633 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1989
2022-01-23T20:11:24.635Z,1642968684.635 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-01-23T20:11:24.636Z,1642968684.636 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-01-23T20:11:24.636Z,1642968684.636 [logger ThreadHandler](INFO): Protected caller Thread ID is 1990
2022-01-23T20:11:24.640Z,1642968684.640 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-01-23T20:11:24.640Z,1642968684.640 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-01-23T20:11:24.642Z,1642968684.642 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-01-23T20:11:25.088Z,1642968685.088 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-01-23T20:11:25.089Z,1642968685.089 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-01-23T20:11:25.169Z,1642968685.169 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-01-23T20:11:25.509Z,1642968685.509 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-01-23T20:11:25.510Z,1642968685.510 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-01-23T20:11:25.619Z,1642968685.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-01-23T20:11:25.620Z,1642968685.620 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-01-23T20:11:25.829Z,1642968685.829 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-01-23T20:11:25.829Z,1642968685.829 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-01-23T20:11:26.354Z,1642968686.354 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-01-23T20:11:26.355Z,1642968686.355 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-01-23T20:11:26.629Z,1642968686.629 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-01-23T20:11:26.630Z,1642968686.630 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-01-23T20:11:26.780Z,1642968686.780 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-01-23T20:11:26.781Z,1642968686.781 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-01-23T20:11:26.980Z,1642968686.980 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-01-23T20:11:26.981Z,1642968686.981 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-01-23T20:11:27.081Z,1642968687.081 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-01-23T20:11:27.082Z,1642968687.082 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-01-23T20:11:27.310Z,1642968687.310 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-01-23T20:11:27.311Z,1642968687.311 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-01-23T20:11:28.162Z,1642968688.162 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-01-23T20:11:28.162Z,1642968688.162 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-01-23T20:11:28.329Z,1642968688.329 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-01-23T20:11:28.463Z,1642968688.463 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-01-23T20:11:28.463Z,1642968688.463 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-01-23T20:11:29.179Z,1642968689.179 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-01-23T20:11:29.180Z,1642968689.180 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-01-23T20:11:29.551Z,1642968689.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-01-23T20:11:29.553Z,1642968689.553 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2022-01-23T20:11:29.554Z,1642968689.554 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2022-01-23T20:11:29.759Z,1642968689.759 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2022-01-23T20:11:29.862Z,1642968689.862 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2022-01-23T20:11:29.962Z,1642968689.962 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2022-01-23T20:11:30.064Z,1642968690.064 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2022-01-23T20:11:30.326Z,1642968690.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-01-23T20:11:30.326Z,1642968690.326 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2022-01-23T20:11:30.413Z,1642968690.413 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2022-01-23T20:11:30.518Z,1642968690.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2022-01-23T20:11:30.646Z,1642968690.646 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2022-01-23T20:11:30.762Z,1642968690.762 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2022-01-23T20:11:30.848Z,1642968690.848 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2022-01-23T20:11:30.935Z,1642968690.935 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2022-01-23T20:11:31.050Z,1642968691.050 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2022-01-23T20:11:31.150Z,1642968691.150 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2022-01-23T20:11:31.366Z,1642968691.366 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2022-01-23T20:11:31.535Z,1642968691.535 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-01-23T20:11:31.551Z,1642968691.551 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-01-23T20:11:31.971Z,1642968691.971 [AHRS_M2] Loaded
2022-01-23T20:11:31.971Z,1642968691.971 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-01-23T20:11:32.005Z,1642968692.005 [BackseatComponent] Loaded
2022-01-23T20:11:32.005Z,1642968692.005 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-01-23T20:11:32.006Z,1642968692.006 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 407DF4E0
2022-01-23T20:11:32.006Z,1642968692.006 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 2084
2022-01-23T20:11:32.009Z,1642968692.009 [LcmUniversalReporter] Loaded
2022-01-23T20:11:32.009Z,1642968692.009 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-01-23T20:11:32.770Z,1642968692.770 [BPC1] Loaded
2022-01-23T20:11:32.771Z,1642968692.771 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-01-23T20:11:32.790Z,1642968692.790 [Depth_Keller] Loaded
2022-01-23T20:11:32.790Z,1642968692.790 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-01-23T20:11:32.795Z,1642968692.795 [DropWeight] Loaded
2022-01-23T20:11:32.795Z,1642968692.795 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-01-23T20:11:32.852Z,1642968692.852 [NAL9602] Loaded
2022-01-23T20:11:32.852Z,1642968692.852 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-01-23T20:11:32.880Z,1642968692.880 [Onboard] Loaded
2022-01-23T20:11:32.880Z,1642968692.880 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-01-23T20:11:32.881Z,1642968692.881 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4080F4E0
2022-01-23T20:11:32.882Z,1642968692.882 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2085
2022-01-23T20:11:32.887Z,1642968692.887 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2022-01-23T20:11:32.898Z,1642968692.898 [PowerOnly] Loaded
2022-01-23T20:11:32.898Z,1642968692.898 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2022-01-23T20:11:32.909Z,1642968692.909 [Power24vConverter] Loaded
2022-01-23T20:11:32.909Z,1642968692.909 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-01-23T20:11:32.910Z,1642968692.910 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-01-23T20:11:32.910Z,1642968692.910 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-01-23T20:11:32.921Z,1642968692.921 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-01-23T20:11:32.922Z,1642968692.922 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-01-23T20:11:33.030Z,1642968693.030 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-01-23T20:11:33.031Z,1642968693.031 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-01-23T20:11:33.059Z,1642968693.059 [LBLNavigation] Loaded
2022-01-23T20:11:33.059Z,1642968693.059 [ComponentRegistry](DEBUG): SyncComponent "LBLNavigation" handled in the control thread.
2022-01-23T20:11:33.072Z,1642968693.072 [NavChart] Loaded
2022-01-23T20:11:33.072Z,1642968693.072 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-01-23T20:11:33.078Z,1642968693.078 [UniversalFixResidualReporter] Loaded
2022-01-23T20:11:33.078Z,1642968693.078 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-01-23T20:11:33.088Z,1642968693.088 [WorkSite] Loaded
2022-01-23T20:11:33.089Z,1642968693.089 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2022-01-23T20:11:33.089Z,1642968693.089 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-01-23T20:11:33.089Z,1642968693.089 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-01-23T20:11:33.184Z,1642968693.184 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-01-23T20:11:33.185Z,1642968693.185 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-01-23T20:11:33.659Z,1642968693.659 [BuoyancyServo] Loaded
2022-01-23T20:11:33.660Z,1642968693.660 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-01-23T20:11:33.742Z,1642968693.742 [ElevatorServo] Loaded
2022-01-23T20:11:33.742Z,1642968693.742 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-01-23T20:11:33.797Z,1642968693.797 [MassServo] Loaded
2022-01-23T20:11:33.797Z,1642968693.797 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-01-23T20:11:33.855Z,1642968693.855 [RudderServo] Loaded
2022-01-23T20:11:33.855Z,1642968693.855 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-01-23T20:11:33.871Z,1642968693.871 [ThrusterHE] Loaded
2022-01-23T20:11:33.871Z,1642968693.871 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-01-23T20:11:33.872Z,1642968693.872 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-01-23T20:11:33.872Z,1642968693.872 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-01-23T20:11:34.067Z,1642968694.067 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-01-23T20:11:34.067Z,1642968694.067 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-01-23T20:11:34.386Z,1642968694.386 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-01-23T20:11:34.386Z,1642968694.386 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-01-23T20:11:34.433Z,1642968694.433 [DepthRateCalculator] Loaded
2022-01-23T20:11:34.433Z,1642968694.433 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-01-23T20:11:34.438Z,1642968694.438 [PitchRateCalculator] Loaded
2022-01-23T20:11:34.439Z,1642968694.439 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-01-23T20:11:34.448Z,1642968694.448 [SpeedCalculator] Loaded
2022-01-23T20:11:34.448Z,1642968694.448 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-01-23T20:11:34.462Z,1642968694.462 [TempGradientCalculator] Loaded
2022-01-23T20:11:34.462Z,1642968694.462 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2022-01-23T20:11:34.477Z,1642968694.477 [VerticalHomogeneityIndexCalculator] Loaded
2022-01-23T20:11:34.477Z,1642968694.477 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2022-01-23T20:11:34.482Z,1642968694.482 [YawRateCalculator] Loaded
2022-01-23T20:11:34.482Z,1642968694.482 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-01-23T20:11:34.503Z,1642968694.503 [ElevatorOffsetCalculator] Loaded
2022-01-23T20:11:34.503Z,1642968694.503 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-01-23T20:11:34.504Z,1642968694.504 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-01-23T20:11:34.504Z,1642968694.504 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-01-23T20:11:34.649Z,1642968694.649 [SBIT](DEBUG): Construct Startup Built In Test.
2022-01-23T20:11:34.662Z,1642968694.662 [SBIT] Loaded
2022-01-23T20:11:34.662Z,1642968694.662 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-01-23T20:11:34.665Z,1642968694.665 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-01-23T20:11:34.678Z,1642968694.678 [IBIT] Loaded
2022-01-23T20:11:34.678Z,1642968694.678 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-01-23T20:11:34.684Z,1642968694.684 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-01-23T20:11:34.784Z,1642968694.784 [CBIT] Loaded
2022-01-23T20:11:34.784Z,1642968694.784 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-01-23T20:11:34.785Z,1642968694.785 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-01-23T20:11:34.785Z,1642968694.785 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-01-23T20:11:34.844Z,1642968694.844 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-01-23T20:11:34.844Z,1642968694.844 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-01-23T20:11:34.951Z,1642968694.951 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-01-23T20:11:34.952Z,1642968694.952 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-01-23T20:11:35.004Z,1642968695.004 [VerticalControl](DEBUG): Construct VerticalControl.
2022-01-23T20:11:35.055Z,1642968695.055 [VerticalControl] Loaded
2022-01-23T20:11:35.056Z,1642968695.056 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-01-23T20:11:35.058Z,1642968695.058 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-01-23T20:11:35.093Z,1642968695.093 [HorizontalControl] Loaded
2022-01-23T20:11:35.094Z,1642968695.094 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-01-23T20:11:35.096Z,1642968695.096 [SpeedControl](DEBUG): Construct SpeedControl.
2022-01-23T20:11:35.099Z,1642968695.099 [SpeedControl] Loaded
2022-01-23T20:11:35.099Z,1642968695.099 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-01-23T20:11:35.102Z,1642968695.102 [LoopControl](DEBUG): Construct LoopControl.
2022-01-23T20:11:35.102Z,1642968695.102 [LoopControl] Loaded
2022-01-23T20:11:35.103Z,1642968695.103 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-01-23T20:11:35.103Z,1642968695.103 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-01-23T20:11:35.104Z,1642968695.104 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-01-23T20:11:35.130Z,1642968695.130 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-01-23T20:11:35.136Z,1642968695.136 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-01-23T20:11:35.139Z,1642968695.139 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-01-23T20:11:35.149Z,1642968695.149 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-01-23T20:11:35.150Z,1642968695.150 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACD4E0
2022-01-23T20:11:35.151Z,1642968695.151 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2086
2022-01-23T20:11:35.155Z,1642968695.155 [Supervisor](INFO): Main Thread ID is 829
2022-01-23T20:11:35.155Z,1642968695.155 [Supervisor](DEBUG): Running supervisor.
2022-01-23T20:11:35.156Z,1642968695.156 [CommandExec ThreadHandler](INFO): Handler Thread ID is 2087
2022-01-23T20:11:35.156Z,1642968695.156 [CommandExec](INFO): Initializing the command executive.
2022-01-23T20:11:35.158Z,1642968695.158 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2088
2022-01-23T20:11:35.160Z,1642968695.160 [controlThread ThreadHandler](INFO): Handler Thread ID is 2089
2022-01-23T20:11:35.160Z,1642968695.160 [controlThread](DEBUG): Initializing ControlThread
2022-01-23T20:11:35.168Z,1642968695.168 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-01-23T20:11:35.169Z,1642968695.169 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-01-23T20:11:35.169Z,1642968695.169 [WorkSite](DEBUG): Initializing WorkSite component.
2022-01-23T20:11:35.171Z,1642968695.171 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-01-23T20:11:35.171Z,1642968695.171 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-01-23T20:11:35.172Z,1642968695.172 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-01-23T20:11:35.172Z,1642968695.172 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2022-01-23T20:11:35.173Z,1642968695.173 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2022-01-23T20:11:35.174Z,1642968695.174 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-01-23T20:11:35.175Z,1642968695.175 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-01-23T20:11:35.175Z,1642968695.175 [SBIT](INFO): Initialize SBIT Component.
2022-01-23T20:11:35.176Z,1642968695.176 [SBIT](IMPORTANT): git: 2022-01-19
2022-01-23T20:11:35.176Z,1642968695.176 [SBIT](INFO): git hash: 3c152841e44dce493716324b2ee7dcf988968060
2022-01-23T20:11:35.176Z,1642968695.176 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-01-23T20:11:35.178Z,1642968695.178 [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
2022-01-23T20:11:35.179Z,1642968695.179 [SBIT](INFO): Beginning SBIT in 44.000000 seconds.
2022-01-23T20:11:35.179Z,1642968695.179 [IBIT](INFO): Initialize IBIT Component.
2022-01-23T20:11:35.180Z,1642968695.180 [CBIT](DEBUG): Initialize CBIT Component.
2022-01-23T20:11:35.181Z,1642968695.181 [logger ThreadHandler](INFO): Handler Thread ID is 2090
2022-01-23T20:11:35.193Z,1642968695.193 [CBIT](DEBUG): Initialized mux pins.
2022-01-23T20:11:35.194Z,1642968695.194 [CBIT](DEBUG): Initializing the watchdog timer.
2022-01-23T20:11:35.202Z,1642968695.202 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 2091
2022-01-23T20:11:35.214Z,1642968695.214 [Onboard ThreadHandler](INFO): Handler Thread ID is 2092
2022-01-23T20:11:35.218Z,1642968695.218 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-01-23T20:11:35.219Z,1642968695.219 [CBIT](DEBUG): Initializing heartbeat.
2022-01-23T20:11:35.234Z,1642968695.234 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2093
2022-01-23T20:11:35.243Z,1642968695.243 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-01-23T20:11:35.244Z,1642968695.244 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-01-23T20:11:35.244Z,1642968695.244 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-01-23T20:11:35.244Z,1642968695.244 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-01-23T20:11:35.244Z,1642968695.244 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-01-23T20:11:35.244Z,1642968695.244 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-01-23T20:11:35.244Z,1642968695.244 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2022-01-23T20:11:35.244Z,1642968695.244 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2022-01-23T20:11:35.245Z,1642968695.245 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-01-23T20:11:35.245Z,1642968695.245 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-01-23T20:11:35.245Z,1642968695.245 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2022-01-23T20:11:35.245Z,1642968695.245 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2022-01-23T20:11:35.245Z,1642968695.245 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2022-01-23T20:11:35.247Z,1642968695.247 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2022-01-23T20:11:35.247Z,1642968695.247 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2022-01-23T20:11:35.247Z,1642968695.247 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2022-01-23T20:11:35.289Z,1642968695.289 [CBIT](DEBUG): Deactivating GF circuits.
2022-01-23T20:11:35.289Z,1642968695.289 [CBIT](DEBUG): Deactivating emergency mode.
2022-01-23T20:11:35.325Z,1642968695.325 [CBIT](DEBUG): Backplane powered.
2022-01-23T20:11:35.326Z,1642968695.326 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-01-23T20:11:35.327Z,1642968695.327 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-01-23T20:11:35.328Z,1642968695.328 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-01-23T20:11:35.329Z,1642968695.329 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-01-23T20:11:35.330Z,1642968695.330 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-01-23T20:11:35.342Z,1642968695.342 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-01-23T20:11:35.369Z,1642968695.369 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2022-01-23T20:11:35.370Z,1642968695.370 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-01-23T20:11:35.439Z,1642968695.439 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-01-23T20:11:35.440Z,1642968695.440 [Default:A.Wait](DEBUG): Construct Wait.
2022-01-23T20:11:35.459Z,1642968695.459 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-01-23T20:11:35.490Z,1642968695.490 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-01-23T20:11:35.493Z,1642968695.493 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-01-23T20:11:35.515Z,1642968695.515 [Default:E.Execute](DEBUG): Construct Execute.
2022-01-23T20:11:35.523Z,1642968695.523 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2022-01-23T20:11:35.538Z,1642968695.538 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,LBLNavigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-01-23T20:11:35.549Z,1642968695.549 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-01-23T20:11:35.720Z,1642968695.720 [Power24vConverter](INFO): Powering up.
2022-01-23T20:11:35.753Z,1642968695.753 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-01-23T20:11:35.762Z,1642968695.762 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-01-23T20:11:35.763Z,1642968695.763 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-01-23T20:11:35.770Z,1642968695.770 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-01-23T20:11:35.771Z,1642968695.771 [MassServo](DEBUG): Initializing EZServoServo.
2022-01-23T20:11:35.778Z,1642968695.778 [MassServo](DEBUG): Initializing MassServo.
2022-01-23T20:11:35.778Z,1642968695.778 [RudderServo](DEBUG): Initializing EZServoServo.
2022-01-23T20:11:35.786Z,1642968695.786 [RudderServo](DEBUG): Initializing RudderServo.
2022-01-23T20:11:35.786Z,1642968695.786 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-01-23T20:11:35.794Z,1642968695.794 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-01-23T20:11:36.681Z,1642968696.681 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-01-23T20:11:36.682Z,1642968696.682 [RudderServo](FAULT): Rudder failed to initialize
2022-01-23T20:11:36.682Z,1642968696.682 [RudderServo] Communications Fault, FailCount= 1
2022-01-23T20:11:36.682Z,1642968696.682 [RudderServo](ERROR): Communications Fault
2022-01-23T20:11:36.686Z,1642968696.686 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-01-23T20:11:36.890Z,1642968696.890 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-01-23T20:11:36.890Z,1642968696.890 [RudderServo](INFO): Powering down
2022-01-23T20:11:37.577Z,1642968697.577 [RudderServo](DEBUG): Initializing EZServoServo.
2022-01-23T20:11:37.694Z,1642968697.694 [RudderServo](DEBUG): Initializing RudderServo.
2022-01-23T20:11:37.698Z,1642968697.698 [CBIT](INFO): Clearing failed state for component RudderServo
2022-01-23T20:11:37.698Z,1642968697.698 [RudderServo] No Fault, FailCount= 1
2022-01-23T20:11:41.578Z,1642968701.578 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-01-23T20:12:03.027Z,1642968723.027 [NAL9602](INFO): Powering up NAL9602
2022-01-23T20:12:13.939Z,1642968733.939 [NAL9602](INFO): NAL9602 initialized
2022-01-23T20:12:19.624Z,1642968739.624 [SBIT](IMPORTANT): Beginning Startup BIT
2022-01-23T20:12:19.633Z,1642968739.633 [CBIT](IMPORTANT): Beginning ground fault scan
2022-01-23T20:12:30.642Z,1642968750.642 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.865238
CHAN A1 (24V): 0.789531
CHAN A2 (12V): 0.561883
CHAN A3 (5V): -0.001639
CHAN B0 (3.3V): 0.000379
CHAN B1 (3.15aV): 0.000013
CHAN B2 (3.15bV): 0.000101
CHAN B3 (GND): 0.001950
OPEN: 0.004681
Full Scale: +/- 1 mA
2022-01-23T20:12:41.018Z,1642968761.018 [NAL9602](INFO): SBD MO Status=0, MOMSN=31710, MT Status=0, MTMSN=0
2022-01-23T20:12:41.018Z,1642968761.018 [NAL9602](INFO): No messages in MT queue
2022-01-23T20:13:13.748Z,1642968793.748 [SBIT](IMPORTANT): SBIT PASSED
2022-01-23T20:13:13.748Z,1642968793.748 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-01-23T20:13:13.749Z,1642968793.749 [SBIT](IMPORTANT): BuoyancyServo.fastPumpCoefficient=2 none;

2022-01-23T20:13:13.749Z,1642968793.749 [SBIT](IMPORTANT): BuoyancyServo.velocity=800 none;

2022-01-23T20:13:13.749Z,1642968793.749 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;

2022-01-23T20:13:13.749Z,1642968793.749 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2022-01-23T20:13:13.749Z,1642968793.749 [SBIT](IMPORTANT): DataOverHttps.loadAtStartup=0 bool;

2022-01-23T20:13:13.750Z,1642968793.750 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;

2022-01-23T20:13:13.750Z,1642968793.750 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_temperature;

2022-01-23T20:13:13.750Z,1642968793.750 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.mass_concentration_of_chlorophyll_in_sea_water;

2022-01-23T20:13:13.750Z,1642968793.750 [SBIT](IMPORTANT): Express none platform_average_current;

2022-01-23T20:13:13.750Z,1642968793.750 [SBIT](IMPORTANT): Micromodem.loadAtStartup=0 bool;

2022-01-23T20:13:13.750Z,1642968793.750 [SBIT](IMPORTANT): NAL9602.fastGPSFix=0 bool;

2022-01-23T20:13:13.750Z,1642968793.750 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=0 bool;

2022-01-23T20:13:13.750Z,1642968793.750 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool;

2022-01-23T20:13:13.751Z,1642968793.751 [SBIT](IMPORTANT): RDI_PathfinderUp.loadAtStartup=0 bool;

2022-01-23T20:13:13.751Z,1642968793.751 [SBIT](IMPORTANT): Radio_Surface.loadAtStartup=0 bool;

2022-01-23T20:13:13.751Z,1642968793.751 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=154 cubic_centimeter;

2022-01-23T20:13:13.751Z,1642968793.751 [SBIT](IMPORTANT): VerticalControl.massDefault=6 millimeter;

2022-01-23T20:13:13.751Z,1642968793.751 [SBIT](IMPORTANT): WetLabsSeaOWL_UV_A.loadAtStartup=0 bool;

2022-01-23T20:13:14.163Z,1642968794.163 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2022-01-23T20:13:14.166Z,1642968794.166 [WorkSite](IMPORTANT): WorkSite fix at 20220123T201030: (40.218362, -70.024453)
2022-01-23T20:13:14.168Z,1642968794.168 [MissionManager](IMPORTANT): Started mission Startup
2022-01-23T20:13:14.168Z,1642968794.168 [Startup] Running Loop=1
2022-01-23T20:13:14.168Z,1642968794.168 [Startup](DEBUG): Aggregate::initialize Startup
2022-01-23T20:13:14.168Z,1642968794.168 [Startup:A.GoToSurface] Running Loop=1
2022-01-23T20:13:14.168Z,1642968794.168 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-01-23T20:13:14.169Z,1642968794.169 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-01-23T20:13:14.169Z,1642968794.169 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-01-23T20:13:14.170Z,1642968794.170 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-01-23T20:13:14.170Z,1642968794.170 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-01-23T20:13:14.171Z,1642968794.171 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-01-23T20:13:14.172Z,1642968794.172 [Startup:StartupSatComms] Running Loop=1
2022-01-23T20:13:14.172Z,1642968794.172 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-01-23T20:13:14.172Z,1642968794.172 [Startup:StartupSatComms:A] Running Loop=1
2022-01-23T20:13:14.578Z,1642968794.578 [LBLNavigation](INFO): Reset ping filters
2022-01-23T20:13:14.578Z,1642968794.578 [LBLNavigation](INFO): Reset fix filter
2022-01-23T20:13:14.579Z,1642968794.579 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-01-23T20:14:14.368Z,1642968854.368 [Startup:StartupSatComms:A](INFO): Timed out from 2022-01-23T20:13:14.2Z
2022-01-23T20:14:14.368Z,1642968854.368 [Startup:StartupSatComms:A] Stopped
2022-01-23T20:14:14.368Z,1642968854.368 [Startup:StartupSatComms:B] Running Loop=1
2022-01-23T20:14:14.792Z,1642968854.792 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-01-23T20:14:43.481Z,1642968883.481 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=31711, MT Status=1, MTMSN=1067
2022-01-23T20:14:43.526Z,1642968883.526 [NAL9602](INFO): Sent 52 bytes from file Logs/20220123T062154/Courier0100.lzma
2022-01-23T20:14:43.526Z,1642968883.526 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:14:44.050Z,1642968884.050 [NAL9602](INFO): Received command: gfscan
2022-01-23T20:14:44.054Z,1642968884.054 [CommandExec](IMPORTANT): got command gfscan
2022-01-23T20:14:44.092Z,1642968884.092 [CBIT](IMPORTANT): Beginning ground fault scan
2022-01-23T20:14:54.899Z,1642968894.899 [NAL9602](INFO): SBD MO Status=1, MOMSN=31712, MT Status=0, MTMSN=0
2022-01-23T20:14:54.954Z,1642968894.954 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Courier0000.lzma
2022-01-23T20:14:54.954Z,1642968894.954 [NAL9602](INFO): Packets left to send: 1
2022-01-23T20:14:58.005Z,1642968898.005 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.863238
CHAN A1 (24V): 0.789043
CHAN A2 (12V): 0.556683
CHAN A3 (5V): -0.001601
CHAN B0 (3.3V): 0.000537
CHAN B1 (3.15aV): -0.000157
CHAN B2 (3.15bV): 0.000120
CHAN B3 (GND): 0.002066
OPEN: 0.004762
Full Scale: +/- 1 mA
2022-01-23T20:15:05.936Z,1642968905.936 [NAL9602](INFO): SBD MO Status=1, MOMSN=31713, MT Status=0, MTMSN=0
2022-01-23T20:15:05.994Z,1642968905.994 [NAL9602](INFO): Sent 71 bytes from file Logs/20220123T201124/Courier0000.lzma
2022-01-23T20:15:05.994Z,1642968905.994 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:15:13.658Z,1642968913.658 [NAL9602](INFO): SBD MO Status=1, MOMSN=31714, MT Status=0, MTMSN=0
2022-01-23T20:15:13.706Z,1642968913.706 [NAL9602](INFO): Sent 119 bytes from file Logs/20220123T062154/Express0098.lzma
2022-01-23T20:15:13.706Z,1642968913.706 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:15:16.501Z,1642968916.501 [Startup:StartupSatComms:B](INFO): Timed out from 2022-01-23T20:14:14.4Z
2022-01-23T20:15:16.501Z,1642968916.501 [Startup:StartupSatComms:B] Stopped
2022-01-23T20:15:16.501Z,1642968916.501 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2022-01-23T20:15:16.501Z,1642968916.501 [Startup:StartupSatComms] Stopped
2022-01-23T20:15:16.502Z,1642968916.502 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-01-23T20:15:16.503Z,1642968916.503 [Startup](INFO): Completed Startup
2022-01-23T20:15:16.503Z,1642968916.503 [MissionManager](INFO): Startup is completed.
2022-01-23T20:15:16.503Z,1642968916.503 [MissionManager](INFO): Uninitializing Mission Startup
2022-01-23T20:15:16.503Z,1642968916.503 [Startup] Stopped
2022-01-23T20:15:16.503Z,1642968916.503 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-01-23T20:15:16.503Z,1642968916.503 [Startup:A.GoToSurface] Stopped
2022-01-23T20:15:16.503Z,1642968916.503 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-01-23T20:15:16.610Z,1642968916.610 [MissionManager](IMPORTANT): Started mission Default
2022-01-23T20:15:16.610Z,1642968916.610 [Default] Running Loop=1
2022-01-23T20:15:16.610Z,1642968916.610 [Default](DEBUG): Aggregate::initialize Default
2022-01-23T20:15:16.611Z,1642968916.611 [Default:B.GoToSurface] Running Loop=1
2022-01-23T20:15:16.611Z,1642968916.611 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-01-23T20:15:16.611Z,1642968916.611 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-01-23T20:15:16.611Z,1642968916.611 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-01-23T20:15:16.611Z,1642968916.611 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-01-23T20:15:16.612Z,1642968916.612 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-01-23T20:15:16.612Z,1642968916.612 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-01-23T20:15:16.612Z,1642968916.612 [Default:A.Wait] Running Loop=1
2022-01-23T20:15:16.612Z,1642968916.612 [Default:A.Wait](DEBUG): Initialize Wait Component.
2022-01-23T20:15:23.436Z,1642968923.436 [NAL9602](INFO): SBD MO Status=1, MOMSN=31715, MT Status=0, MTMSN=0
2022-01-23T20:15:23.490Z,1642968923.490 [NAL9602](INFO): Sent 145 bytes from file Logs/20220123T062154/Express0101.lzma
2022-01-23T20:15:23.490Z,1642968923.490 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:15:29.912Z,1642968929.912 [Default:A.Wait](INFO): Done Waiting.
2022-01-23T20:15:29.912Z,1642968929.912 [Default:A.Wait] Stopped
2022-01-23T20:15:29.912Z,1642968929.912 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2022-01-23T20:15:30.313Z,1642968930.313 [Default:CheckIn] Running Loop=1
2022-01-23T20:15:30.313Z,1642968930.313 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-01-23T20:15:30.313Z,1642968930.313 [Default:CheckIn:Read_GPS] Running Loop=1
2022-01-23T20:15:30.726Z,1642968930.726 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2022-01-23T20:15:32.330Z,1642968932.330 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201530.00,A,4013.09309,N,07001.44143,W,0.700,328.94,230122,,,A*7F
2022-01-23T20:15:32.334Z,1642968932.334 [NAL9602](INFO): GPS fix at 20220123T201530: (40.218218, -70.024024)
2022-01-23T20:15:32.344Z,1642968932.344 [Default:CheckIn:Read_GPS] Stopped
2022-01-23T20:15:32.344Z,1642968932.344 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-01-23T20:15:32.758Z,1642968932.758 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-01-23T20:15:48.927Z,1642968948.927 [NAL9602](INFO): SBD MO Status=1, MOMSN=31716, MT Status=0, MTMSN=0
2022-01-23T20:15:48.982Z,1642968948.982 [NAL9602](INFO): Sent 52 bytes from file Logs/20220123T201124/Courier0004.lzma
2022-01-23T20:15:48.982Z,1642968948.982 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:15:56.240Z,1642968956.240 [NAL9602](INFO): SBD MO Status=1, MOMSN=31717, MT Status=0, MTMSN=0
2022-01-23T20:15:56.294Z,1642968956.294 [NAL9602](INFO): Sent 72 bytes from file Logs/20220123T201124/Courier0007.lzma
2022-01-23T20:15:56.294Z,1642968956.294 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:16:07.594Z,1642968967.594 [NAL9602](INFO): SBD MO Status=1, MOMSN=31718, MT Status=0, MTMSN=0
2022-01-23T20:16:07.642Z,1642968967.642 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0001.lzma
2022-01-23T20:16:07.642Z,1642968967.642 [NAL9602](INFO): Packets left to send: 5
2022-01-23T20:16:16.532Z,1642968976.532 [NAL9602](INFO): SBD MO Status=1, MOMSN=31719, MT Status=0, MTMSN=0
2022-01-23T20:16:16.582Z,1642968976.582 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0001.lzma
2022-01-23T20:16:16.582Z,1642968976.582 [NAL9602](INFO): Packets left to send: 4
2022-01-23T20:16:30.326Z,1642968990.326 [NAL9602](INFO): SBD MO Status=1, MOMSN=31720, MT Status=0, MTMSN=0
2022-01-23T20:16:30.376Z,1642968990.376 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0001.lzma
2022-01-23T20:16:30.376Z,1642968990.376 [NAL9602](INFO): Packets left to send: 3
2022-01-23T20:16:54.600Z,1642969014.600 [NAL9602](INFO): SBD MO Status=2, MOMSN=31721, MT Status=2, MTMSN=0
2022-01-23T20:16:54.600Z,1642969014.600 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2022-01-23T20:17:12.076Z,1642969032.076 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=31721, MT Status=1, MTMSN=1068
2022-01-23T20:17:12.126Z,1642969032.126 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0001.lzma
2022-01-23T20:17:12.126Z,1642969032.126 [NAL9602](INFO): Packets left to send: 2
2022-01-23T20:17:12.642Z,1642969032.642 [NAL9602](INFO): Received command: sched asap "! echo i | tee /dev/loadC3 /dev/loadB6 /dev/loadB2 /dev/loadA7 /dev/loadC7" tcba 1 2
2022-01-23T20:17:12.681Z,1642969032.681 [CommandExec](IMPORTANT): got command schedule asap "! echo i | tee /dev/loadC3 /dev/loadB6 /dev/loadB2 /dev/loadA7 /dev/loadC7" tcba 1 2.000000
2022-01-23T20:17:12.681Z,1642969032.681 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=tcba
2022-01-23T20:17:12.682Z,1642969032.682 [CommandExec](IMPORTANT): Scheduled #1 (#1 of 2 with id='tcba'): "! echo i | tee /dev/loadC3 /dev/loadB6 /dev/loadB2 /dev/loadA7 /dev/loadC7", ASAP
2022-01-23T20:17:23.026Z,1642969043.026 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=31722, MT Status=1, MTMSN=1069
2022-01-23T20:17:23.090Z,1642969043.090 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0001.lzma
2022-01-23T20:17:23.090Z,1642969043.090 [NAL9602](INFO): Packets left to send: 1
2022-01-23T20:17:23.542Z,1642969043.542 [NAL9602](INFO): Received command: sched asap "" tcba 2 2
2022-01-23T20:17:23.564Z,1642969043.564 [CommandExec](IMPORTANT): got command schedule asap "" tcba 2 2.000000
2022-01-23T20:17:23.564Z,1642969043.564 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=tcba
2022-01-23T20:17:23.565Z,1642969043.565 [CommandExec](IMPORTANT): Scheduled #2 (#2 of 2 with id='tcba'): "", ASAP
2022-01-23T20:17:23.617Z,1642969043.617 [CommandExec](IMPORTANT): got command ! echo i | tee /dev/loadC3 /dev/loadB6 /dev/loadB2 /dev/loadA7 /dev/loadC7
2022-01-23T20:17:23.701Z,1642969043.701 [CommandExec](IMPORTANT): i
  
2022-01-23T20:17:34.109Z,1642969054.109 [AHRS_M2](FAULT): Failed to acquire valid data within timeout.
2022-01-23T20:17:34.109Z,1642969054.109 [AHRS_M2] Data Fault, FailCount= 1
2022-01-23T20:17:34.109Z,1642969054.109 [AHRS_M2](ERROR): Data Fault
2022-01-23T20:17:34.157Z,1642969054.157 [CBIT](ERROR): Data Fault in component: AHRS_M2
2022-01-23T20:17:34.493Z,1642969054.493 [AHRS_M2](INFO): Powering down
2022-01-23T20:17:35.322Z,1642969055.322 [CBIT](INFO): Clearing failed state for component AHRS_M2
2022-01-23T20:17:35.322Z,1642969055.322 [AHRS_M2] No Fault, FailCount= 1
2022-01-23T20:17:35.705Z,1642969055.705 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-01-23T20:17:43.515Z,1642969063.515 [NAL9602](INFO): SBD MO Status=1, MOMSN=31723, MT Status=0, MTMSN=0
2022-01-23T20:17:43.566Z,1642969063.566 [NAL9602](INFO): Sent 162 bytes from file Logs/20220123T201124/Express0001.lzma
2022-01-23T20:17:43.566Z,1642969063.566 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:17:55.181Z,1642969075.181 [NAL9602](INFO): SBD MO Status=1, MOMSN=31724, MT Status=0, MTMSN=0
2022-01-23T20:17:55.235Z,1642969075.235 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0005.lzma
2022-01-23T20:17:55.235Z,1642969075.235 [NAL9602](INFO): Packets left to send: 2
2022-01-23T20:18:07.399Z,1642969087.399 [NAL9602](INFO): SBD MO Status=1, MOMSN=31725, MT Status=0, MTMSN=0
2022-01-23T20:18:07.454Z,1642969087.454 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0005.lzma
2022-01-23T20:18:07.454Z,1642969087.454 [NAL9602](INFO): Packets left to send: 1
2022-01-23T20:18:18.756Z,1642969098.756 [NAL9602](INFO): SBD MO Status=1, MOMSN=31726, MT Status=0, MTMSN=0
2022-01-23T20:18:18.806Z,1642969098.806 [NAL9602](INFO): Sent 9 bytes from file Logs/20220123T201124/Express0005.lzma
2022-01-23T20:18:18.806Z,1642969098.806 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:18:28.904Z,1642969108.904 [NAL9602](INFO): SBD MO Status=1, MOMSN=31727, MT Status=0, MTMSN=0
2022-01-23T20:18:28.966Z,1642969108.966 [NAL9602](INFO): Sent 62 bytes from file Logs/20220123T201124/Express0008.lzma
2022-01-23T20:18:28.966Z,1642969108.966 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:18:40.236Z,1642969120.236 [NAL9602](INFO): SBD MO Status=0, MOMSN=31728, MT Status=0, MTMSN=0
2022-01-23T20:18:56.424Z,1642969136.424 [NAL9602](INFO): SBD MO Status=1, MOMSN=31729, MT Status=0, MTMSN=0
2022-01-23T20:18:56.482Z,1642969136.482 [NAL9602](INFO): Sent 52 bytes from file Logs/20220123T201124/Courier0010.lzma
2022-01-23T20:18:56.482Z,1642969136.482 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:18:59.316Z,1642969139.316 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2022-01-23T20:18:59.319Z,1642969139.319 [BPC1](INFO): Received data from all battery sticks.
2022-01-23T20:19:07.408Z,1642969147.408 [NAL9602](INFO): SBD MO Status=1, MOMSN=31730, MT Status=0, MTMSN=0
2022-01-23T20:19:07.458Z,1642969147.458 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0011.lzma
2022-01-23T20:19:07.458Z,1642969147.458 [NAL9602](INFO): Packets left to send: 2
2022-01-23T20:19:18.397Z,1642969158.397 [NAL9602](INFO): SBD MO Status=1, MOMSN=31731, MT Status=0, MTMSN=0
2022-01-23T20:19:18.454Z,1642969158.454 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0011.lzma
2022-01-23T20:19:18.454Z,1642969158.454 [NAL9602](INFO): Packets left to send: 1
2022-01-23T20:19:24.900Z,1642969164.900 [NAL9602](INFO): SBD MO Status=1, MOMSN=31732, MT Status=0, MTMSN=0
2022-01-23T20:19:24.954Z,1642969164.954 [NAL9602](INFO): Sent 4 bytes from file Logs/20220123T201124/Express0011.lzma
2022-01-23T20:19:24.954Z,1642969164.954 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:19:33.384Z,1642969173.384 [NAL9602](INFO): SBD MO Status=0, MOMSN=31733, MT Status=0, MTMSN=0
2022-01-23T20:19:33.475Z,1642969173.475 [Default:CheckIn:Read_Iridium] Stopped
2022-01-23T20:19:33.476Z,1642969173.476 [Default:CheckIn:C.Wait] Running Loop=1
2022-01-23T20:19:33.476Z,1642969173.476 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-01-23T20:20:04.091Z,1642969204.091 [NAL9602](INFO): Powering down
2022-01-23T20:21:36.603Z,1642969296.603 [Power24vConverter](INFO): Powering down.
2022-01-23T20:24:33.967Z,1642969473.967 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-01-23T20:24:33.967Z,1642969473.967 [Default:CheckIn:C.Wait] Stopped
2022-01-23T20:24:33.967Z,1642969473.967 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-01-23T20:24:33.967Z,1642969473.967 [Default:CheckIn:D] Running Loop=1
2022-01-23T20:24:34.374Z,1642969474.374 [Default:CheckIn:D] Stopped
2022-01-23T20:24:34.374Z,1642969474.374 [Default:CheckIn:E] Running Loop=1
2022-01-23T20:24:34.785Z,1642969474.785 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.296061 min 
2022-01-23T20:24:34.785Z,1642969474.785 [Default:CheckIn:E] Stopped
2022-01-23T20:24:34.785Z,1642969474.785 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-01-23T20:24:34.785Z,1642969474.785 [Default:CheckIn] Stopped
2022-01-23T20:24:34.785Z,1642969474.785 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-01-23T20:24:34.785Z,1642969474.785 [Default:CheckIn](INFO): Running loop #2
2022-01-23T20:24:34.785Z,1642969474.785 [Default:CheckIn] Running Loop=2
2022-01-23T20:24:34.786Z,1642969474.786 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-01-23T20:24:34.786Z,1642969474.786 [Default:CheckIn:Read_GPS] Running Loop=1
2022-01-23T20:24:35.569Z,1642969475.569 [NAL9602](INFO): Powering up
2022-01-23T20:24:46.483Z,1642969486.483 [NAL9602](INFO): NAL9602 initialized
2022-01-23T20:25:09.102Z,1642969509.102 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=31734, MT Status=1, MTMSN=1070
2022-01-23T20:25:09.102Z,1642969509.102 [NAL9602](INFO): Data available in MT queue
2022-01-23T20:25:09.590Z,1642969509.590 [NAL9602](INFO): Received command: gfscan
2022-01-23T20:25:09.603Z,1642969509.603 [CommandExec](IMPORTANT): got command gfscan
2022-01-23T20:25:09.616Z,1642969509.616 [CBIT](IMPORTANT): Beginning ground fault scan
2022-01-23T20:25:12.384Z,1642969512.384 [CBIT](ERROR): Error reading 24V bus power status. Assuming off for scan purposes.
2022-01-23T20:25:20.454Z,1642969520.454 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.007196
CHAN A1 (24V) N/A reporting off
CHAN A2 (12V): -0.006118
CHAN A3 (5V): -0.001527
CHAN B0 (3.3V): 0.000164
CHAN B1 (3.15aV): 0.000204
CHAN B2 (3.15bV): 0.000428
CHAN B3 (GND): 0.001775
OPEN: 0.004246
Full Scale: +/- 1 mA
2022-01-23T20:29:34.962Z,1642969774.962 [Default:CheckIn:Read_GPS](INFO): Timed out from 2022-01-23T20:24:34.8Z
2022-01-23T20:29:34.962Z,1642969774.962 [Default:CheckIn:Read_GPS] Stopped
2022-01-23T20:29:34.962Z,1642969774.962 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-01-23T20:29:57.596Z,1642969797.596 [NAL9602](INFO): SBD MO Status=1, MOMSN=31735, MT Status=0, MTMSN=0
2022-01-23T20:29:57.654Z,1642969797.654 [NAL9602](INFO): Sent 180 bytes from file Logs/20220123T201124/Courier0013.lzma
2022-01-23T20:29:57.654Z,1642969797.654 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:30:11.373Z,1642969811.373 [NAL9602](INFO): SBD MO Status=1, MOMSN=31736, MT Status=0, MTMSN=0
2022-01-23T20:30:11.434Z,1642969811.434 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0014.lzma
2022-01-23T20:30:11.434Z,1642969811.434 [NAL9602](INFO): Packets left to send: 2
2022-01-23T20:30:23.550Z,1642969823.550 [NAL9602](INFO): SBD MO Status=1, MOMSN=31737, MT Status=0, MTMSN=0
2022-01-23T20:30:23.598Z,1642969823.598 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0014.lzma
2022-01-23T20:30:23.598Z,1642969823.598 [NAL9602](INFO): Packets left to send: 1
2022-01-23T20:30:34.088Z,1642969834.088 [NAL9602](INFO): SBD MO Status=1, MOMSN=31738, MT Status=0, MTMSN=0
2022-01-23T20:30:34.146Z,1642969834.146 [NAL9602](INFO): Sent 25 bytes from file Logs/20220123T201124/Express0014.lzma
2022-01-23T20:30:34.146Z,1642969834.146 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:30:43.788Z,1642969843.788 [NAL9602](INFO): SBD MO Status=0, MOMSN=31739, MT Status=0, MTMSN=0
2022-01-23T20:30:55.132Z,1642969855.132 [NAL9602](INFO): SBD MO Status=1, MOMSN=31740, MT Status=0, MTMSN=0
2022-01-23T20:30:55.194Z,1642969855.194 [NAL9602](INFO): Sent 52 bytes from file Logs/20220123T201124/Courier0016.lzma
2022-01-23T20:30:55.194Z,1642969855.194 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:31:05.682Z,1642969865.682 [NAL9602](INFO): SBD MO Status=1, MOMSN=31741, MT Status=0, MTMSN=0
2022-01-23T20:31:05.742Z,1642969865.742 [NAL9602](INFO): Sent 62 bytes from file Logs/20220123T201124/Express0017.lzma
2022-01-23T20:31:05.742Z,1642969865.742 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:31:14.155Z,1642969874.155 [NAL9602](INFO): SBD MO Status=0, MOMSN=31742, MT Status=0, MTMSN=0
2022-01-23T20:31:14.239Z,1642969874.239 [Default:CheckIn:Read_Iridium] Stopped
2022-01-23T20:31:14.239Z,1642969874.239 [Default:CheckIn:C.Wait] Running Loop=1
2022-01-23T20:31:14.239Z,1642969874.239 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2022-01-23T20:31:44.862Z,1642969904.862 [NAL9602](INFO): Powering down
2022-01-23T20:36:14.739Z,1642970174.739 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2022-01-23T20:36:14.739Z,1642970174.739 [Default:CheckIn:C.Wait] Stopped
2022-01-23T20:36:14.739Z,1642970174.739 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2022-01-23T20:36:14.740Z,1642970174.740 [Default:CheckIn:D] Running Loop=1
2022-01-23T20:36:15.153Z,1642970175.153 [Default:CheckIn:D] Stopped
2022-01-23T20:36:15.153Z,1642970175.153 [Default:CheckIn:E] Running Loop=1
2022-01-23T20:36:15.547Z,1642970175.547 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.975710 min 
2022-01-23T20:36:15.547Z,1642970175.547 [Default:CheckIn:E] Stopped
2022-01-23T20:36:15.547Z,1642970175.547 [Default:CheckIn](INFO): Completed Default:CheckIn
2022-01-23T20:36:15.547Z,1642970175.547 [Default:CheckIn] Stopped
2022-01-23T20:36:15.547Z,1642970175.547 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-01-23T20:36:15.547Z,1642970175.547 [Default:CheckIn](INFO): Running loop #3
2022-01-23T20:36:15.547Z,1642970175.547 [Default:CheckIn] Running Loop=3
2022-01-23T20:36:15.547Z,1642970175.547 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2022-01-23T20:36:15.547Z,1642970175.547 [Default:CheckIn:Read_GPS] Running Loop=1
2022-01-23T20:36:16.347Z,1642970176.347 [NAL9602](INFO): Powering up
2022-01-23T20:36:27.254Z,1642970187.254 [NAL9602](INFO): NAL9602 initialized
2022-01-23T20:36:28.064Z,1642970188.064 [NAL9602](FAULT): GPS failed to acquire within timeout.
2022-01-23T20:36:28.064Z,1642970188.064 [NAL9602] Data Fault, FailCount= 1
2022-01-23T20:36:28.064Z,1642970188.064 [NAL9602](ERROR): Data Fault
2022-01-23T20:36:28.083Z,1642970188.083 [CBIT](ERROR): Data Fault in component: NAL9602
2022-01-23T20:36:28.466Z,1642970188.466 [NAL9602](INFO): Powering down
2022-01-23T20:36:29.297Z,1642970189.297 [CBIT](INFO): Clearing failed state for component NAL9602
2022-01-23T20:36:29.297Z,1642970189.297 [NAL9602] No Fault, FailCount= 1
2022-01-23T20:36:58.775Z,1642970218.775 [NAL9602](INFO): Powering up NAL9602
2022-01-23T20:37:09.679Z,1642970229.679 [NAL9602](INFO): NAL9602 initialized
2022-01-23T20:37:22.607Z,1642970242.607 [NAL9602](INFO): SBD MO Status=0, MOMSN=31743, MT Status=0, MTMSN=0
2022-01-23T20:37:22.607Z,1642970242.607 [NAL9602](INFO): No messages in MT queue
2022-01-23T20:40:44.608Z,1642970444.608 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204042.00,A,4013.14256,N,07001.41945,W,0.505,323.80,230122,,,A*7F
2022-01-23T20:40:44.611Z,1642970444.611 [NAL9602](INFO): GPS fix at 20220123T204042: (40.219043, -70.023657)
2022-01-23T20:40:44.621Z,1642970444.621 [Default:CheckIn:Read_GPS] Stopped
2022-01-23T20:40:44.621Z,1642970444.621 [Default:CheckIn:Read_Iridium] Running Loop=1
2022-01-23T20:41:02.022Z,1642970462.022 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=31744, MT Status=1, MTMSN=1071
2022-01-23T20:41:02.074Z,1642970462.074 [NAL9602](INFO): Sent 72 bytes from file Logs/20220123T201124/Courier0019.lzma
2022-01-23T20:41:02.074Z,1642970462.074 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:41:02.618Z,1642970462.618 [NAL9602](INFO): Received command: configSet RDI_Pathfinder.loadAtStartup 1 bool persist
2022-01-23T20:41:02.905Z,1642970462.905 [CommandExec](IMPORTANT): got command configSet RDI_Pathfinder.loadAtStartup 1.000000 bool persist
2022-01-23T20:41:02.905Z,1642970462.905 [CommandExec](IMPORTANT): configSet RDI_Pathfinder.loadAtStartup requires a restart to take effect.
2022-01-23T20:41:19.840Z,1642970479.840 [NAL9602](INFO): SBD MO Status=1, MOMSN=31745, MT Status=0, MTMSN=0
2022-01-23T20:41:19.902Z,1642970479.902 [NAL9602](INFO): Sent 161 bytes from file Logs/20220123T201124/Express0020.lzma
2022-01-23T20:41:19.902Z,1642970479.902 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:41:47.309Z,1642970507.309 [NAL9602](INFO): SBD MO Status=0, MOMSN=31746, MT Status=0, MTMSN=0
2022-01-23T20:41:59.064Z,1642970519.064 [NAL9602](INFO): SBD MO Status=1, MOMSN=31747, MT Status=0, MTMSN=0
2022-01-23T20:41:59.122Z,1642970519.122 [NAL9602](INFO): Sent 52 bytes from file Logs/20220123T201124/Courier0022.lzma
2022-01-23T20:41:59.122Z,1642970519.122 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:42:07.194Z,1642970527.194 [NAL9602](INFO): SBD MO Status=1, MOMSN=31748, MT Status=0, MTMSN=0
2022-01-23T20:42:07.242Z,1642970527.242 [NAL9602](INFO): Sent 184 bytes from file Logs/20220123T201124/Express0023.lzma
2022-01-23T20:42:07.242Z,1642970527.242 [NAL9602](INFO): Packets left to send: 1
2022-01-23T20:42:15.332Z,1642970535.332 [NAL9602](INFO): SBD MO Status=1, MOMSN=31749, MT Status=0, MTMSN=0
2022-01-23T20:42:15.382Z,1642970535.382 [NAL9602](INFO): Sent 31 bytes from file Logs/20220123T201124/Express0023.lzma
2022-01-23T20:42:15.382Z,1642970535.382 [NAL9602](INFO): Packets left to send: 0
2022-01-23T20:42:25.429Z,1642970545.429 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=31750, MT Status=1, MTMSN=1072
2022-01-23T20:42:25.930Z,1642970545.930 [NAL9602](INFO): Received command: restart app
2022-01-23T20:42:25.955Z,1642970545.955 [CommandExec](IMPORTANT): got command restart application
2022-01-23T20:42:26.957Z,1642970546.957 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2022-01-23T20:42:26.958Z,1642970546.958 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-23T20:42:26.958Z,1642970546.958 [CommandExec](INFO): Uninitializing the command executive.
2022-01-23T20:42:26.958Z,1642970546.958 [CommandExec](INFO): Uninitializing the command scheduler.
2022-01-23T20:42:26.958Z,1642970546.958 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:27.117Z,1642970547.117 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2022-01-23T20:42:27.118Z,1642970547.118 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-01-23T20:42:27.118Z,1642970547.118 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:27.118Z,1642970547.118 [NavChartDb](INFO): Join timeout helper Thread ID is 2177
2022-01-23T20:42:27.214Z,1642970547.214 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-23T20:42:27.214Z,1642970547.214 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:27.225Z,1642970547.225 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-01-23T20:42:27.225Z,1642970547.225 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:27.226Z,1642970547.226 [Onboard](INFO): Join timeout helper Thread ID is 2178
2022-01-23T20:42:31.797Z,1642970551.797 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-23T20:42:31.798Z,1642970551.798 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:31.805Z,1642970551.805 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2022-01-23T20:42:31.805Z,1642970551.805 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:31.806Z,1642970551.806 [BackseatComponent](INFO): Join timeout helper Thread ID is 2179
2022-01-23T20:42:31.857Z,1642970551.857 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-23T20:42:31.858Z,1642970551.858 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:31.865Z,1642970551.865 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-01-23T20:42:31.865Z,1642970551.865 [logger ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:31.866Z,1642970551.866 [logger](INFO): Join timeout helper Thread ID is 2180
2022-01-23T20:42:31.886Z,1642970551.886 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-23T20:42:31.886Z,1642970551.886 [logger ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:31.905Z,1642970551.905 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-01-23T20:42:31.906Z,1642970551.906 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:31.906Z,1642970551.906 [CommandLine](INFO): Join timeout helper Thread ID is 2181
2022-01-23T20:42:31.994Z,1642970551.994 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-23T20:42:31.994Z,1642970551.994 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:32.010Z,1642970552.010 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-01-23T20:42:32.010Z,1642970552.010 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:32.011Z,1642970552.011 [CommandExec](INFO): Join timeout helper Thread ID is 2182
2022-01-23T20:42:32.012Z,1642970552.012 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-01-23T20:42:32.012Z,1642970552.012 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:32.012Z,1642970552.012 [controlThread](INFO): Join timeout helper Thread ID is 2183
2022-01-23T20:42:32.277Z,1642970552.277 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-01-23T20:42:32.278Z,1642970552.278 [controlThread](DEBUG): Uninitializing ControlThread
2022-01-23T20:42:32.278Z,1642970552.278 [AHRS_M2](INFO): Powering down
2022-01-23T20:42:32.350Z,1642970552.350 [NAL9602](INFO): Powering down
2022-01-23T20:42:32.352Z,1642970552.352 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-01-23T20:42:32.353Z,1642970552.353 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-01-23T20:42:32.353Z,1642970552.353 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-01-23T20:42:32.354Z,1642970552.354 [MissionManager](INFO): Uninitializing Mission Default
2022-01-23T20:42:32.355Z,1642970552.355 [Default] Stopped
2022-01-23T20:42:32.355Z,1642970552.355 [Default](DEBUG): Aggregate::uninitialize Default
2022-01-23T20:42:32.355Z,1642970552.355 [Default:B.GoToSurface] Stopped
2022-01-23T20:42:32.355Z,1642970552.355 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-01-23T20:42:32.355Z,1642970552.355 [Default:CheckIn] Stopped
2022-01-23T20:42:32.355Z,1642970552.355 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2022-01-23T20:42:32.355Z,1642970552.355 [Default:CheckIn:Read_Iridium] Stopped
2022-01-23T20:42:32.358Z,1642970552.358 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-01-23T20:42:32.358Z,1642970552.358 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-01-23T20:42:32.359Z,1642970552.359 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-01-23T20:42:32.359Z,1642970552.359 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-01-23T20:42:32.359Z,1642970552.359 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-01-23T20:42:32.359Z,1642970552.359 [BuoyancyServo](INFO): Powering down
2022-01-23T20:42:32.373Z,1642970552.373 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-01-23T20:42:32.374Z,1642970552.374 [ElevatorServo](INFO): Powering down
2022-01-23T20:42:32.374Z,1642970552.374 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-01-23T20:42:32.374Z,1642970552.374 [MassServo](INFO): Powering down
2022-01-23T20:42:32.375Z,1642970552.375 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-01-23T20:42:32.375Z,1642970552.375 [RudderServo](INFO): Powering down
2022-01-23T20:42:32.376Z,1642970552.376 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-01-23T20:42:32.376Z,1642970552.376 [ThrusterHE](INFO): Powering down
2022-01-23T20:42:32.377Z,1642970552.377 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-01-23T20:42:32.378Z,1642970552.378 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-01-23T20:42:32.378Z,1642970552.378 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-01-23T20:42:32.378Z,1642970552.378 [CBIT](DEBUG): Powering off loads.
2022-01-23T20:42:32.389Z,1642970552.389 [CBIT](DEBUG): Disabling WDT.
2022-01-23T20:42:32.401Z,1642970552.401 [CBIT](DEBUG): Opening all GF detection circuits.
2022-01-23T20:42:32.402Z,1642970552.402 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:32.413Z,1642970552.413 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:32.456Z,1642970552.456 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:32.563Z,1642970552.563 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-01-23T20:42:32.632Z,1642970552.632 [logger ThreadHandler](INFO): Thread cancelled.