2022-05-25T23:25:16.636Z,1653521116.636 [Supervisor](DEBUG): Initializing supervisor.
2022-05-25T23:25:16.640Z,1653521116.640 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-05-25T23:25:16.641Z,1653521116.641 [SyncHandler](INFO): Protected caller Thread ID is 8810
2022-05-25T23:25:16.641Z,1653521116.641 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-05-25T23:25:16.642Z,1653521116.642 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-05-25T23:25:16.642Z,1653521116.642 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8811
2022-05-25T23:25:16.647Z,1653521116.647 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-05-25T23:25:16.666Z,1653521116.666 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-05-25T23:25:16.667Z,1653521116.667 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-05-25T23:25:16.667Z,1653521116.667 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 8812
2022-05-25T23:25:16.671Z,1653521116.671 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-05-25T23:25:16.672Z,1653521116.672 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-05-25T23:25:16.673Z,1653521116.673 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8813
2022-05-25T23:25:16.675Z,1653521116.675 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-05-25T23:25:16.676Z,1653521116.676 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-05-25T23:25:16.676Z,1653521116.676 [logger ThreadHandler](INFO): Protected caller Thread ID is 8814
2022-05-25T23:25:16.680Z,1653521116.680 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-05-25T23:25:16.680Z,1653521116.680 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-05-25T23:25:16.686Z,1653521116.686 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-05-25T23:25:16.847Z,1653521116.847 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-05-25T23:25:16.848Z,1653521116.848 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-05-25T23:25:17.070Z,1653521117.070 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-05-25T23:25:17.070Z,1653521117.070 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-05-25T23:25:17.337Z,1653521117.337 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-05-25T23:25:17.338Z,1653521117.338 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-05-25T23:25:17.447Z,1653521117.447 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-05-25T23:25:17.449Z,1653521117.449 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-05-25T23:25:18.119Z,1653521118.119 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-05-25T23:25:18.120Z,1653521118.120 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-05-25T23:25:18.590Z,1653521118.590 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-05-25T23:25:18.591Z,1653521118.591 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-05-25T23:25:19.174Z,1653521119.174 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-05-25T23:25:19.174Z,1653521119.174 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-05-25T23:25:19.608Z,1653521119.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-05-25T23:25:19.609Z,1653521119.609 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-05-25T23:25:20.448Z,1653521120.448 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-05-25T23:25:20.449Z,1653521120.449 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-05-25T23:25:20.831Z,1653521120.831 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-05-25T23:25:20.831Z,1653521120.831 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-05-25T23:25:21.058Z,1653521121.058 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-05-25T23:25:21.059Z,1653521121.059 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-05-25T23:25:21.192Z,1653521121.192 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-05-25T23:25:21.192Z,1653521121.192 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-05-25T23:25:21.275Z,1653521121.275 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-05-25T23:25:21.355Z,1653521121.355 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-05-25T23:25:21.549Z,1653521121.549 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-05-25T23:25:21.550Z,1653521121.550 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-05-25T23:25:21.773Z,1653521121.773 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-05-25T23:25:21.775Z,1653521121.775 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2022-05-25T23:25:21.778Z,1653521121.778 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2022-05-25T23:25:21.863Z,1653521121.863 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2022-05-25T23:25:22.130Z,1653521122.130 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-05-25T23:25:22.131Z,1653521122.131 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2022-05-25T23:25:22.233Z,1653521122.233 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2022-05-25T23:25:22.402Z,1653521122.402 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2022-05-25T23:25:22.592Z,1653521122.592 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2022-05-25T23:25:22.679Z,1653521122.679 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2022-05-25T23:25:22.790Z,1653521122.790 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2022-05-25T23:25:22.899Z,1653521122.899 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2022-05-25T23:25:23.064Z,1653521123.064 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2022-05-25T23:25:23.171Z,1653521123.171 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2022-05-25T23:25:23.274Z,1653521123.274 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2022-05-25T23:25:23.275Z,1653521123.275 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-05-25T23:25:23.295Z,1653521123.295 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-05-25T23:25:23.433Z,1653521123.433 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-05-25T23:25:23.434Z,1653521123.434 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-05-25T23:25:23.607Z,1653521123.607 [BuoyancyServo] Loaded
2022-05-25T23:25:23.607Z,1653521123.607 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-05-25T23:25:23.628Z,1653521123.628 [ElevatorServo] Loaded
2022-05-25T23:25:23.628Z,1653521123.628 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-05-25T23:25:23.648Z,1653521123.648 [MassServo] Loaded
2022-05-25T23:25:23.648Z,1653521123.648 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-05-25T23:25:23.668Z,1653521123.668 [RudderServo] Loaded
2022-05-25T23:25:23.669Z,1653521123.669 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-05-25T23:25:23.685Z,1653521123.685 [ThrusterHE] Loaded
2022-05-25T23:25:23.685Z,1653521123.685 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-05-25T23:25:23.685Z,1653521123.685 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-05-25T23:25:23.686Z,1653521123.686 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-05-25T23:25:23.851Z,1653521123.851 [SBIT](DEBUG): Construct Startup Built In Test.
2022-05-25T23:25:23.866Z,1653521123.866 [SBIT] Loaded
2022-05-25T23:25:23.866Z,1653521123.866 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-05-25T23:25:23.869Z,1653521123.869 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-05-25T23:25:23.890Z,1653521123.890 [IBIT] Loaded
2022-05-25T23:25:23.890Z,1653521123.890 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-05-25T23:25:23.895Z,1653521123.895 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-05-25T23:25:24.113Z,1653521124.113 [CBIT] Loaded
2022-05-25T23:25:24.114Z,1653521124.114 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-05-25T23:25:24.114Z,1653521124.114 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-05-25T23:25:24.115Z,1653521124.115 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-05-25T23:25:24.321Z,1653521124.321 [CTD_Seabird] Loaded
2022-05-25T23:25:24.321Z,1653521124.321 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-05-25T23:25:24.323Z,1653521124.323 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406614E0
2022-05-25T23:25:24.323Z,1653521124.323 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8896
2022-05-25T23:25:24.355Z,1653521124.355 [ESPComponent] Loaded
2022-05-25T23:25:24.355Z,1653521124.355 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2022-05-25T23:25:24.374Z,1653521124.374 [PAR_Licor] Loaded
2022-05-25T23:25:24.374Z,1653521124.374 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-05-25T23:25:24.406Z,1653521124.406 [WetLabsBB2FL] Loaded
2022-05-25T23:25:24.406Z,1653521124.406 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2022-05-25T23:25:24.407Z,1653521124.407 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406914E0
2022-05-25T23:25:24.407Z,1653521124.407 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8897
2022-05-25T23:25:24.408Z,1653521124.408 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-05-25T23:25:24.409Z,1653521124.409 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-05-25T23:25:24.474Z,1653521124.474 [DepthRateCalculator] Loaded
2022-05-25T23:25:24.475Z,1653521124.475 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-05-25T23:25:24.480Z,1653521124.480 [PitchRateCalculator] Loaded
2022-05-25T23:25:24.480Z,1653521124.480 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-05-25T23:25:24.491Z,1653521124.491 [SpeedCalculator] Loaded
2022-05-25T23:25:24.491Z,1653521124.491 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-05-25T23:25:24.496Z,1653521124.496 [YawRateCalculator] Loaded
2022-05-25T23:25:24.496Z,1653521124.496 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-05-25T23:25:24.515Z,1653521124.515 [ElevatorOffsetCalculator] Loaded
2022-05-25T23:25:24.515Z,1653521124.515 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-05-25T23:25:24.532Z,1653521124.532 [ShortestDistanceToPolygonSidesCalculator] Loaded
2022-05-25T23:25:24.532Z,1653521124.532 [ComponentRegistry](DEBUG): SyncComponent "ShortestDistanceToPolygonSidesCalculator" handled in the control thread.
2022-05-25T23:25:24.533Z,1653521124.533 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-05-25T23:25:24.533Z,1653521124.533 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-05-25T23:25:24.649Z,1653521124.649 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-05-25T23:25:24.650Z,1653521124.650 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-05-25T23:25:25.329Z,1653521125.329 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-05-25T23:25:25.330Z,1653521125.330 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-05-25T23:25:25.777Z,1653521125.777 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-05-25T23:25:25.777Z,1653521125.777 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-05-25T23:25:25.791Z,1653521125.791 [NavChart] Loaded
2022-05-25T23:25:25.791Z,1653521125.791 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-05-25T23:25:25.797Z,1653521125.797 [UniversalFixResidualReporter] Loaded
2022-05-25T23:25:25.797Z,1653521125.797 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-05-25T23:25:25.798Z,1653521125.798 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-05-25T23:25:25.798Z,1653521125.798 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-05-25T23:25:26.324Z,1653521126.324 [AHRS_M2] Loaded
2022-05-25T23:25:26.324Z,1653521126.324 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-05-25T23:25:26.359Z,1653521126.359 [BackseatComponent] Loaded
2022-05-25T23:25:26.359Z,1653521126.359 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-05-25T23:25:26.361Z,1653521126.361 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A0D4E0
2022-05-25T23:25:26.361Z,1653521126.361 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 8898
2022-05-25T23:25:26.364Z,1653521126.364 [LcmUniversalReporter] Loaded
2022-05-25T23:25:26.364Z,1653521126.364 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-05-25T23:25:26.445Z,1653521126.445 [DataOverHttps] Loaded
2022-05-25T23:25:26.445Z,1653521126.445 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2022-05-25T23:25:26.446Z,1653521126.446 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A3D4E0
2022-05-25T23:25:26.446Z,1653521126.446 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8899
2022-05-25T23:25:26.466Z,1653521126.466 [Depth_Keller] Loaded
2022-05-25T23:25:26.466Z,1653521126.466 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-05-25T23:25:26.471Z,1653521126.471 [DropWeight] Loaded
2022-05-25T23:25:26.471Z,1653521126.471 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-05-25T23:25:26.508Z,1653521126.508 [DVL_micro] Loaded
2022-05-25T23:25:26.508Z,1653521126.508 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2022-05-25T23:25:26.567Z,1653521126.567 [NAL9602] Loaded
2022-05-25T23:25:26.568Z,1653521126.568 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-05-25T23:25:26.594Z,1653521126.594 [Onboard] Loaded
2022-05-25T23:25:26.594Z,1653521126.594 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-05-25T23:25:26.595Z,1653521126.595 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40A6D4E0
2022-05-25T23:25:26.595Z,1653521126.595 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 8900
2022-05-25T23:25:26.607Z,1653521126.607 [Power24vConverter] Loaded
2022-05-25T23:25:26.607Z,1653521126.607 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-05-25T23:25:26.621Z,1653521126.621 [Radio_Surface] Loaded
2022-05-25T23:25:26.621Z,1653521126.621 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2022-05-25T23:25:26.622Z,1653521126.622 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A9D4E0
2022-05-25T23:25:26.622Z,1653521126.622 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8901
2022-05-25T23:25:26.623Z,1653521126.623 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-05-25T23:25:26.624Z,1653521126.624 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-05-25T23:25:26.705Z,1653521126.705 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-05-25T23:25:26.705Z,1653521126.705 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-05-25T23:25:26.772Z,1653521126.772 [VerticalControl](DEBUG): Construct VerticalControl.
2022-05-25T23:25:26.823Z,1653521126.823 [VerticalControl] Loaded
2022-05-25T23:25:26.824Z,1653521126.824 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-05-25T23:25:26.826Z,1653521126.826 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-05-25T23:25:26.863Z,1653521126.863 [HorizontalControl] Loaded
2022-05-25T23:25:26.863Z,1653521126.863 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-05-25T23:25:26.866Z,1653521126.866 [SpeedControl](DEBUG): Construct SpeedControl.
2022-05-25T23:25:26.868Z,1653521126.868 [SpeedControl] Loaded
2022-05-25T23:25:26.868Z,1653521126.868 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-05-25T23:25:26.871Z,1653521126.871 [LoopControl](DEBUG): Construct LoopControl.
2022-05-25T23:25:26.871Z,1653521126.871 [LoopControl] Loaded
2022-05-25T23:25:26.871Z,1653521126.871 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-05-25T23:25:26.872Z,1653521126.872 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-05-25T23:25:26.872Z,1653521126.872 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-05-25T23:25:26.886Z,1653521126.886 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-05-25T23:25:26.887Z,1653521126.887 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-05-25T23:25:27.243Z,1653521127.243 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-05-25T23:25:27.249Z,1653521127.249 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-05-25T23:25:27.252Z,1653521127.252 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-05-25T23:25:27.263Z,1653521127.263 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-05-25T23:25:27.264Z,1653521127.264 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BA74E0
2022-05-25T23:25:27.264Z,1653521127.264 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8902
2022-05-25T23:25:27.269Z,1653521127.269 [Supervisor](INFO): Main Thread ID is 8031
2022-05-25T23:25:27.269Z,1653521127.269 [Supervisor](DEBUG): Running supervisor.
2022-05-25T23:25:27.270Z,1653521127.270 [CommandExec ThreadHandler](INFO): Handler Thread ID is 8903
2022-05-25T23:25:27.270Z,1653521127.270 [CommandExec](INFO): Initializing the command executive.
2022-05-25T23:25:27.272Z,1653521127.272 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8904
2022-05-25T23:25:27.275Z,1653521127.275 [controlThread ThreadHandler](INFO): Handler Thread ID is 8905
2022-05-25T23:25:27.275Z,1653521127.275 [controlThread](DEBUG): Initializing ControlThread
2022-05-25T23:25:27.277Z,1653521127.277 [SBIT](INFO): Initialize SBIT Component.
2022-05-25T23:25:27.277Z,1653521127.277 [SBIT](IMPORTANT): git: 2022-05-25A
2022-05-25T23:25:27.278Z,1653521127.278 [SBIT](INFO): git hash: a0086c8a5451a7962f96ee2dcfeec2a8af4d7638
2022-05-25T23:25:27.278Z,1653521127.278 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-05-25T23:25:27.279Z,1653521127.279 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2022-05-25T23:25:27.280Z,1653521127.280 [SBIT](INFO): Beginning SBIT in 116.000000 seconds.
2022-05-25T23:25:27.281Z,1653521127.281 [IBIT](INFO): Initialize IBIT Component.
2022-05-25T23:25:27.282Z,1653521127.282 [CBIT](DEBUG): Initialize CBIT Component.
2022-05-25T23:25:27.283Z,1653521127.283 [logger ThreadHandler](INFO): Handler Thread ID is 8906
2022-05-25T23:25:27.293Z,1653521127.293 [CBIT](DEBUG): Initialized mux pins.
2022-05-25T23:25:27.294Z,1653521127.294 [CBIT](DEBUG): Initializing the watchdog timer.
2022-05-25T23:25:27.302Z,1653521127.302 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8907
2022-05-25T23:25:27.303Z,1653521127.303 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-05-25T23:25:27.307Z,1653521127.307 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8909
2022-05-25T23:25:27.310Z,1653521127.310 [WetLabsBB2FL](INFO): Powering up
2022-05-25T23:25:27.311Z,1653521127.311 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 8911
2022-05-25T23:25:27.317Z,1653521127.317 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-05-25T23:25:27.318Z,1653521127.318 [CBIT](DEBUG): Initializing heartbeat.
2022-05-25T23:25:27.319Z,1653521127.319 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8912
2022-05-25T23:25:27.320Z,1653521127.320 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2022-05-25T23:25:27.334Z,1653521127.334 [Onboard ThreadHandler](INFO): Handler Thread ID is 8913
2022-05-25T23:25:27.351Z,1653521127.351 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8914
2022-05-25T23:25:27.375Z,1653521127.375 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8915
2022-05-25T23:25:27.381Z,1653521127.381 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-05-25T23:25:27.381Z,1653521127.381 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-05-25T23:25:27.381Z,1653521127.381 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-05-25T23:25:27.381Z,1653521127.381 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-05-25T23:25:27.381Z,1653521127.381 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-05-25T23:25:27.382Z,1653521127.382 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-05-25T23:25:27.382Z,1653521127.382 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-05-25T23:25:27.382Z,1653521127.382 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-05-25T23:25:27.382Z,1653521127.382 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA69M.000
2022-05-25T23:25:27.382Z,1653521127.382 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA69M.000
2022-05-25T23:25:27.390Z,1653521127.390 [CBIT](DEBUG): Deactivating GF circuits.
2022-05-25T23:25:27.390Z,1653521127.390 [CBIT](DEBUG): Deactivating emergency mode.
2022-05-25T23:25:27.426Z,1653521127.426 [CBIT](DEBUG): Backplane powered.
2022-05-25T23:25:27.430Z,1653521127.430 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-05-25T23:25:27.430Z,1653521127.430 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-05-25T23:25:27.431Z,1653521127.431 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-05-25T23:25:27.431Z,1653521127.431 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-05-25T23:25:27.431Z,1653521127.431 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-05-25T23:25:27.432Z,1653521127.432 [ShortestDistanceToPolygonSidesCalculator](DEBUG): Initializing.
2022-05-25T23:25:27.434Z,1653521127.434 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-05-25T23:25:27.434Z,1653521127.434 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-05-25T23:25:27.456Z,1653521127.456 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-05-25T23:25:27.466Z,1653521127.466 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-05-25T23:25:27.466Z,1653521127.466 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-05-25T23:25:27.467Z,1653521127.467 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-05-25T23:25:27.468Z,1653521127.468 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-05-25T23:25:27.497Z,1653521127.497 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-05-25T23:25:27.534Z,1653521127.534 [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-05-25T23:25:27.535Z,1653521127.535 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-05-25T23:25:27.631Z,1653521127.631 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-05-25T23:25:27.632Z,1653521127.632 [Default:A.Wait](DEBUG): Construct Wait.
2022-05-25T23:25:27.635Z,1653521127.635 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-05-25T23:25:27.682Z,1653521127.682 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-05-25T23:25:27.685Z,1653521127.685 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-05-25T23:25:27.718Z,1653521127.718 [Default:E.Execute](DEBUG): Construct Execute.
2022-05-25T23:25:27.722Z,1653521127.722 [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-05-25T23:25:27.742Z,1653521127.742 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,ShortestDistanceToPolygonSidesCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-05-25T23:25:27.758Z,1653521127.758 [Radio_Surface](INFO): Powering up
2022-05-25T23:25:27.760Z,1653521127.760 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-05-25T23:25:27.792Z,1653521127.792 [Depth_Keller](ERROR): Pressure reading out of range: 1895.834351 decibar
2022-05-25T23:25:27.803Z,1653521127.803 [Power24vConverter](INFO): Powering up.
2022-05-25T23:25:27.854Z,1653521127.854 [DepthRateCalculator](ERROR): Depth measurement is not active
2022-05-25T23:25:27.884Z,1653521127.884 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-05-25T23:25:27.890Z,1653521127.890 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-05-25T23:25:27.891Z,1653521127.891 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-05-25T23:25:27.898Z,1653521127.898 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-05-25T23:25:27.899Z,1653521127.899 [MassServo](DEBUG): Initializing EZServoServo.
2022-05-25T23:25:27.906Z,1653521127.906 [MassServo](DEBUG): Initializing MassServo.
2022-05-25T23:25:27.907Z,1653521127.907 [RudderServo](DEBUG): Initializing EZServoServo.
2022-05-25T23:25:27.914Z,1653521127.914 [RudderServo](DEBUG): Initializing RudderServo.
2022-05-25T23:25:27.915Z,1653521127.915 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-05-25T23:25:27.922Z,1653521127.922 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-05-25T23:25:28.195Z,1653521128.195 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2022-05-25T23:25:28.196Z,1653521128.196 [DropWeight] Hardware Fault, FailCount= 1
2022-05-25T23:25:28.196Z,1653521128.196 [DropWeight](ERROR): Hardware Fault
2022-05-25T23:25:28.240Z,1653521128.240 [CommandExec](FAULT): Scheduling is paused
2022-05-25T23:25:28.240Z,1653521128.240 [CBIT](INFO): Critical error at 20220525T232528
2022-05-25T23:25:28.241Z,1653521128.241 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2022-05-25T23:25:28.251Z,1653521128.251 [CBIT](ERROR): Hardware Fault in component: DropWeight
2022-05-25T23:25:28.252Z,1653521128.252 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2022-05-25T23:25:28.639Z,1653521128.639 [CBIT](INFO): Critical error at 20220525T232528
2022-05-25T23:25:29.418Z,1653521129.418 [WetLabsBB2FL](INFO): Powering down
2022-05-25T23:25:33.651Z,1653521133.651 [ThrusterHE](ERROR): Zero Speed Commanded.
2022-05-25T23:25:56.848Z,1653521156.848 [NAL9602](INFO): Powering up NAL9602
2022-05-25T23:26:07.752Z,1653521167.752 [NAL9602](INFO): NAL9602 initialized
2022-05-25T23:27:23.736Z,1653521243.736 [SBIT](IMPORTANT): Beginning Startup BIT
2022-05-25T23:27:23.740Z,1653521243.740 [CBIT](IMPORTANT): Beginning ground fault scan
2022-05-25T23:27:34.674Z,1653521254.674 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.003348
CHAN A1 (24V): 0.000757
CHAN A2 (12V): -0.005355
CHAN A3 (5V): -0.002783
CHAN B0 (3.3V): -0.000781
CHAN B1 (3.15aV): 0.000022
CHAN B2 (3.15bV): -0.001106
CHAN B3 (GND): 0.000014
OPEN: 0.007283
Full Scale: +/- 1 mA
2022-05-25T23:28:10.496Z,1653521290.496 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004588
2022-05-25T23:28:17.511Z,1653521297.511 [SBIT](IMPORTANT): SBIT PASSED
2022-05-25T23:28:17.511Z,1653521297.511 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-05-25T23:28:17.512Z,1653521297.512 [SBIT](IMPORTANT): BPC1.loadAtStartup=0 bool;

2022-05-25T23:28:17.512Z,1653521297.512 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;

2022-05-25T23:28:17.512Z,1653521297.512 [SBIT](IMPORTANT): Depth_Keller.offset=-0.41 decibar;

2022-05-25T23:28:17.513Z,1653521297.513 [SBIT](IMPORTANT): ElevatorServo.offsetAngle=1 degree;

2022-05-25T23:28:17.513Z,1653521297.513 [SBIT](IMPORTANT): Express linearApproximation CBIT.ampHoursUsed 5.0 ampere_hour;

2022-05-25T23:28:17.513Z,1653521297.513 [SBIT](IMPORTANT): Express linearApproximation NAL9602.sigQuality 1.000000 count;

2022-05-25T23:28:17.513Z,1653521297.513 [SBIT](IMPORTANT): RudderServo.offsetAngle=0 degree;

2022-05-25T23:28:17.513Z,1653521297.513 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex1=34.5 degree;

2022-05-25T23:28:17.513Z,1653521297.513 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex2=34.4381 degree;

2022-05-25T23:28:17.513Z,1653521297.513 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex3=34.2067 degree;

2022-05-25T23:28:17.514Z,1653521297.514 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex4=34.13 degree;

2022-05-25T23:28:17.514Z,1653521297.514 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.latVertex5=34.4621 degree;

2022-05-25T23:28:17.514Z,1653521297.514 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.loadAtStartup=1 bool;

2022-05-25T23:28:17.514Z,1653521297.514 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex1=-120.84 degree;

2022-05-25T23:28:17.514Z,1653521297.514 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex2=-120.069 degree;

2022-05-25T23:28:17.514Z,1653521297.514 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex3=-119.331 degree;

2022-05-25T23:28:17.514Z,1653521297.514 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex4=-119.331 degree;

2022-05-25T23:28:17.515Z,1653521297.515 [SBIT](IMPORTANT): ShortestDistanceToPolygonSidesCalculator.lonVertex5=-120.845 degree;

2022-05-25T23:28:17.515Z,1653521297.515 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=160 cubic_centimeter;

2022-05-25T23:28:17.515Z,1653521297.515 [SBIT](IMPORTANT): VerticalControl.massDefault=-24 millimeter;

2022-05-25T23:28:17.515Z,1653521297.515 [SBIT](IMPORTANT): VerticalControl.massPositionLimitAft=-28 millimeter;

2022-05-25T23:28:17.875Z,1653521297.875 [MissionManager](IMPORTANT): Started mission Startup
2022-05-25T23:28:17.875Z,1653521297.875 [Startup] Running Loop=1
2022-05-25T23:28:17.875Z,1653521297.875 [Startup](DEBUG): Aggregate::initialize Startup
2022-05-25T23:28:17.875Z,1653521297.875 [Startup:A.GoToSurface] Running Loop=1
2022-05-25T23:28:17.875Z,1653521297.875 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-05-25T23:28:17.876Z,1653521297.876 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-05-25T23:28:17.876Z,1653521297.876 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default v