2021-11-29T15:45:31.936Z,1638200731.936 [Supervisor](DEBUG): Initializing supervisor.
2021-11-29T15:45:31.940Z,1638200731.940 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2021-11-29T15:45:31.940Z,1638200731.940 [SyncHandler](INFO): Protected caller Thread ID is 4006
2021-11-29T15:45:31.941Z,1638200731.941 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2021-11-29T15:45:31.942Z,1638200731.942 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2021-11-29T15:45:31.942Z,1638200731.942 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4007
2021-11-29T15:45:31.946Z,1638200731.946 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2021-11-29T15:45:31.964Z,1638200731.964 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2021-11-29T15:45:31.965Z,1638200731.965 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2021-11-29T15:45:31.966Z,1638200731.966 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 4008
2021-11-29T15:45:31.970Z,1638200731.970 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2021-11-29T15:45:31.971Z,1638200731.971 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2021-11-29T15:45:31.971Z,1638200731.971 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4009
2021-11-29T15:45:31.973Z,1638200731.973 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2021-11-29T15:45:31.974Z,1638200731.974 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2021-11-29T15:45:31.975Z,1638200731.975 [logger ThreadHandler](INFO): Protected caller Thread ID is 4010
2021-11-29T15:45:31.978Z,1638200731.978 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2021-11-29T15:45:31.979Z,1638200731.979 [Supervisor](INFO): Looking for Config files in directory: Config/
2021-11-29T15:45:31.981Z,1638200731.981 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2021-11-29T15:45:32.201Z,1638200732.201 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2021-11-29T15:45:32.201Z,1638200732.201 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2021-11-29T15:45:32.280Z,1638200732.280 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2021-11-29T15:45:32.775Z,1638200732.775 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2021-11-29T15:45:32.776Z,1638200732.776 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2021-11-29T15:45:33.090Z,1638200733.090 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2021-11-29T15:45:33.091Z,1638200733.091 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2021-11-29T15:45:33.184Z,1638200733.184 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2021-11-29T15:45:33.184Z,1638200733.184 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2021-11-29T15:45:33.537Z,1638200733.537 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2021-11-29T15:45:33.538Z,1638200733.538 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2021-11-29T15:45:33.728Z,1638200733.728 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2021-11-29T15:45:33.728Z,1638200733.728 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2021-11-29T15:45:34.171Z,1638200734.171 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2021-11-29T15:45:34.171Z,1638200734.171 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2021-11-29T15:45:34.367Z,1638200734.367 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2021-11-29T15:45:34.367Z,1638200734.367 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2021-11-29T15:45:34.444Z,1638200734.444 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2021-11-29T15:45:35.090Z,1638200735.090 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2021-11-29T15:45:35.091Z,1638200735.091 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2021-11-29T15:45:35.437Z,1638200735.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2021-11-29T15:45:35.437Z,1638200735.437 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2021-11-29T15:45:35.619Z,1638200735.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2021-11-29T15:45:35.620Z,1638200735.620 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2021-11-29T15:45:35.727Z,1638200735.727 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2021-11-29T15:45:35.728Z,1638200735.728 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2021-11-29T15:45:35.874Z,1638200735.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2021-11-29T15:45:35.874Z,1638200735.874 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2021-11-29T15:45:36.092Z,1638200736.092 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2021-11-29T15:45:36.094Z,1638200736.094 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2021-11-29T15:45:36.095Z,1638200736.095 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2021-11-29T15:45:36.183Z,1638200736.183 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2021-11-29T15:45:36.267Z,1638200736.267 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2021-11-29T15:45:36.364Z,1638200736.364 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2021-11-29T15:45:36.446Z,1638200736.446 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2021-11-29T15:45:36.538Z,1638200736.538 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2021-11-29T15:45:36.702Z,1638200736.702 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2021-11-29T15:45:37.252Z,1638200737.252 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2021-11-29T15:45:37.332Z,1638200737.332 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2021-11-29T15:45:37.479Z,1638200737.479 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2021-11-29T15:45:37.610Z,1638200737.610 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2021-11-29T15:45:37.722Z,1638200737.722 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2021-11-29T15:45:37.976Z,1638200737.976 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2021-11-29T15:45:37.978Z,1638200737.978 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2021-11-29T15:45:37.978Z,1638200737.978 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2021-11-29T15:45:37.979Z,1638200737.979 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2021-11-29T15:45:38.035Z,1638200738.035 [VerticalControl](DEBUG): Construct VerticalControl.
2021-11-29T15:45:38.096Z,1638200738.096 [VerticalControl] Loaded
2021-11-29T15:45:38.097Z,1638200738.097 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2021-11-29T15:45:38.099Z,1638200738.099 [HorizontalControl](DEBUG): Construct HorizontalControl.
2021-11-29T15:45:38.137Z,1638200738.137 [HorizontalControl] Loaded
2021-11-29T15:45:38.137Z,1638200738.137 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2021-11-29T15:45:38.140Z,1638200738.140 [SpeedControl](DEBUG): Construct SpeedControl.
2021-11-29T15:45:38.143Z,1638200738.143 [SpeedControl] Loaded
2021-11-29T15:45:38.143Z,1638200738.143 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2021-11-29T15:45:38.146Z,1638200738.146 [LoopControl](DEBUG): Construct LoopControl.
2021-11-29T15:45:38.146Z,1638200738.146 [LoopControl] Loaded
2021-11-29T15:45:38.146Z,1638200738.146 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2021-11-29T15:45:38.147Z,1638200738.147 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2021-11-29T15:45:38.147Z,1638200738.147 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2021-11-29T15:45:38.158Z,1638200738.158 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2021-11-29T15:45:38.159Z,1638200738.159 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2021-11-29T15:45:38.262Z,1638200738.262 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2021-11-29T15:45:38.263Z,1638200738.263 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2021-11-29T15:45:38.390Z,1638200738.390 [BuoyancyServo] Loaded
2021-11-29T15:45:38.390Z,1638200738.390 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2021-11-29T15:45:38.409Z,1638200738.409 [ElevatorServo] Loaded
2021-11-29T15:45:38.410Z,1638200738.410 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2021-11-29T15:45:38.428Z,1638200738.428 [MassServo] Loaded
2021-11-29T15:45:38.428Z,1638200738.428 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2021-11-29T15:45:38.446Z,1638200738.446 [RudderServo] Loaded
2021-11-29T15:45:38.446Z,1638200738.446 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2021-11-29T15:45:38.463Z,1638200738.463 [ThrusterServo] Loaded
2021-11-29T15:45:38.463Z,1638200738.463 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2021-11-29T15:45:38.464Z,1638200738.464 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2021-11-29T15:45:38.464Z,1638200738.464 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2021-11-29T15:45:38.545Z,1638200738.545 [DeadReckonUsingMultipleVelocitySources] Loaded
2021-11-29T15:45:38.546Z,1638200738.546 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2021-11-29T15:45:38.559Z,1638200738.559 [NavChart] Loaded
2021-11-29T15:45:38.559Z,1638200738.559 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2021-11-29T15:45:38.564Z,1638200738.564 [UniversalFixResidualReporter] Loaded
2021-11-29T15:45:38.565Z,1638200738.565 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2021-11-29T15:45:38.565Z,1638200738.565 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2021-11-29T15:45:38.566Z,1638200738.566 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2021-11-29T15:45:38.624Z,1638200738.624 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2021-11-29T15:45:38.625Z,1638200738.625 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2021-11-29T15:45:39.007Z,1638200739.007 [AHRS_M2] Loaded
2021-11-29T15:45:39.007Z,1638200739.007 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2021-11-29T15:45:39.801Z,1638200739.801 [BPC1] Loaded
2021-11-29T15:45:39.801Z,1638200739.801 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2021-11-29T15:45:39.873Z,1638200739.873 [DataOverHttps] Loaded
2021-11-29T15:45:39.874Z,1638200739.874 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2021-11-29T15:45:39.875Z,1638200739.875 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408C64E0
2021-11-29T15:45:39.875Z,1638200739.875 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4096
2021-11-29T15:45:39.895Z,1638200739.895 [Depth_Keller] Loaded
2021-11-29T15:45:39.895Z,1638200739.895 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2021-11-29T15:45:39.900Z,1638200739.900 [DropWeight] Loaded
2021-11-29T15:45:39.900Z,1638200739.900 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2021-11-29T15:45:39.959Z,1638200739.959 [NAL9602] Loaded
2021-11-29T15:45:39.959Z,1638200739.959 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2021-11-29T15:45:39.988Z,1638200739.988 [Onboard] Loaded
2021-11-29T15:45:39.988Z,1638200739.988 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2021-11-29T15:45:39.989Z,1638200739.989 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408F64E0
2021-11-29T15:45:39.990Z,1638200739.990 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 4097
2021-11-29T15:45:40.002Z,1638200740.002 [Power24vConverter] Loaded
2021-11-29T15:45:40.003Z,1638200740.003 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2021-11-29T15:45:40.016Z,1638200740.016 [Radio_Surface] Loaded
2021-11-29T15:45:40.016Z,1638200740.016 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2021-11-29T15:45:40.017Z,1638200740.017 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409264E0
2021-11-29T15:45:40.017Z,1638200740.017 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4098
2021-11-29T15:45:40.037Z,1638200740.037 [AMEcho] Loaded
2021-11-29T15:45:40.037Z,1638200740.037 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread.
2021-11-29T15:45:40.118Z,1638200740.118 [DAT] Loaded
2021-11-29T15:45:40.118Z,1638200740.118 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2021-11-29T15:45:40.119Z,1638200740.119 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2021-11-29T15:45:40.119Z,1638200740.119 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2021-11-29T15:45:40.162Z,1638200740.162 [DepthRateCalculator] Loaded
2021-11-29T15:45:40.162Z,1638200740.162 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2021-11-29T15:45:40.167Z,1638200740.167 [PitchRateCalculator] Loaded
2021-11-29T15:45:40.167Z,1638200740.167 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2021-11-29T15:45:40.176Z,1638200740.176 [SpeedCalculator] Loaded
2021-11-29T15:45:40.177Z,1638200740.177 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2021-11-29T15:45:40.190Z,1638200740.190 [TempGradientCalculator] Loaded
2021-11-29T15:45:40.190Z,1638200740.190 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2021-11-29T15:45:40.195Z,1638200740.195 [YawRateCalculator] Loaded
2021-11-29T15:45:40.195Z,1638200740.195 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2021-11-29T15:45:40.213Z,1638200740.213 [ElevatorOffsetCalculator] Loaded
2021-11-29T15:45:40.213Z,1638200740.213 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2021-11-29T15:45:40.214Z,1638200740.214 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2021-11-29T15:45:40.214Z,1638200740.214 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2021-11-29T15:45:40.386Z,1638200740.386 [CTD_Seabird] Loaded
2021-11-29T15:45:40.386Z,1638200740.386 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2021-11-29T15:45:40.387Z,1638200740.387 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409DB4E0
2021-11-29T15:45:40.387Z,1638200740.387 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4099
2021-11-29T15:45:40.407Z,1638200740.407 [PAR_Licor] Loaded
2021-11-29T15:45:40.407Z,1638200740.407 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2021-11-29T15:45:40.439Z,1638200740.439 [WetLabsBB2FL] Loaded
2021-11-29T15:45:40.439Z,1638200740.439 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2021-11-29T15:45:40.440Z,1638200740.440 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A0B4E0
2021-11-29T15:45:40.441Z,1638200740.441 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4100
2021-11-29T15:45:40.441Z,1638200740.441 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2021-11-29T15:45:40.442Z,1638200740.442 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2021-11-29T15:45:40.469Z,1638200740.469 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2021-11-29T15:45:40.470Z,1638200740.470 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2021-11-29T15:45:40.796Z,1638200740.796 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2021-11-29T15:45:40.797Z,1638200740.797 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2021-11-29T15:45:40.942Z,1638200740.942 [SBIT](DEBUG): Construct Startup Built In Test.
2021-11-29T15:45:40.952Z,1638200740.952 [SBIT] Loaded
2021-11-29T15:45:40.952Z,1638200740.952 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2021-11-29T15:45:40.955Z,1638200740.955 [IBIT](DEBUG): Construct Initiated Built In Test.
2021-11-29T15:45:40.968Z,1638200740.968 [IBIT] Loaded
2021-11-29T15:45:40.968Z,1638200740.968 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2021-11-29T15:45:40.974Z,1638200740.974 [CBIT](DEBUG): Construct Continuous Built In Test.
2021-11-29T15:45:41.076Z,1638200741.076 [CBIT] Loaded
2021-11-29T15:45:41.076Z,1638200741.076 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2021-11-29T15:45:41.076Z,1638200741.076 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2021-11-29T15:45:41.077Z,1638200741.077 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2021-11-29T15:45:41.173Z,1638200741.173 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2021-11-29T15:45:41.179Z,1638200741.179 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2021-11-29T15:45:41.182Z,1638200741.182 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2021-11-29T15:45:41.193Z,1638200741.193 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2021-11-29T15:45:41.194Z,1638200741.194 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B404E0
2021-11-29T15:45:41.195Z,1638200741.195 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4101
2021-11-29T15:45:41.199Z,1638200741.199 [Supervisor](INFO): Main Thread ID is 4005
2021-11-29T15:45:41.200Z,1638200741.200 [Supervisor](DEBUG): Running supervisor.
2021-11-29T15:45:41.200Z,1638200741.200 [CommandExec ThreadHandler](INFO): Handler Thread ID is 4102
2021-11-29T15:45:41.201Z,1638200741.201 [CommandExec](INFO): Initializing the command executive.
2021-11-29T15:45:41.202Z,1638200741.202 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4103
2021-11-29T15:45:41.205Z,1638200741.205 [controlThread ThreadHandler](INFO): Handler Thread ID is 4104
2021-11-29T15:45:41.205Z,1638200741.205 [controlThread](DEBUG): Initializing ControlThread
2021-11-29T15:45:41.206Z,1638200741.206 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2021-11-29T15:45:41.208Z,1638200741.208 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2021-11-29T15:45:41.209Z,1638200741.209 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2021-11-29T15:45:41.209Z,1638200741.209 [LoopControl](DEBUG): Initialize LoopControlComponent.
2021-11-29T15:45:41.211Z,1638200741.211 [NavChart](DEBUG): Initialize NavChart Navigation.
2021-11-29T15:45:41.212Z,1638200741.212 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2021-11-29T15:45:41.218Z,1638200741.218 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2021-11-29T15:45:41.218Z,1638200741.218 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2021-11-29T15:45:41.219Z,1638200741.219 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2021-11-29T15:45:41.219Z,1638200741.219 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2021-11-29T15:45:41.220Z,1638200741.220 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2021-11-29T15:45:41.220Z,1638200741.220 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2021-11-29T15:45:41.224Z,1638200741.224 [SBIT](INFO): Initialize SBIT Component.
2021-11-29T15:45:41.225Z,1638200741.225 [SBIT](IMPORTANT): git: 2021-11-01-22-gea1679f0f
2021-11-29T15:45:41.225Z,1638200741.225 [SBIT](INFO): git hash: ea1679f0fbc9f895a669b42c70dfc339166fc8a2
2021-11-29T15:45:41.225Z,1638200741.225 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2021-11-29T15:45:41.226Z,1638200741.226 [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
2021-11-29T15:45:41.228Z,1638200741.228 [SBIT](INFO): Beginning SBIT in 41.000000 seconds.
2021-11-29T15:45:41.228Z,1638200741.228 [IBIT](INFO): Initialize IBIT Component.
2021-11-29T15:45:41.229Z,1638200741.229 [CBIT](DEBUG): Initialize CBIT Component.
2021-11-29T15:45:41.230Z,1638200741.230 [logger ThreadHandler](INFO): Handler Thread ID is 4105
2021-11-29T15:45:41.244Z,1638200741.244 [CBIT](DEBUG): Initialized mux pins.
2021-11-29T15:45:41.244Z,1638200741.244 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2021-11-29T15:45:41.244Z,1638200741.244 [CBIT](DEBUG): Initializing the watchdog timer.
2021-11-29T15:45:41.248Z,1638200741.248 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4106
2021-11-29T15:45:41.249Z,1638200741.249 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2021-11-29T15:45:41.260Z,1638200741.260 [Onboard ThreadHandler](INFO): Handler Thread ID is 4107
2021-11-29T15:45:41.269Z,1638200741.269 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2021-11-29T15:45:41.269Z,1638200741.269 [CBIT](DEBUG): Initializing heartbeat.
2021-11-29T15:45:41.281Z,1638200741.281 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4108
2021-11-29T15:45:41.296Z,1638200741.296 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4109
2021-11-29T15:45:41.297Z,1638200741.297 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2021-11-29T15:45:41.312Z,1638200741.312 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4111
2021-11-29T15:45:41.316Z,1638200741.316 [WetLabsBB2FL](INFO): Powering up
2021-11-29T15:45:41.317Z,1638200741.317 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4113
2021-11-29T15:45:41.321Z,1638200741.321 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2021-11-29T15:45:41.321Z,1638200741.321 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2021-11-29T15:45:41.321Z,1638200741.321 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2021-11-29T15:45:41.321Z,1638200741.321 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2021-11-29T15:45:41.322Z,1638200741.322 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2021-11-29T15:45:41.322Z,1638200741.322 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2021-11-29T15:45:41.322Z,1638200741.322 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2021-11-29T15:45:41.322Z,1638200741.322 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2021-11-29T15:45:41.322Z,1638200741.322 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2021-11-29T15:45:41.322Z,1638200741.322 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2021-11-29T15:45:41.323Z,1638200741.323 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2021-11-29T15:45:41.323Z,1638200741.323 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2021-11-29T15:45:41.323Z,1638200741.323 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2021-11-29T15:45:41.323Z,1638200741.323 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2021-11-29T15:45:41.324Z,1638200741.324 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2021-11-29T15:45:41.324Z,1638200741.324 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2021-11-29T15:45:41.340Z,1638200741.340 [CBIT](DEBUG): Deactivating GF circuits.
2021-11-29T15:45:41.340Z,1638200741.340 [CBIT](DEBUG): Deactivating emergency mode.
2021-11-29T15:45:41.376Z,1638200741.376 [CBIT](DEBUG): Backplane powered.
2021-11-29T15:45:41.377Z,1638200741.377 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2021-11-29T15:45:41.391Z,1638200741.391 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2021-11-29T15:45:41.441Z,1638200741.441 [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>


2021-11-29T15:45:41.442Z,1638200741.442 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2021-11-29T15:45:41.516Z,1638200741.516 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2021-11-29T15:45:41.518Z,1638200741.518 [Default:A.Wait](DEBUG): Construct Wait.
2021-11-29T15:45:41.536Z,1638200741.536 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2021-11-29T15:45:41.572Z,1638200741.572 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2021-11-29T15:45:41.574Z,1638200741.574 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2021-11-29T15:45:41.593Z,1638200741.593 [Default:E.Execute](DEBUG): Construct Execute.
2021-11-29T15:45:41.596Z,1638200741.596 [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="P1M"/>
            <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>1</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>


2021-11-29T15:45:41.608Z,1638200741.608 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,DropWeight,NAL9602,Power24vConverter,AMEcho,DAT,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2021-11-29T15:45:41.624Z,1638200741.624 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2021-11-29T15:45:41.688Z,1638200741.688 [Radio_Surface](INFO): Powering up
2021-11-29T15:45:41.691Z,1638200741.691 [Power24vConverter](INFO): Powering up.
2021-11-29T15:45:41.700Z,1638200741.700 [AMEcho](INFO): Powering up.
2021-11-29T15:45:41.721Z,1638200741.721 [DAT](INFO): Powering up
2021-11-29T15:45:41.721Z,1638200741.721 [DAT](DEBUG): Initializing DAT.
2021-11-29T15:45:41.822Z,1638200741.822 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2021-11-29T15:45:41.825Z,1638200741.825 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2021-11-29T15:45:41.827Z,1638200741.827 [ElevatorServo](DEBUG): Initializing EZServoServo.
2021-11-29T15:45:41.895Z,1638200741.895 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2021-11-29T15:45:41.896Z,1638200741.896 [MassServo](DEBUG): Initializing EZServoServo.
2021-11-29T15:45:42.012Z,1638200742.012 [MassServo](DEBUG): Initializing MassServo.
2021-11-29T15:45:42.014Z,1638200742.014 [RudderServo](DEBUG): Initializing EZServoServo.
2021-11-29T15:45:42.029Z,1638200742.029 [RudderServo](DEBUG): Initializing RudderServo.
2021-11-29T15:45:42.030Z,1638200742.030 [ThrusterServo](DEBUG): Initializing EZServoServo.
2021-11-29T15:45:42.200Z,1638200742.200 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2021-11-29T15:45:42.202Z,1638200742.202 [CommandExec](FAULT): Scheduling is paused
2021-11-29T15:45:42.203Z,1638200742.203 [CBIT](INFO): Critical error at 20211129T154541
2021-11-29T15:45:42.203Z,1638200742.203 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2021-11-29T15:45:42.416Z,1638200742.416 [WetLabsBB2FL](INFO): Powering down
2021-11-29T15:45:42.536Z,1638200742.536 [AMEcho](INFO): Powering down.
2021-11-29T15:45:42.876Z,1638200742.876 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2021-11-29T15:45:42.876Z,1638200742.876 [RudderServo](FAULT): Rudder failed to initialize
2021-11-29T15:45:42.876Z,1638200742.876 [RudderServo] Communications Fault, FailCount= 1
2021-11-29T15:45:42.876Z,1638200742.876 [RudderServo](ERROR): Communications Fault
2021-11-29T15:45:42.976Z,1638200742.976 [CBIT](ERROR): Communications Fault in component: RudderServo
2021-11-29T15:45:43.189Z,1638200743.189 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2021-11-29T15:45:43.189Z,1638200743.189 [RudderServo](INFO): Powering down
2021-11-29T15:45:43.388Z,1638200743.388 [AMEcho](IMPORTANT): Setting 'depthThreshold' to 20.000000
2021-11-29T15:45:43.841Z,1638200743.841 [RudderServo](DEBUG): Initializing EZServoServo.
2021-11-29T15:45:43.961Z,1638200743.961 [RudderServo](DEBUG): Initializing RudderServo.
2021-11-29T15:45:43.965Z,1638200743.965 [CBIT](INFO): Clearing failed state for component RudderServo
2021-11-29T15:45:43.965Z,1638200743.965 [RudderServo] No Fault, FailCount= 1
2021-11-29T15:45:48.332Z,1638200748.332 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2021-11-29T15:45:54.874Z,1638200754.874 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004734
2021-11-29T15:45:56.324Z,1638200756.324 [DAT](INFO): commRate: 1200
2021-11-29T15:45:58.342Z,1638200758.342 [DAT](INFO): entering command mode
2021-11-29T15:45:58.746Z,1638200758.746 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:45:59.150Z,1638200759.150 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:45:59.554Z,1638200759.554 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:45:59.958Z,1638200759.958 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:00.362Z,1638200760.362 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:00.766Z,1638200760.766 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:01.170Z,1638200761.170 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:01.574Z,1638200761.574 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:01.978Z,1638200761.978 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:02.382Z,1638200762.382 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:02.786Z,1638200762.786 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:03.190Z,1638200763.190 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:03.594Z,1638200763.594 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:03.998Z,1638200763.998 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:04.410Z,1638200764.410 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:04.806Z,1638200764.806 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:05.210Z,1638200765.210 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:05.614Z,1638200765.614 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:06.018Z,1638200766.018 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:06.422Z,1638200766.422 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:06.826Z,1638200766.826 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:07.237Z,1638200767.237 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:07.634Z,1638200767.634 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:08.038Z,1638200768.038 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:08.442Z,1638200768.442 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:08.850Z,1638200768.850 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:09.250Z,1638200769.250 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:09.654Z,1638200769.654 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:10.057Z,1638200770.057 [NAL9602](INFO): Powering up NAL9602
2021-11-29T15:46:10.060Z,1638200770.060 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:10.462Z,1638200770.462 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:10.866Z,1638200770.866 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:11.271Z,1638200771.271 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:11.674Z,1638200771.674 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:12.078Z,1638200772.078 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:12.482Z,1638200772.482 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:12.886Z,1638200772.886 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:13.290Z,1638200773.290 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:13.694Z,1638200773.694 [DAT](DEBUG): checking for command mode acknowledgment
2021-11-29T15:46:13.694Z,1638200773.694 [DAT](FAULT): failed to enter command mode
2021-11-29T15:46:14.110Z,1638200774.110 [DAT](INFO): entering command mode
2021-11-29T15:46:14.503Z,1638200774.503 [DAT](INFO): setting verbose to 3
2021-11-29T15:46:14.907Z,1638200774.907 [DAT](INFO): set verbose to 3
2021-11-29T15:46:14.908Z,1638200774.908 [DAT](INFO): setting DatVerbose to 27440
2021-11-29T15:46:15.311Z,1638200775.311 [DAT](INFO): set DatVerbose to 27440
2021-11-29T15:46:15.311Z,1638200775.311 [DAT](INFO): setting transmit power to 8
2021-11-29T15:46:15.723Z,1638200775.723 [DAT](INFO): set transmit power to 8
2021-11-29T15:46:15.723Z,1638200775.723 [DAT](INFO): setting local address to 7
2021-11-29T15:46:16.119Z,1638200776.119 [DAT](INFO): set local address to 7
2021-11-29T15:46:20.966Z,1638200780.966 [NAL9602](INFO): NAL9602 initialized
2021-11-29T15:46:23.019Z,1638200783.019 [SBIT](IMPORTANT): Beginning Startup BIT
2021-11-29T15:46:23.056Z,1638200783.056 [CBIT](IMPORTANT): Beginning ground fault scan
2021-11-29T15:46:25.104Z,1638200785.104 [CommandExec](IMPORTANT): got command failComponent
2021-11-29T15:46:25.105Z,1638200785.105 [CommandExec](IMPORTANT): Failed components:
2021-11-29T15:46:25.105Z,1638200785.105 [CommandExec](IMPORTANT): No failed Components.
2021-11-29T15:46:33.949Z,1638200793.949 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-11-29T15:46:34.365Z,1638200794.365 [CBIT](IMPORTANT): Beginning ground fault scan
2021-11-29T15:46:45.302Z,1638200805.302 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-11-29T15:46:45.696Z,1638200805.696 [CBIT](IMPORTANT): Beginning ground fault scan
2021-11-29T15:46:47.644Z,1638200807.644 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-11-29T15:46:47.672Z,1638200807.672 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:46:56.583Z,1638200816.583 [CBIT](ERROR): Ground fault scan returned out of bounds value. Re-running scan.
2021-11-29T15:46:56.583Z,1638200816.583 [CBIT](IMPORTANT): Ground fault scan returned out of bounds value in succession 3 times. Will re-run scan on normal schedule.
2021-11-29T15:46:58.605Z,1638200818.605 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-11-29T15:46:58.678Z,1638200818.678 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:47:09.517Z,1638200829.517 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-11-29T15:47:09.593Z,1638200829.593 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:47:17.188Z,1638200837.188 [SBIT](IMPORTANT): SBIT PASSED
2021-11-29T15:47:17.188Z,1638200837.188 [SBIT](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2021-11-29T15:47:17.555Z,1638200837.555 [MissionManager](IMPORTANT): Started mission Startup
2021-11-29T15:47:17.555Z,1638200837.555 [Startup] Running Loop=1
2021-11-29T15:47:17.555Z,1638200837.555 [Startup](DEBUG): Aggregate::initialize Startup
2021-11-29T15:47:17.555Z,1638200837.555 [Startup:A.GoToSurface] Running Loop=1
2021-11-29T15:47:17.555Z,1638200837.555 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-11-29T15:47:17.560Z,1638200837.560 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-11-29T15:47:17.561Z,1638200837.561 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-11-29T15:47:17.561Z,1638200837.561 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-11-29T15:47:17.561Z,1638200837.561 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-11-29T15:47:17.562Z,1638200837.562 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-11-29T15:47:17.563Z,1638200837.563 [Startup:StartupSatComms] Running Loop=1
2021-11-29T15:47:17.563Z,1638200837.563 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2021-11-29T15:47:17.568Z,1638200837.568 [Startup:StartupSatComms:A] Running Loop=1
2021-11-29T15:47:17.962Z,1638200837.962 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2021-11-29T15:47:18.335Z,1638200838.335 [AMEcho](INFO): Powering up.
2021-11-29T15:47:20.421Z,1638200840.421 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-11-29T15:47:20.493Z,1638200840.493 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:47:31.745Z,1638200851.745 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-11-29T15:47:31.821Z,1638200851.821 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:47:42.681Z,1638200862.681 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2021-11-29T15:47:42.751Z,1638200862.751 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:47:53.557Z,1638200873.557 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:48:04.459Z,1638200884.459 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:48:15.372Z,1638200895.372 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:48:17.771Z,1638200897.771 [Startup:StartupSatComms:A](INFO): Timed out from 2021-11-29T15:47:17.6Z
2021-11-29T15:48:17.771Z,1638200897.771 [Startup:StartupSatComms:A] Stopped
2021-11-29T15:48:17.771Z,1638200897.771 [Startup:StartupSatComms:B] Running Loop=1
2021-11-29T15:48:18.149Z,1638200898.149 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2021-11-29T15:48:20.013Z,1638200900.013 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20211123T112704/Courier0820.lzma
2021-11-29T15:48:20.354Z,1638200900.354 [DataOverHttps](INFO): Moved sent file to Logs/20211123T112704/Courier0820.lzma.bak
2021-11-29T15:48:20.354Z,1638200900.354 [DataOverHttps](INFO): SBD MOMSN=16305097
2021-11-29T15:48:26.475Z,1638200906.475 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:48:41.322Z,1638200921.322 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2021-11-29T15:48:41.322Z,1638200921.322 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2021-11-29T15:48:41.345Z,1638200921.345 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2021-11-29T15:48:41.756Z,1638200921.756 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2021-11-29T15:48:41.756Z,1638200921.756 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2021-11-29T15:48:44.660Z,1638200924.660 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20211129T154531/Courier0000.lzma
2021-11-29T15:48:45.662Z,1638200925.662 [DataOverHttps](INFO): Moved sent file to Logs/20211129T154531/Courier0000.lzma.bak
2021-11-29T15:48:45.662Z,1638200925.662 [DataOverHttps](INFO): SBD MOMSN=16305099
2021-11-29T15:48:49.774Z,1638200929.774 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:49:00.802Z,1638200940.802 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:49:02.420Z,1638200942.420 [CommandExec](IMPORTANT): got command failComponent
2021-11-29T15:49:02.421Z,1638200942.421 [CommandExec](IMPORTANT): Failed components:
2021-11-29T15:49:02.421Z,1638200942.421 [CommandExec](IMPORTANT): No failed Components.
2021-11-29T15:49:03.456Z,1638200943.456 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20211123T112704/Express0821.lzma
2021-11-29T15:49:04.458Z,1638200944.458 [DataOverHttps](INFO): Moved sent file to Logs/20211123T112704/Express0821.lzma.bak
2021-11-29T15:49:04.458Z,1638200944.458 [DataOverHttps](INFO): SBD MOMSN=16305103
2021-11-29T15:49:11.716Z,1638200951.716 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:49:18.111Z,1638200958.111 [Startup:StartupSatComms:B](INFO): Timed out from 2021-11-29T15:48:17.8Z
2021-11-29T15:49:18.111Z,1638200958.111 [Startup:StartupSatComms:B] Stopped
2021-11-29T15:49:18.111Z,1638200958.111 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2021-11-29T15:49:18.111Z,1638200958.111 [Startup:StartupSatComms] Stopped
2021-11-29T15:49:18.111Z,1638200958.111 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2021-11-29T15:49:18.116Z,1638200958.116 [Startup](INFO): Completed Startup
2021-11-29T15:49:18.116Z,1638200958.116 [MissionManager](INFO): Startup is completed.
2021-11-29T15:49:18.116Z,1638200958.116 [MissionManager](INFO): Uninitializing Mission Startup
2021-11-29T15:49:18.117Z,1638200958.117 [Startup] Stopped
2021-11-29T15:49:18.117Z,1638200958.117 [Startup](DEBUG): Aggregate::uninitialize Startup
2021-11-29T15:49:18.117Z,1638200958.117 [Startup:A.GoToSurface] Stopped
2021-11-29T15:49:18.117Z,1638200958.117 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2021-11-29T15:49:18.492Z,1638200958.492 [MissionManager](IMPORTANT): Started mission Default
2021-11-29T15:49:18.492Z,1638200958.492 [Default] Running Loop=1
2021-11-29T15:49:18.493Z,1638200958.493 [Default](DEBUG): Aggregate::initialize Default
2021-11-29T15:49:18.493Z,1638200958.493 [Default:B.GoToSurface] Running Loop=1
2021-11-29T15:49:18.493Z,1638200958.493 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2021-11-29T15:49:18.493Z,1638200958.493 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2021-11-29T15:49:18.493Z,1638200958.493 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2021-11-29T15:49:18.494Z,1638200958.494 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2021-11-29T15:49:18.494Z,1638200958.494 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2021-11-29T15:49:18.494Z,1638200958.494 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2021-11-29T15:49:18.495Z,1638200958.495 [Default:A.Wait] Running Loop=1
2021-11-29T15:49:18.495Z,1638200958.495 [Default:A.Wait](DEBUG): Initialize Wait Component.
2021-11-29T15:49:19.024Z,1638200959.024 [AMEcho](INFO): Powering down.
2021-11-29T15:49:20.070Z,1638200960.070 [AMEcho](INFO): Powering up.
2021-11-29T15:49:21.801Z,1638200961.801 [DataOverHttps](INFO): Sending 747 bytes from file Logs/20211129T154531/Express0001.lzma
2021-11-29T15:49:22.562Z,1638200962.562 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2021-11-29T15:49:22.801Z,1638200962.801 [DataOverHttps](INFO): Moved sent file to Logs/20211129T154531/Express0001.lzma.bak
2021-11-29T15:49:22.802Z,1638200962.802 [DataOverHttps](INFO): SBD MOMSN=16305108
2021-11-29T15:49:31.800Z,1638200971.800 [Default:A.Wait](INFO): Done Waiting.
2021-11-29T15:49:31.800Z,1638200971.800 [Default:A.Wait] Stopped