2022-01-28T14:53:01.977Z,1643381581.977 [Supervisor](DEBUG): Initializing supervisor.
2022-01-28T14:53:01.981Z,1643381581.981 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2022-01-28T14:53:01.982Z,1643381581.982 [SyncHandler](INFO): Protected caller Thread ID is 835
2022-01-28T14:53:01.982Z,1643381581.982 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2022-01-28T14:53:01.983Z,1643381581.983 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2022-01-28T14:53:01.983Z,1643381581.983 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 836
2022-01-28T14:53:01.987Z,1643381581.987 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2022-01-28T14:53:02.006Z,1643381582.006 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2022-01-28T14:53:02.007Z,1643381582.007 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2022-01-28T14:53:02.007Z,1643381582.007 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 837
2022-01-28T14:53:02.011Z,1643381582.011 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2022-01-28T14:53:02.012Z,1643381582.012 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2022-01-28T14:53:02.013Z,1643381582.013 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 838
2022-01-28T14:53:02.015Z,1643381582.015 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2022-01-28T14:53:02.015Z,1643381582.015 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2022-01-28T14:53:02.016Z,1643381582.016 [logger ThreadHandler](INFO): Protected caller Thread ID is 839
2022-01-28T14:53:02.020Z,1643381582.020 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2022-01-28T14:53:02.020Z,1643381582.020 [Supervisor](INFO): Looking for Config files in directory: Config/
2022-01-28T14:53:02.026Z,1643381582.026 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2022-01-28T14:53:02.444Z,1643381582.444 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2022-01-28T14:53:02.446Z,1643381582.446 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2022-01-28T14:53:02.526Z,1643381582.526 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2022-01-28T14:53:02.847Z,1643381582.847 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2022-01-28T14:53:02.848Z,1643381582.848 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2022-01-28T14:53:02.957Z,1643381582.957 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2022-01-28T14:53:02.959Z,1643381582.959 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2022-01-28T14:53:03.159Z,1643381583.159 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2022-01-28T14:53:03.161Z,1643381583.161 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2022-01-28T14:53:03.684Z,1643381583.684 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2022-01-28T14:53:03.686Z,1643381583.686 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2022-01-28T14:53:03.949Z,1643381583.949 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2022-01-28T14:53:03.950Z,1643381583.950 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2022-01-28T14:53:04.097Z,1643381584.097 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2022-01-28T14:53:04.099Z,1643381584.099 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2022-01-28T14:53:04.288Z,1643381584.288 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2022-01-28T14:53:04.289Z,1643381584.289 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2022-01-28T14:53:04.387Z,1643381584.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2022-01-28T14:53:04.388Z,1643381584.388 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2022-01-28T14:53:04.608Z,1643381584.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2022-01-28T14:53:04.610Z,1643381584.610 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2022-01-28T14:53:04.990Z,1643381584.990 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2022-01-28T14:53:04.991Z,1643381584.991 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2022-01-28T14:53:05.072Z,1643381585.072 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2022-01-28T14:53:05.198Z,1643381585.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2022-01-28T14:53:05.200Z,1643381585.200 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2022-01-28T14:53:05.888Z,1643381585.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2022-01-28T14:53:05.889Z,1643381585.889 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2022-01-28T14:53:06.849Z,1643381586.849 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2022-01-28T14:53:06.851Z,1643381586.851 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-polaris/
2022-01-28T14:53:06.855Z,1643381586.855 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/vehicle.cfg
2022-01-28T14:53:07.052Z,1643381587.052 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Control.cfg
2022-01-28T14:53:07.152Z,1643381587.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Estimation.cfg
2022-01-28T14:53:07.250Z,1643381587.250 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/BIT.cfg
2022-01-28T14:53:07.350Z,1643381587.350 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Battery.cfg
2022-01-28T14:53:07.608Z,1643381587.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2022-01-28T14:53:07.610Z,1643381587.610 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Simulator.cfg
2022-01-28T14:53:07.695Z,1643381587.695 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Navigation.cfg
2022-01-28T14:53:07.798Z,1643381587.798 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Derivation.cfg
2022-01-28T14:53:07.921Z,1643381587.921 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/logger.cfg
2022-01-28T14:53:08.034Z,1643381588.034 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/secure.cfg
2022-01-28T14:53:08.119Z,1643381588.119 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Dock.cfg
2022-01-28T14:53:08.205Z,1643381588.205 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Servo.cfg
2022-01-28T14:53:08.316Z,1643381588.316 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/workSite.cfg
2022-01-28T14:53:08.415Z,1643381588.415 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Sensor.cfg
2022-01-28T14:53:08.620Z,1643381588.620 [Supervisor](INFO): Opening Config file at: Config/lrauv-polaris/Science.cfg
2022-01-28T14:53:08.781Z,1643381588.781 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2022-01-28T14:53:08.807Z,1643381588.807 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2022-01-28T14:53:09.542Z,1643381589.542 [AHRS_M2] Loaded
2022-01-28T14:53:09.542Z,1643381589.542 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2022-01-28T14:53:09.805Z,1643381589.805 [BackseatComponent] Loaded
2022-01-28T14:53:09.805Z,1643381589.805 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2022-01-28T14:53:09.806Z,1643381589.806 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 407DF4E0
2022-01-28T14:53:09.807Z,1643381589.807 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 933
2022-01-28T14:53:09.809Z,1643381589.809 [LcmUniversalReporter] Loaded
2022-01-28T14:53:09.810Z,1643381589.810 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2022-01-28T14:53:10.565Z,1643381590.565 [BPC1] Loaded
2022-01-28T14:53:10.565Z,1643381590.565 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2022-01-28T14:53:10.584Z,1643381590.584 [Depth_Keller] Loaded
2022-01-28T14:53:10.585Z,1643381590.585 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2022-01-28T14:53:10.589Z,1643381590.589 [DropWeight] Loaded
2022-01-28T14:53:10.589Z,1643381590.589 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2022-01-28T14:53:10.646Z,1643381590.646 [NAL9602] Loaded
2022-01-28T14:53:10.646Z,1643381590.646 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2022-01-28T14:53:10.674Z,1643381590.674 [Onboard] Loaded
2022-01-28T14:53:10.675Z,1643381590.675 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2022-01-28T14:53:10.676Z,1643381590.676 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4080F4E0
2022-01-28T14:53:10.676Z,1643381590.676 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 934
2022-01-28T14:53:10.682Z,1643381590.682 [PowerOnly](INFO): Adding load control power supply at /dev/loadC1
2022-01-28T14:53:10.692Z,1643381590.692 [PowerOnly] Loaded
2022-01-28T14:53:10.692Z,1643381590.692 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2022-01-28T14:53:10.703Z,1643381590.703 [Power24vConverter] Loaded
2022-01-28T14:53:10.704Z,1643381590.704 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2022-01-28T14:53:10.746Z,1643381590.746 [RDI_Pathfinder] Loaded
2022-01-28T14:53:10.746Z,1643381590.746 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2022-01-28T14:53:10.747Z,1643381590.747 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2022-01-28T14:53:10.748Z,1643381590.748 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2022-01-28T14:53:10.764Z,1643381590.764 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2022-01-28T14:53:10.765Z,1643381590.765 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2022-01-28T14:53:10.900Z,1643381590.900 [DeadReckonUsingMultipleVelocitySources] Loaded
2022-01-28T14:53:10.900Z,1643381590.900 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2022-01-28T14:53:10.929Z,1643381590.929 [LBLNavigation] Loaded
2022-01-28T14:53:10.929Z,1643381590.929 [ComponentRegistry](DEBUG): SyncComponent "LBLNavigation" handled in the control thread.
2022-01-28T14:53:10.941Z,1643381590.941 [NavChart] Loaded
2022-01-28T14:53:10.941Z,1643381590.941 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2022-01-28T14:53:10.947Z,1643381590.947 [UniversalFixResidualReporter] Loaded
2022-01-28T14:53:10.947Z,1643381590.947 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2022-01-28T14:53:10.958Z,1643381590.958 [WorkSite] Loaded
2022-01-28T14:53:10.958Z,1643381590.958 [ComponentRegistry](DEBUG): SyncComponent "WorkSite" handled in the control thread.
2022-01-28T14:53:10.958Z,1643381590.958 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2022-01-28T14:53:10.960Z,1643381590.960 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2022-01-28T14:53:11.613Z,1643381591.613 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2022-01-28T14:53:11.613Z,1643381591.613 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2022-01-28T14:53:12.150Z,1643381592.150 [BuoyancyServo] Loaded
2022-01-28T14:53:12.150Z,1643381592.150 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2022-01-28T14:53:12.171Z,1643381592.171 [ElevatorServo] Loaded
2022-01-28T14:53:12.171Z,1643381592.171 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2022-01-28T14:53:12.191Z,1643381592.191 [MassServo] Loaded
2022-01-28T14:53:12.192Z,1643381592.192 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2022-01-28T14:53:12.211Z,1643381592.211 [RudderServo] Loaded
2022-01-28T14:53:12.211Z,1643381592.211 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2022-01-28T14:53:12.228Z,1643381592.228 [ThrusterHE] Loaded
2022-01-28T14:53:12.228Z,1643381592.228 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2022-01-28T14:53:12.228Z,1643381592.228 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2022-01-28T14:53:12.229Z,1643381592.229 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2022-01-28T14:53:12.446Z,1643381592.446 [CTD_Seabird] Loaded
2022-01-28T14:53:12.446Z,1643381592.446 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2022-01-28T14:53:12.447Z,1643381592.447 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4094B4E0
2022-01-28T14:53:12.447Z,1643381592.447 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 935
2022-01-28T14:53:12.467Z,1643381592.467 [PAR_Licor] Loaded
2022-01-28T14:53:12.467Z,1643381592.467 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2022-01-28T14:53:12.499Z,1643381592.499 [WetLabsSeaOWL_UV_A] Loaded
2022-01-28T14:53:12.499Z,1643381592.499 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2022-01-28T14:53:12.500Z,1643381592.500 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 4097B4E0
2022-01-28T14:53:12.501Z,1643381592.501 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 936
2022-01-28T14:53:12.501Z,1643381592.501 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2022-01-28T14:53:12.502Z,1643381592.502 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2022-01-28T14:53:12.873Z,1643381592.873 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2022-01-28T14:53:12.873Z,1643381592.873 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2022-01-28T14:53:12.936Z,1643381592.936 [DepthRateCalculator] Loaded
2022-01-28T14:53:12.936Z,1643381592.936 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2022-01-28T14:53:12.941Z,1643381592.941 [PitchRateCalculator] Loaded
2022-01-28T14:53:12.942Z,1643381592.942 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2022-01-28T14:53:12.951Z,1643381592.951 [SpeedCalculator] Loaded
2022-01-28T14:53:12.951Z,1643381592.951 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2022-01-28T14:53:12.965Z,1643381592.965 [TempGradientCalculator] Loaded
2022-01-28T14:53:12.965Z,1643381592.965 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2022-01-28T14:53:12.981Z,1643381592.981 [VerticalHomogeneityIndexCalculator] Loaded
2022-01-28T14:53:12.981Z,1643381592.981 [ComponentRegistry](DEBUG): SyncComponent "VerticalHomogeneityIndexCalculator" handled in the control thread.
2022-01-28T14:53:12.986Z,1643381592.986 [YawRateCalculator] Loaded
2022-01-28T14:53:12.986Z,1643381592.986 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2022-01-28T14:53:13.007Z,1643381593.007 [ElevatorOffsetCalculator] Loaded
2022-01-28T14:53:13.007Z,1643381593.007 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2022-01-28T14:53:13.008Z,1643381593.008 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2022-01-28T14:53:13.008Z,1643381593.008 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2022-01-28T14:53:13.184Z,1643381593.184 [SBIT](DEBUG): Construct Startup Built In Test.
2022-01-28T14:53:13.197Z,1643381593.197 [SBIT] Loaded
2022-01-28T14:53:13.197Z,1643381593.197 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2022-01-28T14:53:13.200Z,1643381593.200 [IBIT](DEBUG): Construct Initiated Built In Test.
2022-01-28T14:53:13.212Z,1643381593.212 [IBIT] Loaded
2022-01-28T14:53:13.213Z,1643381593.213 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2022-01-28T14:53:13.218Z,1643381593.218 [CBIT](DEBUG): Construct Continuous Built In Test.
2022-01-28T14:53:13.319Z,1643381593.319 [CBIT] Loaded
2022-01-28T14:53:13.319Z,1643381593.319 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2022-01-28T14:53:13.319Z,1643381593.319 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2022-01-28T14:53:13.320Z,1643381593.320 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2022-01-28T14:53:13.401Z,1643381593.401 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2022-01-28T14:53:13.402Z,1643381593.402 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2022-01-28T14:53:13.536Z,1643381593.536 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2022-01-28T14:53:13.536Z,1643381593.536 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2022-01-28T14:53:13.607Z,1643381593.607 [VerticalControl](DEBUG): Construct VerticalControl.
2022-01-28T14:53:13.659Z,1643381593.659 [VerticalControl] Loaded
2022-01-28T14:53:13.660Z,1643381593.660 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2022-01-28T14:53:13.662Z,1643381593.662 [HorizontalControl](DEBUG): Construct HorizontalControl.
2022-01-28T14:53:13.698Z,1643381593.698 [HorizontalControl] Loaded
2022-01-28T14:53:13.698Z,1643381593.698 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2022-01-28T14:53:13.701Z,1643381593.701 [SpeedControl](DEBUG): Construct SpeedControl.
2022-01-28T14:53:13.702Z,1643381593.702 [SpeedControl] Loaded
2022-01-28T14:53:13.703Z,1643381593.703 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2022-01-28T14:53:13.705Z,1643381593.705 [LoopControl](DEBUG): Construct LoopControl.
2022-01-28T14:53:13.706Z,1643381593.706 [LoopControl] Loaded
2022-01-28T14:53:13.706Z,1643381593.706 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2022-01-28T14:53:13.707Z,1643381593.707 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2022-01-28T14:53:13.707Z,1643381593.707 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2022-01-28T14:53:13.749Z,1643381593.749 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2022-01-28T14:53:13.755Z,1643381593.755 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2022-01-28T14:53:13.758Z,1643381593.758 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2022-01-28T14:53:13.768Z,1643381593.768 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2022-01-28T14:53:13.769Z,1643381593.769 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B2D4E0
2022-01-28T14:53:13.770Z,1643381593.770 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 937
2022-01-28T14:53:13.774Z,1643381593.774 [Supervisor](INFO): Main Thread ID is 829
2022-01-28T14:53:13.774Z,1643381593.774 [Supervisor](DEBUG): Running supervisor.
2022-01-28T14:53:13.775Z,1643381593.775 [CommandExec ThreadHandler](INFO): Handler Thread ID is 938
2022-01-28T14:53:13.775Z,1643381593.775 [CommandExec](INFO): Initializing the command executive.
2022-01-28T14:53:13.777Z,1643381593.777 [CommandLine ThreadHandler](INFO): Handler Thread ID is 939
2022-01-28T14:53:13.779Z,1643381593.779 [controlThread ThreadHandler](INFO): Handler Thread ID is 940
2022-01-28T14:53:13.779Z,1643381593.779 [controlThread](DEBUG): Initializing ControlThread
2022-01-28T14:53:13.787Z,1643381593.787 [NavChart](DEBUG): Initialize NavChart Navigation.
2022-01-28T14:53:13.787Z,1643381593.787 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2022-01-28T14:53:13.787Z,1643381593.787 [WorkSite](DEBUG): Initializing WorkSite component.
2022-01-28T14:53:13.792Z,1643381593.792 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2022-01-28T14:53:13.793Z,1643381593.793 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2022-01-28T14:53:13.793Z,1643381593.793 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2022-01-28T14:53:13.793Z,1643381593.793 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2022-01-28T14:53:13.794Z,1643381593.794 [VerticalHomogeneityIndexCalculator](DEBUG): (re)initializing
2022-01-28T14:53:13.795Z,1643381593.795 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2022-01-28T14:53:13.795Z,1643381593.795 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2022-01-28T14:53:13.796Z,1643381593.796 [SBIT](INFO): Initialize SBIT Component.
2022-01-28T14:53:13.796Z,1643381593.796 [SBIT](IMPORTANT): git: 2022-01-19
2022-01-28T14:53:13.797Z,1643381593.797 [SBIT](INFO): git hash: 3c152841e44dce493716324b2ee7dcf988968060
2022-01-28T14:53:13.797Z,1643381593.797 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2022-01-28T14:53:13.798Z,1643381593.798 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2022-01-28T14:53:13.799Z,1643381593.799 [SBIT](INFO): Beginning SBIT in 44.000000 seconds.
2022-01-28T14:53:13.800Z,1643381593.800 [IBIT](INFO): Initialize IBIT Component.
2022-01-28T14:53:13.801Z,1643381593.801 [CBIT](DEBUG): Initialize CBIT Component.
2022-01-28T14:53:13.802Z,1643381593.802 [logger ThreadHandler](INFO): Handler Thread ID is 941
2022-01-28T14:53:13.812Z,1643381593.812 [CBIT](DEBUG): Initialized mux pins.
2022-01-28T14:53:13.812Z,1643381593.812 [CBIT](DEBUG): Initializing the watchdog timer.
2022-01-28T14:53:13.820Z,1643381593.820 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 942
2022-01-28T14:53:13.832Z,1643381593.832 [Onboard ThreadHandler](INFO): Handler Thread ID is 943
2022-01-28T14:53:13.837Z,1643381593.837 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2022-01-28T14:53:13.837Z,1643381593.837 [CBIT](DEBUG): Initializing heartbeat.
2022-01-28T14:53:13.853Z,1643381593.853 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 944
2022-01-28T14:53:13.857Z,1643381593.857 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2022-01-28T14:53:13.872Z,1643381593.872 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 946
2022-01-28T14:53:13.873Z,1643381593.873 [WetLabsSeaOWL_UV_A](INFO): Powering down
2022-01-28T14:53:13.884Z,1643381593.884 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 947
2022-01-28T14:53:13.893Z,1643381593.893 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2022-01-28T14:53:13.893Z,1643381593.893 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2022-01-28T14:53:13.893Z,1643381593.893 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2022-01-28T14:53:13.893Z,1643381593.893 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2022-01-28T14:53:13.894Z,1643381593.894 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2022-01-28T14:53:13.894Z,1643381593.894 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2022-01-28T14:53:13.894Z,1643381593.894 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2022-01-28T14:53:13.894Z,1643381593.894 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2022-01-28T14:53:13.894Z,1643381593.894 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2022-01-28T14:53:13.894Z,1643381593.894 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2022-01-28T14:53:13.895Z,1643381593.895 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2022-01-28T14:53:13.895Z,1643381593.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2022-01-28T14:53:13.895Z,1643381593.895 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2022-01-28T14:53:13.895Z,1643381593.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2022-01-28T14:53:13.895Z,1643381593.895 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2022-01-28T14:53:13.895Z,1643381593.895 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2022-01-28T14:53:13.908Z,1643381593.908 [CBIT](DEBUG): Deactivating GF circuits.
2022-01-28T14:53:13.908Z,1643381593.908 [CBIT](DEBUG): Deactivating emergency mode.
2022-01-28T14:53:13.944Z,1643381593.944 [CBIT](DEBUG): Backplane powered.
2022-01-28T14:53:13.944Z,1643381593.944 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2022-01-28T14:53:13.946Z,1643381593.946 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2022-01-28T14:53:13.947Z,1643381593.947 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2022-01-28T14:53:13.947Z,1643381593.947 [LoopControl](DEBUG): Initialize LoopControlComponent.
2022-01-28T14:53:13.948Z,1643381593.948 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2022-01-28T14:53:13.992Z,1643381593.992 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2022-01-28T14:53:14.011Z,1643381594.011 [MissionManager](DEBUG):
2022-01-28T14:53:14.012Z,1643381594.012 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2022-01-28T14:53:14.075Z,1643381594.075 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2022-01-28T14:53:14.089Z,1643381594.089 [Default:A.Wait](DEBUG): Construct Wait.
2022-01-28T14:53:14.091Z,1643381594.091 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2022-01-28T14:53:14.127Z,1643381594.127 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2022-01-28T14:53:14.130Z,1643381594.130 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2022-01-28T14:53:14.168Z,1643381594.168 [Default:E.Execute](DEBUG): Construct Execute.
2022-01-28T14:53:14.176Z,1643381594.176 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2022-01-28T14:53:14.181Z,1643381594.181 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,PowerOnly,Power24vConverter,RDI_Pathfinder,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,WorkSite,LBLNavigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2022-01-28T14:53:14.200Z,1643381594.200 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2022-01-28T14:53:14.443Z,1643381594.443 [Power24vConverter](INFO): Powering up.
2022-01-28T14:53:14.546Z,1643381594.546 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2022-01-28T14:53:14.552Z,1643381594.552 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2022-01-28T14:53:14.553Z,1643381594.553 [ElevatorServo](DEBUG): Initializing EZServoServo.
2022-01-28T14:53:14.560Z,1643381594.560 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2022-01-28T14:53:14.561Z,1643381594.561 [MassServo](DEBUG): Initializing EZServoServo.
2022-01-28T14:53:14.568Z,1643381594.568 [MassServo](DEBUG): Initializing MassServo.
2022-01-28T14:53:14.569Z,1643381594.569 [RudderServo](DEBUG): Initializing EZServoServo.
2022-01-28T14:53:14.576Z,1643381594.576 [RudderServo](DEBUG): Initializing RudderServo.
2022-01-28T14:53:14.577Z,1643381594.577 [ThrusterHE](DEBUG): Initializing EZServoServo.
2022-01-28T14:53:14.584Z,1643381594.584 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2022-01-28T14:53:20.885Z,1643381600.885 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2022-01-28T14:53:40.865Z,1643381620.865 [NAL9602](INFO): Powering up NAL9602
2022-01-28T14:53:51.782Z,1643381631.782 [NAL9602](INFO): NAL9602 initialized
2022-01-28T14:53:58.315Z,1643381638.315 [SBIT](IMPORTANT): Beginning Startup BIT
2022-01-28T14:53:58.320Z,1643381638.320 [CBIT](IMPORTANT): Beginning ground fault scan
2022-01-28T14:54:05.113Z,1643381645.113 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=35064, MT Status=1, MTMSN=1375
2022-01-28T14:54:05.113Z,1643381645.113 [NAL9602](INFO): Data available in MT queue
2022-01-28T14:54:05.869Z,1643381645.869 [NAL9602](INFO): Received command: configSet Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature .5 celsius persist
2022-01-28T14:54:07.352Z,1643381647.352 [CommandExec](IMPORTANT): got command configSet Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.500000 celsius persist
2022-01-28T14:54:09.328Z,1643381649.328 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.115521
CHAN A1 (24V): 0.177945
CHAN A2 (12V): 0.064492
CHAN A3 (5V): 0.020485
CHAN B0 (3.3V): 0.012511
CHAN B1 (3.15aV): 0.011629
CHAN B2 (3.15bV): 0.011205
CHAN B3 (GND): -0.010671
OPEN: 0.008967
Full Scale: +/- 1 mA
2022-01-28T14:54:52.479Z,1643381692.479 [SBIT](IMPORTANT): SBIT PASSED
2022-01-28T14:54:52.480Z,1643381692.480 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2022-01-28T14:54:52.481Z,1643381692.481 [SBIT](IMPORTANT): BuoyancyServo.fastPumpCoefficient=2 none;
2022-01-28T14:54:52.481Z,1643381692.481 [SBIT](IMPORTANT): BuoyancyServo.velocity=800 none;
2022-01-28T14:54:52.481Z,1643381692.481 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour;
2022-01-28T14:54:52.481Z,1643381692.481 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=1 bool;
2022-01-28T14:54:52.481Z,1643381692.481 [SBIT](IMPORTANT): DataOverHttps.loadAtStartup=0 bool;
2022-01-28T14:54:52.481Z,1643381692.481 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.200000 practical_salinity_unit;
2022-01-28T14:54:52.481Z,1643381692.481 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.500000 celsius;
2022-01-28T14:54:52.481Z,1643381692.481 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.Output700;
2022-01-28T14:54:52.482Z,1643381692.482 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.OutputFDOM;
2022-01-28T14:54:52.482Z,1643381692.482 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.concentration_of_colored_dissolved_organic_matter_in_sea_water;
2022-01-28T14:54:52.482Z,1643381692.482 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.mass_concentration_of_chlorophyll_in_sea_water;
2022-01-28T14:54:52.482Z,1643381692.482 [SBIT](IMPORTANT): Express none WetLabsSeaOWL_UV_A.mass_concentration_of_petroleum_hydrocarbons_in_sea_water;
2022-01-28T14:54:52.482Z,1643381692.482 [SBIT](IMPORTANT): Express none concentration_of_colored_dissolved_organic_matter_in_sea_water;
2022-01-28T14:54:52.482Z,1643381692.482 [SBIT](IMPORTANT): Express none mass_concentration_of_chlorophyll_in_sea_water;
2022-01-28T14:54:52.482Z,1643381692.482 [SBIT](IMPORTANT): Express linearApproximation platform_average_current 0.500000 ampere;
2022-01-28T14:54:52.482Z,1643381692.482 [SBIT](IMPORTANT): Micromodem.loadAtStartup=0 bool;
2022-01-28T14:54:52.483Z,1643381692.483 [SBIT](IMPORTANT): NAL9602.fastGPSFix=1 bool;
2022-01-28T14:54:52.483Z,1643381692.483 [SBIT](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;
2022-01-28T14:54:52.483Z,1643381692.483 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=1 bool;
2022-01-28T14:54:52.483Z,1643381692.483 [SBIT](IMPORTANT): RDI_PathfinderUp.loadAtStartup=0 bool;
2022-01-28T14:54:52.483Z,1643381692.483 [SBIT](IMPORTANT): Radio_Surface.loadAtStartup=0 bool;
2022-01-28T14:54:52.483Z,1643381692.483 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=154 cubic_centimeter;
2022-01-28T14:54:52.483Z,1643381692.483 [SBIT](IMPORTANT): VerticalControl.massDefault=6 millimeter;
2022-01-28T14:54:52.483Z,1643381692.483 [SBIT](IMPORTANT): WetLabsSeaOWL_UV_A.loadAtStartup=1 bool;
2022-01-28T14:54:52.901Z,1643381692.901 [WorkSite](IMPORTANT): Reading workSite position from Data/workSite.cfg
2022-01-28T14:54:52.905Z,1643381692.905 [WorkSite](IMPORTANT): WorkSite fix at 20220128T144718: (40.710135, -70.722423)
2022-01-28T14:54:52.907Z,1643381692.907 [MissionManager](IMPORTANT): Started mission Startup
2022-01-28T14:54:52.907Z,1643381692.907 [Startup] Running Loop=1
2022-01-28T14:54:52.907Z,1643381692.907 [Startup](DEBUG): Aggregate::initialize Startup
2022-01-28T14:54:52.907Z,1643381692.907 [Startup:A.GoToSurface] Running Loop=1
2022-01-28T14:54:52.907Z,1643381692.907 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2022-01-28T14:54:52.908Z,1643381692.908 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2022-01-28T14:54:52.908Z,1643381692.908 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2022-01-28T14:54:52.909Z,1643381692.909 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2022-01-28T14:54:52.909Z,1643381692.909 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2022-01-28T14:54:52.909Z,1643381692.909 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2022-01-28T14:54:52.911Z,1643381692.911 [Startup:StartupSatComms] Running Loop=1
2022-01-28T14:54:52.911Z,1643381692.911 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2022-01-28T14:54:52.911Z,1643381692.911 [Startup:StartupSatComms:A] Running Loop=1
2022-01-28T14:54:53.301Z,1643381693.301 [LBLNavigation](INFO): Reset ping filters
2022-01-28T14:54:53.301Z,1643381693.301 [LBLNavigation](INFO): Reset fix filter
2022-01-28T14:54:53.302Z,1643381693.302 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2022-01-28T14:55:18.742Z,1643381718.742 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145517.00,A,4042.15198,N,07043.49294,W,1.011,0.00,280122,,,A*71
2022-01-28T14:55:18.749Z,1643381718.749 [NAL9602](INFO): GPS fix at 20220128T145517: (40.702533, -70.724882)
2022-01-28T14:55:18.782Z,1643381718.782 [Startup:StartupSatComms:A] Stopped
2022-01-28T14:55:18.782Z,1643381718.782 [Startup:StartupSatComms:B] Running Loop=1
2022-01-28T14:55:19.191Z,1643381719.191 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2022-01-28T14:55:39.857Z,1643381739.857 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=35065, MT Status=1, MTMSN=1376
2022-01-28T14:55:39.925Z,1643381739.925 [NAL9602](INFO): Sent 93 bytes from file Logs/20220127T205752/Courier0066.lzma
2022-01-28T14:55:39.925Z,1643381739.925 [NAL9602](INFO): Packets left to send: 0
2022-01-28T14:55:40.372Z,1643381740.372 [NAL9602](INFO): Received command: restart logs