2018-08-01T17:54:33.662Z,1533146073.662 [Supervisor](DEBUG): Initializing supervisor. 2018-08-01T17:54:33.664Z,1533146073.664 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2018-08-01T17:54:33.665Z,1533146073.665 [SyncHandler](INFO): Protected caller Thread ID is 2667 2018-08-01T17:54:33.665Z,1533146073.665 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2018-08-01T17:54:33.666Z,1533146073.666 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2018-08-01T17:54:33.667Z,1533146073.667 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2668 2018-08-01T17:54:33.669Z,1533146073.669 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2018-08-01T17:54:33.681Z,1533146073.681 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2018-08-01T17:54:33.682Z,1533146073.682 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2018-08-01T17:54:33.683Z,1533146073.683 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2669 2018-08-01T17:54:33.684Z,1533146073.684 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2018-08-01T17:54:33.685Z,1533146073.685 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2018-08-01T17:54:33.685Z,1533146073.685 [logger ThreadHandler](INFO): Protected caller Thread ID is 2670 2018-08-01T17:54:33.687Z,1533146073.687 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2018-08-01T17:54:33.687Z,1533146073.687 [Supervisor](INFO): Looking for Config files in directory: Config/ 2018-08-01T17:54:33.689Z,1533146073.689 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2018-08-01T17:54:33.890Z,1533146073.890 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2018-08-01T17:54:33.891Z,1533146073.891 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2018-08-01T17:54:34.036Z,1533146074.036 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2018-08-01T17:54:34.036Z,1533146074.036 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2018-08-01T17:54:34.395Z,1533146074.395 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2018-08-01T17:54:34.396Z,1533146074.396 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2018-08-01T17:54:34.536Z,1533146074.536 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2018-08-01T17:54:34.537Z,1533146074.537 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2018-08-01T17:54:34.617Z,1533146074.617 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2018-08-01T17:54:34.826Z,1533146074.826 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2018-08-01T17:54:34.827Z,1533146074.827 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2018-08-01T17:54:34.926Z,1533146074.926 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2018-08-01T17:54:34.926Z,1533146074.926 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2018-08-01T17:54:35.283Z,1533146075.283 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2018-08-01T17:54:35.283Z,1533146075.283 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2018-08-01T17:54:35.743Z,1533146075.743 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2018-08-01T17:54:35.744Z,1533146075.744 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2018-08-01T17:54:36.136Z,1533146076.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2018-08-01T17:54:36.136Z,1533146076.136 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2018-08-01T17:54:36.662Z,1533146076.662 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2018-08-01T17:54:36.662Z,1533146076.662 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2018-08-01T17:54:36.874Z,1533146076.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2018-08-01T17:54:36.874Z,1533146076.874 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2018-08-01T17:54:36.973Z,1533146076.973 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2018-08-01T17:54:36.973Z,1533146076.973 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2018-08-01T17:54:37.477Z,1533146077.477 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2018-08-01T17:54:37.478Z,1533146077.478 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2018-08-01T17:54:37.586Z,1533146077.586 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2018-08-01T17:54:37.588Z,1533146077.588 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/ 2018-08-01T17:54:37.588Z,1533146077.588 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg 2018-08-01T17:54:37.828Z,1533146077.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2018-08-01T17:54:37.829Z,1533146077.829 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg 2018-08-01T17:54:37.928Z,1533146077.928 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg 2018-08-01T17:54:38.022Z,1533146078.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg 2018-08-01T17:54:38.125Z,1533146078.125 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg 2018-08-01T17:54:38.210Z,1533146078.210 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg 2018-08-01T17:54:38.346Z,1533146078.346 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg 2018-08-01T17:54:38.541Z,1533146078.541 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg 2018-08-01T17:54:38.670Z,1533146078.670 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg 2018-08-01T17:54:38.754Z,1533146078.754 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg 2018-08-01T17:54:38.838Z,1533146078.838 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg 2018-08-01T17:54:39.030Z,1533146079.030 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/root/ 2018-08-01T17:54:39.031Z,1533146079.031 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2018-08-01T17:54:39.036Z,1533146079.036 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2018-08-01T17:54:39.215Z,1533146079.215 [SBIT](DEBUG): Construct Startup Built In Test. 2018-08-01T17:54:39.247Z,1533146079.247 [SBIT] Loaded 2018-08-01T17:54:39.247Z,1533146079.247 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2018-08-01T17:54:39.248Z,1533146079.248 [IBIT](DEBUG): Construct Initiated Built In Test. 2018-08-01T17:54:39.277Z,1533146079.277 [IBIT] Loaded 2018-08-01T17:54:39.277Z,1533146079.277 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2018-08-01T17:54:39.280Z,1533146079.280 [CBIT](DEBUG): Construct Continuous Built In Test. 2018-08-01T17:54:39.499Z,1533146079.499 [CBIT] Loaded 2018-08-01T17:54:39.499Z,1533146079.499 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2018-08-01T17:54:39.500Z,1533146079.500 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2018-08-01T17:54:39.500Z,1533146079.500 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2018-08-01T17:54:39.573Z,1533146079.573 [VerticalControl](DEBUG): Construct VerticalControl. 2018-08-01T17:54:39.679Z,1533146079.679 [VerticalControl] Loaded 2018-08-01T17:54:39.679Z,1533146079.679 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2018-08-01T17:54:39.680Z,1533146079.680 [HorizontalControl](DEBUG): Construct HorizontalControl. 2018-08-01T17:54:39.746Z,1533146079.746 [HorizontalControl] Loaded 2018-08-01T17:54:39.746Z,1533146079.746 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2018-08-01T17:54:39.746Z,1533146079.746 [SpeedControl](DEBUG): Construct SpeedControl. 2018-08-01T17:54:39.752Z,1533146079.752 [SpeedControl] Loaded 2018-08-01T17:54:39.753Z,1533146079.753 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2018-08-01T17:54:39.753Z,1533146079.753 [LoopControl](DEBUG): Construct LoopControl. 2018-08-01T17:54:39.754Z,1533146079.754 [LoopControl] Loaded 2018-08-01T17:54:39.754Z,1533146079.754 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2018-08-01T17:54:39.755Z,1533146079.755 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2018-08-01T17:54:39.755Z,1533146079.755 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2018-08-01T17:54:39.799Z,1533146079.799 [DepthRateCalculator] Loaded 2018-08-01T17:54:39.799Z,1533146079.799 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2018-08-01T17:54:39.805Z,1533146079.805 [PitchRateCalculator] Loaded 2018-08-01T17:54:39.805Z,1533146079.805 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2018-08-01T17:54:39.822Z,1533146079.822 [SpeedCalculator] Loaded 2018-08-01T17:54:39.822Z,1533146079.822 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2018-08-01T17:54:39.845Z,1533146079.845 [TempGradientCalculator] Loaded 2018-08-01T17:54:39.846Z,1533146079.846 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2018-08-01T17:54:39.862Z,1533146079.862 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2018-08-01T17:54:39.862Z,1533146079.862 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2018-08-01T17:54:39.868Z,1533146079.868 [YawRateCalculator] Loaded 2018-08-01T17:54:39.868Z,1533146079.868 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2018-08-01T17:54:39.900Z,1533146079.900 [ElevatorOffsetCalculator] Loaded 2018-08-01T17:54:39.900Z,1533146079.900 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2018-08-01T17:54:39.900Z,1533146079.900 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2018-08-01T17:54:39.901Z,1533146079.901 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2018-08-01T17:54:39.989Z,1533146079.989 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2018-08-01T17:54:39.989Z,1533146079.989 [StratificationFrontDetector](DEBUG): (re)initializing 2018-08-01T17:54:39.989Z,1533146079.989 [StratificationFrontDetector] Loaded 2018-08-01T17:54:39.990Z,1533146079.990 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2018-08-01T17:54:39.990Z,1533146079.990 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2018-08-01T17:54:39.991Z,1533146079.991 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2018-08-01T17:54:40.246Z,1533146080.246 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2018-08-01T17:54:40.247Z,1533146080.247 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2018-08-01T17:54:40.349Z,1533146080.349 [DeadReckonUsingMultipleVelocitySources] Loaded 2018-08-01T17:54:40.349Z,1533146080.349 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2018-08-01T17:54:40.407Z,1533146080.407 [DeadReckonUsingSpeedCalculator] Loaded 2018-08-01T17:54:40.407Z,1533146080.407 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2018-08-01T17:54:40.425Z,1533146080.425 [NavChart] Loaded 2018-08-01T17:54:40.426Z,1533146080.426 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2018-08-01T17:54:40.430Z,1533146080.430 [UniversalFixResidualReporter] Loaded 2018-08-01T17:54:40.430Z,1533146080.430 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2018-08-01T17:54:40.431Z,1533146080.431 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2018-08-01T17:54:40.431Z,1533146080.431 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2018-08-01T17:54:40.445Z,1533146080.445 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2018-08-01T17:54:40.445Z,1533146080.445 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2018-08-01T17:54:40.608Z,1533146080.608 [Aanderaa_O2] Loaded 2018-08-01T17:54:40.608Z,1533146080.608 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2018-08-01T17:54:40.657Z,1533146080.657 [WetLabsSeaOWL_UV_A] Loaded 2018-08-01T17:54:40.657Z,1533146080.657 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2018-08-01T17:54:40.658Z,1533146080.658 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 406D44E0 2018-08-01T17:54:40.658Z,1533146080.658 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 2750 2018-08-01T17:54:40.659Z,1533146080.659 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2018-08-01T17:54:40.660Z,1533146080.660 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2018-08-01T17:54:41.146Z,1533146081.146 [AHRS_M2] Loaded 2018-08-01T17:54:41.146Z,1533146081.146 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2018-08-01T17:54:41.215Z,1533146081.215 [DataOverHttps] Loaded 2018-08-01T17:54:41.216Z,1533146081.216 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2018-08-01T17:54:41.230Z,1533146081.230 [Depth_Keller] Loaded 2018-08-01T17:54:41.230Z,1533146081.230 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2018-08-01T17:54:41.235Z,1533146081.235 [DropWeight] Loaded 2018-08-01T17:54:41.236Z,1533146081.236 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2018-08-01T17:54:41.334Z,1533146081.334 [NAL9602] Loaded 2018-08-01T17:54:41.334Z,1533146081.334 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2018-08-01T17:54:41.340Z,1533146081.340 [Onboard] Loaded 2018-08-01T17:54:41.340Z,1533146081.340 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2018-08-01T17:54:41.347Z,1533146081.347 [Radio_Surface] Loaded 2018-08-01T17:54:41.348Z,1533146081.348 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2018-08-01T17:54:41.349Z,1533146081.349 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4092B4E0 2018-08-01T17:54:41.349Z,1533146081.349 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2751 2018-08-01T17:54:41.380Z,1533146081.380 [RDI_Pathfinder] Loaded 2018-08-01T17:54:41.380Z,1533146081.380 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2018-08-01T17:54:41.387Z,1533146081.387 [SCPI] Loaded 2018-08-01T17:54:41.387Z,1533146081.387 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2018-08-01T17:54:43.635Z,1533146083.635 [BPC1] Loaded 2018-08-01T17:54:43.635Z,1533146083.635 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2018-08-01T17:54:43.635Z,1533146083.635 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2018-08-01T17:54:43.636Z,1533146083.636 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2018-08-01T17:54:43.760Z,1533146083.760 [BuoyancyServo] Loaded 2018-08-01T17:54:43.761Z,1533146083.761 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2018-08-01T17:54:43.773Z,1533146083.773 [ElevatorServo] Loaded 2018-08-01T17:54:43.773Z,1533146083.773 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2018-08-01T17:54:43.785Z,1533146083.785 [MassServo] Loaded 2018-08-01T17:54:43.785Z,1533146083.785 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2018-08-01T17:54:43.796Z,1533146083.796 [RudderServo] Loaded 2018-08-01T17:54:43.797Z,1533146083.797 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2018-08-01T17:54:43.808Z,1533146083.808 [ThrusterServo] Loaded 2018-08-01T17:54:43.808Z,1533146083.808 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2018-08-01T17:54:43.809Z,1533146083.809 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2018-08-01T17:54:43.809Z,1533146083.809 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2018-08-01T17:54:43.917Z,1533146083.917 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2018-08-01T17:54:43.918Z,1533146083.918 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2018-08-01T17:54:43.944Z,1533146083.944 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2018-08-01T17:54:43.947Z,1533146083.947 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2018-08-01T17:54:43.948Z,1533146083.948 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2018-08-01T17:54:43.955Z,1533146083.955 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2018-08-01T17:54:43.956Z,1533146083.956 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 409D44E0 2018-08-01T17:54:43.957Z,1533146083.957 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2752 2018-08-01T17:54:43.961Z,1533146083.961 [Supervisor](INFO): Main Thread ID is 2666 2018-08-01T17:54:43.961Z,1533146083.961 [Supervisor](DEBUG): Running supervisor. 2018-08-01T17:54:43.962Z,1533146083.962 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2753 2018-08-01T17:54:43.965Z,1533146083.965 [controlThread ThreadHandler](INFO): Handler Thread ID is 2754 2018-08-01T17:54:43.965Z,1533146083.965 [controlThread](DEBUG): Initializing ControlThread 2018-08-01T17:54:43.966Z,1533146083.966 [SBIT](INFO): Initialize SBIT Component. 2018-08-01T17:54:43.966Z,1533146083.966 [SBIT](IMPORTANT): git: 2018-08-01 2018-08-01T17:54:43.967Z,1533146083.967 [SBIT](INFO): git hash: c5330d63aa4aa24925a837de3544ce564256766d 2018-08-01T17:54:43.967Z,1533146083.967 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2018-08-01T17:54:43.968Z,1533146083.968 [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-01T17:54:43.970Z,1533146083.970 [SBIT](INFO): Beginning SBIT in 24.000000 seconds. 2018-08-01T17:54:43.970Z,1533146083.970 [IBIT](INFO): Initialize IBIT Component. 2018-08-01T17:54:43.971Z,1533146083.971 [CBIT](DEBUG): Initialize CBIT Component. 2018-08-01T17:54:43.971Z,1533146083.971 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2018-08-01T17:54:43.972Z,1533146083.972 [logger ThreadHandler](INFO): Handler Thread ID is 2755 2018-08-01T17:54:43.992Z,1533146083.992 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 2756 2018-08-01T17:54:43.993Z,1533146083.993 [WetLabsSeaOWL_UV_A](INFO): Powering down 2018-08-01T17:54:44.021Z,1533146084.021 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2757 2018-08-01T17:54:44.027Z,1533146084.027 [Radio_Surface](INFO): Powering up 2018-08-01T17:54:44.040Z,1533146084.040 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2758 2018-08-01T17:54:44.043Z,1533146084.043 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2018-08-01T17:54:44.043Z,1533146084.043 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2018-08-01T17:54:44.044Z,1533146084.044 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2018-08-01T17:54:44.044Z,1533146084.044 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2018-08-01T17:54:44.044Z,1533146084.044 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2018-08-01T17:54:44.044Z,1533146084.044 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2018-08-01T17:54:44.044Z,1533146084.044 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2018-08-01T17:54:44.045Z,1533146084.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2018-08-01T17:54:44.045Z,1533146084.045 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2018-08-01T17:54:44.045Z,1533146084.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2018-08-01T17:54:44.045Z,1533146084.045 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2018-08-01T17:54:44.045Z,1533146084.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2018-08-01T17:54:44.046Z,1533146084.046 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2018-08-01T17:54:44.046Z,1533146084.046 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2018-08-01T17:54:44.046Z,1533146084.046 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2018-08-01T17:54:44.046Z,1533146084.046 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2018-08-01T17:54:44.076Z,1533146084.076 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2018-08-01T17:54:44.078Z,1533146084.078 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2018-08-01T17:54:44.078Z,1533146084.078 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2018-08-01T17:54:44.079Z,1533146084.079 [LoopControl](DEBUG): Initialize LoopControlComponent. 2018-08-01T17:54:44.079Z,1533146084.079 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-08-01T17:54:44.079Z,1533146084.079 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2018-08-01T17:54:44.080Z,1533146084.080 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2018-08-01T17:54:44.080Z,1533146084.080 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2018-08-01T17:54:44.081Z,1533146084.081 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2018-08-01T17:54:44.081Z,1533146084.081 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2018-08-01T17:54:44.082Z,1533146084.082 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2018-08-01T17:54:44.083Z,1533146084.083 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-08-01T17:54:44.084Z,1533146084.084 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-08-01T17:54:44.084Z,1533146084.084 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-08-01T17:54:44.084Z,1533146084.084 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-08-01T17:54:44.085Z,1533146084.085 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-08-01T17:54:44.085Z,1533146084.085 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-08-01T17:54:44.086Z,1533146084.086 [NavChart](DEBUG): Initialize NavChart Navigation. 2018-08-01T17:54:44.086Z,1533146084.086 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2018-08-01T17:54:44.101Z,1533146084.101 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2018-08-01T17:54:44.136Z,1533146084.136 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2018-08-01T17:54:44.168Z,1533146084.168 [MissionManager](DEBUG): 2018-08-01T17:54:44.168Z,1533146084.168 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2018-08-01T17:54:44.258Z,1533146084.258 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2018-08-01T17:54:44.260Z,1533146084.260 [Default:A.Wait](DEBUG): Construct Wait. 2018-08-01T17:54:44.261Z,1533146084.261 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2018-08-01T17:54:44.308Z,1533146084.308 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2018-08-01T17:54:44.311Z,1533146084.311 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2018-08-01T17:54:44.340Z,1533146084.340 [Default:E.Execute](DEBUG): Construct Execute. 2018-08-01T17:54:44.354Z,1533146084.354 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn 300 Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2018-08-01T17:54:44.359Z,1533146084.359 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,SCPI,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-08-01T17:54:44.407Z,1533146084.407 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2018-08-01T17:54:44.484Z,1533146084.484 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2018-08-01T17:54:44.493Z,1533146084.493 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar 2018-08-01T17:54:44.724Z,1533146084.724 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-08-01T17:54:44.833Z,1533146084.833 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:44.858Z,1533146084.858 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:44.976Z,1533146084.976 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-08-01T17:54:44.984Z,1533146084.984 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-08-01T17:54:45.006Z,1533146085.006 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-08-01T17:54:45.012Z,1533146085.012 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-08-01T17:54:45.018Z,1533146085.018 [MassServo](DEBUG): Initializing EZServoServo. 2018-08-01T17:54:45.024Z,1533146085.024 [MassServo](DEBUG): Initializing MassServo. 2018-08-01T17:54:45.030Z,1533146085.030 [RudderServo](DEBUG): Initializing EZServoServo. 2018-08-01T17:54:45.036Z,1533146085.036 [RudderServo](DEBUG): Initializing RudderServo. 2018-08-01T17:54:45.042Z,1533146085.042 [ThrusterServo](DEBUG): Initializing EZServoServo. 2018-08-01T17:54:45.048Z,1533146085.048 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2018-08-01T17:54:45.109Z,1533146085.109 [CommandLine](FAULT): Scheduling is paused 2018-08-01T17:54:45.109Z,1533146085.109 [CBIT](INFO): Critical error at 20180801T175443 2018-08-01T17:54:45.109Z,1533146085.109 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2018-08-01T17:54:45.308Z,1533146085.308 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-08-01T17:54:45.328Z,1533146085.328 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:45.329Z,1533146085.329 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:54.112Z,1533146094.112 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:54.113Z,1533146094.113 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:54.505Z,1533146094.505 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:54.506Z,1533146094.506 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:54.933Z,1533146094.933 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:54.934Z,1533146094.934 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:55.352Z,1533146095.352 [Aanderaa_O2](INFO): Powering down 2018-08-01T17:54:55.429Z,1533146095.429 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004099 2018-08-01T17:54:55.472Z,1533146095.472 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:55.473Z,1533146095.473 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:55.696Z,1533146095.696 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:55.697Z,1533146095.697 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:56.184Z,1533146096.184 [AHRS_M2](ERROR): Subscribe Pitch UART error: serial timeout 2018-08-01T17:54:56.212Z,1533146096.212 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:56.213Z,1533146096.213 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:56.756Z,1533146096.756 [AHRS_M2](ERROR): Subscribe Pitch UART error: serial timeout 2018-08-01T17:54:56.784Z,1533146096.784 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:56.785Z,1533146096.785 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:57.320Z,1533146097.320 [AHRS_M2](ERROR): Subscribe Pitch UART error: serial timeout 2018-08-01T17:54:57.352Z,1533146097.352 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:57.353Z,1533146097.353 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:58.200Z,1533146098.200 [AHRS_M2](ERROR): Subscribe Pitch UART error: serial timeout 2018-08-01T17:54:58.233Z,1533146098.233 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2018-08-01T17:54:58.250Z,1533146098.250 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:58.251Z,1533146098.251 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:58.669Z,1533146098.669 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:58.670Z,1533146098.670 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:58.793Z,1533146098.793 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:58.794Z,1533146098.794 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:59.242Z,1533146099.242 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:59.243Z,1533146099.243 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:59.588Z,1533146099.588 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:59.589Z,1533146099.589 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:59.992Z,1533146099.992 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:54:59.993Z,1533146099.993 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:55:00.381Z,1533146100.381 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:55:00.382Z,1533146100.382 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:55:00.785Z,1533146100.785 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:55:00.786Z,1533146100.786 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-08-01T17:55:08.418Z,1533146108.418 [SBIT](IMPORTANT): Beginning Startup BIT 2018-08-01T17:55:08.427Z,1533146108.427 [CBIT](IMPORTANT): Beginning ground fault scan 2018-08-01T17:55:11.666Z,1533146111.666 [NAL9602](INFO): Powering up NAL9602 2018-08-01T17:55:19.485Z,1533146119.485 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.008417 CHAN A1 (24V): -0.012057 CHAN A2 (12V): -0.007256 CHAN A3 (5V): -0.001927 CHAN B0 (3.3V): 0.000314 CHAN B1 (3.15aV): 0.000242 CHAN B2 (3.15bV): 0.000146 CHAN B3 (GND): 0.002236 OPEN: 0.005127 Full Scale Calc: 4.765 mA, -1.589 mA 2018-08-01T17:55:22.862Z,1533146122.862 [NAL9602](INFO): NAL9602 initialized 2018-08-01T17:56:05.151Z,1533146165.151 [SBIT](IMPORTANT): SBIT PASSED 2018-08-01T17:56:05.243Z,1533146165.243 [CommandLine](IMPORTANT): got command configSet list 2018-08-01T17:56:05.244Z,1533146165.244 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2018-08-01T17:56:05.245Z,1533146165.245 [CommandLine](IMPORTANT): Radio_Surface.loadAtStartup=1 bool; 2018-08-01T17:56:05.245Z,1533146165.245 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=160 cubic_centimeter; 2018-08-01T17:56:05.245Z,1533146165.245 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 millimeter; 2018-08-01T17:56:05.576Z,1533146165.576 [MissionManager](IMPORTANT): Started mission Startup 2018-08-01T17:56:05.576Z,1533146165.576 [Startup] Running Loop=1 2018-08-01T17:56:05.576Z,1533146165.576 [Startup](DEBUG): Aggregate::initialize Startup 2018-08-01T17:56:05.576Z,1533146165.576 [Startup:A.GoToSurface] Running Loop=1 2018-08-01T17:56:05.577Z,1533146165.577 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-08-01T17:56:05.577Z,1533146165.577 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-08-01T17:56:05.578Z,1533146165.578 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-08-01T17:56:05.578Z,1533146165.578 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-08-01T17:56:05.578Z,1533146165.578 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-08-01T17:56:05.579Z,1533146165.579 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-08-01T17:56:05.585Z,1533146165.585 [Startup:StartupSatComms] Running Loop=1 2018-08-01T17:56:05.585Z,1533146165.585 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2018-08-01T17:56:05.585Z,1533146165.585 [Startup:StartupSatComms:A] Running Loop=1 2018-08-01T17:56:05.933Z,1533146165.933 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2018-08-01T17:57:05.652Z,1533146225.652 [Startup:StartupSatComms:A](INFO): Timed out from 2018-08-01T17:56:05.6Z 2018-08-01T17:57:05.652Z,1533146225.652 [Startup:StartupSatComms:A] Stopped 2018-08-01T17:57:05.652Z,1533146225.652 [Startup:StartupSatComms:B] Running Loop=1 2018-08-01T17:57:06.034Z,1533146226.034 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-08-01T17:57:10.131Z,1533146230.131 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180801T154544/Courier0016.lzma 2018-08-01T17:57:10.898Z,1533146230.898 [DataOverHttps](INFO): Moved sent file to Logs/20180801T154544/Courier0016.lzma.bak 2018-08-01T17:57:10.898Z,1533146230.898 [DataOverHttps](INFO): SBD MOMSN=8391389 2018-08-01T17:57:11.330Z,1533146231.330 [RDI_Pathfinder](ERROR): Failed to parse: 2018-08-01T17:57:19.898Z,1533146239.898 [DataOverHttps](INFO): Sending 99 bytes from file Logs/20180801T175433/Courier0000.lzma 2018-08-01T17:57:20.681Z,1533146240.681 [DataOverHttps](INFO): Moved sent file to Logs/20180801T175433/Courier0000.lzma.bak 2018-08-01T17:57:20.682Z,1533146240.682 [DataOverHttps](INFO): SBD MOMSN=8391391 2018-08-01T17:57:29.719Z,1533146249.719 [DataOverHttps](INFO): Sending 303 bytes from file Logs/20180801T154544/Express0017.lzma 2018-08-01T17:57:30.489Z,1533146250.489 [DataOverHttps](INFO): Moved sent file to Logs/20180801T154544/Express0017.lzma.bak 2018-08-01T17:57:30.489Z,1533146250.489 [DataOverHttps](INFO): SBD MOMSN=8391395 2018-08-01T17:57:39.545Z,1533146259.545 [DataOverHttps](INFO): Sending 677 bytes from file Logs/20180801T175433/Express0001.lzma 2018-08-01T17:57:40.313Z,1533146260.313 [DataOverHttps](INFO): Moved sent file to Logs/20180801T175433/Express0001.lzma.bak 2018-08-01T17:57:40.313Z,1533146260.313 [DataOverHttps](INFO): SBD MOMSN=8391410 2018-08-01T17:57:40.777Z,1533146260.777 [Startup:StartupSatComms:B] Stopped 2018-08-01T17:57:40.777Z,1533146260.777 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2018-08-01T17:57:40.777Z,1533146260.777 [Startup:StartupSatComms] Stopped 2018-08-01T17:57:40.777Z,1533146260.777 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2018-08-01T17:57:40.778Z,1533146260.778 [Startup](INFO): Completed Startup 2018-08-01T17:57:40.778Z,1533146260.778 [MissionManager](INFO): Startup is completed. 2018-08-01T17:57:40.779Z,1533146260.779 [MissionManager](INFO): Uninitializing Mission Startup 2018-08-01T17:57:40.779Z,1533146260.779 [Startup] Stopped 2018-08-01T17:57:40.779Z,1533146260.779 [Startup](DEBUG): Aggregate::uninitialize Startup 2018-08-01T17:57:40.779Z,1533146260.779 [Startup:A.GoToSurface] Stopped 2018-08-01T17:57:40.779Z,1533146260.779 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-08-01T17:57:41.169Z,1533146261.169 [MissionManager](IMPORTANT): Started mission Default 2018-08-01T17:57:41.169Z,1533146261.169 [Default] Running Loop=1 2018-08-01T17:57:41.170Z,1533146261.170 [Default](DEBUG): Aggregate::initialize Default 2018-08-01T17:57:41.170Z,1533146261.170 [Default:B.GoToSurface] Running Loop=1 2018-08-01T17:57:41.170Z,1533146261.170 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-08-01T17:57:41.170Z,1533146261.170 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-08-01T17:57:41.170Z,1533146261.170 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-08-01T17:57:41.171Z,1533146261.171 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-08-01T17:57:41.171Z,1533146261.171 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-08-01T17:57:41.172Z,1533146261.172 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-08-01T17:57:41.173Z,1533146261.173 [Default:A.Wait] Running Loop=1 2018-08-01T17:57:41.173Z,1533146261.173 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-08-01T17:57:44.470Z,1533146264.470 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-08-01T17:57:44.470Z,1533146264.470 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2018-08-01T17:57:44.470Z,1533146264.470 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2018-08-01T17:57:44.472Z,1533146264.472 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-08-01T17:57:44.472Z,1533146264.472 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2018-08-01T17:57:44.472Z,1533146264.472 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-08-01T17:57:44.486Z,1533146264.486 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2018-08-01T17:57:44.486Z,1533146264.486 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-08-01T17:57:44.618Z,1533146264.618 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2018-08-01T17:57:44.619Z,1533146264.619 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2018-08-01T17:57:44.619Z,1533146264.619 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-08-01T17:57:44.619Z,1533146264.619 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2018-08-01T17:57:44.969Z,1533146264.969 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-08-01T17:57:44.970Z,1533146264.970 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-08-01T17:57:44.970Z,1533146264.970 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-08-01T17:57:44.971Z,1533146264.971 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-08-01T17:57:44.971Z,1533146264.971 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-08-01T17:57:44.972Z,1533146264.972 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-08-01T17:57:45.378Z,1533146265.378 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.9 s old, using for 20.0 s. 2018-08-01T17:57:45.743Z,1533146265.743 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.3 s old, using for 20.0 s. 2018-08-01T17:57:46.147Z,1533146266.147 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.7 s old, using for 20.0 s. 2018-08-01T17:57:46.578Z,1533146266.578 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.1 s old, using for 20.0 s. 2018-08-01T17:57:46.977Z,1533146266.977 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.5 s old, using for 20.0 s. 2018-08-01T17:57:47.352Z,1533146267.352 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.9 s old, using for 20.0 s. 2018-08-01T17:57:47.762Z,1533146267.762 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.3 s old, using for 20.0 s. 2018-08-01T17:57:48.161Z,1533146268.161 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.7 s old, using for 20.0 s. 2018-08-01T17:57:48.551Z,1533146268.551 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.1 s old, using for 20.0 s. 2018-08-01T17:57:48.951Z,1533146268.951 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.5 s old, using for 20.0 s. 2018-08-01T17:57:49.380Z,1533146269.380 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.9 s old, using for 20.0 s. 2018-08-01T17:57:49.762Z,1533146269.762 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.3 s old, using for 20.0 s. 2018-08-01T17:57:50.176Z,1533146270.176 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.7 s old, using for 20.0 s. 2018-08-01T17:57:50.566Z,1533146270.566 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.1 s old, using for 20.0 s. 2018-08-01T17:57:50.930Z,1533146270.930 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.5 s old, using for 20.0 s. 2018-08-01T17:57:51.359Z,1533146271.359 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.9 s old, using for 20.0 s. 2018-08-01T17:57:51.747Z,1533146271.747 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.3 s old, using for 20.0 s. 2018-08-01T17:57:52.174Z,1533146272.174 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.7 s old, using for 20.0 s. 2018-08-01T17:57:52.555Z,1533146272.555 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.1 s old, using for 20.0 s. 2018-08-01T17:57:52.950Z,1533146272.950 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.5 s old, using for 20.0 s. 2018-08-01T17:57:53.358Z,1533146273.358 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.9 s old, using for 20.0 s. 2018-08-01T17:57:53.751Z,1533146273.751 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.3 s old, using for 20.0 s. 2018-08-01T17:57:54.162Z,1533146274.162 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.7 s old, using for 20.0 s. 2018-08-01T17:57:54.182Z,1533146274.182 [Default:A.Wait](INFO): Done Waiting. 2018-08-01T17:57:54.182Z,1533146274.182 [Default:A.Wait] Stopped 2018-08-01T17:57:54.182Z,1533146274.182 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-08-01T17:57:54.562Z,1533146274.562 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.1 s old, using for 20.0 s. 2018-08-01T17:57:54.566Z,1533146274.566 [Default:CheckIn] Running Loop=1 2018-08-01T17:57:54.566Z,1533146274.566 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-08-01T17:57:54.566Z,1533146274.566 [Default:CheckIn:Read_GPS] Running Loop=1 2018-08-01T17:57:54.960Z,1533146274.960 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.5 s old, using for 20.0 s. 2018-08-01T17:57:54.964Z,1533146274.964 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2018-08-01T17:57:55.376Z,1533146275.376 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.9 s old, using for 20.0 s. 2018-08-01T17:57:55.758Z,1533146275.758 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.3 s old, using for 20.0 s. 2018-08-01T17:57:56.153Z,1533146276.153 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.7 s old, using for 20.0 s. 2018-08-01T17:57:56.561Z,1533146276.561 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.1 s old, using for 20.0 s. 2018-08-01T17:57:56.952Z,1533146276.952 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.5 s old, using for 20.0 s. 2018-08-01T17:57:57.359Z,1533146277.359 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.9 s old, using for 20.0 s. 2018-08-01T17:57:57.775Z,1533146277.775 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.3 s old, using for 20.0 s. 2018-08-01T17:57:58.165Z,1533146278.165 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.7 s old, using for 20.0 s. 2018-08-01T17:57:58.544Z,1533146278.544 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.1 s old, using for 20.0 s. 2018-08-01T17:57:58.961Z,1533146278.961 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.5 s old, using for 20.0 s. 2018-08-01T17:57:59.371Z,1533146279.371 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.9 s old, using for 20.0 s. 2018-08-01T17:57:59.780Z,1533146279.780 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.3 s old, using for 20.0 s. 2018-08-01T17:58:00.177Z,1533146280.177 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.7 s old, using for 20.0 s. 2018-08-01T17:58:00.585Z,1533146280.585 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.1 s old, using for 20.0 s. 2018-08-01T17:58:00.955Z,1533146280.955 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.5 s old, using for 20.0 s. 2018-08-01T17:58:01.368Z,1533146281.368 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.9 s old, using for 20.0 s. 2018-08-01T17:58:01.753Z,1533146281.753 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.3 s old, using for 20.0 s. 2018-08-01T17:58:02.160Z,1533146282.160 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.7 s old, using for 20.0 s. 2018-08-01T17:58:02.547Z,1533146282.547 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.1 s old, using for 20.0 s. 2018-08-01T17:58:02.942Z,1533146282.942 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.5 s old, using for 20.0 s. 2018-08-01T17:58:03.362Z,1533146283.362 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.9 s old, using for 20.0 s. 2018-08-01T17:58:03.746Z,1533146283.746 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.3 s old, using for 20.0 s. 2018-08-01T17:58:04.166Z,1533146284.166 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.7 s old, using for 20.0 s. 2018-08-01T17:59:33.601Z,1533146373.601 [CommandLine](IMPORTANT): got command get WetLabsSeaOWL_UV_A.loadAtStartup 2018-08-01T17:59:33.602Z,1533146373.602 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.loadAtStartup 1 bool 2018-08-01T17:59:48.345Z,1533146388.345 [CommandLine](IMPORTANT): got command quit 2018-08-01T17:59:49.355Z,1533146389.355 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-01T17:59:49.355Z,1533146389.355 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.432Z,1533146389.432 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2018-08-01T17:59:49.432Z,1533146389.432 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.432Z,1533146389.432 [CommandLine](INFO): Join timeout helper Thread ID is 2780 2018-08-01T17:59:49.433Z,1533146389.433 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2018-08-01T17:59:49.433Z,1533146389.433 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.434Z,1533146389.434 [NavChartDb](INFO): Join timeout helper Thread ID is 2781 2018-08-01T17:59:49.572Z,1533146389.572 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-01T17:59:49.572Z,1533146389.572 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.576Z,1533146389.576 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2018-08-01T17:59:49.576Z,1533146389.576 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.576Z,1533146389.576 [Radio_Surface](INFO): Join timeout helper Thread ID is 2782 2018-08-01T17:59:49.636Z,1533146389.636 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-01T17:59:49.636Z,1533146389.636 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.644Z,1533146389.644 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler 2018-08-01T17:59:49.644Z,1533146389.644 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.644Z,1533146389.644 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 2783 2018-08-01T17:59:49.940Z,1533146389.940 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-01T17:59:49.940Z,1533146389.940 [WetLabsSeaOWL_UV_A](INFO): Powering down 2018-08-01T17:59:49.941Z,1533146389.941 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.948Z,1533146389.948 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2018-08-01T17:59:49.948Z,1533146389.948 [logger ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.948Z,1533146389.948 [logger](INFO): Join timeout helper Thread ID is 2784 2018-08-01T17:59:49.969Z,1533146389.969 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-01T17:59:49.970Z,1533146389.970 [logger ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.989Z,1533146389.989 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2018-08-01T17:59:49.989Z,1533146389.989 [CommandLine ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.989Z,1533146389.989 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2018-08-01T17:59:49.990Z,1533146389.990 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:49.991Z,1533146389.991 [controlThread](INFO): Join timeout helper Thread ID is 2785 2018-08-01T17:59:50.288Z,1533146390.288 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2018-08-01T17:59:50.288Z,1533146390.288 [controlThread](DEBUG): Uninitializing ControlThread 2018-08-01T17:59:50.288Z,1533146390.288 [Aanderaa_O2](INFO): Powering down 2018-08-01T17:59:50.289Z,1533146390.289 [AHRS_M2](INFO): Powering down 2018-08-01T17:59:50.361Z,1533146390.361 [NAL9602](INFO): Powering down 2018-08-01T17:59:50.432Z,1533146390.432 [RDI_Pathfinder](INFO): Powering down 2018-08-01T17:59:50.434Z,1533146390.434 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-08-01T17:59:50.435Z,1533146390.435 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2018-08-01T17:59:50.436Z,1533146390.436 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2018-08-01T17:59:50.436Z,1533146390.436 [MissionManager](INFO): Uninitializing Mission Default 2018-08-01T17:59:50.437Z,1533146390.437 [Default] Stopped 2018-08-01T17:59:50.437Z,1533146390.437 [Default](DEBUG): Aggregate::uninitialize Default 2018-08-01T17:59:50.437Z,1533146390.437 [Default:B.GoToSurface] Stopped 2018-08-01T17:59:50.437Z,1533146390.437 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-08-01T17:59:50.437Z,1533146390.437 [Default:CheckIn] Stopped 2018-08-01T17:59:50.437Z,1533146390.437 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-08-01T17:59:50.437Z,1533146390.437 [Default:CheckIn:Read_GPS] Stopped 2018-08-01T17:59:50.440Z,1533146390.440 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2018-08-01T17:59:50.441Z,1533146390.441 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2018-08-01T17:59:50.441Z,1533146390.441 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2018-08-01T17:59:50.441Z,1533146390.441 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2018-08-01T17:59:50.441Z,1533146390.441 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-08-01T17:59:50.442Z,1533146390.442 [BuoyancyServo](INFO): Powering down 2018-08-01T17:59:50.456Z,1533146390.456 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2018-08-01T17:59:50.456Z,1533146390.456 [ElevatorServo](INFO): Powering down 2018-08-01T17:59:50.457Z,1533146390.457 [MassServo](DEBUG): Uninitialize Mass Servo. 2018-08-01T17:59:50.457Z,1533146390.457 [MassServo](INFO): Powering down 2018-08-01T17:59:50.458Z,1533146390.458 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2018-08-01T17:59:50.458Z,1533146390.458 [RudderServo](INFO): Powering down 2018-08-01T17:59:50.459Z,1533146390.459 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2018-08-01T17:59:50.459Z,1533146390.459 [ThrusterServo](INFO): Powering down 2018-08-01T17:59:50.460Z,1533146390.460 [SBIT](DEBUG): Uninitialize SBIT Component. 2018-08-01T17:59:50.460Z,1533146390.460 [IBIT](DEBUG): Uninitialize IBIT Component. 2018-08-01T17:59:50.461Z,1533146390.461 [CBIT](DEBUG): Uninitialize CBIT Component. 2018-08-01T17:59:50.462Z,1533146390.462 [controlThread ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:50.515Z,1533146390.515 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:50.574Z,1533146390.574 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:50.617Z,1533146390.617 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2018-08-01T17:59:50.672Z,1533146390.672 [logger ThreadHandler](INFO): Thread cancelled.