2022-11-02T16:34:27.166Z,1667406867.166 [Supervisor](DEBUG): Initializing supervisor. 2022-11-02T16:34:27.171Z,1667406867.171 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2022-11-02T16:34:27.171Z,1667406867.171 [SyncHandler](INFO): Protected caller Thread ID is 975 2022-11-02T16:34:27.172Z,1667406867.172 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2022-11-02T16:34:27.173Z,1667406867.173 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2022-11-02T16:34:27.173Z,1667406867.173 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 976 2022-11-02T16:34:27.177Z,1667406867.177 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2022-11-02T16:34:27.195Z,1667406867.195 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread. 2022-11-02T16:34:27.196Z,1667406867.196 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2022-11-02T16:34:27.197Z,1667406867.197 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 977 2022-11-02T16:34:27.201Z,1667406867.201 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2022-11-02T16:34:27.202Z,1667406867.202 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2022-11-02T16:34:27.202Z,1667406867.202 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 978 2022-11-02T16:34:27.205Z,1667406867.205 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2022-11-02T16:34:27.206Z,1667406867.206 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0 2022-11-02T16:34:27.206Z,1667406867.206 [logger ThreadHandler](INFO): Protected caller Thread ID is 979 2022-11-02T16:34:27.210Z,1667406867.210 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2022-11-02T16:34:27.210Z,1667406867.210 [Supervisor](INFO): Looking for Config files in directory: Config/ 2022-11-02T16:34:27.212Z,1667406867.212 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2022-11-02T16:34:27.634Z,1667406867.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2022-11-02T16:34:27.634Z,1667406867.634 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2022-11-02T16:34:27.845Z,1667406867.845 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2022-11-02T16:34:27.846Z,1667406867.846 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2022-11-02T16:34:28.025Z,1667406868.025 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2022-11-02T16:34:28.026Z,1667406868.026 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2022-11-02T16:34:28.130Z,1667406868.130 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2022-11-02T16:34:28.130Z,1667406868.130 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2022-11-02T16:34:28.492Z,1667406868.492 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2022-11-02T16:34:28.493Z,1667406868.493 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2022-11-02T16:34:28.809Z,1667406868.809 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2022-11-02T16:34:28.809Z,1667406868.809 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2022-11-02T16:34:28.902Z,1667406868.902 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2022-11-02T16:34:28.903Z,1667406868.903 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2022-11-02T16:34:29.118Z,1667406869.118 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2022-11-02T16:34:29.119Z,1667406869.119 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2022-11-02T16:34:29.696Z,1667406869.696 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2022-11-02T16:34:29.697Z,1667406869.697 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2022-11-02T16:34:30.044Z,1667406870.044 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2022-11-02T16:34:30.045Z,1667406870.045 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2022-11-02T16:34:30.123Z,1667406870.123 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2022-11-02T16:34:30.330Z,1667406870.330 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2022-11-02T16:34:30.331Z,1667406870.331 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2022-11-02T16:34:30.464Z,1667406870.464 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2022-11-02T16:34:30.465Z,1667406870.465 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2022-11-02T16:34:31.182Z,1667406871.182 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2022-11-02T16:34:31.182Z,1667406871.182 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2022-11-02T16:34:31.260Z,1667406871.260 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2022-11-02T16:34:31.544Z,1667406871.544 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2022-11-02T16:34:31.546Z,1667406871.546 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/ 2022-11-02T16:34:31.547Z,1667406871.547 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/vehicle.cfg 2022-11-02T16:34:31.722Z,1667406871.722 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/logger.cfg 2022-11-02T16:34:31.813Z,1667406871.813 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Servo.cfg 2022-11-02T16:34:31.921Z,1667406871.921 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Control.cfg 2022-11-02T16:34:32.018Z,1667406872.018 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/secure.cfg 2022-11-02T16:34:32.099Z,1667406872.099 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Simulator.cfg 2022-11-02T16:34:32.190Z,1667406872.190 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Science.cfg 2022-11-02T16:34:32.390Z,1667406872.390 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/BIT.cfg 2022-11-02T16:34:32.730Z,1667406872.730 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Sensor.cfg 2022-11-02T16:34:33.192Z,1667406873.192 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Battery.cfg 2022-11-02T16:34:33.458Z,1667406873.458 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2022-11-02T16:34:33.459Z,1667406873.459 [Supervisor](INFO): Opening Config file at: Config/lrauv-galene/Navigation.cfg 2022-11-02T16:34:33.551Z,1667406873.551 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-galene/root/ 2022-11-02T16:34:33.551Z,1667406873.551 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2022-11-02T16:34:33.564Z,1667406873.564 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2022-11-02T16:34:33.868Z,1667406873.868 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2022-11-02T16:34:33.869Z,1667406873.869 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2022-11-02T16:34:33.981Z,1667406873.981 [DeadReckonUsingMultipleVelocitySources] Loaded 2022-11-02T16:34:33.982Z,1667406873.982 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2022-11-02T16:34:34.021Z,1667406874.021 [DeadReckonUsingSpeedCalculator] Loaded 2022-11-02T16:34:34.021Z,1667406874.021 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2022-11-02T16:34:34.034Z,1667406874.034 [NavChart] Loaded 2022-11-02T16:34:34.034Z,1667406874.034 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2022-11-02T16:34:34.040Z,1667406874.040 [UniversalFixResidualReporter] Loaded 2022-11-02T16:34:34.040Z,1667406874.040 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2022-11-02T16:34:34.041Z,1667406874.041 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2022-11-02T16:34:34.041Z,1667406874.041 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2022-11-02T16:34:34.051Z,1667406874.051 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2022-11-02T16:34:34.052Z,1667406874.052 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2022-11-02T16:34:34.209Z,1667406874.209 [PAR_Licor] Loaded 2022-11-02T16:34:34.209Z,1667406874.209 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2022-11-02T16:34:34.241Z,1667406874.241 [WetLabsBB2FL] Loaded 2022-11-02T16:34:34.241Z,1667406874.241 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2022-11-02T16:34:34.242Z,1667406874.242 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4065A4E0 2022-11-02T16:34:34.242Z,1667406874.242 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1062 2022-11-02T16:34:34.243Z,1667406874.243 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2022-11-02T16:34:34.244Z,1667406874.244 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2022-11-02T16:34:34.295Z,1667406874.295 [VerticalControl](DEBUG): Construct VerticalControl. 2022-11-02T16:34:34.356Z,1667406874.356 [VerticalControl] Loaded 2022-11-02T16:34:34.357Z,1667406874.357 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2022-11-02T16:34:34.359Z,1667406874.359 [HorizontalControl](DEBUG): Construct HorizontalControl. 2022-11-02T16:34:34.401Z,1667406874.401 [HorizontalControl] Loaded 2022-11-02T16:34:34.401Z,1667406874.401 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2022-11-02T16:34:34.403Z,1667406874.403 [SpeedControl](DEBUG): Construct SpeedControl. 2022-11-02T16:34:34.406Z,1667406874.406 [SpeedControl] Loaded 2022-11-02T16:34:34.407Z,1667406874.407 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2022-11-02T16:34:34.409Z,1667406874.409 [LoopControl](DEBUG): Construct LoopControl. 2022-11-02T16:34:34.410Z,1667406874.410 [LoopControl] Loaded 2022-11-02T16:34:34.410Z,1667406874.410 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2022-11-02T16:34:34.411Z,1667406874.411 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2022-11-02T16:34:34.411Z,1667406874.411 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2022-11-02T16:34:34.461Z,1667406874.461 [DepthRateCalculator] Loaded 2022-11-02T16:34:34.461Z,1667406874.461 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2022-11-02T16:34:34.466Z,1667406874.466 [PitchRateCalculator] Loaded 2022-11-02T16:34:34.467Z,1667406874.467 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2022-11-02T16:34:34.476Z,1667406874.476 [SpeedCalculator] Loaded 2022-11-02T16:34:34.476Z,1667406874.476 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2022-11-02T16:34:34.480Z,1667406874.480 [YawRateCalculator] Loaded 2022-11-02T16:34:34.481Z,1667406874.481 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2022-11-02T16:34:34.499Z,1667406874.499 [ElevatorOffsetCalculator] Loaded 2022-11-02T16:34:34.499Z,1667406874.499 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2022-11-02T16:34:34.500Z,1667406874.500 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2022-11-02T16:34:34.500Z,1667406874.500 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2022-11-02T16:34:34.593Z,1667406874.593 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2022-11-02T16:34:34.594Z,1667406874.594 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2022-11-02T16:34:34.653Z,1667406874.653 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2022-11-02T16:34:34.653Z,1667406874.653 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2022-11-02T16:34:34.778Z,1667406874.778 [BuoyancyServo] Loaded 2022-11-02T16:34:34.778Z,1667406874.778 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2022-11-02T16:34:34.798Z,1667406874.798 [ElevatorServo] Loaded 2022-11-02T16:34:34.799Z,1667406874.799 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2022-11-02T16:34:34.818Z,1667406874.818 [MassServo] Loaded 2022-11-02T16:34:34.818Z,1667406874.818 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2022-11-02T16:34:34.836Z,1667406874.836 [RudderServo] Loaded 2022-11-02T16:34:34.837Z,1667406874.837 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2022-11-02T16:34:34.851Z,1667406874.851 [ThrusterHE] Loaded 2022-11-02T16:34:34.851Z,1667406874.851 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread. 2022-11-02T16:34:34.852Z,1667406874.852 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2022-11-02T16:34:34.852Z,1667406874.852 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2022-11-02T16:34:35.005Z,1667406875.005 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2022-11-02T16:34:35.005Z,1667406875.005 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2022-11-02T16:34:35.407Z,1667406875.407 [AHRS_M2] Loaded 2022-11-02T16:34:35.408Z,1667406875.408 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2022-11-02T16:34:35.443Z,1667406875.443 [BackseatComponent] Loaded 2022-11-02T16:34:35.443Z,1667406875.443 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread. 2022-11-02T16:34:35.444Z,1667406875.444 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 40A544E0 2022-11-02T16:34:35.445Z,1667406875.445 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1063 2022-11-02T16:34:35.447Z,1667406875.447 [LcmUniversalReporter] Loaded 2022-11-02T16:34:35.448Z,1667406875.448 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread. 2022-11-02T16:34:36.270Z,1667406876.270 [BPC1] Loaded 2022-11-02T16:34:36.271Z,1667406876.271 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2022-11-02T16:34:36.346Z,1667406876.346 [DataOverHttps] Loaded 2022-11-02T16:34:36.346Z,1667406876.346 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2022-11-02T16:34:36.347Z,1667406876.347 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 40A844E0 2022-11-02T16:34:36.348Z,1667406876.348 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1064 2022-11-02T16:34:36.369Z,1667406876.369 [Depth_Keller] Loaded 2022-11-02T16:34:36.369Z,1667406876.369 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2022-11-02T16:34:36.374Z,1667406876.374 [DropWeight] Loaded 2022-11-02T16:34:36.374Z,1667406876.374 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2022-11-02T16:34:36.391Z,1667406876.391 [MultiRay] Loaded 2022-11-02T16:34:36.391Z,1667406876.391 [ComponentRegistry](DEBUG): SyncComponent "MultiRay" handled in the control thread. 2022-11-02T16:34:36.454Z,1667406876.454 [NAL9602] Loaded 2022-11-02T16:34:36.454Z,1667406876.454 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2022-11-02T16:34:36.485Z,1667406876.485 [Onboard] Loaded 2022-11-02T16:34:36.486Z,1667406876.486 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2022-11-02T16:34:36.486Z,1667406876.486 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 40AB44E0 2022-11-02T16:34:36.487Z,1667406876.487 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1065 2022-11-02T16:34:36.493Z,1667406876.493 [PowerOnly](INFO): Adding load control power supply at /dev/loadC3 2022-11-02T16:34:36.504Z,1667406876.504 [PowerOnly] Loaded 2022-11-02T16:34:36.505Z,1667406876.505 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread. 2022-11-02T16:34:36.516Z,1667406876.516 [Power24vConverter] Loaded 2022-11-02T16:34:36.517Z,1667406876.517 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread. 2022-11-02T16:34:36.530Z,1667406876.530 [Radio_Surface] Loaded 2022-11-02T16:34:36.531Z,1667406876.531 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2022-11-02T16:34:36.532Z,1667406876.532 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40AE44E0 2022-11-02T16:34:36.532Z,1667406876.532 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1066 2022-11-02T16:34:36.626Z,1667406876.626 [DAT] Loaded 2022-11-02T16:34:36.626Z,1667406876.626 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread. 2022-11-02T16:34:36.627Z,1667406876.627 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 40B144E0 2022-11-02T16:34:36.627Z,1667406876.627 [DAT ThreadHandler](INFO): Protected caller Thread ID is 1067 2022-11-02T16:34:36.628Z,1667406876.628 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2022-11-02T16:34:36.628Z,1667406876.628 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2022-11-02T16:34:36.773Z,1667406876.773 [SBIT](DEBUG): Construct Startup Built In Test. 2022-11-02T16:34:36.782Z,1667406876.782 [SBIT] Loaded 2022-11-02T16:34:36.782Z,1667406876.782 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2022-11-02T16:34:36.785Z,1667406876.785 [IBIT](DEBUG): Construct Initiated Built In Test. 2022-11-02T16:34:36.799Z,1667406876.799 [IBIT] Loaded 2022-11-02T16:34:36.799Z,1667406876.799 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2022-11-02T16:34:36.805Z,1667406876.805 [CBIT](DEBUG): Construct Continuous Built In Test. 2022-11-02T16:34:36.910Z,1667406876.910 [CBIT] Loaded 2022-11-02T16:34:36.910Z,1667406876.910 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2022-11-02T16:34:36.910Z,1667406876.910 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2022-11-02T16:34:36.911Z,1667406876.911 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2022-11-02T16:34:36.938Z,1667406876.938 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2022-11-02T16:34:36.945Z,1667406876.945 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2022-11-02T16:34:36.948Z,1667406876.948 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2022-11-02T16:34:36.959Z,1667406876.959 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2022-11-02T16:34:36.960Z,1667406876.960 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BA24E0 2022-11-02T16:34:36.960Z,1667406876.960 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1068 2022-11-02T16:34:36.965Z,1667406876.965 [Supervisor](INFO): Main Thread ID is 974 2022-11-02T16:34:36.965Z,1667406876.965 [Supervisor](DEBUG): Running supervisor. 2022-11-02T16:34:36.966Z,1667406876.966 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1069 2022-11-02T16:34:36.966Z,1667406876.966 [CommandExec](INFO): Initializing the command executive. 2022-11-02T16:34:36.968Z,1667406876.968 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1070 2022-11-02T16:34:36.970Z,1667406876.970 [controlThread ThreadHandler](INFO): Handler Thread ID is 1071 2022-11-02T16:34:36.970Z,1667406876.970 [controlThread](DEBUG): Initializing ControlThread 2022-11-02T16:34:36.972Z,1667406876.972 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-02T16:34:36.972Z,1667406876.972 [NavChart](DEBUG): Initialize NavChart Navigation. 2022-11-02T16:34:36.973Z,1667406876.973 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2022-11-02T16:34:36.977Z,1667406876.977 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2022-11-02T16:34:36.979Z,1667406876.979 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2022-11-02T16:34:36.979Z,1667406876.979 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2022-11-02T16:34:36.980Z,1667406876.980 [LoopControl](DEBUG): Initialize LoopControlComponent. 2022-11-02T16:34:36.980Z,1667406876.980 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2022-11-02T16:34:36.981Z,1667406876.981 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2022-11-02T16:34:36.981Z,1667406876.981 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2022-11-02T16:34:36.981Z,1667406876.981 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2022-11-02T16:34:36.982Z,1667406876.982 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2022-11-02T16:34:36.987Z,1667406876.987 [SBIT](INFO): Initialize SBIT Component. 2022-11-02T16:34:36.987Z,1667406876.987 [SBIT](IMPORTANT): git: 2022-10-11-37-g3067145cf 2022-11-02T16:34:36.987Z,1667406876.987 [SBIT](INFO): git hash: 3067145cfe0a71a9d335ed48764d88f81a84ec20 2022-11-02T16:34:36.988Z,1667406876.988 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2022-11-02T16:34:36.989Z,1667406876.989 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021 2022-11-02T16:34:36.990Z,1667406876.990 [SBIT](INFO): Beginning SBIT in 109.000000 seconds. 2022-11-02T16:34:36.991Z,1667406876.991 [IBIT](INFO): Initialize IBIT Component. 2022-11-02T16:34:36.992Z,1667406876.992 [CBIT](DEBUG): Initialize CBIT Component. 2022-11-02T16:34:36.993Z,1667406876.993 [logger ThreadHandler](INFO): Handler Thread ID is 1072 2022-11-02T16:34:37.005Z,1667406877.005 [CBIT](DEBUG): Initialized mux pins. 2022-11-02T16:34:37.005Z,1667406877.005 [CBIT](DEBUG): Initializing the watchdog timer. 2022-11-02T16:34:37.013Z,1667406877.013 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1073 2022-11-02T16:34:37.018Z,1667406877.018 [WetLabsBB2FL](INFO): Powering up 2022-11-02T16:34:37.019Z,1667406877.019 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1075 2022-11-02T16:34:37.025Z,1667406877.025 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1076 2022-11-02T16:34:37.026Z,1667406877.026 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2022-11-02T16:34:37.029Z,1667406877.029 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2022-11-02T16:34:37.029Z,1667406877.029 [CBIT](DEBUG): Initializing heartbeat. 2022-11-02T16:34:37.037Z,1667406877.037 [Onboard ThreadHandler](INFO): Handler Thread ID is 1077 2022-11-02T16:34:37.055Z,1667406877.055 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1078 2022-11-02T16:34:37.077Z,1667406877.077 [DAT ThreadHandler](INFO): Handler Thread ID is 1079 2022-11-02T16:34:37.078Z,1667406877.078 [DAT](INFO): Powering up 2022-11-02T16:34:37.078Z,1667406877.078 [DAT](DEBUG): Initializing DAT. 2022-11-02T16:34:37.082Z,1667406877.082 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1081 2022-11-02T16:34:37.085Z,1667406877.085 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2022-11-02T16:34:37.085Z,1667406877.085 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2022-11-02T16:34:37.085Z,1667406877.085 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2022-11-02T16:34:37.085Z,1667406877.085 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2022-11-02T16:34:37.086Z,1667406877.086 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2022-11-02T16:34:37.086Z,1667406877.086 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2022-11-02T16:34:37.086Z,1667406877.086 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2022-11-02T16:34:37.086Z,1667406877.086 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2022-11-02T16:34:37.101Z,1667406877.101 [CBIT](DEBUG): Deactivating GF circuits. 2022-11-02T16:34:37.101Z,1667406877.101 [CBIT](DEBUG): Deactivating emergency mode. 2022-11-02T16:34:37.137Z,1667406877.137 [CBIT](DEBUG): Backplane powered. 2022-11-02T16:34:37.138Z,1667406877.138 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml 2022-11-02T16:34:37.150Z,1667406877.150 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2022-11-02T16:34:37.174Z,1667406877.174 [MissionManager](DEBUG): 2022-11-02T16:34:37.174Z,1667406877.174 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml 2022-11-02T16:34:37.248Z,1667406877.248 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2022-11-02T16:34:37.249Z,1667406877.249 [Default:A.Wait](DEBUG): Construct Wait. 2022-11-02T16:34:37.252Z,1667406877.252 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2022-11-02T16:34:37.310Z,1667406877.310 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2022-11-02T16:34:37.330Z,1667406877.330 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2022-11-02T16:34:37.461Z,1667406877.461 [Radio_Surface](INFO): Powering up 2022-11-02T16:34:37.472Z,1667406877.472 [Default:E.Execute](DEBUG): Construct Execute. 2022-11-02T16:34:37.503Z,1667406877.503 [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-11-02T16:34:37.511Z,1667406877.511 [controlThread](DEBUG): Component order: CycleStarter,PAR_Licor,AHRS_M2,BPC1,Depth_Keller,DropWeight,MultiRay,NAL9602,PowerOnly,Power24vConverter,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter, 2022-11-02T16:34:37.571Z,1667406877.571 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2022-11-02T16:34:37.652Z,1667406877.652 [MultiRay](INFO): Start 2022-11-02T16:34:37.652Z,1667406877.652 [MultiRay](INFO): Powering up MultiRay Lights 2022-11-02T16:34:37.686Z,1667406877.686 [Power24vConverter](INFO): Powering up. 2022-11-02T16:34:37.715Z,1667406877.715 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2022-11-02T16:34:37.729Z,1667406877.729 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2022-11-02T16:34:37.730Z,1667406877.730 [ElevatorServo](DEBUG): Initializing EZServoServo. 2022-11-02T16:34:37.737Z,1667406877.737 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2022-11-02T16:34:37.738Z,1667406877.738 [MassServo](DEBUG): Initializing EZServoServo. 2022-11-02T16:34:37.749Z,1667406877.749 [MassServo](DEBUG): Initializing MassServo. 2022-11-02T16:34:37.750Z,1667406877.750 [RudderServo](DEBUG): Initializing EZServoServo. 2022-11-02T16:34:37.757Z,1667406877.757 [RudderServo](DEBUG): Initializing RudderServo. 2022-11-02T16:34:37.758Z,1667406877.758 [ThrusterHE](DEBUG): Initializing EZServoServo. 2022-11-02T16:34:37.765Z,1667406877.765 [ThrusterHE](DEBUG): Initializing ThrusterHE. 2022-11-02T16:34:37.959Z,1667406877.959 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2022-11-02T16:34:37.959Z,1667406877.959 [DropWeight] Hardware Fault, FailCount= 1 2022-11-02T16:34:37.959Z,1667406877.959 [DropWeight](ERROR): Hardware Fault 2022-11-02T16:34:37.960Z,1667406877.960 [MultiRay](INFO): Starting 2022-11-02T16:34:37.960Z,1667406877.960 [MultiRay](INFO): Finished reading config 2022-11-02T16:34:37.984Z,1667406877.984 [CommandExec](FAULT): Scheduling is paused 2022-11-02T16:34:37.993Z,1667406877.993 [CBIT](INFO): Critical error at 20221102T163437 2022-11-02T16:34:37.993Z,1667406877.993 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2022-11-02T16:34:37.996Z,1667406877.996 [CBIT](ERROR): Hardware Fault in component: DropWeight 2022-11-02T16:34:37.996Z,1667406877.996 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2022-11-02T16:34:38.653Z,1667406878.653 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2022-11-02T16:34:38.653Z,1667406878.653 [RudderServo](FAULT): Rudder failed to initialize 2022-11-02T16:34:38.653Z,1667406878.653 [RudderServo] Communications Fault, FailCount= 1 2022-11-02T16:34:38.653Z,1667406878.653 [RudderServo](ERROR): Communications Fault 2022-11-02T16:34:38.655Z,1667406878.655 [CBIT](INFO): Critical error at 20221102T163437 2022-11-02T16:34:38.657Z,1667406878.657 [CBIT](ERROR): Communications Fault in component: RudderServo 2022-11-02T16:34:38.882Z,1667406878.882 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2022-11-02T16:34:38.882Z,1667406878.882 [RudderServo](INFO): Powering down 2022-11-02T16:34:39.566Z,1667406879.566 [RudderServo](DEBUG): Initializing EZServoServo. 2022-11-02T16:34:39.629Z,1667406879.629 [WetLabsBB2FL](INFO): Powering down 2022-11-02T16:34:39.686Z,1667406879.686 [RudderServo](DEBUG): Initializing RudderServo. 2022-11-02T16:34:39.690Z,1667406879.690 [CBIT](INFO): Clearing failed state for component RudderServo 2022-11-02T16:34:39.690Z,1667406879.690 [RudderServo] No Fault, FailCount= 1 2022-11-02T16:34:43.466Z,1667406883.466 [ThrusterHE](ERROR): Zero Speed Commanded. 2022-11-02T16:34:52.199Z,1667406892.199 [DAT](INFO): commRate: 800 2022-11-02T16:34:54.265Z,1667406894.265 [DAT](INFO): entering command mode 2022-11-02T16:34:54.466Z,1667406894.466 [DAT](INFO): setting verbose to 3 2022-11-02T16:34:54.719Z,1667406894.719 [DAT](INFO): set verbose to 3 2022-11-02T16:34:54.719Z,1667406894.719 [DAT](INFO): setting DatVerbose to 27440 2022-11-02T16:34:54.970Z,1667406894.970 [DAT](INFO): set DatVerbose to 27440 2022-11-02T16:34:54.971Z,1667406894.971 [DAT](INFO): setting transmit power to 8 2022-11-02T16:34:55.222Z,1667406895.222 [DAT](INFO): set transmit power to 8 2022-11-02T16:34:55.223Z,1667406895.223 [DAT](INFO): setting local address to 10 2022-11-02T16:34:55.474Z,1667406895.474 [DAT](INFO): set local address to 10 2022-11-02T16:34:55.475Z,1667406895.475 [DAT](INFO): Setting time to: 16:34:55 And date to:11/2/2022 2022-11-02T16:34:55.727Z,1667406895.727 [DAT](INFO): Local DAT time set to Wed Nov 2, 2022 16:34:55 2022-11-02T16:35:06.631Z,1667406906.631 [NAL9602](INFO): Powering up NAL9602 2022-11-02T16:35:09.577Z,1667406909.577 [MassServo](ERROR): getPosition uart error serial timeout 2022-11-02T16:35:09.577Z,1667406909.577 [MassServo](FAULT): Invalid EZ Servo response:"\r" 2022-11-02T16:35:09.577Z,1667406909.577 [MassServo] Communications Fault, FailCount= 1 2022-11-02T16:35:09.577Z,1667406909.577 [MassServo](ERROR): Communications Fault 2022-11-02T16:35:09.602Z,1667406909.602 [CBIT](ERROR): Communications Fault in component: MassServo 2022-11-02T16:35:09.878Z,1667406909.878 [MassServo](DEBUG): Uninitialize Mass Servo. 2022-11-02T16:35:09.878Z,1667406909.878 [MassServo](INFO): Powering down 2022-11-02T16:35:10.697Z,1667406910.697 [MassServo](DEBUG): Initializing EZServoServo. 2022-11-02T16:35:10.818Z,1667406910.818 [MassServo](DEBUG): Initializing MassServo. 2022-11-02T16:35:10.822Z,1667406910.822 [CBIT](INFO): Clearing failed state for component MassServo 2022-11-02T16:35:10.822Z,1667406910.822 [MassServo] No Fault, FailCount= 1 2022-11-02T16:35:17.530Z,1667406917.530 [NAL9602](INFO): NAL9602 initialized 2022-11-02T16:36:17.355Z,1667406977.355 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode0.xml 2022-11-02T16:36:17.355Z,1667406977.355 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode0.xml 2022-11-02T16:36:17.419Z,1667406977.419 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 90.000000 min 2022-11-02T16:36:17.426Z,1667406977.426 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 5.000000 s 2022-11-02T16:36:17.433Z,1667406977.433 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-02T16:36:17.435Z,1667406977.435 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-02T16:36:17.442Z,1667406977.442 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-02T16:36:17.466Z,1667406977.466 [MissionManager](INFO): DefineArg multiray_lab.EnabledMultiray = 1 bool 2022-11-02T16:36:17.475Z,1667406977.475 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 90 How long to turn on / off lights, default 30 seconds 5 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 Automatically set to true if the Multiray is enabled. 2022-11-02T16:36:17.485Z,1667406977.485 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode0.xml 2022-11-02T16:36:25.628Z,1667406985.628 [CommandExec](IMPORTANT): got command run ./Missions/Maintenance/multiray_mode1.xml 2022-11-02T16:36:25.628Z,1667406985.628 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-02T16:36:25.630Z,1667406985.630 [MissionManager](INFO): Loading Mission from file: ./Missions/Maintenance/multiray_mode1.xml 2022-11-02T16:36:25.651Z,1667406985.651 [MissionManager](INFO): DefineArg multiray_lab.MissionTimeout = 90.000000 min 2022-11-02T16:36:25.654Z,1667406985.654 [MissionManager](INFO): DefineArg multiray_lab.LightDuration = 5.000000 s 2022-11-02T16:36:25.656Z,1667406985.656 [MissionManager](INFO): DefineArg multiray_lab.LightMode0 = 0.000000 count 2022-11-02T16:36:25.659Z,1667406985.659 [MissionManager](INFO): DefineArg multiray_lab.LightMode1 = 1.000000 count 2022-11-02T16:36:25.661Z,1667406985.661 [MissionManager](INFO): DefineArg multiray_lab.LightMode2 = 2.000000 count 2022-11-02T16:36:25.663Z,1667406985.663 [MissionManager](INFO): DefineArg multiray_lab.EnabledMultiray = 1 bool 2022-11-02T16:36:25.668Z,1667406985.668 [MissionManager](DEBUG): This mission is designed to run in the lab only. Turns on and off MultiRay lights. How long to let the mission run. 90 How long to turn on / off lights, default 30 seconds 5 Light mode = 0 0 Light mode = 1 1 Light mode = 2 2 Automatically set to true if the Multiray is enabled. 2022-11-02T16:36:25.670Z,1667406985.670 [CommandExec](IMPORTANT): Running ./Missions/Maintenance/multiray_mode1.xml 2022-11-02T16:36:26.631Z,1667406986.631 [SBIT](IMPORTANT): Beginning Startup BIT 2022-11-02T16:36:26.636Z,1667406986.636 [CBIT](IMPORTANT): Beginning ground fault scan 2022-11-02T16:36:37.586Z,1667406997.586 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): 0.012450 CHAN A1 (24V): 0.000787 CHAN A2 (12V): -0.005859 CHAN A3 (5V): -0.002080 CHAN B0 (3.3V): -0.001572 CHAN B1 (3.15aV): -0.001877 CHAN B2 (3.15bV): -0.001929 CHAN B3 (GND): -0.000877 OPEN: 0.004532 Full Scale: +/- 1 mA 2022-11-02T16:37:05.943Z,1667407025.943 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004982 2022-11-02T16:37:20.787Z,1667407040.787 [SBIT](IMPORTANT): SBIT PASSED 2022-11-02T16:37:20.787Z,1667407040.787 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2022-11-02T16:37:20.788Z,1667407040.788 [SBIT](IMPORTANT): BackseatComponent.needs24v=1 bool; 2022-11-02T16:37:20.788Z,1667407040.788 [SBIT](IMPORTANT): BuoyancyServo.fastPumpCoefficient=6 none; 2022-11-02T16:37:20.788Z,1667407040.788 [SBIT](IMPORTANT): CBIT.gf24Offset=149 microampere; 2022-11-02T16:37:20.788Z,1667407040.788 [SBIT](IMPORTANT): CBIT.gfScanTimeout=2 hour; 2022-11-02T16:37:20.788Z,1667407040.788 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool; 2022-11-02T16:37:20.788Z,1667407040.788 [SBIT](IMPORTANT): DAT.surfaceThreshold=-1 meter; 2022-11-02T16:37:20.789Z,1667407040.789 [SBIT](IMPORTANT): Express none _.ayeris_disk_space; 2022-11-02T16:37:20.789Z,1667407040.789 [SBIT](IMPORTANT): Express linearApproximation _.ayeris_particle_counts 250.000000 count; 2022-11-02T16:37:20.789Z,1667407040.789 [SBIT](IMPORTANT): Express none _.ayeris_particle_size; 2022-11-02T16:37:20.789Z,1667407040.789 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=5 ampere_hour; 2022-11-02T16:37:20.789Z,1667407040.789 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=11 volt; 2022-11-02T16:37:20.789Z,1667407040.789 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=210.367112 cubic_centimeter; 2022-11-02T16:37:20.789Z,1667407040.789 [SBIT](IMPORTANT): VerticalControl.massDefault=22.333859 millimeter; 2022-11-02T16:37:21.179Z,1667407041.179 [MissionManager](IMPORTANT): Started mission Startup 2022-11-02T16:37:21.179Z,1667407041.179 [Startup] Running Loop=1 2022-11-02T16:37:21.179Z,1667407041.179 [Startup](DEBUG): Aggregate::initialize Startup 2022-11-02T16:37:21.179Z,1667407041.179 [Startup:A.GoToSurface] Running Loop=1 2022-11-02T16:37:21.180Z,1667407041.180 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-02T16:37:21.180Z,1667407041.180 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-02T16:37:21.201Z,1667407041.201 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-02T16:37:21.201Z,1667407041.201 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-02T16:37:21.202Z,1667407041.202 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-02T16:37:21.202Z,1667407041.202 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-02T16:37:21.212Z,1667407041.212 [Startup:StartupSatComms] Running Loop=1 2022-11-02T16:37:21.212Z,1667407041.212 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2022-11-02T16:37:21.212Z,1667407041.212 [Startup:StartupSatComms:A] Running Loop=1 2022-11-02T16:37:21.579Z,1667407041.579 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2022-11-02T16:37:37.029Z,1667407057.029 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2022-11-02T16:37:37.030Z,1667407057.030 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2022-11-02T16:37:37.031Z,1667407057.031 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2022-11-02T16:37:37.031Z,1667407057.031 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2022-11-02T16:37:37.094Z,1667407057.094 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2022-11-02T16:37:37.094Z,1667407057.094 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2022-11-02T16:37:37.527Z,1667407057.527 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2022-11-02T16:37:37.528Z,1667407057.528 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2022-11-02T16:37:37.528Z,1667407057.528 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2022-11-02T16:37:37.528Z,1667407057.528 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2022-11-02T16:37:37.756Z,1667407057.756 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2022-11-02T16:38:21.361Z,1667407101.361 [Startup:StartupSatComms:A](INFO): Timed out from 2022-11-02T16:37:21.2Z 2022-11-02T16:38:21.361Z,1667407101.361 [Startup:StartupSatComms:A] Stopped 2022-11-02T16:38:21.362Z,1667407101.362 [Startup:StartupSatComms:B] Running Loop=1 2022-11-02T16:38:21.755Z,1667407101.755 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2022-11-02T16:38:23.307Z,1667407103.307 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-02T16:38:23.308Z,1667407103.308 [DAT](INFO): setting remote address to 1 2022-11-02T16:38:23.562Z,1667407103.562 [DAT](INFO): set remote address to 1 2022-11-02T16:38:23.563Z,1667407103.563 [DAT](INFO): entering online mode 2022-11-02T16:38:23.815Z,1667407103.815 [DAT](INFO): commRate: 800 2022-11-02T16:38:23.815Z,1667407103.815 [DAT](INFO): online mode acknowledged 2022-11-02T16:38:23.816Z,1667407103.816 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-02T16:38:27.090Z,1667407107.090 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-02T16:38:29.762Z,1667407109.762 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20221102T160538/Courier0000.lzma 2022-11-02T16:38:30.763Z,1667407110.763 [DataOverHttps](INFO): Moved sent file to Logs/20221102T160538/Courier0000.lzma.bak 2022-11-02T16:38:30.763Z,1667407110.763 [DataOverHttps](INFO): SBD MOMSN=17269779 2022-11-02T16:38:37.177Z,1667407117.177 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-02T16:38:38.038Z,1667407118.038 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-02T16:38:38.040Z,1667407118.040 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-02T16:38:41.334Z,1667407121.334 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-02T16:38:46.557Z,1667407126.557 [DataOverHttps](INFO): Sending 284 bytes from file Logs/20221102T161009/Courier0000.lzma 2022-11-02T16:38:47.558Z,1667407127.558 [DataOverHttps](INFO): Moved sent file to Logs/20221102T161009/Courier0000.lzma.bak 2022-11-02T16:38:47.559Z,1667407127.559 [DataOverHttps](INFO): SBD MOMSN=17269782 2022-11-02T16:38:59.481Z,1667407139.481 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-02T16:39:01.009Z,1667407141.009 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-02T16:39:01.011Z,1667407141.011 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-02T16:39:03.865Z,1667407143.865 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20221102T161555/Courier0000.lzma 2022-11-02T16:39:04.286Z,1667407144.286 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-02T16:39:04.866Z,1667407144.866 [DataOverHttps](INFO): Moved sent file to Logs/20221102T161555/Courier0000.lzma.bak 2022-11-02T16:39:04.867Z,1667407144.867 [DataOverHttps](INFO): SBD MOMSN=17269788 2022-11-02T16:39:21.438Z,1667407161.438 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2022-11-02T16:39:21.627Z,1667407161.627 [Startup:StartupSatComms:B](INFO): Timed out from 2022-11-02T16:38:21.4Z 2022-11-02T16:39:21.627Z,1667407161.627 [Startup:StartupSatComms:B] Stopped 2022-11-02T16:39:21.627Z,1667407161.627 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2022-11-02T16:39:21.627Z,1667407161.627 [Startup:StartupSatComms] Stopped 2022-11-02T16:39:21.627Z,1667407161.627 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2022-11-02T16:39:21.628Z,1667407161.628 [Startup](INFO): Completed Startup 2022-11-02T16:39:21.677Z,1667407161.677 [MissionManager](INFO): Startup is completed. 2022-11-02T16:39:21.678Z,1667407161.678 [MissionManager](INFO): Uninitializing Mission Startup 2022-11-02T16:39:21.678Z,1667407161.678 [Startup] Stopped 2022-11-02T16:39:21.678Z,1667407161.678 [Startup](DEBUG): Aggregate::uninitialize Startup 2022-11-02T16:39:21.678Z,1667407161.678 [Startup:A.GoToSurface] Stopped 2022-11-02T16:39:21.678Z,1667407161.678 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2022-11-02T16:39:21.690Z,1667407161.690 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2022-11-02T16:39:21.945Z,1667407161.945 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2022-11-02T16:39:22.018Z,1667407162.018 [MissionManager](IMPORTANT): Started mission multiray_lab 2022-11-02T16:39:22.018Z,1667407162.018 [multiray_lab] Running Loop=1 2022-11-02T16:39:22.019Z,1667407162.019 [multiray_lab](DEBUG): Aggregate::initialize multiray_lab 2022-11-02T16:39:25.242Z,1667407165.242 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2022-11-02T16:39:25.832Z,1667407165.832 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20221102T161555/Courier0004.lzma 2022-11-02T16:39:26.735Z,1667407166.735 [DataOverHttps](INFO): Moved sent file to Logs/20221102T161555/Courier0004.lzma.bak 2022-11-02T16:39:26.735Z,1667407166.735 [DataOverHttps](INFO): SBD MOMSN=17269793 2022-11-02T16:39:27.255Z,1667407167.255 [multiray_lab](INFO): Timed out from 2022-11-02T16:39:22.0Z 2022-11-02T16:39:27.255Z,1667407167.255 [multiray_lab:A_Timeout] Running Loop=1 2022-11-02T16:39:27.255Z,1667407167.255 [multiray_lab:A_Timeout](DEBUG): Aggregate::initialize multiray_lab:A_Timeout 2022-11-02T16:39:27.256Z,1667407167.256 [multiray_lab:A_Timeout:A] Running Loop=1 2022-11-02T16:39:27.256Z,1667407167.256 [multiray_lab:A_Timeout:A] Stopped 2022-11-02T16:39:27.256Z,1667407167.256 [multiray_lab:A_Timeout](INFO): Completed multiray_lab:A_Timeout 2022-11-02T16:39:27.256Z,1667407167.256 [MissionManager](INFO): multiray_lab is completed. 2022-11-02T16:39:27.256Z,1667407167.256 [MissionManager](INFO): Uninitializing Mission multiray_lab 2022-11-02T16:39:27.256Z,1667407167.256 [multiray_lab] Stopped 2022-11-02T16:39:27.258Z,1667407167.258 [multiray_lab](DEBUG): Aggregate::uninitialize multiray_lab 2022-11-02T16:39:27.638Z,1667407167.638 [MultiRay](IMPORTANT): Turning on red lights 2022-11-02T16:39:27.651Z,1667407167.651 [MultiRay](DEBUG): Recieved MultiRay unrecognized response 2022-11-02T16:39:27.666Z,1667407167.666 [MultiRay](DEBUG): Recieved MultiRay unrecognized response 2022-11-02T16:39:27.667Z,1667407167.667 [MultiRay](INFO): Red lights on 2022-11-02T16:39:27.719Z,1667407167.719 [MissionManager](IMPORTANT): Started mission Default 2022-11-02T16:39:27.719Z,1667407167.719 [Default] Running Loop=1 2022-11-02T16:39:27.719Z,1667407167.719 [Default](DEBUG): Aggregate::initialize Default 2022-11-02T16:39:27.719Z,1667407167.719 [Default:B.GoToSurface] Running Loop=1 2022-11-02T16:39:27.719Z,1667407167.719 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2022-11-02T16:39:27.719Z,1667407167.719 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2022-11-02T16:39:27.720Z,1667407167.720 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2022-11-02T16:39:27.720Z,1667407167.720 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2022-11-02T16:39:27.720Z,1667407167.720 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2022-11-02T16:39:27.729Z,1667407167.729 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2022-11-02T16:39:27.729Z,1667407167.729 [Default:A.Wait] Running Loop=1 2022-11-02T16:39:27.729Z,1667407167.729 [Default:A.Wait](DEBUG): Initialize Wait Component. 2022-11-02T16:39:39.554Z,1667407179.554 [CommandExec](IMPORTANT): got command restart system 2022-11-02T16:39:41.002Z,1667407181.002 [Default:A.Wait](INFO): Done Waiting. 2022-11-02T16:39:41.002Z,1667407181.002 [Default:A.Wait] Stopped 2022-11-02T16:39:41.002Z,1667407181.002 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2022-11-02T16:39:41.493Z,1667407181.493 [Default:CheckIn] Running Loop=1 2022-11-02T16:39:41.493Z,1667407181.493 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2022-11-02T16:39:41.494Z,1667407181.494 [Default:CheckIn:Read_GPS] Running Loop=1 2022-11-02T16:39:41.653Z,1667407181.653 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2022-11-02T16:39:41.653Z,1667407181.653 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-02T16:39:41.653Z,1667407181.653 [CommandExec](INFO): Uninitializing the command executive. 2022-11-02T16:39:41.653Z,1667407181.653 [CommandExec](INFO): Uninitializing the command scheduler. 2022-11-02T16:39:41.654Z,1667407181.654 [CommandExec ThreadHandler](INFO): Thread cancelled. 2022-11-02T16:39:41.685Z,1667407181.685 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2022-11-02T16:39:41.685Z,1667407181.685 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2022-11-02T16:39:41.686Z,1667407181.686 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-02T16:39:41.686Z,1667407181.686 [NavChartDb](INFO): Join timeout helper Thread ID is 1119 2022-11-02T16:39:41.866Z,1667407181.866 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2022-11-02T16:39:42.089Z,1667407182.089 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-02T16:39:42.090Z,1667407182.090 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2022-11-02T16:39:42.109Z,1667407182.109 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2022-11-02T16:39:42.109Z,1667407182.109 [DAT ThreadHandler](INFO): Thread cancelled. 2022-11-02T16:39:42.109Z,1667407182.109 [DAT](INFO): Join timeout helper Thread ID is 1120 2022-11-02T16:39:42.129Z,1667407182.129 [DAT](INFO): Powering down 2022-11-02T16:39:42.130Z,1667407182.130 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2022-11-02T16:39:42.130Z,1667407182.130 [DAT](INFO): Powering down 2022-11-02T16:39:42.131Z,1667407182.131 [DAT ThreadHandler](INFO): Thread cancelled. 2022-11-02T16:39:42.132Z,1667407182.132 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2022-11-02T16:39:42.132Z,1667407182.132 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2022-11-02T16:39:42.132Z,1667407182.132 [Radio_Surface](INFO): Join timeout helper Thread ID is