2022-09-01T14:17:17.868Z,1662041837.868 [Supervisor](DEBUG): Initializing supervisor.
2022-09-01T14:17:17.872Z,1662041837.872 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-09-01T14:17:17.873Z,1662041837.873 [SyncHandler](INFO): Protected caller Thread ID is 5861
2022-09-01T14:17:17.873Z,1662041837.873 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-09-01T14:17:17.874Z,1662041837.874 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-09-01T14:17:17.875Z,1662041837.875 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5862
2022-09-01T14:17:17.879Z,1662041837.879 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-09-01T14:17:17.897Z,1662041837.897 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-09-01T14:17:17.898Z,1662041837.898 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-09-01T14:17:17.898Z,1662041837.898 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 5863
2022-09-01T14:17:17.902Z,1662041837.902 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-09-01T14:17:17.903Z,1662041837.903 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-09-01T14:17:17.904Z,1662041837.904 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5864
2022-09-01T14:17:17.906Z,1662041837.906 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-09-01T14:17:17.907Z,1662041837.907 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-09-01T14:17:17.907Z,1662041837.907 [logger ThreadHandler](INFO): Protected caller Thread ID is 5865
2022-09-01T14:17:17.911Z,1662041837.911 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-09-01T14:17:17.912Z,1662041837.912 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-09-01T14:17:17.913Z,1662041837.913 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-09-01T14:17:18.341Z,1662041838.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-09-01T14:17:18.342Z,1662041838.342 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-09-01T14:17:18.420Z,1662041838.420 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-09-01T14:17:18.762Z,1662041838.762 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-09-01T14:17:18.763Z,1662041838.763 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-09-01T14:17:18.870Z,1662041838.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-09-01T14:17:18.870Z,1662041838.870 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-09-01T14:17:19.070Z,1662041839.070 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-09-01T14:17:19.071Z,1662041839.071 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-09-01T14:17:19.569Z,1662041839.569 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-09-01T14:17:19.570Z,1662041839.570 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-09-01T14:17:19.848Z,1662041839.848 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-09-01T14:17:19.848Z,1662041839.848 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-09-01T14:17:20.071Z,1662041840.071 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-09-01T14:17:20.071Z,1662041840.071 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-09-01T14:17:20.271Z,1662041840.271 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-09-01T14:17:20.272Z,1662041840.272 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-09-01T14:17:20.369Z,1662041840.369 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-09-01T14:17:20.369Z,1662041840.369 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-09-01T14:17:20.602Z,1662041840.602 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-09-01T14:17:20.602Z,1662041840.602 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-09-01T14:17:20.989Z,1662041840.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-09-01T14:17:20.990Z,1662041840.990 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-09-01T14:17:21.070Z,1662041841.070 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-09-01T14:17:21.209Z,1662041841.209 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-09-01T14:17:21.209Z,1662041841.209 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-09-01T14:17:21.945Z,1662041841.945 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-09-01T14:17:21.945Z,1662041841.945 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-09-01T14:17:22.317Z,1662041842.317 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-09-01T14:17:22.319Z,1662041842.319 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2022-09-01T14:17:22.320Z,1662041842.320 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2022-09-01T14:17:22.528Z,1662041842.528 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2022-09-01T14:17:22.655Z,1662041842.655 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2022-09-01T14:17:22.894Z,1662041842.894 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2022-09-01T14:17:23.144Z,1662041843.144 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2022-09-01T14:17:23.755Z,1662041843.755 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-09-01T14:17:23.756Z,1662041843.756 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2022-09-01T14:17:23.868Z,1662041843.868 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2022-09-01T14:17:23.972Z,1662041843.972 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2022-09-01T14:17:24.097Z,1662041844.097 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2022-09-01T14:17:24.212Z,1662041844.212 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2022-09-01T14:17:24.296Z,1662041844.296 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2022-09-01T14:17:24.382Z,1662041844.382 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2022-09-01T14:17:24.493Z,1662041844.493 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2022-09-01T14:17:24.600Z,1662041844.600 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2022-09-01T14:17:24.810Z,1662041844.810 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2022-09-01T14:17:24.974Z,1662041844.974 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-09-01T14:17:24.987Z,1662041844.987 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-09-01T14:17:25.374Z,1662041845.374 [AHRS_M2] Loaded
2022-09-01T14:17:25.374Z,1662041845.374 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-09-01T14:17:26.158Z,1662041846.158 [BPC1] Loaded
2022-09-01T14:17:26.159Z,1662041846.159 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-09-01T14:17:26.242Z,1662041846.242 [DataOverHttps] Loaded
2022-09-01T14:17:26.242Z,1662041846.242 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-09-01T14:17:26.249Z,1662041846.249 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 407E44E0
2022-09-01T14:17:26.249Z,1662041846.249 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5959
2022-09-01T14:17:26.275Z,1662041846.275 [DDM] Loaded
2022-09-01T14:17:26.275Z,1662041846.275 [ComponentRegistry](DEBUG): SyncComponent "DDM" handled in the control thread.
2022-09-01T14:17:26.295Z,1662041846.295 [Depth_Keller] Loaded
2022-09-01T14:17:26.295Z,1662041846.295 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-09-01T14:17:26.300Z,1662041846.300 [DropWeight] Loaded
2022-09-01T14:17:26.300Z,1662041846.300 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-09-01T14:17:26.351Z,1662041846.351 [Micromodem] Loaded
2022-09-01T14:17:26.352Z,1662041846.352 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2022-09-01T14:17:26.414Z,1662041846.414 [NAL9602] Loaded
2022-09-01T14:17:26.415Z,1662041846.415 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-09-01T14:17:26.445Z,1662041846.445 [Onboard] Loaded
2022-09-01T14:17:26.445Z,1662041846.445 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-09-01T14:17:26.446Z,1662041846.446 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408144E0
2022-09-01T14:17:26.446Z,1662041846.446 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5960
2022-09-01T14:17:26.453Z,1662041846.453 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2022-09-01T14:17:26.463Z,1662041846.463 [PowerOnly] Loaded
2022-09-01T14:17:26.464Z,1662041846.464 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2022-09-01T14:17:26.475Z,1662041846.475 [Power24vConverter] Loaded
2022-09-01T14:17:26.476Z,1662041846.476 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-09-01T14:17:26.490Z,1662041846.490 [Radio_Surface] Loaded
2022-09-01T14:17:26.490Z,1662041846.490 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-09-01T14:17:26.491Z,1662041846.491 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408444E0
2022-09-01T14:17:26.492Z,1662041846.492 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5961
2022-09-01T14:17:26.538Z,1662041846.538 [RDI_Pathfinder] Loaded
2022-09-01T14:17:26.538Z,1662041846.538 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-09-01T14:17:26.566Z,1662041846.566 [RDI_PathfinderUp] Loaded
2022-09-01T14:17:26.566Z,1662041846.566 [ComponentRegistry](DEBUG): SyncComponent "RDI_PathfinderUp" handled in the control thread.
2022-09-01T14:17:26.567Z,1662041846.567 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-09-01T14:17:26.567Z,1662041846.567 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-09-01T14:17:26.578Z,1662041846.578 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-09-01T14:17:26.578Z,1662041846.578 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-09-01T14:17:26.689Z,1662041846.689 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-09-01T14:17:26.689Z,1662041846.689 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-09-01T14:17:26.714Z,1662041846.714 [LBLNavigation] Loaded
2022-09-01T14:17:26.714Z,1662041846.714 [ComponentRegistry](DEBUG): SyncComponent "LBLNavigation" handled in the control thread.
2022-09-01T14:17:26.727Z,1662041846.727 [NavChart] Loaded
2022-09-01T14:17:26.727Z,1662041846.727 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-09-01T14:17:26.733Z,1662041846.733 [UniversalFixResidualReporter] Loaded
2022-09-01T14:17:26.734Z,1662041846.734 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-09-01T14:17:26.744Z,1662041846.744 [WorkSite] Loaded
2022-09-01T14:17:26.745Z,1662041846.745 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2022-09-01T14:17:26.745Z,1662041846.745 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-09-01T14:17:26.745Z,1662041846.745 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-09-01T14:17:26.840Z,1662041846.840 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-09-01T14:17:26.840Z,1662041846.840 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-09-01T14:17:26.964Z,1662041846.964 [BuoyancyServo] Loaded
2022-09-01T14:17:26.965Z,1662041846.965 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-09-01T14:17:26.987Z,1662041846.987 [ElevatorServo] Loaded
2022-09-01T14:17:26.987Z,1662041846.987 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-09-01T14:17:27.013Z,1662041847.013 [DockingServo] Loaded
2022-09-01T14:17:27.013Z,1662041847.013 [ComponentRegistry](DEBUG): SyncComponent "DockingServo" handled in the control thread.
2022-09-01T14:17:27.035Z,1662041847.035 [MassServo] Loaded
2022-09-01T14:17:27.035Z,1662041847.035 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-09-01T14:17:27.056Z,1662041847.056 [RudderServo] Loaded
2022-09-01T14:17:27.056Z,1662041847.056 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-09-01T14:17:27.073Z,1662041847.073 [ThrusterHE] Loaded
2022-09-01T14:17:27.073Z,1662041847.073 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-09-01T14:17:27.073Z,1662041847.073 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-09-01T14:17:27.074Z,1662041847.074 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-09-01T14:17:27.242Z,1662041847.242 [CTD_Seabird] Loaded
2022-09-01T14:17:27.242Z,1662041847.242 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-09-01T14:17:27.248Z,1662041847.248 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409824E0
2022-09-01T14:17:27.248Z,1662041847.248 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5962
2022-09-01T14:17:27.281Z,1662041847.281 [WetLabsSeaOWL_UV_A] Loaded
2022-09-01T14:17:27.282Z,1662041847.282 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2022-09-01T14:17:27.283Z,1662041847.283 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409B24E0
2022-09-01T14:17:27.283Z,1662041847.283 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 5963
2022-09-01T14:17:27.284Z,1662041847.284 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-09-01T14:17:27.284Z,1662041847.284 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-09-01T14:17:27.585Z,1662041847.585 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-09-01T14:17:27.586Z,1662041847.586 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-09-01T14:17:27.636Z,1662041847.636 [DepthRateCalculator] Loaded
2022-09-01T14:17:27.637Z,1662041847.637 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-09-01T14:17:27.642Z,1662041847.642 [PitchRateCalculator] Loaded
2022-09-01T14:17:27.643Z,1662041847.643 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-09-01T14:17:27.652Z,1662041847.652 [SpeedCalculator] Loaded
2022-09-01T14:17:27.652Z,1662041847.652 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-09-01T14:17:27.666Z,1662041847.666 [TempGradientCalculator] Loaded
2022-09-01T14:17:27.666Z,1662041847.666 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2022-09-01T14:17:27.681Z,1662041847.681 [VerticalHomogeneityIndexCalculator] Loaded
2022-09-01T14:17:27.681Z,1662041847.681 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2022-09-01T14:17:27.686Z,1662041847.686 [YawRateCalculator] Loaded
2022-09-01T14:17:27.686Z,1662041847.686 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-09-01T14:17:27.709Z,1662041847.709 [ElevatorOffsetCalculator] Loaded
2022-09-01T14:17:27.709Z,1662041847.709 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-09-01T14:17:27.710Z,1662041847.710 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-09-01T14:17:27.710Z,1662041847.710 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-09-01T14:17:28.056Z,1662041848.056 [SBIT](DEBUG): Construct Startup Built In Test.
2022-09-01T14:17:28.070Z,1662041848.070 [SBIT] Loaded
2022-09-01T14:17:28.070Z,1662041848.070 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-09-01T14:17:28.113Z,1662041848.113 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-09-01T14:17:28.126Z,1662041848.126 [IBIT] Loaded
2022-09-01T14:17:28.127Z,1662041848.127 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-09-01T14:17:28.133Z,1662041848.133 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-09-01T14:17:28.302Z,1662041848.302 [CBIT] Loaded
2022-09-01T14:17:28.302Z,1662041848.302 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-09-01T14:17:28.303Z,1662041848.303 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-09-01T14:17:28.303Z,1662041848.303 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-09-01T14:17:28.358Z,1662041848.358 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-09-01T14:17:28.358Z,1662041848.358 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-09-01T14:17:28.509Z,1662041848.509 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-09-01T14:17:28.510Z,1662041848.510 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-09-01T14:17:28.560Z,1662041848.560 [VerticalControl](DEBUG): Construct VerticalControl.
2022-09-01T14:17:28.614Z,1662041848.614 [VerticalControl] Loaded
2022-09-01T14:17:28.614Z,1662041848.614 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-09-01T14:17:28.617Z,1662041848.617 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-09-01T14:17:28.655Z,1662041848.655 [HorizontalControl] Loaded
2022-09-01T14:17:28.656Z,1662041848.656 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-09-01T14:17:28.658Z,1662041848.658 [SpeedControl](DEBUG): Construct SpeedControl.
2022-09-01T14:17:28.660Z,1662041848.660 [SpeedControl] Loaded
2022-09-01T14:17:28.660Z,1662041848.660 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-09-01T14:17:28.663Z,1662041848.663 [LoopControl](DEBUG): Construct LoopControl.
2022-09-01T14:17:28.664Z,1662041848.664 [LoopControl] Loaded
2022-09-01T14:17:28.664Z,1662041848.664 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-09-01T14:17:28.664Z,1662041848.664 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-09-01T14:17:28.665Z,1662041848.665 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-09-01T14:17:28.691Z,1662041848.691 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-09-01T14:17:28.698Z,1662041848.698 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-09-01T14:17:28.701Z,1662041848.701 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-09-01T14:17:28.712Z,1662041848.712 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-09-01T14:17:28.718Z,1662041848.718 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B6E4E0
2022-09-01T14:17:28.718Z,1662041848.718 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5964
2022-09-01T14:17:28.723Z,1662041848.723 [Supervisor](INFO): Main Thread ID is 5860
2022-09-01T14:17:28.723Z,1662041848.723 [Supervisor](DEBUG): Running supervisor.
2022-09-01T14:17:28.724Z,1662041848.724 [CommandExec ThreadHandler](INFO): Handler Thread ID is 5965
2022-09-01T14:17:28.725Z,1662041848.725 [CommandExec](INFO): Initializing the command executive.
2022-09-01T14:17:28.726Z,1662041848.726 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5966
2022-09-01T14:17:28.728Z,1662041848.728 [controlThread ThreadHandler](INFO): Handler Thread ID is 5967
2022-09-01T14:17:28.729Z,1662041848.729 [controlThread](DEBUG): Initializing ControlThread
2022-09-01T14:17:28.735Z,1662041848.735 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-09-01T14:17:28.735Z,1662041848.735 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-09-01T14:17:28.735Z,1662041848.735 [WorkSite](DEBUG): Initializing WorkSite component.
2022-09-01T14:17:28.737Z,1662041848.737 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-09-01T14:17:28.737Z,1662041848.737 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-09-01T14:17:28.738Z,1662041848.738 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-09-01T14:17:28.738Z,1662041848.738 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2022-09-01T14:17:28.738Z,1662041848.738 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2022-09-01T14:17:28.739Z,1662041848.739 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-09-01T14:17:28.740Z,1662041848.740 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-09-01T14:17:28.740Z,1662041848.740 [SBIT](INFO): Initialize SBIT Component.
2022-09-01T14:17:28.741Z,1662041848.741 [SBIT](IMPORTANT): git: 2022-08-25
2022-09-01T14:17:28.741Z,1662041848.741 [SBIT](INFO): git hash: e1ddd60859d931066d70c4e9618f9367e52a6cfe
2022-09-01T14:17:28.741Z,1662041848.741 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-09-01T14:17:28.742Z,1662041848.742 [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-09-01T14:17:28.744Z,1662041848.744 [SBIT](INFO): Beginning SBIT in 55.000000 seconds.
2022-09-01T14:17:28.744Z,1662041848.744 [IBIT](INFO): Initialize IBIT Component.
2022-09-01T14:17:28.745Z,1662041848.745 [CBIT](DEBUG): Initialize CBIT Component.
2022-09-01T14:17:28.746Z,1662041848.746 [logger ThreadHandler](INFO): Handler Thread ID is 5968
2022-09-01T14:17:28.759Z,1662041848.759 [CBIT](DEBUG): Initialized mux pins.
2022-09-01T14:17:28.760Z,1662041848.760 [CBIT](DEBUG): Initializing the watchdog timer.
2022-09-01T14:17:28.764Z,1662041848.764 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5969
2022-09-01T14:17:28.765Z,1662041848.765 [DataOverHttps](DEBUG): dashIP=128.128.181.226 starts with a digit so assuming it is a numeric IP
2022-09-01T14:17:28.772Z,1662041848.772 [Onboard ThreadHandler](INFO): Handler Thread ID is 5970
2022-09-01T14:17:28.783Z,1662041848.783 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-09-01T14:17:28.784Z,1662041848.784 [CBIT](DEBUG): Initializing heartbeat.
2022-09-01T14:17:28.789Z,1662041848.789 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5971
2022-09-01T14:17:28.812Z,1662041848.812 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5972
2022-09-01T14:17:28.812Z,1662041848.812 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-09-01T14:17:28.817Z,1662041848.817 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 5974
2022-09-01T14:17:28.829Z,1662041848.829 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5975
2022-09-01T14:17:28.831Z,1662041848.831 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-09-01T14:17:28.831Z,1662041848.831 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-09-01T14:17:28.831Z,1662041848.831 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-09-01T14:17:28.831Z,1662041848.831 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-09-01T14:17:28.832Z,1662041848.832 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-09-01T14:17:28.832Z,1662041848.832 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-09-01T14:17:28.832Z,1662041848.832 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-09-01T14:17:28.832Z,1662041848.832 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-09-01T14:17:28.855Z,1662041848.855 [CBIT](DEBUG): Deactivating GF circuits.
2022-09-01T14:17:28.855Z,1662041848.855 [CBIT](DEBUG): Deactivating emergency mode.
2022-09-01T14:17:28.891Z,1662041848.891 [CBIT](DEBUG): Backplane powered.
2022-09-01T14:17:28.892Z,1662041848.892 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-09-01T14:17:28.893Z,1662041848.893 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-09-01T14:17:28.894Z,1662041848.894 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-09-01T14:17:28.895Z,1662041848.895 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-09-01T14:17:28.896Z,1662041848.896 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-09-01T14:17:28.909Z,1662041848.909 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-09-01T14:17:28.936Z,1662041848.936 [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-09-01T14:17:28.937Z,1662041848.937 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-09-01T14:17:29.010Z,1662041849.010 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-09-01T14:17:29.024Z,1662041849.024 [Default:A.Wait](DEBUG): Construct Wait.
2022-09-01T14:17:29.026Z,1662041849.026 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-09-01T14:17:29.082Z,1662041849.082 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-09-01T14:17:29.085Z,1662041849.085 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-09-01T14:17:29.107Z,1662041849.107 [Default:E.Execute](DEBUG): Construct Execute.
2022-09-01T14:17:29.110Z,1662041849.110 [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-09-01T14:17:29.115Z,1662041849.115 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,DDM,Depth_Keller,DropWeight,Micromodem,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,RDI_PathfinderUp,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,LBLNavigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,DockingServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2022-09-01T14:17:29.136Z,1662041849.136 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-09-01T14:17:29.195Z,1662041849.195 [Radio_Surface](INFO): Powering up
2022-09-01T14:17:29.197Z,1662041849.197 [DDM](INFO): Powering up
2022-09-01T14:17:29.197Z,1662041849.197 [DDM](DEBUG): Initializing DDM.
2022-09-01T14:17:29.223Z,1662041849.223 [Power24vConverter](INFO): Powering up.
2022-09-01T14:17:29.224Z,1662041849.224 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format
2022-09-01T14:17:29.289Z,1662041849.289 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-09-01T14:17:29.296Z,1662041849.296 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-09-01T14:17:29.297Z,1662041849.297 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-09-01T14:17:29.304Z,1662041849.304 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-09-01T14:17:29.304Z,1662041849.304 [DockingServo](DEBUG): Initializing DockingServo.
2022-09-01T14:17:29.305Z,1662041849.305 [MassServo](DEBUG): Initializing EZServoServo.
2022-09-01T14:17:29.312Z,1662041849.312 [MassServo](DEBUG): Initializing MassServo.
2022-09-01T14:17:29.312Z,1662041849.312 [RudderServo](DEBUG): Initializing EZServoServo.
2022-09-01T14:17:29.320Z,1662041849.320 [RudderServo](DEBUG): Initializing RudderServo.
2022-09-01T14:17:29.320Z,1662041849.320 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-09-01T14:17:29.328Z,1662041849.328 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-09-01T14:17:29.574Z,1662041849.574 [Micromodem](INFO): Powering up
2022-09-01T14:17:29.574Z,1662041849.574 [Micromodem](DEBUG): Initializing Micromodem.
2022-09-01T14:17:30.259Z,1662041850.259 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2022-09-01T14:17:30.260Z,1662041850.260 [RudderServo](FAULT): Rudder failed to initialize
2022-09-01T14:17:30.260Z,1662041850.260 [RudderServo] Communications Fault, FailCount= 1
2022-09-01T14:17:30.260Z,1662041850.260 [RudderServo](ERROR): Communications Fault
2022-09-01T14:17:30.264Z,1662041850.264 [CBIT](ERROR): Communications Fault in component: RudderServo
2022-09-01T14:17:30.478Z,1662041850.478 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-09-01T14:17:30.479Z,1662041850.479 [RudderServo](INFO): Powering down
2022-09-01T14:17:31.155Z,1662041851.155 [RudderServo](DEBUG): Initializing EZServoServo.
2022-09-01T14:17:31.276Z,1662041851.276 [RudderServo](DEBUG): Initializing RudderServo.
2022-09-01T14:17:31.280Z,1662041851.280 [CBIT](INFO): Clearing failed state for component RudderServo
2022-09-01T14:17:31.280Z,1662041851.280 [RudderServo] No Fault, FailCount= 1
2022-09-01T14:17:34.419Z,1662041854.419 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33
2022-09-01T14:17:34.822Z,1662041854.822 [Micromodem](INFO): Nmea in: $CATMG,2022-09-01T14:17:34.900789Z,RTC,RTC*51
2022-09-01T14:17:34.822Z,1662041854.822 [Micromodem](ERROR): CFG response from modem unexpected: $CATMG,2022-09-01T14:17:34.900789Z,RTC,RTC*51
2022-09-01T14:17:35.049Z,1662041855.049 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-09-01T14:17:35.225Z,1662041855.225 [Micromodem](INFO): Nmea in: $CACFG,ALL,0*31
2022-09-01T14:17:35.226Z,1662041855.226 [Micromodem](INFO): Nmea out: $CCCFG,POW,20*08
2022-09-01T14:17:35.629Z,1662041855.629 [Micromodem](INFO): Nmea in: $CACFG,POW,20*0A
2022-09-01T14:17:35.630Z,1662041855.630 [Micromodem](INFO): Nmea out: $CCCFG,SRC,0*30
2022-09-01T14:17:36.033Z,1662041856.033 [Micromodem](INFO): Nmea in: $CACFG,SRC,0*32
2022-09-01T14:17:36.034Z,1662041856.034 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64
2022-09-01T14:17:36.438Z,1662041856.438 [Micromodem](INFO): Nmea in: $CACFG,nav.dt.txtrig_gpio4,1*66
2022-09-01T14:17:36.438Z,1662041856.438 [Micromodem](INFO): Nmea out: $CCCFG,pwramp.txlevel,0*2F
2022-09-01T14:17:36.842Z,1662041856.842 [Micromodem](INFO): Nmea in: $CACFG,pwramp.txlevel,0*2D
2022-09-01T14:17:36.842Z,1662041856.842 [Micromodem](INFO): Nmea out: $CCCFG,DTO,30*1E
2022-09-01T14:17:37.233Z,1662041857.233 [Micromodem](INFO): Nmea in: $CACFG,DTO,30*1C
2022-09-01T14:17:37.234Z,1662041857.234 [Micromodem](INFO): Nmea out: $CCCFG,FC0,14500*47
2022-09-01T14:17:37.638Z,1662041857.638 [Micromodem](INFO): Nmea in: $CACFG,FC0,14500*45
2022-09-01T14:17:37.638Z,1662041857.638 [Micromodem](INFO): Nmea out: $CCCFG,BW0,4000*63
2022-09-01T14:17:38.027Z,1662041858.027 [Micromodem](INFO): Nmea in: $CACFG,BW0,4000*61
2022-09-01T14:17:38.028Z,1662041858.028 [Micromodem](INFO): Nmea out: $CCCFG,BND,0*3A
2022-09-01T14:17:38.425Z,1662041858.425 [Micromodem](INFO): Nmea in: $CACFG,BND,0*38
2022-09-01T14:17:38.426Z,1662041858.426 [Micromodem](INFO): Nmea out: $CCCLK,2022,09,01,14,17,39*47
2022-09-01T14:17:38.830Z,1662041858.830 [Micromodem](INFO): Nmea in: $CACLK,2022,9,1,14,17,39*45
2022-09-01T14:17:38.831Z,1662041858.831 [Micromodem](INFO): Nmea in: $CATMS,0,2022-09-01T14:17:40Z*7B
2022-09-01T14:17:38.833Z,1662041858.833 [Micromodem](INFO): Nmea in: $CATMG,2022-09-01T14:17:40.026205Z,USER_CMD,RTC*1F
2022-09-01T14:17:44.882Z,1662041864.882 [DDM](INFO): Latch/Whisker Boards:V1,H_RECOVERY_LATCH
!V2,H_RECOVERY_WHISKERS
2022-09-01T14:17:44.983Z,1662041864.983 [DDM](INFO): Dynamic Docking Module:C REMUS Capture Rev 1.1
2022-09-01T14:17:56.602Z,1662041876.602 [NAL9602](INFO): Powering up NAL9602
2022-09-01T14:18:07.514Z,1662041887.514 [NAL9602](INFO): NAL9602 initialized
2022-09-01T14:18:24.496Z,1662041904.496 [SBIT](IMPORTANT): Beginning Startup BIT
2022-09-01T14:18:24.501Z,1662041904.501 [CBIT](IMPORTANT): Beginning ground fault scan
2022-09-01T14:18:26.095Z,1662041906.095 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=44517, MT Status=1, MTMSN=1697
2022-09-01T14:18:26.096Z,1662041906.096 [NAL9602](INFO): Data available in MT queue
2022-09-01T14:18:26.596Z,1662041906.596 [NAL9602](INFO): Received command: stop
2022-09-01T14:18:26.677Z,1662041906.677 [CommandExec](IMPORTANT): got command stop
2022-09-01T14:18:26.677Z,1662041906.677 [CommandExec](IMPORTANT): Scheduling is paused
2022-09-01T14:18:26.677Z,1662041906.677 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2022-09-01T14:18:27.716Z,1662041907.716 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141833.00,A,4044.70994,N,07045.31909,W,1.555,232.07,010922,,,A*7B
2022-09-01T14:18:27.720Z,1662041907.720 [NAL9602](INFO): GPS fix at 20220901T141833: (40.745166, -70.755318)
2022-09-01T14:18:27.799Z,1662041907.799 [LBLNavigation](INFO): Reset ping filters
2022-09-01T14:18:27.799Z,1662041907.799 [LBLNavigation](INFO): Reset fix filter
2022-09-01T14:18:35.505Z,1662041915.505 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.109589
CHAN A1 (24V): 0.022623
CHAN A2 (12V): 0.010583
CHAN A3 (5V): 0.000118
CHAN B0 (3.3V): 0.001559
CHAN B1 (3.15aV): 0.001617
CHAN B2 (3.15bV): 0.002182
CHAN B3 (GND): -0.002966
OPEN: 0.005674
Full Scale: +/- 1 mA
2022-09-01T14:19:00.037Z,1662041940.037 [NAL9602](INFO): Not Powering down - fast GPS
2022-09-01T14:19:18.238Z,1662041958.238 [SBIT](IMPORTANT): SBIT PASSED
2022-09-01T14:19:18.239Z,1662041958.239 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-09-01T14:19:18.240Z,1662041958.240 [SBIT](IMPORTANT): CBIT.abortDepth=250 meter;
2022-09-01T14:19:18.240Z,1662041958.240 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;
2022-09-01T14:19:18.240Z,1662041958.240 [SBIT](IMPORTANT): CBIT.stopDepth=200 meter;
2022-09-01T14:19:18.240Z,1662041958.240 [SBIT](IMPORTANT): DDM.loadAtStartup=1 bool;
2022-09-01T14:19:18.240Z,1662041958.240 [SBIT](IMPORTANT): DockingServo.loadAtStartup=1 bool;
2022-09-01T14:19:18.240Z,1662041958.240 [SBIT](IMPORTANT): LineCapture.armSpeed=1.2 meter_per_second;
2022-09-01T14:19:18.241Z,1662041958.241 [SBIT](IMPORTANT): LineCapture.midcourseSpeed=1.2 meter_per_second;
2022-09-01T14:19:18.241Z,1662041958.241 [SBIT](IMPORTANT): LineCapture.rolloutTimeout=6 minute;
2022-09-01T14:19:18.241Z,1662041958.241 [SBIT](IMPORTANT): LineCapture.shortFinalRange=-1 meter;
2022-09-01T14:19:18.241Z,1662041958.241 [SBIT](IMPORTANT): LineCapture.terminalRange=300 meter;
2022-09-01T14:19:18.241Z,1662041958.241 [SBIT](IMPORTANT): LineCapture.verbose=1 bool;
2022-09-01T14:19:18.241Z,1662041958.241 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=152.268921 cubic_centimeter;
2022-09-01T14:19:18.241Z,1662041958.241 [SBIT](IMPORTANT): VerticalControl.massDefault=8.973020 millimeter;
2022-09-01T14:19:18.682Z,1662041958.682 [WorkSite](INFO): Already have valid position. Ignoring workSite position from Data/workSite.cfg
2022-09-01T14:19:18.691Z,1662041958.691 [MissionManager](IMPORTANT): Started mission Startup
2022-09-01T14:19:18.696Z,1662041958.696 [Startup] Running Loop=1
2022-09-01T14:19:18.696Z,1662041958.696 [Startup](DEBUG): Aggregate::initialize Startup
2022-09-01T14:19:18.696Z,1662041958.696 [Startup:A.GoToSurface] Running Loop=1
2022-09-01T14:19:18.696Z,1662041958.696 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-09-01T14:19:18.697Z,1662041958.697 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-09-01T14:19:18.697Z,1662041958.697 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-09-01T14:19:18.698Z,1662041958.698 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-09-01T14:19:18.698Z,1662041958.698 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-09-01T14:19:18.698Z,1662041958.698 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-09-01T14:19:18.700Z,1662041958.700 [Startup:StartupSatComms] Running Loop=1
2022-09-01T14:19:18.700Z,1662041958.700 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-09-01T14:19:18.700Z,1662041958.700 [Startup:StartupSatComms:A] Running Loop=1
2022-09-01T14:19:19.042Z,1662041959.042 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-09-01T14:19:20.639Z,1662041960.639 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,141926.00,A,4044.69855,N,07045.33161,W,0.855,218.73,010922,,,A*79
2022-09-01T14:19:20.641Z,1662041960.641 [NAL9602](INFO): GPS fix at 20220901T141926: (40.744976, -70.755527)
2022-09-01T14:19:20.653Z,1662041960.653 [Startup:StartupSatComms:A] Stopped
2022-09-01T14:19:20.653Z,1662041960.653 [Startup:StartupSatComms:B] Running Loop=1
2022-09-01T14:19:21.109Z,1662041961.109 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-09-01T14:19:34.901Z,1662041974.901 [CommandExec](IMPORTANT): got command restart application
2022-09-01T14:19:35.903Z,1662041975.903 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T14:19:35.904Z,1662041975.904 [CommandExec](INFO): Uninitializing the command executive.
2022-09-01T14:19:35.904Z,1662041975.904 [CommandExec](INFO): Uninitializing the command scheduler.
2022-09-01T14:19:35.904Z,1662041975.904 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:36.059Z,1662041976.059 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2022-09-01T14:19:36.059Z,1662041976.059 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2022-09-01T14:19:36.060Z,1662041976.060 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:36.060Z,1662041976.060 [NavChartDb](INFO): Join timeout helper Thread ID is 5996
2022-09-01T14:19:36.307Z,1662041976.307 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T14:19:36.308Z,1662041976.308 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:36.308Z,1662041976.308 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2022-09-01T14:19:36.309Z,1662041976.309 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:36.309Z,1662041976.309 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 5997
2022-09-01T14:19:36.356Z,1662041976.356 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T14:19:36.356Z,1662041976.356 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:36.368Z,1662041976.368 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2022-09-01T14:19:36.368Z,1662041976.368 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:36.368Z,1662041976.368 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5998
2022-09-01T14:19:37.332Z,1662041977.332 [CTD_Seabird](INFO): Powering down
2022-09-01T14:19:37.343Z,1662041977.343 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T14:19:37.344Z,1662041977.344 [CTD_Seabird](INFO): Powering down
2022-09-01T14:19:37.356Z,1662041977.356 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:37.375Z,1662041977.375 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2022-09-01T14:19:37.375Z,1662041977.375 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:37.376Z,1662041977.376 [Radio_Surface](INFO): Join timeout helper Thread ID is 5999
2022-09-01T14:19:37.707Z,1662041977.707 [Radio_Surface](INFO): Powering down
2022-09-01T14:19:37.708Z,1662041977.708 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T14:19:37.709Z,1662041977.709 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:37.715Z,1662041977.715 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2022-09-01T14:19:37.715Z,1662041977.715 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:37.716Z,1662041977.716 [Onboard](INFO): Join timeout helper Thread ID is 6000
2022-09-01T14:19:38.877Z,1662041978.877 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T14:19:38.878Z,1662041978.878 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:38.884Z,1662041978.884 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2022-09-01T14:19:38.884Z,1662041978.884 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:38.885Z,1662041978.885 [DataOverHttps](INFO): Join timeout helper Thread ID is 6001
2022-09-01T14:19:39.348Z,1662041979.348 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T14:19:39.348Z,1662041979.348 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:39.356Z,1662041979.356 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2022-09-01T14:19:39.356Z,1662041979.356 [logger ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:39.357Z,1662041979.357 [logger](INFO): Join timeout helper Thread ID is 6002
2022-09-01T14:19:39.391Z,1662041979.391 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T14:19:39.392Z,1662041979.392 [logger ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:39.396Z,1662041979.396 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2022-09-01T14:19:39.396Z,1662041979.396 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:39.397Z,1662041979.397 [CommandLine](INFO): Join timeout helper Thread ID is 6003
2022-09-01T14:19:39.448Z,1662041979.448 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T14:19:39.449Z,1662041979.449 [CommandLine ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:39.467Z,1662041979.467 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2022-09-01T14:19:39.467Z,1662041979.467 [CommandExec ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:39.468Z,1662041979.468 [CommandExec](INFO): Join timeout helper Thread ID is 6004
2022-09-01T14:19:39.471Z,1662041979.471 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2022-09-01T14:19:39.472Z,1662041979.472 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:39.473Z,1662041979.473 [controlThread](INFO): Join timeout helper Thread ID is 6005
2022-09-01T14:19:39.520Z,1662041979.520 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2022-09-01T14:19:39.520Z,1662041979.520 [controlThread](DEBUG): Uninitializing ControlThread
2022-09-01T14:19:39.520Z,1662041979.520 [AHRS_M2](INFO): Powering down
2022-09-01T14:19:39.593Z,1662041979.593 [DDM](INFO): Powering down
2022-09-01T14:19:39.664Z,1662041979.664 [Micromodem](INFO): Powering down
2022-09-01T14:19:39.760Z,1662041979.760 [NAL9602](INFO): Powering down
2022-09-01T14:19:39.832Z,1662041979.832 [RDI_Pathfinder](INFO): Powering down
2022-09-01T14:19:39.903Z,1662041979.903 [RDI_PathfinderUp](INFO): Powering down
2022-09-01T14:19:39.905Z,1662041979.905 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2022-09-01T14:19:39.906Z,1662041979.906 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2022-09-01T14:19:39.906Z,1662041979.906 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2022-09-01T14:19:39.907Z,1662041979.907 [MissionManager](INFO): Uninitializing Mission Default
2022-09-01T14:19:39.910Z,1662041979.910 [MissionManager](INFO): Uninitializing Mission Startup
2022-09-01T14:19:39.910Z,1662041979.910 [Startup] Stopped
2022-09-01T14:19:39.910Z,1662041979.910 [Startup](DEBUG): Aggregate::uninitialize Startup
2022-09-01T14:19:39.910Z,1662041979.910 [Startup:A.GoToSurface] Stopped
2022-09-01T14:19:39.910Z,1662041979.910 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2022-09-01T14:19:39.910Z,1662041979.910 [Startup:StartupSatComms] Stopped
2022-09-01T14:19:39.910Z,1662041979.910 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2022-09-01T14:19:39.910Z,1662041979.910 [Startup:StartupSatComms:B] Stopped
2022-09-01T14:19:39.912Z,1662041979.912 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2022-09-01T14:19:39.912Z,1662041979.912 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2022-09-01T14:19:39.912Z,1662041979.912 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2022-09-01T14:19:39.913Z,1662041979.913 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2022-09-01T14:19:39.913Z,1662041979.913 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2022-09-01T14:19:39.913Z,1662041979.913 [BuoyancyServo](INFO): Powering down
2022-09-01T14:19:39.927Z,1662041979.927 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2022-09-01T14:19:39.928Z,1662041979.928 [ElevatorServo](INFO): Powering down
2022-09-01T14:19:39.928Z,1662041979.928 [DockingServo](DEBUG): Uninitialize Docking Servo.
2022-09-01T14:19:39.929Z,1662041979.929 [MassServo](DEBUG): Uninitialize Mass Servo.
2022-09-01T14:19:39.929Z,1662041979.929 [MassServo](INFO): Powering down
2022-09-01T14:19:39.930Z,1662041979.930 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2022-09-01T14:19:39.930Z,1662041979.930 [RudderServo](INFO): Powering down
2022-09-01T14:19:39.931Z,1662041979.931 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2022-09-01T14:19:39.931Z,1662041979.931 [ThrusterHE](INFO): Powering down
2022-09-01T14:19:39.932Z,1662041979.932 [SBIT](DEBUG): Uninitialize SBIT Component.
2022-09-01T14:19:39.932Z,1662041979.932 [IBIT](DEBUG): Uninitialize IBIT Component.
2022-09-01T14:19:39.932Z,1662041979.932 [CBIT](DEBUG): Uninitialize CBIT Component.
2022-09-01T14:19:39.933Z,1662041979.933 [CBIT](DEBUG): Powering off loads.
2022-09-01T14:19:39.943Z,1662041979.943 [CBIT](DEBUG): Disabling WDT.
2022-09-01T14:19:39.955Z,1662041979.955 [CBIT](DEBUG): Opening all GF detection circuits.
2022-09-01T14:19:39.956Z,1662041979.956 [controlThread ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:39.976Z,1662041979.976 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:39.980Z,1662041979.980 [Onboard ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:39.990Z,1662041979.990 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:40.084Z,1662041980.084 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:40.087Z,1662041980.087 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:40.149Z,1662041980.149 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2022-09-01T14:19:40.216Z,1662041980.216 [logger ThreadHandler](INFO): Thread cancelled.