2023-09-08T13:28:00.288Z,1694179680.288 [Supervisor](DEBUG): Initializing supervisor.
2023-09-08T13:28:00.292Z,1694179680.292 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-09-08T13:28:00.293Z,1694179680.293 [SyncHandler](INFO): Protected caller Thread ID is 830
2023-09-08T13:28:00.293Z,1694179680.293 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-09-08T13:28:00.294Z,1694179680.294 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-09-08T13:28:00.295Z,1694179680.295 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 831
2023-09-08T13:28:00.299Z,1694179680.299 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-09-08T13:28:00.317Z,1694179680.317 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-09-08T13:28:00.318Z,1694179680.318 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-09-08T13:28:00.318Z,1694179680.318 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 832
2023-09-08T13:28:00.323Z,1694179680.323 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-09-08T13:28:00.324Z,1694179680.324 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-09-08T13:28:00.324Z,1694179680.324 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 833
2023-09-08T13:28:00.326Z,1694179680.326 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-09-08T13:28:00.327Z,1694179680.327 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-09-08T13:28:00.328Z,1694179680.328 [logger ThreadHandler](INFO): Protected caller Thread ID is 834
2023-09-08T13:28:00.332Z,1694179680.332 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-09-08T13:28:00.332Z,1694179680.332 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-09-08T13:28:00.338Z,1694179680.338 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-09-08T13:28:00.434Z,1694179680.434 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-09-08T13:28:00.435Z,1694179680.435 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-09-08T13:28:00.658Z,1694179680.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-09-08T13:28:00.660Z,1694179680.660 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-09-08T13:28:00.921Z,1694179680.921 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-09-08T13:28:00.921Z,1694179680.921 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-09-08T13:28:01.028Z,1694179681.028 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-09-08T13:28:01.030Z,1694179681.030 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-09-08T13:28:01.779Z,1694179681.779 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-09-08T13:28:01.781Z,1694179681.781 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-09-08T13:28:02.275Z,1694179682.275 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-09-08T13:28:02.277Z,1694179682.277 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-09-08T13:28:02.774Z,1694179682.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-09-08T13:28:02.776Z,1694179682.776 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-09-08T13:28:03.188Z,1694179683.188 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-09-08T13:28:03.189Z,1694179683.189 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-09-08T13:28:03.569Z,1694179683.569 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-09-08T13:28:03.570Z,1694179683.570 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-09-08T13:28:04.575Z,1694179684.575 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-09-08T13:28:04.575Z,1694179684.575 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-09-08T13:28:04.800Z,1694179684.800 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-09-08T13:28:04.801Z,1694179684.801 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-09-08T13:28:04.942Z,1694179684.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-09-08T13:28:04.942Z,1694179684.942 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-09-08T13:28:05.025Z,1694179685.025 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-09-08T13:28:05.105Z,1694179685.105 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-09-08T13:28:05.306Z,1694179685.306 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-09-08T13:28:05.307Z,1694179685.307 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-09-08T13:28:05.543Z,1694179685.543 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-09-08T13:28:05.545Z,1694179685.545 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2023-09-08T13:28:05.547Z,1694179685.547 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2023-09-08T13:28:05.631Z,1694179685.631 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2023-09-08T13:28:05.897Z,1694179685.897 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-09-08T13:28:05.899Z,1694179685.899 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2023-09-08T13:28:06.008Z,1694179686.008 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2023-09-08T13:28:06.170Z,1694179686.170 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2023-09-08T13:28:06.275Z,1694179686.275 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2023-09-08T13:28:06.390Z,1694179686.390 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2023-09-08T13:28:06.501Z,1694179686.501 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2023-09-08T13:28:06.606Z,1694179686.606 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2023-09-08T13:28:06.770Z,1694179686.770 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Derivation.cfg
2023-09-08T13:28:06.868Z,1694179686.868 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2023-09-08T13:28:06.965Z,1694179686.965 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2023-09-08T13:28:07.066Z,1694179687.066 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2023-09-08T13:28:07.072Z,1694179687.072 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-09-08T13:28:07.267Z,1694179687.267 [InternalEnvSim] Loaded
2023-09-08T13:28:07.267Z,1694179687.267 [ComponentRegistry](DEBUG): SyncComponent "InternalEnvSim" handled in the control thread.
2023-09-08T13:28:07.268Z,1694179687.268 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-09-08T13:28:07.269Z,1694179687.269 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-09-08T13:28:07.453Z,1694179687.453 [BuoyancyServo] Loaded
2023-09-08T13:28:07.453Z,1694179687.453 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-09-08T13:28:07.475Z,1694179687.475 [ElevatorServo] Loaded
2023-09-08T13:28:07.475Z,1694179687.475 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-09-08T13:28:07.496Z,1694179687.496 [MassServo] Loaded
2023-09-08T13:28:07.496Z,1694179687.496 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-09-08T13:28:07.516Z,1694179687.516 [RudderServo] Loaded
2023-09-08T13:28:07.517Z,1694179687.517 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-09-08T13:28:07.533Z,1694179687.533 [ThrusterHE] Loaded
2023-09-08T13:28:07.533Z,1694179687.533 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-09-08T13:28:07.534Z,1694179687.534 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-09-08T13:28:07.535Z,1694179687.536 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-09-08T13:28:07.705Z,1694179687.705 [SBIT](DEBUG): Construct Startup Built In Test.
2023-09-08T13:28:07.721Z,1694179687.721 [SBIT] Loaded
2023-09-08T13:28:07.721Z,1694179687.721 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-09-08T13:28:07.724Z,1694179687.724 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-09-08T13:28:07.746Z,1694179687.746 [IBIT] Loaded
2023-09-08T13:28:07.746Z,1694179687.746 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-09-08T13:28:07.752Z,1694179687.752 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-09-08T13:28:07.974Z,1694179687.974 [CBIT] Loaded
2023-09-08T13:28:07.974Z,1694179687.974 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-09-08T13:28:07.975Z,1694179687.975 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-09-08T13:28:07.976Z,1694179687.976 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-09-08T13:28:08.194Z,1694179688.194 [CTD_Seabird] Loaded
2023-09-08T13:28:08.194Z,1694179688.194 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-09-08T13:28:08.196Z,1694179688.196 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406674E0
2023-09-08T13:28:08.196Z,1694179688.196 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 920
2023-09-08T13:28:08.229Z,1694179688.229 [ESPComponent] Loaded
2023-09-08T13:28:08.229Z,1694179688.229 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-09-08T13:28:08.249Z,1694179688.249 [PAR_Licor] Loaded
2023-09-08T13:28:08.249Z,1694179688.249 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-09-08T13:28:08.290Z,1694179688.290 [WetLabsBB2FL] Loaded
2023-09-08T13:28:08.291Z,1694179688.291 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-09-08T13:28:08.292Z,1694179688.292 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406974E0
2023-09-08T13:28:08.292Z,1694179688.292 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 921
2023-09-08T13:28:08.323Z,1694179688.323 [WetLabsSeaOWL_UV_A] Loaded
2023-09-08T13:28:08.323Z,1694179688.323 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2023-09-08T13:28:08.324Z,1694179688.324 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 406C74E0
2023-09-08T13:28:08.324Z,1694179688.324 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 922
2023-09-08T13:28:08.325Z,1694179688.325 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-09-08T13:28:08.326Z,1694179688.326 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-09-08T13:28:08.395Z,1694179688.395 [DepthRateCalculator] Loaded
2023-09-08T13:28:08.396Z,1694179688.396 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-09-08T13:28:08.401Z,1694179688.401 [PitchRateCalculator] Loaded
2023-09-08T13:28:08.402Z,1694179688.402 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-09-08T13:28:08.412Z,1694179688.412 [SpeedCalculator] Loaded
2023-09-08T13:28:08.413Z,1694179688.413 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-09-08T13:28:08.417Z,1694179688.417 [YawRateCalculator] Loaded
2023-09-08T13:28:08.418Z,1694179688.418 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-09-08T13:28:08.438Z,1694179688.438 [ElevatorOffsetCalculator] Loaded
2023-09-08T13:28:08.438Z,1694179688.438 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-09-08T13:28:08.439Z,1694179688.439 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-09-08T13:28:08.439Z,1694179688.439 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-09-08T13:28:08.566Z,1694179688.566 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-09-08T13:28:08.567Z,1694179688.567 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-09-08T13:28:08.610Z,1694179688.610 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-09-08T13:28:08.610Z,1694179688.610 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-09-08T13:28:08.748Z,1694179688.748 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-09-08T13:28:08.748Z,1694179688.748 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-09-08T13:28:08.763Z,1694179688.763 [NavChart] Loaded
2023-09-08T13:28:08.763Z,1694179688.763 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-09-08T13:28:08.769Z,1694179688.769 [UniversalFixResidualReporter] Loaded
2023-09-08T13:28:08.769Z,1694179688.769 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-09-08T13:28:08.770Z,1694179688.770 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-09-08T13:28:08.771Z,1694179688.771 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-09-08T13:28:09.602Z,1694179689.602 [AHRS_M2] Loaded
2023-09-08T13:28:09.602Z,1694179689.602 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-09-08T13:28:09.970Z,1694179689.970 [BackseatComponent] Loaded
2023-09-08T13:28:09.970Z,1694179689.970 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-09-08T13:28:09.971Z,1694179689.971 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A5F4E0
2023-09-08T13:28:09.972Z,1694179689.972 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 923
2023-09-08T13:28:09.975Z,1694179689.975 [LcmUniversalReporter] Loaded
2023-09-08T13:28:09.975Z,1694179689.975 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-09-08T13:28:11.221Z,1694179691.221 [BPC1] Loaded
2023-09-08T13:28:11.222Z,1694179691.222 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-09-08T13:28:11.362Z,1694179691.362 [DataOverHttps] Loaded
2023-09-08T13:28:11.363Z,1694179691.363 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-09-08T13:28:11.364Z,1694179691.364 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A8F4E0
2023-09-08T13:28:11.364Z,1694179691.364 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 924
2023-09-08T13:28:11.386Z,1694179691.386 [Depth_Keller] Loaded
2023-09-08T13:28:11.386Z,1694179691.386 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-09-08T13:28:11.391Z,1694179691.391 [DropWeight] Loaded
2023-09-08T13:28:11.392Z,1694179691.392 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2023-09-08T13:28:11.432Z,1694179691.432 [DVL_micro] Loaded
2023-09-08T13:28:11.432Z,1694179691.432 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2023-09-08T13:28:11.493Z,1694179691.493 [NAL9602] Loaded
2023-09-08T13:28:11.493Z,1694179691.493 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-09-08T13:28:11.519Z,1694179691.519 [Onboard] Loaded
2023-09-08T13:28:11.519Z,1694179691.519 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-09-08T13:28:11.520Z,1694179691.520 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40ABF4E0
2023-09-08T13:28:11.521Z,1694179691.521 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 925
2023-09-08T13:28:11.533Z,1694179691.533 [Power24vConverter] Loaded
2023-09-08T13:28:11.534Z,1694179691.534 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-09-08T13:28:11.547Z,1694179691.547 [Radio_Surface] Loaded
2023-09-08T13:28:11.548Z,1694179691.548 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-09-08T13:28:11.549Z,1694179691.549 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AEF4E0
2023-09-08T13:28:11.549Z,1694179691.549 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 926
2023-09-08T13:28:11.645Z,1694179691.645 [DAT] Loaded
2023-09-08T13:28:11.645Z,1694179691.645 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-09-08T13:28:11.646Z,1694179691.646 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40B1F4E0
2023-09-08T13:28:11.646Z,1694179691.646 [DAT ThreadHandler](INFO): Protected caller Thread ID is 927
2023-09-08T13:28:11.647Z,1694179691.647 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-09-08T13:28:11.648Z,1694179691.648 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-09-08T13:28:11.729Z,1694179691.729 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-09-08T13:28:11.730Z,1694179691.730 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-09-08T13:28:11.796Z,1694179691.796 [VerticalControl](DEBUG): Construct VerticalControl.
2023-09-08T13:28:11.848Z,1694179691.848 [VerticalControl] Loaded
2023-09-08T13:28:11.849Z,1694179691.849 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-09-08T13:28:11.852Z,1694179691.852 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-09-08T13:28:11.891Z,1694179691.891 [HorizontalControl] Loaded
2023-09-08T13:28:11.891Z,1694179691.891 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-09-08T13:28:11.893Z,1694179691.893 [SpeedControl](DEBUG): Construct SpeedControl.
2023-09-08T13:28:11.895Z,1694179691.895 [SpeedControl] Loaded
2023-09-08T13:28:11.896Z,1694179691.896 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-09-08T13:28:11.898Z,1694179691.898 [LoopControl](DEBUG): Construct LoopControl.
2023-09-08T13:28:11.899Z,1694179691.899 [LoopControl] Loaded
2023-09-08T13:28:11.899Z,1694179691.899 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-09-08T13:28:11.900Z,1694179691.900 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-09-08T13:28:11.900Z,1694179691.900 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-09-08T13:28:11.916Z,1694179691.916 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-09-08T13:28:11.916Z,1694179691.916 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-09-08T13:28:12.270Z,1694179692.270 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-09-08T13:28:12.276Z,1694179692.276 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-09-08T13:28:12.279Z,1694179692.279 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-09-08T13:28:12.290Z,1694179692.290 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-09-08T13:28:12.292Z,1694179692.292 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C2B4E0
2023-09-08T13:28:12.292Z,1694179692.292 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 928
2023-09-08T13:28:12.297Z,1694179692.297 [Supervisor](INFO): Main Thread ID is 823
2023-09-08T13:28:12.297Z,1694179692.297 [Supervisor](DEBUG): Running supervisor.
2023-09-08T13:28:12.297Z,1694179692.297 [CommandExec ThreadHandler](INFO): Handler Thread ID is 929
2023-09-08T13:28:12.298Z,1694179692.298 [CommandExec](INFO): Initializing the command executive.
2023-09-08T13:28:12.299Z,1694179692.299 [CommandLine ThreadHandler](INFO): Handler Thread ID is 930
2023-09-08T13:28:12.301Z,1694179692.301 [controlThread ThreadHandler](INFO): Handler Thread ID is 931
2023-09-08T13:28:12.302Z,1694179692.302 [controlThread](DEBUG): Initializing ControlThread
2023-09-08T13:28:12.303Z,1694179692.303 [InternalEnvSim](DEBUG):  InternaEnvlSim initializing...
2023-09-08T13:28:12.306Z,1694179692.306 [logger ThreadHandler](INFO): Handler Thread ID is 932
2023-09-08T13:28:12.336Z,1694179692.336 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 933
2023-09-08T13:28:12.337Z,1694179692.337 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-09-08T13:28:12.340Z,1694179692.340 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 935
2023-09-08T13:28:12.351Z,1694179692.351 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 937
2023-09-08T13:28:12.357Z,1694179692.357 [WetLabsBB2FL](INFO): Powering up
2023-09-08T13:28:12.372Z,1694179692.372 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 938
2023-09-08T13:28:12.388Z,1694179692.388 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 939
2023-09-08T13:28:12.389Z,1694179692.389 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-09-08T13:28:12.400Z,1694179692.400 [Onboard ThreadHandler](INFO): Handler Thread ID is 940
2023-09-08T13:28:12.424Z,1694179692.424 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 941
2023-09-08T13:28:12.442Z,1694179692.442 [SBIT](INFO): Initialize SBIT Component.
2023-09-08T13:28:12.443Z,1694179692.443 [SBIT](IMPORTANT): git: 2023-09-07
2023-09-08T13:28:12.443Z,1694179692.443 [SBIT](INFO): git hash: de73b65bba9e058a7fe4bf2bc7b950ee8b764c06
2023-09-08T13:28:12.443Z,1694179692.443 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-09-08T13:28:12.445Z,1694179692.445 [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
2023-09-08T13:28:12.446Z,1694179692.446 [SBIT](INFO): Beginning SBIT in 107.000000 seconds.
2023-09-08T13:28:12.447Z,1694179692.447 [DAT ThreadHandler](INFO): Handler Thread ID is 942
2023-09-08T13:28:12.447Z,1694179692.447 [DAT](INFO): Powering up
2023-09-08T13:28:12.448Z,1694179692.448 [DAT](DEBUG): Initializing DAT.
2023-09-08T13:28:12.452Z,1694179692.452 [IBIT](INFO): Initialize IBIT Component.
2023-09-08T13:28:12.453Z,1694179692.453 [CBIT](DEBUG): Initialize CBIT Component.
2023-09-08T13:28:12.453Z,1694179692.453 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 944
2023-09-08T13:28:12.463Z,1694179692.463 [NavChartDb](FAULT): Change detected in ENC collection. Wiping NavChart Directory
2023-09-08T13:28:12.465Z,1694179692.465 [CBIT](DEBUG): Initialized mux pins.
2023-09-08T13:28:12.465Z,1694179692.465 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2023-09-08T13:28:12.465Z,1694179692.465 [CBIT](DEBUG): Initializing the watchdog timer.
2023-09-08T13:28:12.488Z,1694179692.488 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000
2023-09-08T13:28:12.490Z,1694179692.490 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2MI01M.000
2023-09-08T13:28:12.490Z,1694179692.490 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI80M.000
2023-09-08T13:28:12.491Z,1694179692.491 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2023-09-08T13:28:12.492Z,1694179692.492 [CBIT](DEBUG): Initializing heartbeat.
2023-09-08T13:28:12.492Z,1694179692.492 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US2MI80M.000
2023-09-08T13:28:12.492Z,1694179692.492 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI57M.000
2023-09-08T13:28:12.494Z,1694179692.494 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI57M.000
2023-09-08T13:28:12.494Z,1694179692.494 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI56M.000
2023-09-08T13:28:12.496Z,1694179692.496 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI56M.000
2023-09-08T13:28:12.496Z,1694179692.496 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI90M.000
2023-09-08T13:28:12.497Z,1694179692.497 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI90M.000
2023-09-08T13:28:12.497Z,1694179692.497 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI89M.000
2023-09-08T13:28:12.499Z,1694179692.499 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4MI89M.000
2023-09-08T13:28:12.499Z,1694179692.499 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI03M.000
2023-09-08T13:28:12.517Z,1694179692.517 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI03M.000
2023-09-08T13:28:12.517Z,1694179692.517 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI06M.000
2023-09-08T13:28:12.519Z,1694179692.519 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4WI06M.000
2023-09-08T13:28:12.519Z,1694179692.519 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH01M.000
2023-09-08T13:28:12.520Z,1694179692.520 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4OH01M.000
2023-09-08T13:28:12.521Z,1694179692.521 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH04M.000
2023-09-08T13:28:12.522Z,1694179692.522 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4OH04M.000
2023-09-08T13:28:12.522Z,1694179692.522 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH02M.000
2023-09-08T13:28:12.524Z,1694179692.524 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4OH02M.000
2023-09-08T13:28:12.524Z,1694179692.524 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4PA20M.000
2023-09-08T13:28:12.526Z,1694179692.526 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4PA20M.000
2023-09-08T13:28:12.526Z,1694179692.526 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4PA21M.000
2023-09-08T13:28:12.534Z,1694179692.534 [NavChartDb](IMPORTANT): Will load Electronic Nav Chart data from US4PA21M.000
2023-09-08T13:28:12.564Z,1694179692.564 [CBIT](DEBUG): Deactivating GF circuits.
2023-09-08T13:28:12.564Z,1694179692.564 [CBIT](DEBUG): Deactivating emergency mode.
2023-09-08T13:28:12.588Z,1694179692.588 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4PA21M.000
2023-09-08T13:28:12.604Z,1694179692.604 [CBIT](DEBUG): Backplane powered.
2023-09-08T13:28:12.608Z,1694179692.608 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-09-08T13:28:12.609Z,1694179692.609 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-09-08T13:28:12.609Z,1694179692.609 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-09-08T13:28:12.609Z,1694179692.609 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-09-08T13:28:12.610Z,1694179692.610 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-09-08T13:28:12.611Z,1694179692.611 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-09-08T13:28:12.612Z,1694179692.612 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-09-08T13:28:12.615Z,1694179692.615 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-09-08T13:28:12.619Z,1694179692.619 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-09-08T13:28:12.620Z,1694179692.620 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-09-08T13:28:12.621Z,1694179692.621 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-09-08T13:28:12.622Z,1694179692.622 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-09-08T13:28:12.657Z,1694179692.657 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-09-08T13:28:12.681Z,1694179692.681 [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>


2023-09-08T13:28:12.684Z,1694179692.684 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-09-08T13:28:12.761Z,1694179692.761 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-09-08T13:28:12.762Z,1694179692.762 [Default:A.Wait](DEBUG): Construct Wait.
2023-09-08T13:28:12.764Z,1694179692.764 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-09-08T13:28:12.788Z,1694179692.788 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-09-08T13:28:12.790Z,1694179692.790 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-09-08T13:28:12.828Z,1694179692.828 [Radio_Surface](INFO): Powering up
2023-09-08T13:28:12.842Z,1694179692.842 [Default:E.Execute](DEBUG): Construct Execute.
2023-09-08T13:28:12.848Z,1694179692.848 [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="P4H">
                <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>


2023-09-08T13:28:12.853Z,1694179692.853 [controlThread](DEBUG): Component order: CycleStarter,InternalEnvSim,ESPComponent,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,DVL_micro,NAL9602,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-09-08T13:28:12.863Z,1694179692.863 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-09-08T13:28:13.040Z,1694179693.040 [Depth_Keller](ERROR): Pressure or depth reading out of range: 1895.894409 decibar, 0.000000 m
2023-09-08T13:28:13.049Z,1694179693.049 [Power24vConverter](INFO): Powering up.
2023-09-08T13:28:13.055Z,1694179693.055 [DepthRateCalculator](ERROR): Depth measurement is not active
2023-09-08T13:28:13.103Z,1694179693.103 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-09-08T13:28:13.128Z,1694179693.128 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-09-08T13:28:13.129Z,1694179693.129 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-09-08T13:28:13.136Z,1694179693.136 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-09-08T13:28:13.137Z,1694179693.137 [MassServo](DEBUG): Initializing EZServoServo.
2023-09-08T13:28:13.144Z,1694179693.144 [MassServo](DEBUG): Initializing MassServo.
2023-09-08T13:28:13.145Z,1694179693.145 [RudderServo](DEBUG): Initializing EZServoServo.
2023-09-08T13:28:13.152Z,1694179693.152 [RudderServo](DEBUG): Initializing RudderServo.
2023-09-08T13:28:13.153Z,1694179693.153 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-09-08T13:28:13.160Z,1694179693.160 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-09-08T13:28:13.162Z,1694179693.162 [CommandExec](FAULT): Scheduling is paused
2023-09-08T13:28:13.162Z,1694179693.162 [CBIT](INFO): Critical error at 20230908T132812
2023-09-08T13:28:13.162Z,1694179693.162 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2023-09-08T13:28:14.152Z,1694179694.152 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4PA21M.000
2023-09-08T13:28:14.452Z,1694179694.452 [WetLabsBB2FL](INFO): Powering down
2023-09-08T13:28:18.756Z,1694179698.756 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-09-08T13:28:24.544Z,1694179704.544 [DAT](INFO): DAT read: 

2023-09-08T13:28:24.546Z,1694179704.546 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-09-08T13:28:26.056Z,1694179706.056 [DAT](INFO): DAT read: MF Frequency Band

2023-09-08T13:28:26.058Z,1694179706.058 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-09-08T13:28:26.058Z,1694179706.058 [DAT](INFO): DAT read: Sep  8 2023 13:28:20 

2023-09-08T13:28:27.317Z,1694179707.317 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-09-08T13:28:27.318Z,1694179707.318 [DAT](INFO): DAT read: CONNECT 01200 bits/sec 1 of 4, Rate 1/2 CC

2023-09-08T13:28:27.318Z,1694179707.318 [DAT](INFO): commRate: 1200
2023-09-08T13:28:28.593Z,1694179708.593 [NavChartDb](INFO): # of records loaded: 5000
2023-09-08T13:28:29.384Z,1694179709.384 [DAT](INFO): entering command mode
2023-09-08T13:28:29.584Z,1694179709.584 [DAT](INFO): DAT read: 

2023-09-08T13:28:29.585Z,1694179709.585 [DAT](INFO): DAT read: user:1>

2023-09-08T13:28:29.585Z,1694179709.585 [DAT](INFO): setting verbose to 3
2023-09-08T13:28:29.836Z,1694179709.836 [DAT](INFO): DAT read: user:1>

2023-09-08T13:28:29.837Z,1694179709.837 [DAT](INFO): DAT read: Verbose         | 3           

2023-09-08T13:28:29.837Z,1694179709.837 [DAT](INFO): set verbose to 3
2023-09-08T13:28:29.838Z,1694179709.838 [DAT](INFO): setting DatVerbose to 27440
2023-09-08T13:28:30.088Z,1694179710.088 [DAT](INFO): DAT read: user:2>

2023-09-08T13:28:30.092Z,1694179710.092 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-09-08T13:28:30.093Z,1694179710.093 [DAT](INFO): set DatVerbose to 27440
2023-09-08T13:28:30.093Z,1694179710.093 [DAT](INFO): setting transmit power to 8
2023-09-08T13:28:30.340Z,1694179710.340 [DAT](INFO): DAT read: user:3>

2023-09-08T13:28:30.341Z,1694179710.341 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-09-08T13:28:30.342Z,1694179710.342 [DAT](INFO): set transmit power to 8
2023-09-08T13:28:30.342Z,1694179710.342 [DAT](INFO): setting local address to 5
2023-09-08T13:28:30.593Z,1694179710.593 [DAT](INFO): DAT read: user:4>

2023-09-08T13:28:30.595Z,1694179710.595 [DAT](INFO): DAT read: LocalAddr       | 5           

2023-09-08T13:28:30.595Z,1694179710.595 [DAT](INFO): set local address to 5
2023-09-08T13:28:30.651Z,1694179710.651 [DAT](INFO): Setting time to: 13:28:30 And date to:9/8/2023
2023-09-08T13:28:30.844Z,1694179710.844 [DAT](INFO): DAT read: user:5>

2023-09-08T13:28:30.845Z,1694179710.845 [DAT](INFO): DAT read: Fri Sep 8, 2023  13:28:30  

2023-09-08T13:28:30.845Z,1694179710.845 [DAT](INFO): Local DAT time set to Fri Sep 8, 2023  13:28:30  

2023-09-08T13:28:38.195Z,1694179718.195 [NavChartDb](INFO): # of records loaded: 10000
2023-09-08T13:28:41.048Z,1694179721.048 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4PA21M.000
2023-09-08T13:28:41.581Z,1694179721.581 [NAL9602](INFO): Powering up NAL9602
2023-09-08T13:28:46.325Z,1694179726.325 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4PA21M.000
2023-09-08T13:28:47.751Z,1694179727.751 [NavChartDb](INFO): # of records loaded: 15000
2023-09-08T13:28:50.901Z,1694179730.901 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4PA21M.000
2023-09-08T13:28:51.420Z,1694179731.420 [NavChartDb](INFO): # of records loaded: 16189
2023-09-08T13:28:51.423Z,1694179731.423 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4PA21M.000
2023-09-08T13:28:51.424Z,1694179731.424 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4PA20M.000
2023-09-08T13:28:51.576Z,1694179731.576 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4PA20M.000
2023-09-08T13:28:51.945Z,1694179731.945 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4PA20M.000
2023-09-08T13:28:51.947Z,1694179731.947 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4PA20M.000
2023-09-08T13:28:51.965Z,1694179731.965 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4PA20M.000
2023-09-08T13:28:52.300Z,1694179732.300 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4PA20M.000
2023-09-08T13:28:52.466Z,1694179732.466 [NAL9602](INFO): NAL9602 initialized
2023-09-08T13:28:52.719Z,1694179732.719 [NavChartDb](INFO): # of records loaded: 262
2023-09-08T13:28:52.721Z,1694179732.721 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4PA20M.000
2023-09-08T13:28:52.721Z,1694179732.721 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4OH02M.000
2023-09-08T13:28:53.765Z,1694179733.765 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4OH02M.000
2023-09-08T13:29:03.510Z,1694179743.510 [NavChartDb](INFO): # of records loaded: 5000
2023-09-08T13:29:09.111Z,1694179749.111 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4OH02M.000
2023-09-08T13:29:09.443Z,1694179749.443 [NAL9602](INFO): SBD MO Status=0, MOMSN=9002, MT Status=0, MTMSN=0
2023-09-08T13:29:09.443Z,1694179749.443 [NAL9602](INFO): No messages in MT queue
2023-09-08T13:29:09.513Z,1694179749.513 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4OH02M.000
2023-09-08T13:29:11.965Z,1694179751.965 [NavChartDb](INFO): # of records loaded: 10000
2023-09-08T13:29:13.546Z,1694179753.546 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4OH02M.000
2023-09-08T13:29:15.186Z,1694179755.186 [NavChartDb](INFO): # of records loaded: 10534
2023-09-08T13:29:15.190Z,1694179755.190 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4OH02M.000
2023-09-08T13:29:15.192Z,1694179755.192 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4OH04M.000
2023-09-08T13:29:15.315Z,1694179755.315 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4OH04M.000
2023-09-08T13:29:15.503Z,1694179755.503 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4OH04M.000
2023-09-08T13:29:15.506Z,1694179755.506 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4OH04M.000
2023-09-08T13:29:15.511Z,1694179755.511 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4OH04M.000
2023-09-08T13:29:15.609Z,1694179755.609 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4OH04M.000
2023-09-08T13:29:16.157Z,1694179756.157 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4OH04M.000
2023-09-08T13:29:17.645Z,1694179757.645 [NavChartDb](INFO): # of records loaded: 473
2023-09-08T13:29:17.647Z,1694179757.647 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4OH04M.000
2023-09-08T13:29:17.649Z,1694179757.649 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4OH01M.000
2023-09-08T13:29:18.808Z,1694179758.808 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4OH01M.000
2023-09-08T13:29:22.384Z,1694179762.384 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,132919.00,A,4145.52835,N,08116.65505,W,0.039,0.00,080923,,,A*77
2023-09-08T13:29:22.387Z,1694179762.387 [NAL9602](INFO): GPS fix at 20230908T132919: (41.758806, -81.277584)
2023-09-08T13:29:28.168Z,1694179768.168 [NavChartDb](INFO): # of records loaded: 5000
2023-09-08T13:29:32.020Z,1694179772.020 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4OH01M.000
2023-09-08T13:29:35.148Z,1694179775.148 [NavChartDb](INFO): Done scanning edges of Resources/ElectronicNavigationCharts/US4OH01M.000
2023-09-08T13:29:38.079Z,1694179778.079 [NavChartDb](INFO): # of records loaded: 10000
2023-09-08T13:29:38.682Z,1694179778.682 [NavChartDb](INFO): Done scanning nodes of Resources/ElectronicNavigationCharts/US4OH01M.000
2023-09-08T13:29:40.346Z,1694179780.346 [NavChartDb](INFO): # of records loaded: 10183
2023-09-08T13:29:40.349Z,1694179780.349 [NavChartDb](IMPORTANT): Loaded Electronic Nav Chart data from US4OH01M.000
2023-09-08T13:29:40.350Z,1694179780.350 [NavChartDb](INFO): Setup scan of Resources/ElectronicNavigationCharts/US4WI06M.000
2023-09-08T13:29:44.124Z,1694179784.124 [NavChartDb](INFO): Done scanning features of Resources/ElectronicNavigationCharts/US4WI06M.000
2023-09-08T13:29:52.596Z,1694179792.596 [NavChartDb](INFO): # of records loaded: 5000
2023-09-08T13:29:55.116Z,1694179795.116 [NAL9602](INFO): Not Powering down - fast GPS
2023-09-08T13:30:00.024Z,1694179800.024 [SBIT](IMPORTANT): Beginning Startup BIT
2023-09-08T13:30:00.036Z,1694179800.036 [CBIT](IMPORTANT): Beginning ground fault scan
2023-09-08T13:30:01.702Z,1694179801.702 [NavChartDb](INFO): # of records loaded: 10000
2023-09-08T13:30:10.919Z,1694179810.919 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005470
CHAN A1 (24V): 0.002119
CHAN A2 (12V): -0.006632
CHAN A3 (5V): -0.004152
CHAN B0 (3.3V): -0.001482
CHAN B1 (3.15aV): -0.001417
CHAN B2 (3.15bV): -0.001200
CHAN B3 (GND): -0.000332
OPEN: 0.000464
Full Scale: +/- 1 mA
2023-09-08T13:30:13.394Z,1694179813.394 [NavChartDb](INFO): # of records loaded: 15000
2023-09-08T13:30:22.742Z,1694179822.742 [NavChartDb](INFO): # of records loaded: 20000
2023-09-08T13:30:31.221Z,1694179831.221 [NavChartDb](INFO): # of records loaded: 25000
2023-09-08T13:30:39.374Z,1694179839.374 [SBIT](FAULT): Elevator: EXPECTED:-15.000000 ACTUAL:-14.714098
2023-09-08T13:30:39.374Z,1694179839.374 [SBIT](FAULT): Control surface position failure.
2023-09-08T13:30:40.627Z,1694179840.627 [NavChartDb](INFO): # of records loaded: 30000
2023-09-08T13:30:48.752Z,1694179848.752 [NavChartDb](INFO): # of records loaded: 35000
2023-09-08T13:30:53.332Z,1694179853.332 [SBIT](CRITICAL): SBIT FAILED
2023-09-08T13:30:53.333Z,1694179853.333 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2023-09-08T13:30:53.334Z,1694179853.334 [CBIT](INFO): Critical error at 20230908T133053
2023-09-08T13:30:53.701Z,1694179853.701 [MissionManager](IMPORTANT): Started mission Startup
2023-09-08T13:30:53.702Z,1694179853.702 [Startup] Running Loop=1
2023-09-08T13:30:53.702Z,1694179853.702 [Startup](DEBUG): Aggregate::initialize Startup
2023-09-08T13:30:53.702Z,1694179853.702 [Startup:A.GoToSurface] Running Loop=1
2023-09-08T13:30:53.702Z,1694179853.702 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-09-08T13:30:53.703Z,1694179853.703 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-09-08T13:30:53.703Z,1694179853.703 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-09-08T13:30:53.704Z,1694179853.704 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-09-08T13:30:53.704Z,1694179853.704 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-09-08T13:30:53.704Z,1694179853.704 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-09-08T13:30:53.706Z,1694179853.706 [Startup:StartupSatComms] Running Loop=1
2023-09-08T13:30:53.707Z,1694179853.707 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-09-08T13:30:53.707Z,1694179853.707 [Startup:StartupSatComms:A] Running Loop=1
2023-09-08T13:30:54.106Z,1694179854.106 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-09-08T13:30:55.691Z,1694179855.691 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,133052.00,A,4145.53087,N,08116.65348,W,0.019,0.00,080923,,,A*7D
2023-09-08T13:30:55.693Z,1694179855.693 [NAL9602](INFO): GPS fix at 20230908T133052: (41.758848, -81.277558)
2023-09-08T13:30:55.719Z,1694179855.719 [Startup:StartupSatComms:A] Stopped
2023-09-08T13:30:55.719Z,1694179855.719 [Startup:StartupSatComms:B] Running Loop=1
2023-09-08T13:30:56.175Z,1694179856.175 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-09-08T13:30:57.739Z,1694179857.739 [NavChartDb](INFO): # of records loaded: 40000
2023-09-08T13:31:01.106Z,1694179861.106 [NavChartDb](INFO): Calculating coverage of Resources/ElectronicNavigationCharts/US4WI06M.000
2023-09-08T13:31:07.015Z,1694179867.015 [NavChartDb](INFO): # of records loaded: 45000
2023-09-08T13:31:16.361Z,1694179876.361 [NavChartDb](INFO): # of records loaded: 50000
2023-09-08T13:31:18.517Z,1694179878.517 [NAL9602](INFO): SBD MO Status=1, MOMSN=9003, MT Status=0, MTMSN=0
2023-09-08T13:31:18.636Z,1694179878.636 [NAL9602](INFO): Sent 18 bytes from file Logs/20230908T132150/Courier0007.lzma
2023-09-08T13:31:18.636Z,1694179878.636 [NAL9602](INFO): Packets left to send: 0
2023-09-08T13:31:27.664Z,1694179887.664 [NavChartDb](INFO): # of records lo