2018-07-25T15:57:14.710Z,1532534234.710 [Supervisor](DEBUG): Initializing supervisor. 2018-07-25T15:57:14.713Z,1532534234.713 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2018-07-25T15:57:14.714Z,1532534234.714 [SyncHandler](INFO): Protected caller Thread ID is 799 2018-07-25T15:57:14.714Z,1532534234.714 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2018-07-25T15:57:14.715Z,1532534234.715 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2018-07-25T15:57:14.715Z,1532534234.715 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 800 2018-07-25T15:57:14.718Z,1532534234.718 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2018-07-25T15:57:14.730Z,1532534234.730 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2018-07-25T15:57:14.730Z,1532534234.730 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2018-07-25T15:57:14.731Z,1532534234.731 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 801 2018-07-25T15:57:14.732Z,1532534234.732 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2018-07-25T15:57:14.733Z,1532534234.733 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2018-07-25T15:57:14.733Z,1532534234.733 [logger ThreadHandler](INFO): Protected caller Thread ID is 802 2018-07-25T15:57:14.735Z,1532534234.735 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2018-07-25T15:57:14.735Z,1532534234.735 [Supervisor](INFO): Looking for Config files in directory: Config/ 2018-07-25T15:57:14.739Z,1532534234.739 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2018-07-25T15:57:14.936Z,1532534234.936 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2018-07-25T15:57:14.938Z,1532534234.938 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2018-07-25T15:57:15.081Z,1532534235.081 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2018-07-25T15:57:15.083Z,1532534235.083 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2018-07-25T15:57:15.431Z,1532534235.431 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2018-07-25T15:57:15.433Z,1532534235.433 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2018-07-25T15:57:15.572Z,1532534235.572 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2018-07-25T15:57:15.573Z,1532534235.573 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2018-07-25T15:57:15.655Z,1532534235.655 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2018-07-25T15:57:15.858Z,1532534235.858 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2018-07-25T15:57:15.859Z,1532534235.859 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2018-07-25T15:57:15.960Z,1532534235.960 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2018-07-25T15:57:15.961Z,1532534235.961 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2018-07-25T15:57:16.302Z,1532534236.302 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2018-07-25T15:57:16.303Z,1532534236.303 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2018-07-25T15:57:16.743Z,1532534236.743 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2018-07-25T15:57:16.744Z,1532534236.744 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2018-07-25T15:57:17.051Z,1532534237.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2018-07-25T15:57:17.051Z,1532534237.051 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2018-07-25T15:57:17.570Z,1532534237.570 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2018-07-25T15:57:17.571Z,1532534237.571 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2018-07-25T15:57:17.843Z,1532534237.843 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2018-07-25T15:57:17.843Z,1532534237.843 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2018-07-25T15:57:20.610Z,1532534240.610 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2018-07-25T15:57:20.611Z,1532534240.611 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2018-07-25T15:57:21.107Z,1532534241.107 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2018-07-25T15:57:21.108Z,1532534241.108 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2018-07-25T15:57:21.216Z,1532534241.216 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2018-07-25T15:57:21.218Z,1532534241.218 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/ 2018-07-25T15:57:21.224Z,1532534241.224 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg 2018-07-25T15:57:21.456Z,1532534241.456 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2018-07-25T15:57:21.457Z,1532534241.457 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg 2018-07-25T15:57:21.556Z,1532534241.556 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg 2018-07-25T15:57:21.651Z,1532534241.651 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg 2018-07-25T15:57:21.754Z,1532534241.754 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg 2018-07-25T15:57:21.841Z,1532534241.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg 2018-07-25T15:57:21.974Z,1532534241.974 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg 2018-07-25T15:57:22.145Z,1532534242.145 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg 2018-07-25T15:57:22.256Z,1532534242.256 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg 2018-07-25T15:57:22.342Z,1532534242.342 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg 2018-07-25T15:57:22.427Z,1532534242.427 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg 2018-07-25T15:57:22.631Z,1532534242.631 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2018-07-25T15:57:26.065Z,1532534246.065 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2018-07-25T15:57:26.311Z,1532534246.311 [SBIT](DEBUG): Construct Startup Built In Test. 2018-07-25T15:57:26.341Z,1532534246.341 [SBIT] Loaded 2018-07-25T15:57:26.341Z,1532534246.341 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2018-07-25T15:57:26.342Z,1532534246.342 [IBIT](DEBUG): Construct Initiated Built In Test. 2018-07-25T15:57:26.369Z,1532534246.369 [IBIT] Loaded 2018-07-25T15:57:26.370Z,1532534246.370 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2018-07-25T15:57:26.373Z,1532534246.373 [CBIT](DEBUG): Construct Continuous Built In Test. 2018-07-25T15:57:26.529Z,1532534246.529 [CBIT] Loaded 2018-07-25T15:57:26.529Z,1532534246.529 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2018-07-25T15:57:26.530Z,1532534246.530 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2018-07-25T15:57:26.532Z,1532534246.532 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2018-07-25T15:57:26.620Z,1532534246.620 [VerticalControl](DEBUG): Construct VerticalControl. 2018-07-25T15:57:26.719Z,1532534246.719 [VerticalControl] Loaded 2018-07-25T15:57:26.719Z,1532534246.719 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2018-07-25T15:57:26.720Z,1532534246.720 [HorizontalControl](DEBUG): Construct HorizontalControl. 2018-07-25T15:57:26.780Z,1532534246.780 [HorizontalControl] Loaded 2018-07-25T15:57:26.781Z,1532534246.781 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2018-07-25T15:57:26.781Z,1532534246.781 [SpeedControl](DEBUG): Construct SpeedControl. 2018-07-25T15:57:26.787Z,1532534246.787 [SpeedControl] Loaded 2018-07-25T15:57:26.787Z,1532534246.787 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2018-07-25T15:57:26.788Z,1532534246.788 [LoopControl](DEBUG): Construct LoopControl. 2018-07-25T15:57:26.788Z,1532534246.788 [LoopControl] Loaded 2018-07-25T15:57:26.789Z,1532534246.789 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2018-07-25T15:57:26.789Z,1532534246.789 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2018-07-25T15:57:26.790Z,1532534246.790 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2018-07-25T15:57:26.846Z,1532534246.846 [DepthRateCalculator] Loaded 2018-07-25T15:57:26.846Z,1532534246.846 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2018-07-25T15:57:26.851Z,1532534246.851 [PitchRateCalculator] Loaded 2018-07-25T15:57:26.851Z,1532534246.851 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2018-07-25T15:57:26.867Z,1532534246.867 [SpeedCalculator] Loaded 2018-07-25T15:57:26.868Z,1532534246.868 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2018-07-25T15:57:26.890Z,1532534246.890 [TempGradientCalculator] Loaded 2018-07-25T15:57:26.890Z,1532534246.890 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2018-07-25T15:57:26.905Z,1532534246.905 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2018-07-25T15:57:26.906Z,1532534246.906 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2018-07-25T15:57:26.911Z,1532534246.911 [YawRateCalculator] Loaded 2018-07-25T15:57:26.911Z,1532534246.911 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2018-07-25T15:57:26.940Z,1532534246.940 [ElevatorOffsetCalculator] Loaded 2018-07-25T15:57:26.940Z,1532534246.940 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2018-07-25T15:57:26.941Z,1532534246.941 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2018-07-25T15:57:26.942Z,1532534246.942 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2018-07-25T15:57:27.066Z,1532534247.066 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2018-07-25T15:57:27.066Z,1532534247.066 [StratificationFrontDetector](DEBUG): (re)initializing 2018-07-25T15:57:27.066Z,1532534247.066 [StratificationFrontDetector] Loaded 2018-07-25T15:57:27.066Z,1532534247.066 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2018-07-25T15:57:27.067Z,1532534247.067 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2018-07-25T15:57:27.067Z,1532534247.067 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2018-07-25T15:57:27.353Z,1532534247.353 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2018-07-25T15:57:27.355Z,1532534247.355 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2018-07-25T15:57:27.469Z,1532534247.469 [DeadReckonUsingMultipleVelocitySources] Loaded 2018-07-25T15:57:27.469Z,1532534247.469 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2018-07-25T15:57:27.524Z,1532534247.524 [DeadReckonUsingSpeedCalculator] Loaded 2018-07-25T15:57:27.524Z,1532534247.524 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2018-07-25T15:57:27.541Z,1532534247.541 [NavChart] Loaded 2018-07-25T15:57:27.541Z,1532534247.541 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2018-07-25T15:57:27.545Z,1532534247.545 [UniversalFixResidualReporter] Loaded 2018-07-25T15:57:27.545Z,1532534247.545 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2018-07-25T15:57:27.546Z,1532534247.546 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2018-07-25T15:57:27.546Z,1532534247.546 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2018-07-25T15:57:27.572Z,1532534247.572 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2018-07-25T15:57:27.573Z,1532534247.573 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2018-07-25T15:57:27.773Z,1532534247.773 [PAR_Licor] Loaded 2018-07-25T15:57:27.773Z,1532534247.773 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2018-07-25T15:57:27.823Z,1532534247.823 [WetLabsBB2FL] Loaded 2018-07-25T15:57:27.823Z,1532534247.823 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2018-07-25T15:57:27.825Z,1532534247.825 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406D24E0 2018-07-25T15:57:27.825Z,1532534247.825 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 881 2018-07-25T15:57:27.868Z,1532534247.868 [WetLabsSeaOWL_UV_A] Loaded 2018-07-25T15:57:27.869Z,1532534247.869 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2018-07-25T15:57:27.870Z,1532534247.870 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 407024E0 2018-07-25T15:57:27.870Z,1532534247.870 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 882 2018-07-25T15:57:27.871Z,1532534247.871 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2018-07-25T15:57:27.871Z,1532534247.871 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2018-07-25T15:57:28.510Z,1532534248.510 [AHRS_M2] Loaded 2018-07-25T15:57:28.510Z,1532534248.510 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2018-07-25T15:57:28.643Z,1532534248.643 [DataOverHttps] Loaded 2018-07-25T15:57:28.644Z,1532534248.644 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2018-07-25T15:57:28.658Z,1532534248.658 [Depth_Keller] Loaded 2018-07-25T15:57:28.658Z,1532534248.658 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2018-07-25T15:57:28.663Z,1532534248.663 [DropWeight] Loaded 2018-07-25T15:57:28.663Z,1532534248.663 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2018-07-25T15:57:28.755Z,1532534248.755 [NAL9602] Loaded 2018-07-25T15:57:28.755Z,1532534248.755 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2018-07-25T15:57:28.761Z,1532534248.761 [Onboard] Loaded 2018-07-25T15:57:28.761Z,1532534248.761 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2018-07-25T15:57:28.768Z,1532534248.768 [Radio_Surface] Loaded 2018-07-25T15:57:28.768Z,1532534248.768 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2018-07-25T15:57:28.769Z,1532534248.769 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409584E0 2018-07-25T15:57:28.770Z,1532534248.770 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 883 2018-07-25T15:57:28.798Z,1532534248.798 [RDI_Pathfinder] Loaded 2018-07-25T15:57:28.799Z,1532534248.799 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread. 2018-07-25T15:57:28.805Z,1532534248.805 [SCPI] Loaded 2018-07-25T15:57:28.805Z,1532534248.805 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2018-07-25T15:57:30.619Z,1532534250.619 [BPC1] Loaded 2018-07-25T15:57:30.619Z,1532534250.619 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2018-07-25T15:57:30.619Z,1532534250.619 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2018-07-25T15:57:30.621Z,1532534250.621 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2018-07-25T15:57:30.741Z,1532534250.741 [BuoyancyServo] Loaded 2018-07-25T15:57:30.741Z,1532534250.741 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2018-07-25T15:57:30.753Z,1532534250.753 [ElevatorServo] Loaded 2018-07-25T15:57:30.754Z,1532534250.754 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2018-07-25T15:57:30.765Z,1532534250.765 [MassServo] Loaded 2018-07-25T15:57:30.765Z,1532534250.765 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2018-07-25T15:57:30.776Z,1532534250.776 [RudderServo] Loaded 2018-07-25T15:57:30.777Z,1532534250.777 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2018-07-25T15:57:30.788Z,1532534250.788 [ThrusterServo] Loaded 2018-07-25T15:57:30.788Z,1532534250.788 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2018-07-25T15:57:30.788Z,1532534250.788 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2018-07-25T15:57:30.789Z,1532534250.789 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2018-07-25T15:57:30.916Z,1532534250.916 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2018-07-25T15:57:30.917Z,1532534250.917 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2018-07-25T15:57:30.955Z,1532534250.955 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2018-07-25T15:57:30.959Z,1532534250.959 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2018-07-25T15:57:30.959Z,1532534250.959 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2018-07-25T15:57:30.966Z,1532534250.966 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2018-07-25T15:57:30.967Z,1532534250.967 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A014E0 2018-07-25T15:57:30.968Z,1532534250.968 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 884 2018-07-25T15:57:30.972Z,1532534250.972 [Supervisor](INFO): Main Thread ID is 795 2018-07-25T15:57:30.972Z,1532534250.972 [Supervisor](DEBUG): Running supervisor. 2018-07-25T15:57:30.973Z,1532534250.973 [CommandLine ThreadHandler](INFO): Handler Thread ID is 885 2018-07-25T15:57:30.975Z,1532534250.975 [controlThread ThreadHandler](INFO): Handler Thread ID is 886 2018-07-25T15:57:30.975Z,1532534250.975 [controlThread](DEBUG): Initializing ControlThread 2018-07-25T15:57:30.976Z,1532534250.976 [SBIT](INFO): Initialize SBIT Component. 2018-07-25T15:57:30.977Z,1532534250.977 [SBIT](IMPORTANT): git: 2018-07-13-7-g7a5c4dc 2018-07-25T15:57:30.977Z,1532534250.977 [SBIT](INFO): git hash: 7a5c4dc9ca9b4be628f083a717b6227e0804b4b7 2018-07-25T15:57:30.977Z,1532534250.977 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2018-07-25T15:57:30.979Z,1532534250.979 [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-07-25T15:57:30.980Z,1532534250.980 [SBIT](INFO): Beginning SBIT in 28.000000 seconds. 2018-07-25T15:57:30.980Z,1532534250.980 [IBIT](INFO): Initialize IBIT Component. 2018-07-25T15:57:30.981Z,1532534250.981 [CBIT](DEBUG): Initialize CBIT Component. 2018-07-25T15:57:30.982Z,1532534250.982 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2018-07-25T15:57:30.983Z,1532534250.983 [logger ThreadHandler](INFO): Handler Thread ID is 887 2018-07-25T15:57:31.009Z,1532534251.009 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 888 2018-07-25T15:57:31.025Z,1532534251.025 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 889 2018-07-25T15:57:31.026Z,1532534251.026 [WetLabsSeaOWL_UV_A](INFO): Powering down 2018-07-25T15:57:31.089Z,1532534251.089 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 891 2018-07-25T15:57:31.093Z,1532534251.093 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2018-07-25T15:57:31.095Z,1532534251.095 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2018-07-25T15:57:31.096Z,1532534251.096 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2018-07-25T15:57:31.096Z,1532534251.096 [LoopControl](DEBUG): Initialize LoopControlComponent. 2018-07-25T15:57:31.096Z,1532534251.096 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-07-25T15:57:31.100Z,1532534251.100 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2018-07-25T15:57:31.100Z,1532534251.100 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2018-07-25T15:57:31.100Z,1532534251.100 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2018-07-25T15:57:31.101Z,1532534251.101 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2018-07-25T15:57:31.102Z,1532534251.102 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2018-07-25T15:57:31.102Z,1532534251.102 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2018-07-25T15:57:31.103Z,1532534251.103 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-07-25T15:57:31.104Z,1532534251.104 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-07-25T15:57:31.104Z,1532534251.104 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-07-25T15:57:31.105Z,1532534251.105 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-07-25T15:57:31.105Z,1532534251.105 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-07-25T15:57:31.106Z,1532534251.106 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-07-25T15:57:31.106Z,1532534251.106 [NavChart](DEBUG): Initialize NavChart Navigation. 2018-07-25T15:57:31.106Z,1532534251.106 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2018-07-25T15:57:31.115Z,1532534251.115 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2018-07-25T15:57:31.116Z,1532534251.116 [Radio_Surface](INFO): Powering up 2018-07-25T15:57:31.127Z,1532534251.127 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 892 2018-07-25T15:57:31.143Z,1532534251.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2018-07-25T15:57:31.143Z,1532534251.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2018-07-25T15:57:31.144Z,1532534251.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2018-07-25T15:57:31.144Z,1532534251.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2018-07-25T15:57:31.144Z,1532534251.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2018-07-25T15:57:31.144Z,1532534251.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2018-07-25T15:57:31.145Z,1532534251.145 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2018-07-25T15:57:31.145Z,1532534251.145 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2018-07-25T15:57:31.145Z,1532534251.145 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2018-07-25T15:57:31.145Z,1532534251.145 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2018-07-25T15:57:31.146Z,1532534251.146 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2018-07-25T15:57:31.146Z,1532534251.146 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2018-07-25T15:57:31.146Z,1532534251.146 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2018-07-25T15:57:31.146Z,1532534251.146 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2018-07-25T15:57:31.147Z,1532534251.147 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2018-07-25T15:57:31.147Z,1532534251.147 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2018-07-25T15:57:31.180Z,1532534251.180 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2018-07-25T15:57:31.211Z,1532534251.211 [MissionManager](DEBUG): 2018-07-25T15:57:31.212Z,1532534251.212 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2018-07-25T15:57:31.302Z,1532534251.302 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2018-07-25T15:57:31.303Z,1532534251.303 [Default:A.Wait](DEBUG): Construct Wait. 2018-07-25T15:57:31.305Z,1532534251.305 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2018-07-25T15:57:31.336Z,1532534251.336 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2018-07-25T15:57:31.354Z,1532534251.354 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2018-07-25T15:57:31.360Z,1532534251.360 [Default:E.Execute](DEBUG): Construct Execute. 2018-07-25T15:57:31.384Z,1532534251.384 [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-07-25T15:57:31.389Z,1532534251.389 [controlThread](DEBUG): Component order: CycleStarter,PAR_Licor,AHRS_M2,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,RDI_Pathfinder,SCPI,BPC1,PAR_Licor,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-07-25T15:57:31.422Z,1532534251.422 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2018-07-25T15:57:31.583Z,1532534251.583 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2018-07-25T15:57:32.093Z,1532534252.093 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:32.121Z,1532534252.121 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:32.227Z,1532534252.227 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-07-25T15:57:32.233Z,1532534252.233 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-07-25T15:57:32.240Z,1532534252.240 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-07-25T15:57:32.245Z,1532534252.245 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-07-25T15:57:32.251Z,1532534252.251 [MassServo](DEBUG): Initializing EZServoServo. 2018-07-25T15:57:32.257Z,1532534252.257 [MassServo](DEBUG): Initializing MassServo. 2018-07-25T15:57:32.263Z,1532534252.263 [RudderServo](DEBUG): Initializing EZServoServo. 2018-07-25T15:57:32.269Z,1532534252.269 [RudderServo](DEBUG): Initializing RudderServo. 2018-07-25T15:57:32.275Z,1532534252.275 [ThrusterServo](DEBUG): Initializing EZServoServo. 2018-07-25T15:57:32.281Z,1532534252.281 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2018-07-25T15:57:32.417Z,1532534252.417 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2018-07-25T15:57:32.417Z,1532534252.417 [DropWeight] Hardware Fault, FailCount= 1 2018-07-25T15:57:32.417Z,1532534252.417 [DropWeight](ERROR): Hardware Fault 2018-07-25T15:57:32.485Z,1532534252.485 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:32.487Z,1532534252.487 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:32.514Z,1532534252.514 [CommandLine](FAULT): Scheduling is paused 2018-07-25T15:57:32.514Z,1532534252.514 [CBIT](INFO): Critical error at 20180725T155732 2018-07-25T15:57:32.514Z,1532534252.514 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2018-07-25T15:57:32.517Z,1532534252.517 [CBIT](ERROR): Hardware Fault in component: DropWeight 2018-07-25T15:57:32.518Z,1532534252.518 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2018-07-25T15:57:32.821Z,1532534252.821 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:32.829Z,1532534252.829 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:33.161Z,1532534253.161 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2018-07-25T15:57:33.161Z,1532534253.161 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2018-07-25T15:57:33.161Z,1532534253.161 [BuoyancyServo] Communications Fault, FailCount= 1 2018-07-25T15:57:33.161Z,1532534253.161 [BuoyancyServo](ERROR): Communications Fault 2018-07-25T15:57:33.371Z,1532534253.371 [CBIT](INFO): Critical error at 20180725T155732 2018-07-25T15:57:33.374Z,1532534253.374 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2018-07-25T15:57:33.453Z,1532534253.453 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:33.454Z,1532534253.454 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:33.467Z,1532534253.467 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-07-25T15:57:33.467Z,1532534253.467 [BuoyancyServo](INFO): Powering down 2018-07-25T15:57:33.877Z,1532534253.877 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:33.878Z,1532534253.878 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:34.297Z,1532534254.297 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:34.298Z,1532534254.298 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:34.657Z,1532534254.657 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:34.658Z,1532534254.658 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:35.057Z,1532534255.057 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:35.058Z,1532534255.058 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:35.469Z,1532534255.469 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:35.471Z,1532534255.471 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:35.851Z,1532534255.851 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:35.852Z,1532534255.852 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:36.093Z,1532534256.093 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2018-07-25T15:57:36.093Z,1532534256.093 [BuoyancyServo] No Fault, FailCount= 1 2018-07-25T15:57:36.241Z,1532534256.241 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:36.243Z,1532534256.243 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:36.259Z,1532534256.259 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-07-25T15:57:36.379Z,1532534256.379 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-07-25T15:57:36.695Z,1532534256.695 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:36.696Z,1532534256.696 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:37.054Z,1532534257.054 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:37.055Z,1532534257.055 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:37.437Z,1532534257.437 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:37.438Z,1532534257.438 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:37.839Z,1532534257.839 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:37.840Z,1532534257.840 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:38.254Z,1532534258.254 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:38.255Z,1532534258.255 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-25T15:57:45.425Z,1532534265.425 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2018-07-25T15:57:45.822Z,1532534265.822 [RDI_Pathfinder](ERROR): Failed to parse: All rights reserved. 2018-07-25T15:57:46.233Z,1532534266.233 [RDI_Pathfinder](ERROR): Failed to parse: Current time is: 18/07/25,15:57:10.80 2018-07-25T15:57:46.620Z,1532534266.620 [RDI_Pathfinder](ERROR): Failed to parse: > 2018-07-25T15:57:59.002Z,1532534279.002 [NAL9602](INFO): Powering up NAL9602 2018-07-25T15:57:59.505Z,1532534279.505 [SBIT](IMPORTANT): Beginning Startup BIT 2018-07-25T15:57:59.522Z,1532534279.522 [CBIT](IMPORTANT): Beginning ground fault scan 2018-07-25T15:58:09.966Z,1532534289.966 [NAL9602](INFO): NAL9602 initialized 2018-07-25T15:58:10.567Z,1532534290.567 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.019527 CHAN A1 (24V): -0.022648 CHAN A2 (12V): -0.007473 CHAN A3 (5V): -0.001910 CHAN B0 (3.3V): 0.000235 CHAN B1 (3.15aV): 0.000289 CHAN B2 (3.15bV): 0.000302 CHAN B3 (GND): 0.002191 OPEN: 0.006933 Full Scale Calc: 4.765 mA, -1.589 mA 2018-07-25T15:58:53.601Z,1532534333.601 [SBIT](IMPORTANT): SBIT PASSED 2018-07-25T15:58:53.663Z,1532534333.663 [CommandLine](IMPORTANT): got command configSet list 2018-07-25T15:58:53.663Z,1532534333.663 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2018-07-25T15:58:53.664Z,1532534333.664 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=300 cubic_centimeter; 2018-07-25T15:58:53.664Z,1532534333.664 [CommandLine](IMPORTANT): VerticalControl.massDefault=2 millimeter; 2018-07-25T15:58:54.001Z,1532534334.001 [MissionManager](IMPORTANT): Started mission Startup 2018-07-25T15:58:54.001Z,1532534334.001 [Startup] Running Loop=1 2018-07-25T15:58:54.001Z,1532534334.001 [Startup](DEBUG): Aggregate::initialize Startup 2018-07-25T15:58:54.002Z,1532534334.002 [Startup:A.GoToSurface] Running Loop=1 2018-07-25T15:58:54.002Z,1532534334.002 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-07-25T15:58:54.002Z,1532534334.002 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-07-25T15:58:54.003Z,1532534334.003 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-07-25T15:58:54.003Z,1532534334.003 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-07-25T15:58:54.004Z,1532534334.004 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-07-25T15:58:54.004Z,1532534334.004 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-07-25T15:58:54.010Z,1532534334.010 [Startup:StartupSatComms] Running Loop=1 2018-07-25T15:58:54.011Z,1532534334.011 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2018-07-25T15:58:54.011Z,1532534334.011 [Startup:StartupSatComms:A] Running Loop=1 2018-07-25T15:58:54.402Z,1532534334.402 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2018-07-25T15:59:55.263Z,1532534395.263 [Startup:StartupSatComms:A](INFO): Timed out from 2018-07-25T15:58:54.0Z 2018-07-25T15:59:55.263Z,1532534395.263 [Startup:StartupSatComms:A] Stopped 2018-07-25T15:59:55.263Z,1532534395.263 [Startup:StartupSatComms:B] Running Loop=1 2018-07-25T15:59:55.491Z,1532534395.491 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-07-25T15:59:56.157Z,1532534396.157 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004301 2018-07-25T16:00:00.294Z,1532534400.294 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20180725T155714/Courier0000.lzma 2018-07-25T16:00:01.034Z,1532534401.034 [DataOverHttps](INFO): Moved sent file to Logs/20180725T155714/Courier0000.lzma.bak 2018-07-25T16:00:01.034Z,1532534401.034 [DataOverHttps](INFO): SBD MOMSN=8375760 2018-07-25T16:00:05.042Z,1532534405.042 [NAL9602](INFO): SBD MO Status=0, MOMSN=367, MT Status=0, MTMSN=0 2018-07-25T16:00:05.042Z,1532534405.042 [NAL9602](INFO): No messages in MT queue 2018-07-25T16:00:10.106Z,1532534410.106 [DataOverHttps](INFO): Sending 700 bytes from file Logs/20180725T155714/Express0001.lzma 2018-07-25T16:00:10.894Z,1532534410.894 [DataOverHttps](INFO): Moved sent file to Logs/20180725T155714/Express0001.lzma.bak 2018-07-25T16:00:10.894Z,1532534410.894 [DataOverHttps](INFO): SBD MOMSN=8375765 2018-07-25T16:00:11.358Z,1532534411.358 [Startup:StartupSatComms:B] Stopped 2018-07-25T16:00:11.358Z,1532534411.358 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2018-07-25T16:00:11.358Z,1532534411.358 [Startup:StartupSatComms] Stopped 2018-07-25T16:00:11.359Z,1532534411.359 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2018-07-25T16:00:11.360Z,1532534411.360 [Startup](INFO): Completed Startup 2018-07-25T16:00:11.360Z,1532534411.360 [MissionManager](INFO): Startup is completed. 2018-07-25T16:00:11.360Z,1532534411.360 [MissionManager](INFO): Uninitializing Mission Startup 2018-07-25T16:00:11.360Z,1532534411.360 [Startup] Stopped 2018-07-25T16:00:11.360Z,1532534411.360 [Startup](DEBUG): Aggregate::uninitialize Startup 2018-07-25T16:00:11.360Z,1532534411.360 [Startup:A.GoToSurface] Stopped 2018-07-25T16:00:11.360Z,1532534411.360 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-07-25T16:00:11.747Z,1532534411.747 [MissionManager](IMPORTANT): Started mission Default 2018-07-25T16:00:11.747Z,1532534411.747 [Default] Running Loop=1 2018-07-25T16:00:11.747Z,1532534411.747 [Default](DEBUG): Aggregate::initialize Default 2018-07-25T16:00:11.748Z,1532534411.748 [Default:B.GoToSurface] Running Loop=1 2018-07-25T16:00:11.748Z,1532534411.748 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-07-25T16:00:11.748Z,1532534411.748 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-07-25T16:00:11.748Z,1532534411.748 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-07-25T16:00:11.749Z,1532534411.749 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-07-25T16:00:11.749Z,1532534411.749 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-07-25T16:00:11.750Z,1532534411.750 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-07-25T16:00:11.750Z,1532534411.750 [Default:A.Wait] Running Loop=1 2018-07-25T16:00:11.750Z,1532534411.750 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-07-25T16:00:25.071Z,1532534425.071 [Default:A.Wait](INFO): Done Waiting. 2018-07-25T16:00:25.072Z,1532534425.072 [Default:A.Wait] Stopped 2018-07-25T16:00:25.072Z,1532534425.072 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-07-25T16:00:25.474Z,1532534425.474 [Default:CheckIn] Running Loop=1 2018-07-25T16:00:25.474Z,1532534425.474 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-25T16:00:25.474Z,1532534425.474 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-25T16:00:25.847Z,1532534425.847 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2018-07-25T16:00:31.471Z,1532534431.471 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-07-25T16:00:31.471Z,1532534431.471 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2018-07-25T16:00:31.471Z,1532534431.471 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2018-07-25T16:00:31.474Z,1532534431.474 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-07-25T16:00:31.474Z,1532534431.474 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2018-07-25T16:00:31.474Z,1532534431.474 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-07-25T16:00:31.504Z,1532534431.504 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2018-07-25T16:00:31.504Z,1532534431.504 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-07-25T16:00:31.884Z,1532534431.884 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2018-07-25T16:00:31.884Z,1532534431.884 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2018-07-25T16:00:31.889Z,1532534431.889 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-07-25T16:00:31.889Z,1532534431.889 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2018-07-25T16:00:32.239Z,1532534432.239 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-07-25T16:00:32.240Z,1532534432.240 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-07-25T16:00:32.240Z,1532534432.240 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-07-25T16:00:32.240Z,1532534432.240 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-07-25T16:00:32.257Z,1532534432.257 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-07-25T16:00:32.258Z,1532534432.258 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-07-25T16:00:32.668Z,1532534432.668 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s. 2018-07-25T16:00:33.036Z,1532534433.036 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s. 2018-07-25T16:00:33.448Z,1532534433.448 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s. 2018-07-25T16:00:33.853Z,1532534433.853 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s. 2018-07-25T16:00:34.249Z,1532534434.249 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s. 2018-07-25T16:00:34.640Z,1532534434.640 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s. 2018-07-25T16:00:35.074Z,1532534435.074 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s. 2018-07-25T16:00:35.459Z,1532534435.459 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s. 2018-07-25T16:00:35.843Z,1532534435.843 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s. 2018-07-25T16:00:36.250Z,1532534436.250 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s. 2018-07-25T16:00:36.693Z,1532534436.693 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s. 2018-07-25T16:00:37.059Z,1532534437.059 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s. 2018-07-25T16:00:37.455Z,1532534437.455 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s. 2018-07-25T16:00:37.847Z,1532534437.847 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s. 2018-07-25T16:00:38.252Z,1532534438.252 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s. 2018-07-25T16:00:38.650Z,1532534438.650 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s. 2018-07-25T16:00:39.055Z,1532534439.055 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s. 2018-07-25T16:00:39.461Z,1532534439.461 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s. 2018-07-25T16:00:39.850Z,1532534439.850 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s. 2018-07-25T16:00:40.259Z,1532534440.259 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s. 2018-07-25T16:00:40.655Z,1532534440.655 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s. 2018-07-25T16:00:41.024Z,1532534441.024 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s. 2018-07-25T16:00:41.469Z,1532534441.469 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s. 2018-07-25T16:00:41.851Z,1532534441.851 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s. 2018-07-25T16:00:42.262Z,1532534442.262 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s. 2018-07-25T16:00:42.661Z,1532534442.661 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s. 2018-07-25T16:00:43.051Z,1532534443.051 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s. 2018-07-25T16:00:43.446Z,1532534443.446 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s. 2018-07-25T16:00:43.866Z,1532534443.866 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.4 s old, using for 20.0 s. 2018-07-25T16:00:44.237Z,1532534444.237 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.8 s old, using for 20.0 s. 2018-07-25T16:00:44.635Z,1532534444.635 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s. 2018-07-25T16:00:45.052Z,1532534445.052 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s. 2018-07-25T16:00:45.452Z,1532534445.452 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.0 s old, using for 20.0 s. 2018-07-25T16:00:45.856Z,1532534445.856 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.4 s old, using for 20.0 s. 2018-07-25T16:00:46.252Z,1532534446.252 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.8 s old, using for 20.0 s. 2018-07-25T16:00:46.651Z,1532534446.651 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.2 s old, using for 20.0 s. 2018-07-25T16:00:47.040Z,1532534447.040 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s. 2018-07-25T16:00:47.469Z,1532534447.469 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s. 2018-07-25T16:00:47.887Z,1532534447.887 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s. 2018-07-25T16:00:48.268Z,1532534448.268 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.8 s old, using for 20.0 s. 2018-07-25T16:00:48.663Z,1532534448.663 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s. 2018-07-25T16:00:49.056Z,1532534449.056 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.6 s old, using for 20.0 s. 2018-07-25T16:00:49.453Z,1532534449.453 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.0 s old, using for 20.0 s. 2018-07-25T16:00:49.843Z,1532534449.843 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s. 2018-07-25T16:00:50.248Z,1532534450.248 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.8 s old, using for 20.0 s. 2018-07-25T16:00:50.652Z,1532534450.652 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.2 s old, using for 20.0 s. 2018-07-25T16:00:51.047Z,1532534451.047 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s. 2018-07-25T16:00:51.469Z,1532534451.469 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 20.0 s old, using for 20.0 s. 2018-07-25T16:01:30.847Z,1532534490.847 [CommandLine](IMPORTANT): got command burn 5.000000 2018-07-25T16:01:35.869Z,1532534495.869 [CommandLine](IMPORTANT): Deactivating dropweight wire 2018-07-25T16:02:02.740Z,1532534522.740 [CommandLine](IMPORTANT): got command burn 5.000000 2018-07-25T16:02:07.769Z,1532534527.769 [CommandLine](IMPORTANT): Deactivating dropweight wire 2018-07-25T16:02:53.635Z,1532534573.635 [CommandLine](IMPORTANT): got command burn 5.000000 2018-07-25T16:02:58.657Z,1532534578.657 [CommandLine](IMPORTANT): Deactivating dropweight wire 2018-07-25T16:03:16.633Z,1532534596.633 [RDI_Pathfinder](ERROR): Failed to parse: :HM,G,G,0e87,0e88, 14.590, -0.061, 0.000 2018-07-25T16:03:17.033Z,1532534597.033 [RDI_Pathfinder](ERROR): Failed to parse::SA, +0.00, +0.00, 0.00 2018-07-25T16:03:17.442Z,1532534597.442 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2018-07-25T16:03:17.857Z,1532534597.857 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2018-07-25T16:03:18.254Z,1532534598.254 [RDI_Pathfinder](ERROR): Failed to parse: :HM,G,G,0e87,0e88, 14.590, -0.061, 0.000 2018-07-25T16:03:18.636Z,1532534598.636 [RDI_Pathfinder](ERROR): Failed to parse::SA, +0.00, +0.00, 0.00 2018-07-25T16:03:19.045Z,1532534599.045 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2018-07-25T16:03:19.454Z,1532534599.454 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2018-07-25T16:03:19.843Z,1532534599.843 [RDI_Pathfinder](ERROR): Failed to parse: :HM,G,G,0e87,0e87, 14.590, -0.061, 0.000 2018-07-25T16:03:20.252Z,1532534600.252 [RDI_Pathfinder](ERROR): Failed to parse::SA, +0.00, +0.00, 0.00 2018-07-25T16:03:20.656Z,1532534600.656 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2018-07-25T16:03:21.055Z,1532534601.055 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2018-07-25T16:03:21.459Z,1532534601.459 [RDI_Pathfinder](ERROR): Failed to parse: :HM,G,G,0e87,0e88, 14.590, -0.061, 0.000 2018-07-25T16:03:21.827Z,1532534601.827 [RDI_Pathfinder](ERROR): Failed to parse::SA, +0.00, +0.00, 0.00 2018-07-25T16:03:22.244Z,1532534602.244 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2018-07-25T16:03:22.656Z,1532534602.656 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2018-07-25T16:03:23.063Z,1532534603.063 [RDI_Pathfinder](ERROR): Failed to parse: :HM,G,G,0e87,0e87, 14.590, -0.061, 0.000 2018-07-25T16:03:23.449Z,1532534603.449 [RDI_Pathfinder](ERROR): Failed to parse::SA, +0.00, +0.00, 0.00 2018-07-25T16:03:23.853Z,1532534603.853 [RDI_Pathfinder](ERROR): Failed to parse: :BI,-32768,-32768,-32768,-32768,V 2018-07-25T16:03:24.249Z,1532534604.249 [RDI_Pathfinder](ERROR): Failed to parse: :BE,-32768,-32768,-32768,V 2018-07-25T16:03:24.648Z,1532534604.648 [RDI_Pathfinder](ERROR): Failed to parse: :HM,G,G,0e87,0e87, 14.590, -0.061, 0.000 2018-07-25T16:03:25.030Z,1532534605.030 [RDI_Pathfinder](ERROR): Failed to parse::SA, +0.00, +0.00, 0.00 2018-07-25T16:03:25.433Z,1532534605.433 [RDI_Pathfinder](ERROR): No DVL communication! Re-initializing 2018-07-25T16:03:25.434Z,1532534605.434 [RDI_Pathfinder] Communications Fault, FailCount= 1 2018-07-25T16:03:25.434Z,1532534605.434 [RDI_Pathfinder](ERROR): Communications Fault 2018-07-25T16:03:25.509Z,1532534605.509 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2018-07-25T16:03:25.921Z,1532534605.921 [RDI_Pathfinder](INFO): Powering down 2018-07-25T16:03:26.685Z,1532534606.685 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2018-07-25T16:03:26.685Z,1532534606.685 [RDI_Pathfinder] No Fault, FailCount= 1 2018-07-25T16:03:32.280Z,1532534612.280 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-07-25T16:03:32.297Z,1532534612.297 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2018-07-25T16:03:32.297Z,1532534612.297 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2018-07-25T16:03:32.299Z,1532534612.299 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-07-25T16:03:32.299Z,1532534612.299 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2018-07-25T16:03:32.299Z,1532534612.299 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-07-25T16:03:32.341Z,1532534612.341 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2018-07-25T16:03:32.341Z,1532534612.341 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-07-25T16:03:32.660Z,1532534612.660 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2018-07-25T16:03:32.660Z,1532534612.660 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2018-07-25T16:03:32.661Z,1532534612.661 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-07-25T16:03:32.661Z,1532534612.661 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2018-07-25T16:03:33.039Z,1532534613.039 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2018-07-25T16:03:33.039Z,1532534613.039 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2018-07-25T16:03:33.040Z,1532534613.040 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2018-07-25T16:03:33.040Z,1532534613.040 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-07-25T16:03:33.053Z,1532534613.053 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-07-25T16:03:33.053Z,1532534613.053 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-07-25T16:03:33.436Z,1532534613.436 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s. 2018-07-25T16:03:33.848Z,1532534613.848 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s. 2018-07-25T16:03:34.239Z,1532534614.239 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s. 2018-07-25T16:03:34.668Z,1532534614.668 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s. 2018-07-25T16:03:35.065Z,1532534615.065 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s. 2018-07-25T16:03:35.465Z,1532534615.465 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s. 2018-07-25T16:03:35.842Z,1532534615.842 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s. 2018-07-25T16:03:36.248Z,1532534616.248 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s. 2018-07-25T16:03:36.647Z,1532534616.647 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s. 2018-07-25T16:03:37.048Z,1532534617.048 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s. 2018-07-25T16:03:37.446Z,1532534617.446 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s. 2018-07-25T16:03:37.851Z,1532534617.851 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s. 2018-07-25T16:03:38.247Z,1532534618.247 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s. 2018-07-25T16:03:38.650Z,1532534618.650 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s. 2018-07-25T16:03:39.043Z,1532534619.043 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s. 2018-07-25T16:03:39.452Z,1532534619.452 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s. 2018-07-25T16:03:39.855Z,1532534619.855 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s. 2018-07-25T16:03:40.258Z,1532534620.258 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.0 s old, using for 20.0 s. 2018-07-25T16:03:40.643Z,1532534620.643 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder 2018-07-25T16:03:40.652Z,1532534620.652 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s. 2018-07-25T16:03:41.045Z,1532534621.045 [RDI_Pathfinder](ERROR): Failed to parse: All rights reserved. 2018-07-25T16:03:41.079Z,1532534621.079 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s. 2018-07-25T16:03:41.459Z,1532534621.459 [RDI_Pathfinder](ERROR): Failed to parse: Current time is: 18/07/25,16:03:05.71 2018-07-25T16:03:41.468Z,1532534621.468 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s. 2018-07-25T16:03:41.827Z,1532534621.827 [RDI_Pathfinder](ERROR): Failed to parse: > 2018-07-25T16:03:41.871Z,1532534621.871 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s. 2018-07-25T16:03:42.299Z,1532534622.299 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.0 s old, using for 20.0 s. 2018-07-25T16:03:42.655Z,1532534622.655 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.4 s old, using for 20.0 s. 2018-07-25T16:03:43.068Z,1532534623.068 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s. 2018-07-25T16:03:43.488Z,1532534623.488 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s. 2018-07-25T16:03:43.889Z,1532534623.889 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s. 2018-07-25T16:03:44.306Z,1532534624.306 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s. 2018-07-25T16:03:44.648Z,1532534624.648 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.4 s old, using for 20.0 s. 2018-07-25T16:03:45.043Z,1532534625.043 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.8 s old, using for 20.0 s. 2018-07-25T16:03:45.469Z,1532534625.469 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.2 s old, using for 20.0 s. 2018-07-25T16:03:45.848Z,1532534625.848 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 13.6 s old, using for 20.0 s. 2018-07-25T16:03:46.242Z,1532534626.242 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.0 s old, using for 20.0 s. 2018-07-25T16:03:46.663Z,1532534626.663 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.4 s old, using for 20.0 s. 2018-07-25T16:03:47.060Z,1532534627.060 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 14.8 s old, using for 20.0 s. 2018-07-25T16:03:47.478Z,1532534627.478 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.2 s old, using for 20.0 s. 2018-07-25T16:03:47.856Z,1532534627.856 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 15.6 s old, using for 20.0 s. 2018-07-25T16:03:48.250Z,1532534628.250 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.0 s old, using for 20.0 s. 2018-07-25T16:03:48.667Z,1532534628.667 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.4 s old, using for 20.0 s. 2018-07-25T16:03:49.053Z,1532534629.053 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 16.8 s old, using for 20.0 s. 2018-07-25T16:03:49.468Z,1532534629.468 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.2 s old, using for 20.0 s. 2018-07-25T16:03:49.897Z,1532534629.897 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 17.6 s old, using for 20.0 s. 2018-07-25T16:03:50.286Z,1532534630.286 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.0 s old, using for 20.0 s. 2018-07-25T16:03:50.659Z,1532534630.659 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.4 s old, using for 20.0 s. 2018-07-25T16:03:51.056Z,1532534631.056 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 18.8 s old, using for 20.0 s. 2018-07-25T16:03:51.472Z,1532534631.472 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.2 s old, using for 20.0 s. 2018-07-25T16:03:51.858Z,1532534631.858 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 19.6 s old, using for 20.0 s. 2018-07-25T16:03:52.270Z,1532534632.270 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 20.0 s old, using for 20.0 s. 2018-07-25T16:05:25.644Z,1532534725.644 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-07-25T16:00:25.5Z 2018-07-25T16:05:25.644Z,1532534725.644 [Default:CheckIn:Read_GPS] Stopped 2018-07-25T16:05:25.644Z,1532534725.644 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-25T16:05:26.024Z,1532534726.024 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-07-25T16:05:30.733Z,1532534730.733 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20180725T155714/Courier0004.lzma 2018-07-25T16:05:31.469Z,1532534731.469 [DataOverHttps](INFO): Moved sent file to Logs/20180725T155714/Courier0004.lzma.bak 2018-07-25T16:05:31.470Z,1532534731.470 [DataOverHttps](INFO): SBD MOMSN=8375783 2018-07-25T16:05:40.642Z,1532534740.642 [DataOverHttps](INFO): Sending 154 bytes from file Logs/20180725T155714/Express0005.lzma 2018-07-25T16:05:41.383Z,1532534741.383 [DataOverHttps](INFO): Moved sent file to Logs/20180725T155714/Express0005.lzma.bak 2018-07-25T16:05:41.383Z,1532534741.383 [DataOverHttps](INFO): SBD MOMSN=8375785 2018-07-25T16:05:41.832Z,1532534741.832 [Default:CheckIn:Read_Iridium] Stopped 2018-07-25T16:05:41.832Z,1532534741.832 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-25T16:05:41.832Z,1532534741.832 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-25T16:05:45.067Z,1532534745.067 [CommandLine](IMPORTANT): got command burn on 2018-07-25T16:05:45.067Z,1532534745.067 [CommandLine](IMPORTANT): Activating dropweight wire 2018-07-25T16:05:55.807Z,1532534755.807 [CommandLine](IMPORTANT): got command burn off 2018-07-25T16:05:55.807Z,1532534755.807 [CommandLine](IMPORTANT): Deactivating dropweight wire 2018-07-25T16:06:06.796Z,1532534766.796 [NAL9602](INFO): GPS fix at 20180725T160433: (36.802742, -121.787998) 2018-07-25T16:06:09.941Z,1532534769.941 [CommandLine](IMPORTANT): got command burn on 2018-07-25T16:06:09.941Z,1532534769.941 [CommandLine](IMPORTANT): Activating dropweight wire 2018-07-25T16:06:10.029Z,1532534770.029 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error 2018-07-25T16:06:10.029Z,1532534770.029 [RDI_Pathfinder](ERROR): Failed to parse: :TS,18072516054478,35.0, -0.1,448.9, 0 2018-07-25T16:06:10.394Z,1532534770.394 [RDI_Pathfinder](ERROR): Failed to parse: :BS,-32768,-32768,-32768,V 2018-07-25T16:06:10.796Z,1532534770.796 [RDI_Pathfinder](ERROR): Failed to parse: :BD, +0.00, +0.00, +0.00, 0.00,149.00 2018-07-25T16:06:11.189Z,1532534771.189 [RDI_Pathfinder](ERROR): Failed to parse: 2018-07-25T16:06:38.476Z,1532534798.476 [CommandLi