2018-08-28T17:31:11.154Z,1535477471.154 [Supervisor](DEBUG): Initializing supervisor. 2018-08-28T17:31:11.157Z,1535477471.157 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2018-08-28T17:31:11.157Z,1535477471.157 [SyncHandler](INFO): Protected caller Thread ID is 953 2018-08-28T17:31:11.158Z,1535477471.158 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2018-08-28T17:31:11.159Z,1535477471.159 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2018-08-28T17:31:11.159Z,1535477471.159 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 954 2018-08-28T17:31:11.163Z,1535477471.163 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2018-08-28T17:31:11.174Z,1535477471.174 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2018-08-28T17:31:11.175Z,1535477471.175 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2018-08-28T17:31:11.176Z,1535477471.176 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 955 2018-08-28T17:31:11.177Z,1535477471.177 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2018-08-28T17:31:11.178Z,1535477471.178 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2018-08-28T17:31:11.178Z,1535477471.178 [logger ThreadHandler](INFO): Protected caller Thread ID is 956 2018-08-28T17:31:11.180Z,1535477471.180 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2018-08-28T17:31:11.180Z,1535477471.180 [Supervisor](INFO): Looking for Config files in directory: Config/ 2018-08-28T17:31:11.182Z,1535477471.182 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2018-08-28T17:31:11.280Z,1535477471.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2018-08-28T17:31:11.281Z,1535477471.281 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2018-08-28T17:31:11.383Z,1535477471.383 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2018-08-28T17:31:11.384Z,1535477471.384 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2018-08-28T17:31:11.592Z,1535477471.592 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2018-08-28T17:31:11.593Z,1535477471.593 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2018-08-28T17:31:11.927Z,1535477471.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2018-08-28T17:31:11.928Z,1535477471.928 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2018-08-28T17:31:12.277Z,1535477472.277 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2018-08-28T17:31:12.277Z,1535477472.277 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2018-08-28T17:31:12.750Z,1535477472.750 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2018-08-28T17:31:12.751Z,1535477472.751 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2018-08-28T17:31:13.186Z,1535477473.186 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2018-08-28T17:31:13.186Z,1535477473.186 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2018-08-28T17:31:13.671Z,1535477473.671 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2018-08-28T17:31:13.671Z,1535477473.671 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2018-08-28T17:31:13.753Z,1535477473.753 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2018-08-28T17:31:14.071Z,1535477474.071 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2018-08-28T17:31:14.072Z,1535477474.072 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2018-08-28T17:31:14.220Z,1535477474.220 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2018-08-28T17:31:14.221Z,1535477474.221 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2018-08-28T17:31:14.435Z,1535477474.435 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2018-08-28T17:31:14.436Z,1535477474.436 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2018-08-28T17:31:14.653Z,1535477474.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2018-08-28T17:31:14.654Z,1535477474.654 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2018-08-28T17:31:14.753Z,1535477474.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2018-08-28T17:31:14.754Z,1535477474.754 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2018-08-28T17:31:14.898Z,1535477474.898 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2018-08-28T17:31:14.900Z,1535477474.900 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2018-08-28T17:31:14.901Z,1535477474.901 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2018-08-28T17:31:15.136Z,1535477475.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2018-08-28T17:31:15.136Z,1535477475.136 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2018-08-28T17:31:15.243Z,1535477475.243 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2018-08-28T17:31:15.399Z,1535477475.399 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2018-08-28T17:31:15.631Z,1535477475.631 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2018-08-28T17:31:15.824Z,1535477475.824 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2018-08-28T17:31:15.975Z,1535477475.975 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2018-08-28T17:31:16.159Z,1535477476.159 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2018-08-28T17:31:16.258Z,1535477476.258 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2018-08-28T17:31:16.354Z,1535477476.354 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2018-08-28T17:31:16.452Z,1535477476.452 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2018-08-28T17:31:16.537Z,1535477476.537 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2018-08-28T17:31:16.537Z,1535477476.537 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2018-08-28T17:31:16.550Z,1535477476.550 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2018-08-28T17:31:16.647Z,1535477476.647 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2018-08-28T17:31:16.648Z,1535477476.648 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2018-08-28T17:31:16.661Z,1535477476.661 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2018-08-28T17:31:16.661Z,1535477476.661 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2018-08-28T17:31:16.702Z,1535477476.702 [DepthRateCalculator] Loaded 2018-08-28T17:31:16.702Z,1535477476.702 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2018-08-28T17:31:16.708Z,1535477476.708 [PitchRateCalculator] Loaded 2018-08-28T17:31:16.708Z,1535477476.708 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2018-08-28T17:31:16.724Z,1535477476.724 [SpeedCalculator] Loaded 2018-08-28T17:31:16.724Z,1535477476.724 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2018-08-28T17:31:16.745Z,1535477476.745 [TempGradientCalculator] Loaded 2018-08-28T17:31:16.746Z,1535477476.746 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2018-08-28T17:31:16.761Z,1535477476.761 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2018-08-28T17:31:16.761Z,1535477476.761 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2018-08-28T17:31:16.767Z,1535477476.767 [YawRateCalculator] Loaded 2018-08-28T17:31:16.767Z,1535477476.767 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2018-08-28T17:31:16.807Z,1535477476.807 [ElevatorOffsetCalculator] Loaded 2018-08-28T17:31:16.807Z,1535477476.807 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2018-08-28T17:31:16.807Z,1535477476.807 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2018-08-28T17:31:16.808Z,1535477476.808 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2018-08-28T17:31:16.832Z,1535477476.832 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2018-08-28T17:31:16.833Z,1535477476.833 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2018-08-28T17:31:17.111Z,1535477477.111 [DataOverHttps] Loaded 2018-08-28T17:31:17.111Z,1535477477.111 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2018-08-28T17:31:17.136Z,1535477477.136 [Depth_Keller] Loaded 2018-08-28T17:31:17.136Z,1535477477.136 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2018-08-28T17:31:17.141Z,1535477477.141 [DropWeight] Loaded 2018-08-28T17:31:17.141Z,1535477477.141 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2018-08-28T17:31:17.240Z,1535477477.240 [NAL9602] Loaded 2018-08-28T17:31:17.240Z,1535477477.240 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2018-08-28T17:31:17.256Z,1535477477.256 [Onboard] Loaded 2018-08-28T17:31:17.256Z,1535477477.256 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2018-08-28T17:31:17.266Z,1535477477.266 [Radio_Surface] Loaded 2018-08-28T17:31:17.267Z,1535477477.267 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2018-08-28T17:31:17.268Z,1535477477.268 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407B84E0 2018-08-28T17:31:17.268Z,1535477477.268 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1035 2018-08-28T17:31:17.315Z,1535477477.315 [PNI_TCM] Loaded 2018-08-28T17:31:17.316Z,1535477477.316 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2018-08-28T17:31:19.070Z,1535477479.070 [BPC1] Loaded 2018-08-28T17:31:19.070Z,1535477479.070 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2018-08-28T17:31:19.070Z,1535477479.070 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2018-08-28T17:31:19.071Z,1535477479.071 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2018-08-28T17:31:19.200Z,1535477479.200 [SBIT](DEBUG): Construct Startup Built In Test. 2018-08-28T17:31:19.222Z,1535477479.222 [SBIT] Loaded 2018-08-28T17:31:19.223Z,1535477479.223 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2018-08-28T17:31:19.223Z,1535477479.223 [IBIT](DEBUG): Construct Initiated Built In Test. 2018-08-28T17:31:19.235Z,1535477479.235 [IBIT] Loaded 2018-08-28T17:31:19.235Z,1535477479.235 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2018-08-28T17:31:19.238Z,1535477479.238 [CBIT](DEBUG): Construct Continuous Built In Test. 2018-08-28T17:31:19.387Z,1535477479.387 [CBIT] Loaded 2018-08-28T17:31:19.388Z,1535477479.388 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2018-08-28T17:31:19.388Z,1535477479.388 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2018-08-28T17:31:19.389Z,1535477479.389 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2018-08-28T17:31:19.529Z,1535477479.529 [Aanderaa_O2] Loaded 2018-08-28T17:31:19.529Z,1535477479.529 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2018-08-28T17:31:19.582Z,1535477479.582 [CTD_Seabird] Loaded 2018-08-28T17:31:19.582Z,1535477479.582 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2018-08-28T17:31:19.583Z,1535477479.583 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4087C4E0 2018-08-28T17:31:19.583Z,1535477479.583 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1036 2018-08-28T17:31:19.601Z,1535477479.601 [ESPComponent] Loaded 2018-08-28T17:31:19.601Z,1535477479.601 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2018-08-28T17:31:19.615Z,1535477479.615 [PAR_Licor] Loaded 2018-08-28T17:31:19.616Z,1535477479.616 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2018-08-28T17:31:19.664Z,1535477479.664 [WetLabsBB2FL] Loaded 2018-08-28T17:31:19.664Z,1535477479.664 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2018-08-28T17:31:19.665Z,1535477479.665 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 408AC4E0 2018-08-28T17:31:19.666Z,1535477479.666 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1037 2018-08-28T17:31:19.666Z,1535477479.666 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2018-08-28T17:31:19.667Z,1535477479.667 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2018-08-28T17:31:19.900Z,1535477479.900 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2018-08-28T17:31:19.901Z,1535477479.901 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2018-08-28T17:31:19.968Z,1535477479.968 [VerticalControl](DEBUG): Construct VerticalControl. 2018-08-28T17:31:20.062Z,1535477480.062 [VerticalControl] Loaded 2018-08-28T17:31:20.062Z,1535477480.062 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2018-08-28T17:31:20.063Z,1535477480.063 [HorizontalControl](DEBUG): Construct HorizontalControl. 2018-08-28T17:31:20.123Z,1535477480.123 [HorizontalControl] Loaded 2018-08-28T17:31:20.123Z,1535477480.123 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2018-08-28T17:31:20.124Z,1535477480.124 [SpeedControl](DEBUG): Construct SpeedControl. 2018-08-28T17:31:20.129Z,1535477480.129 [SpeedControl] Loaded 2018-08-28T17:31:20.130Z,1535477480.130 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2018-08-28T17:31:20.130Z,1535477480.130 [LoopControl](DEBUG): Construct LoopControl. 2018-08-28T17:31:20.131Z,1535477480.131 [LoopControl] Loaded 2018-08-28T17:31:20.131Z,1535477480.131 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2018-08-28T17:31:20.131Z,1535477480.131 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2018-08-28T17:31:20.132Z,1535477480.132 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2018-08-28T17:31:20.213Z,1535477480.213 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2018-08-28T17:31:20.213Z,1535477480.213 [StratificationFrontDetector](DEBUG): (re)initializing 2018-08-28T17:31:20.214Z,1535477480.214 [StratificationFrontDetector] Loaded 2018-08-28T17:31:20.214Z,1535477480.214 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2018-08-28T17:31:20.215Z,1535477480.215 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2018-08-28T17:31:20.215Z,1535477480.215 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2018-08-28T17:31:20.312Z,1535477480.312 [BuoyancyServo] Loaded 2018-08-28T17:31:20.312Z,1535477480.312 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2018-08-28T17:31:20.323Z,1535477480.323 [ElevatorServo] Loaded 2018-08-28T17:31:20.324Z,1535477480.324 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2018-08-28T17:31:20.334Z,1535477480.334 [MassServo] Loaded 2018-08-28T17:31:20.335Z,1535477480.335 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2018-08-28T17:31:20.346Z,1535477480.346 [RudderServo] Loaded 2018-08-28T17:31:20.346Z,1535477480.346 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2018-08-28T17:31:20.357Z,1535477480.357 [ThrusterServo] Loaded 2018-08-28T17:31:20.358Z,1535477480.358 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2018-08-28T17:31:20.358Z,1535477480.358 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2018-08-28T17:31:20.359Z,1535477480.359 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2018-08-28T17:31:20.448Z,1535477480.448 [DeadReckonUsingSpeedCalculator] Loaded 2018-08-28T17:31:20.448Z,1535477480.448 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2018-08-28T17:31:20.453Z,1535477480.453 [UniversalFixResidualReporter] Loaded 2018-08-28T17:31:20.453Z,1535477480.453 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2018-08-28T17:31:20.453Z,1535477480.453 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2018-08-28T17:31:20.482Z,1535477480.482 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2018-08-28T17:31:20.483Z,1535477480.483 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2018-08-28T17:31:20.499Z,1535477480.499 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2018-08-28T17:31:20.529Z,1535477480.529 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A054E0 2018-08-28T17:31:20.529Z,1535477480.529 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1038 2018-08-28T17:31:20.534Z,1535477480.534 [Supervisor](INFO): Main Thread ID is 796 2018-08-28T17:31:20.534Z,1535477480.534 [Supervisor](DEBUG): Running supervisor. 2018-08-28T17:31:20.535Z,1535477480.535 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1039 2018-08-28T17:31:20.543Z,1535477480.543 [controlThread ThreadHandler](INFO): Handler Thread ID is 1040 2018-08-28T17:31:20.543Z,1535477480.543 [controlThread](DEBUG): Initializing ControlThread 2018-08-28T17:31:20.544Z,1535477480.544 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-08-28T17:31:20.544Z,1535477480.544 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2018-08-28T17:31:20.545Z,1535477480.545 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2018-08-28T17:31:20.545Z,1535477480.545 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2018-08-28T17:31:20.546Z,1535477480.546 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2018-08-28T17:31:20.547Z,1535477480.547 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2018-08-28T17:31:20.547Z,1535477480.547 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2018-08-28T17:31:20.552Z,1535477480.552 [SBIT](INFO): Initialize SBIT Component. 2018-08-28T17:31:20.552Z,1535477480.552 [SBIT](IMPORTANT): git: 2018-08-28 2018-08-28T17:31:20.552Z,1535477480.552 [SBIT](INFO): git hash: d6107db9677002c22763a174f01a68f0b5afcf19 2018-08-28T17:31:20.553Z,1535477480.553 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2018-08-28T17:31:20.554Z,1535477480.554 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 2018-08-28T17:31:20.555Z,1535477480.555 [SBIT](INFO): Beginning SBIT in 68.000000 seconds. 2018-08-28T17:31:20.556Z,1535477480.556 [IBIT](INFO): Initialize IBIT Component. 2018-08-28T17:31:20.557Z,1535477480.557 [CBIT](DEBUG): Initialize CBIT Component. 2018-08-28T17:31:20.557Z,1535477480.557 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2018-08-28T17:31:20.558Z,1535477480.558 [logger ThreadHandler](INFO): Handler Thread ID is 1041 2018-08-28T17:31:20.573Z,1535477480.573 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1042 2018-08-28T17:31:20.580Z,1535477480.580 [Radio_Surface](INFO): Powering up 2018-08-28T17:31:20.585Z,1535477480.585 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1043 2018-08-28T17:31:20.586Z,1535477480.586 [CTD_Seabird](INFO): Initializing 2018-08-28T17:31:20.586Z,1535477480.586 [CTD_Seabird](INFO): Checking LCM 2018-08-28T17:31:20.595Z,1535477480.595 [CTD_Seabird](INFO): LCM OK 2018-08-28T17:31:20.595Z,1535477480.595 [CTD_Seabird](INFO): Powering up 2018-08-28T17:31:20.597Z,1535477480.597 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1045 2018-08-28T17:31:20.600Z,1535477480.600 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI11M.000 2018-08-28T17:31:20.600Z,1535477480.600 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI11M.000 2018-08-28T17:31:20.600Z,1535477480.600 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5MI07M.000 2018-08-28T17:31:20.600Z,1535477480.600 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5MI07M.000 2018-08-28T17:31:20.601Z,1535477480.601 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH07M.000 2018-08-28T17:31:20.601Z,1535477480.601 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH07M.000 2018-08-28T17:31:20.602Z,1535477480.602 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5OH31M.000 2018-08-28T17:31:20.602Z,1535477480.602 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5OH31M.000 2018-08-28T17:31:20.652Z,1535477480.652 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1044 2018-08-28T17:31:20.654Z,1535477480.654 [WetLabsBB2FL](INFO): Powering down 2018-08-28T17:31:20.669Z,1535477480.669 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2018-08-28T17:31:20.671Z,1535477480.671 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2018-08-28T17:31:20.672Z,1535477480.672 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2018-08-28T17:31:20.672Z,1535477480.672 [LoopControl](DEBUG): Initialize LoopControlComponent. 2018-08-28T17:31:20.674Z,1535477480.674 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-08-28T17:31:20.675Z,1535477480.675 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-08-28T17:31:20.675Z,1535477480.675 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-08-28T17:31:20.676Z,1535477480.676 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2018-08-28T17:31:20.677Z,1535477480.677 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2018-08-28T17:31:20.692Z,1535477480.692 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2018-08-28T17:31:20.732Z,1535477480.732 [MissionManager](DEBUG): 2018-08-28T17:31:20.749Z,1535477480.749 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2018-08-28T17:31:20.820Z,1535477480.820 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2018-08-28T17:31:20.834Z,1535477480.834 [Default:A.Wait](DEBUG): Construct Wait. 2018-08-28T17:31:20.835Z,1535477480.835 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2018-08-28T17:31:20.855Z,1535477480.855 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2018-08-28T17:31:20.881Z,1535477480.881 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2018-08-28T17:31:20.887Z,1535477480.887 [Default:E.Execute](DEBUG): Construct Execute. 2018-08-28T17:31:20.907Z,1535477480.907 [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 2018-08-28T17:31:20.912Z,1535477480.912 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-08-28T17:31:20.945Z,1535477480.945 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2018-08-28T17:31:20.958Z,1535477480.958 [Depth_Keller](ERROR): Pressure reading out of range: 1895.684326 decibar 2018-08-28T17:31:21.229Z,1535477481.229 [ESPComponent](INFO): powering down ESP 2018-08-28T17:31:21.641Z,1535477481.641 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-08-28T17:31:21.749Z,1535477481.749 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-28T17:31:21.860Z,1535477481.860 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-08-28T17:31:21.869Z,1535477481.869 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-08-28T17:31:21.891Z,1535477481.891 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-08-28T17:31:21.897Z,1535477481.897 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-08-28T17:31:21.911Z,1535477481.911 [MassServo](DEBUG): Initializing EZServoServo. 2018-08-28T17:31:21.917Z,1535477481.917 [MassServo](DEBUG): Initializing MassServo. 2018-08-28T17:31:21.934Z,1535477481.934 [RudderServo](DEBUG): Initializing EZServoServo. 2018-08-28T17:31:21.941Z,1535477481.941 [RudderServo](DEBUG): Initializing RudderServo. 2018-08-28T17:31:21.963Z,1535477481.963 [ThrusterServo](DEBUG): Initializing EZServoServo. 2018-08-28T17:31:21.969Z,1535477481.969 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2018-08-28T17:31:22.278Z,1535477482.278 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-28T17:31:22.526Z,1535477482.526 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-28T17:31:23.041Z,1535477483.041 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-28T17:31:23.433Z,1535477483.433 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-28T17:31:23.814Z,1535477483.814 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-28T17:31:24.217Z,1535477484.217 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-28T17:31:24.697Z,1535477484.697 [Aanderaa_O2](INFO): Powering down 2018-08-28T17:31:24.760Z,1535477484.760 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-28T17:31:26.099Z,1535477486.099 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-08-28T17:31:26.212Z,1535477486.212 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null & 2018-08-28T17:31:26.276Z,1535477486.276 [CTD_Seabird](INFO): LCM subscribed to channel:seabird_gpctd_t.seabird-gpctd 2018-08-28T17:31:26.706Z,1535477486.706 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-08-28T17:31:26.707Z,1535477486.707 [CTD_Seabird](INFO): Powering down 2018-08-28T17:31:47.543Z,1535477507.543 [NAL9602](INFO): Powering up NAL9602 2018-08-28T17:31:58.346Z,1535477518.346 [NAL9602](INFO): NAL9602 initialized 2018-08-28T17:32:04.344Z,1535477524.344 [NAL9602](INFO): SBD MO Status=0, MOMSN=24176, MT Status=0, MTMSN=0 2018-08-28T17:32:04.344Z,1535477524.344 [NAL9602](INFO): No messages in MT queue 2018-08-28T17:32:09.107Z,1535477529.107 [CommandLine](IMPORTANT): got command configSet Rowe_600LCM.loadAtStartup 0.000000 bool 2018-08-28T17:32:09.107Z,1535477529.107 [CommandLine](FAULT): configSet Rowe_600LCM.loadAtStartup without persist will have no effect. 2018-08-28T17:32:29.200Z,1535477549.200 [SBIT](IMPORTANT): Beginning Startup BIT 2018-08-28T17:32:29.220Z,1535477549.220 [CBIT](IMPORTANT): Beginning ground fault scan 2018-08-28T17:32:40.163Z,1535477560.163 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.007150 CHAN A1 (24V): -0.010975 CHAN A2 (12V): -0.005101 CHAN A3 (5V): -0.002407 CHAN B0 (3.3V): -0.000945 CHAN B1 (3.15aV): -0.000811 CHAN B2 (3.15bV): -0.001320 CHAN B3 (GND): 0.000034 OPEN: 0.004750 Full Scale Calc: 4.765 mA, -1.589 mA 2018-08-28T17:33:23.243Z,1535477603.243 [SBIT](IMPORTANT): SBIT PASSED 2018-08-28T17:33:23.326Z,1535477603.326 [CommandLine](IMPORTANT): got command configSet list 2018-08-28T17:33:23.326Z,1535477603.326 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2018-08-28T17:33:23.327Z,1535477603.327 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.loadAtStartup=0 bool; 2018-08-28T17:33:23.327Z,1535477603.327 [CommandLine](IMPORTANT): CTD_Seabird.minSalinityBound=0.01 practical_salinity_unit; 2018-08-28T17:33:23.327Z,1535477603.327 [CommandLine](IMPORTANT): Depth_Keller.offset=-0.56 decibar; 2018-08-28T17:33:23.327Z,1535477603.327 [CommandLine](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_salinity 0.000500 practical_salinity_unit; 2018-08-28T17:33:23.327Z,1535477603.327 [CommandLine](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.005000 kelvin; 2018-08-28T17:33:23.327Z,1535477603.327 [CommandLine](IMPORTANT): Express linearApproximation WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 0.100000 microgram_per_liter; 2018-08-28T17:33:23.328Z,1535477603.328 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 2.000000 meter; 2018-08-28T17:33:23.328Z,1535477603.328 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_chlorophyll_in_sea_water 1.000000 microgram_per_liter; 2018-08-28T17:33:23.328Z,1535477603.328 [CommandLine](IMPORTANT): IBIT.batteryHibernationTimeout=1 minute; 2018-08-28T17:33:23.328Z,1535477603.328 [CommandLine](IMPORTANT): IBIT.batteryMissingStickThreshold=18 count; 2018-08-28T17:33:23.328Z,1535477603.328 [CommandLine](IMPORTANT): NavChart.loadAtStartup=0 bool; 2018-08-28T17:33:23.328Z,1535477603.328 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=0 bool; 2018-08-28T17:33:23.328Z,1535477603.328 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=539 cubic_centimeter; 2018-08-28T17:33:23.329Z,1535477603.329 [CommandLine](IMPORTANT): VerticalControl.massDefault=-12 millimeter; 2018-08-28T17:33:23.663Z,1535477603.663 [MissionManager](IMPORTANT): Started mission Startup 2018-08-28T17:33:23.663Z,1535477603.663 [Startup] Running Loop=1 2018-08-28T17:33:23.663Z,1535477603.663 [Startup](DEBUG): Aggregate::initialize Startup 2018-08-28T17:33:23.663Z,1535477603.663 [Startup:A.GoToSurface] Running Loop=1 2018-08-28T17:33:23.663Z,1535477603.663 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-08-28T17:33:23.664Z,1535477603.664 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-08-28T17:33:23.693Z,1535477603.693 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-08-28T17:33:23.693Z,1535477603.693 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-08-28T17:33:23.694Z,1535477603.694 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-08-28T17:33:23.694Z,1535477603.694 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-08-28T17:33:23.700Z,1535477603.700 [Startup:StartupSatComms] Running Loop=1 2018-08-28T17:33:23.701Z,1535477603.701 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2018-08-28T17:33:23.701Z,1535477603.701 [Startup:StartupSatComms:A] Running Loop=1 2018-08-28T17:33:24.053Z,1535477604.053 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2018-08-28T17:34:20.833Z,1535477660.833 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-08-28T17:34:20.833Z,1535477660.833 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2018-08-28T17:34:20.834Z,1535477660.834 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-08-28T17:34:20.858Z,1535477660.858 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-08-28T17:34:21.244Z,1535477661.244 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-08-28T17:34:21.244Z,1535477661.244 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2018-08-28T17:34:21.641Z,1535477661.641 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-08-28T17:34:21.641Z,1535477661.641 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-08-28T17:34:21.642Z,1535477661.642 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-08-28T17:34:24.034Z,1535477664.034 [Startup:StartupSatComms:A](INFO): Timed out from 2018-08-28T17:33:23.7Z 2018-08-28T17:34:24.034Z,1535477664.034 [Startup:StartupSatComms:A] Stopped 2018-08-28T17:34:24.034Z,1535477664.034 [Startup:StartupSatComms:B] Running Loop=1 2018-08-28T17:34:24.446Z,1535477664.446 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-08-28T17:34:51.144Z,1535477691.144 [NAL9602](INFO): SBD MO Status=2, MOMSN=24177, MT Status=2, MTMSN=0 2018-08-28T17:34:51.144Z,1535477691.144 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-08-28T17:35:18.856Z,1535477718.856 [NAL9602](INFO): SBD MO Status=2, MOMSN=24177, MT Status=2, MTMSN=0 2018-08-28T17:35:18.856Z,1535477718.856 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-08-28T17:35:26.447Z,1535477726.447 [Startup:StartupSatComms:B](INFO): Timed out from 2018-08-28T17:34:24.0Z 2018-08-28T17:35:26.448Z,1535477726.448 [Startup:StartupSatComms:B] Stopped 2018-08-28T17:35:26.448Z,1535477726.448 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2018-08-28T17:35:26.448Z,1535477726.448 [Startup:StartupSatComms] Stopped 2018-08-28T17:35:26.448Z,1535477726.448 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2018-08-28T17:35:26.466Z,1535477726.466 [Startup](INFO): Completed Startup 2018-08-28T17:35:26.466Z,1535477726.466 [MissionManager](INFO): Startup is completed. 2018-08-28T17:35:26.466Z,1535477726.466 [MissionManager](INFO): Uninitializing Mission Startup 2018-08-28T17:35:26.466Z,1535477726.466 [Startup] Stopped 2018-08-28T17:35:26.466Z,1535477726.466 [Startup](DEBUG): Aggregate::uninitialize Startup 2018-08-28T17:35:26.467Z,1535477726.467 [Startup:A.GoToSurface] Stopped 2018-08-28T17:35:26.467Z,1535477726.467 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-08-28T17:35:27.303Z,1535477727.303 [MissionManager](IMPORTANT): Started mission Default 2018-08-28T17:35:27.304Z,1535477727.304 [Default] Running Loop=1 2018-08-28T17:35:27.304Z,1535477727.304 [Default](DEBUG): Aggregate::initialize Default 2018-08-28T17:35:27.304Z,1535477727.304 [Default:B.GoToSurface] Running Loop=1 2018-08-28T17:35:27.304Z,1535477727.304 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-08-28T17:35:27.304Z,1535477727.304 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-08-28T17:35:27.305Z,1535477727.305 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-08-28T17:35:27.305Z,1535477727.305 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-08-28T17:35:27.305Z,1535477727.305 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-08-28T17:35:27.306Z,1535477727.306 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-08-28T17:35:27.306Z,1535477727.306 [Default:A.Wait] Running Loop=1 2018-08-28T17:35:27.306Z,1535477727.306 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-08-28T17:35:27.745Z,1535477727.745 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.006591 2018-08-28T17:35:40.595Z,1535477740.595 [Default:A.Wait](INFO): Done Waiting. 2018-08-28T17:35:40.596Z,1535477740.596 [Default:A.Wait]