2018-10-16T22:40:10.523Z,1539729610.523 [Supervisor](DEBUG): Initializing supervisor. 2018-10-16T22:40:10.525Z,1539729610.525 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2018-10-16T22:40:10.526Z,1539729610.526 [SyncHandler](INFO): Protected caller Thread ID is 8221 2018-10-16T22:40:10.526Z,1539729610.526 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2018-10-16T22:40:10.527Z,1539729610.527 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2018-10-16T22:40:10.528Z,1539729610.528 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8222 2018-10-16T22:40:10.530Z,1539729610.530 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2018-10-16T22:40:10.542Z,1539729610.542 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2018-10-16T22:40:10.543Z,1539729610.543 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2018-10-16T22:40:10.543Z,1539729610.543 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8223 2018-10-16T22:40:10.544Z,1539729610.544 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2018-10-16T22:40:10.545Z,1539729610.545 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2018-10-16T22:40:10.545Z,1539729610.545 [logger ThreadHandler](INFO): Protected caller Thread ID is 8224 2018-10-16T22:40:10.547Z,1539729610.547 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2018-10-16T22:40:10.548Z,1539729610.548 [Supervisor](INFO): Looking for Config files in directory: Config/ 2018-10-16T22:40:10.549Z,1539729610.549 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2018-10-16T22:40:10.884Z,1539729610.884 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2018-10-16T22:40:10.885Z,1539729610.885 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2018-10-16T22:40:11.088Z,1539729611.088 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2018-10-16T22:40:11.088Z,1539729611.088 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2018-10-16T22:40:11.392Z,1539729611.392 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2018-10-16T22:40:11.393Z,1539729611.393 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2018-10-16T22:40:11.539Z,1539729611.539 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2018-10-16T22:40:11.540Z,1539729611.540 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2018-10-16T22:40:11.638Z,1539729611.638 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2018-10-16T22:40:11.639Z,1539729611.639 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2018-10-16T22:40:12.114Z,1539729612.114 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2018-10-16T22:40:12.115Z,1539729612.115 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2018-10-16T22:40:12.587Z,1539729612.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2018-10-16T22:40:12.588Z,1539729612.588 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2018-10-16T22:40:13.069Z,1539729613.069 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2018-10-16T22:40:13.070Z,1539729613.070 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2018-10-16T22:40:13.173Z,1539729613.173 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2018-10-16T22:40:13.174Z,1539729613.174 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2018-10-16T22:40:13.306Z,1539729613.306 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2018-10-16T22:40:13.307Z,1539729613.307 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2018-10-16T22:40:13.565Z,1539729613.565 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2018-10-16T22:40:13.566Z,1539729613.566 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2018-10-16T22:40:13.773Z,1539729613.773 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2018-10-16T22:40:13.773Z,1539729613.773 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2018-10-16T22:40:14.132Z,1539729614.132 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2018-10-16T22:40:14.133Z,1539729614.133 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2018-10-16T22:40:14.279Z,1539729614.279 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2018-10-16T22:40:14.280Z,1539729614.280 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2018-10-16T22:40:14.361Z,1539729614.361 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2018-10-16T22:40:14.362Z,1539729614.362 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2018-10-16T22:40:14.464Z,1539729614.464 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2018-10-16T22:40:14.584Z,1539729614.584 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2018-10-16T22:40:14.679Z,1539729614.679 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2018-10-16T22:40:14.763Z,1539729614.763 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2018-10-16T22:40:14.929Z,1539729614.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2018-10-16T22:40:15.112Z,1539729615.112 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2018-10-16T22:40:15.188Z,1539729615.188 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2018-10-16T22:40:15.454Z,1539729615.454 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2018-10-16T22:40:15.454Z,1539729615.454 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2018-10-16T22:40:15.709Z,1539729615.709 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2018-10-16T22:40:15.920Z,1539729615.920 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2018-10-16T22:40:16.144Z,1539729616.144 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2018-10-16T22:40:16.586Z,1539729616.586 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2018-10-16T22:40:16.587Z,1539729616.587 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2018-10-16T22:40:16.599Z,1539729616.599 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2018-10-16T22:40:16.873Z,1539729616.873 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2018-10-16T22:40:16.873Z,1539729616.873 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2018-10-16T22:40:16.920Z,1539729616.920 [DepthRateCalculator] Loaded 2018-10-16T22:40:16.920Z,1539729616.920 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2018-10-16T22:40:16.926Z,1539729616.926 [PitchRateCalculator] Loaded 2018-10-16T22:40:16.927Z,1539729616.927 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2018-10-16T22:40:16.944Z,1539729616.944 [SpeedCalculator] Loaded 2018-10-16T22:40:16.944Z,1539729616.944 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2018-10-16T22:40:16.966Z,1539729616.966 [TempGradientCalculator] Loaded 2018-10-16T22:40:16.966Z,1539729616.966 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2018-10-16T22:40:16.972Z,1539729616.972 [YawRateCalculator] Loaded 2018-10-16T22:40:16.973Z,1539729616.973 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2018-10-16T22:40:17.014Z,1539729617.014 [ElevatorOffsetCalculator] Loaded 2018-10-16T22:40:17.015Z,1539729617.015 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2018-10-16T22:40:17.015Z,1539729617.015 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2018-10-16T22:40:17.015Z,1539729617.015 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2018-10-16T22:40:17.087Z,1539729617.087 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2018-10-16T22:40:17.087Z,1539729617.087 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2018-10-16T22:40:17.211Z,1539729617.211 [BuoyancyServo] Loaded 2018-10-16T22:40:17.211Z,1539729617.211 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2018-10-16T22:40:17.226Z,1539729617.226 [ElevatorServo] Loaded 2018-10-16T22:40:17.226Z,1539729617.226 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2018-10-16T22:40:17.242Z,1539729617.242 [MassServo] Loaded 2018-10-16T22:40:17.242Z,1539729617.242 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2018-10-16T22:40:17.258Z,1539729617.258 [RudderServo] Loaded 2018-10-16T22:40:17.258Z,1539729617.258 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2018-10-16T22:40:17.272Z,1539729617.272 [ThrusterServo] Loaded 2018-10-16T22:40:17.273Z,1539729617.273 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2018-10-16T22:40:17.273Z,1539729617.273 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2018-10-16T22:40:17.274Z,1539729617.274 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2018-10-16T22:40:17.288Z,1539729617.288 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2018-10-16T22:40:17.288Z,1539729617.288 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2018-10-16T22:40:17.403Z,1539729617.403 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2018-10-16T22:40:17.404Z,1539729617.404 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2018-10-16T22:40:17.719Z,1539729617.719 [DataOverHttps] Loaded 2018-10-16T22:40:17.719Z,1539729617.719 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2018-10-16T22:40:17.734Z,1539729617.734 [Depth_Keller] Loaded 2018-10-16T22:40:17.734Z,1539729617.734 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2018-10-16T22:40:17.739Z,1539729617.739 [DropWeight] Loaded 2018-10-16T22:40:17.739Z,1539729617.739 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2018-10-16T22:40:17.845Z,1539729617.845 [NAL9602] Loaded 2018-10-16T22:40:17.845Z,1539729617.845 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2018-10-16T22:40:17.862Z,1539729617.862 [Onboard] Loaded 2018-10-16T22:40:17.862Z,1539729617.862 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2018-10-16T22:40:17.873Z,1539729617.873 [Radio_Surface] Loaded 2018-10-16T22:40:17.874Z,1539729617.874 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2018-10-16T22:40:17.875Z,1539729617.875 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4088F4E0 2018-10-16T22:40:17.875Z,1539729617.875 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8307 2018-10-16T22:40:17.925Z,1539729617.925 [PNI_TCM] Loaded 2018-10-16T22:40:17.925Z,1539729617.925 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2018-10-16T22:40:17.989Z,1539729617.989 [Rowe_600LCM] Loaded 2018-10-16T22:40:17.990Z,1539729617.990 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2018-10-16T22:40:17.991Z,1539729617.991 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408BF4E0 2018-10-16T22:40:17.991Z,1539729617.991 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 8308 2018-10-16T22:40:17.992Z,1539729617.992 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2018-10-16T22:40:17.992Z,1539729617.992 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2018-10-16T22:40:18.139Z,1539729618.139 [SBIT](DEBUG): Construct Startup Built In Test. 2018-10-16T22:40:18.162Z,1539729618.162 [SBIT] Loaded 2018-10-16T22:40:18.163Z,1539729618.163 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2018-10-16T22:40:18.163Z,1539729618.163 [IBIT](DEBUG): Construct Initiated Built In Test. 2018-10-16T22:40:18.176Z,1539729618.176 [IBIT] Loaded 2018-10-16T22:40:18.176Z,1539729618.176 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2018-10-16T22:40:18.179Z,1539729618.179 [CBIT](DEBUG): Construct Continuous Built In Test. 2018-10-16T22:40:18.335Z,1539729618.335 [CBIT] Loaded 2018-10-16T22:40:18.336Z,1539729618.336 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2018-10-16T22:40:18.336Z,1539729618.336 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2018-10-16T22:40:18.337Z,1539729618.337 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2018-10-16T22:40:18.511Z,1539729618.511 [Aanderaa_O2] Loaded 2018-10-16T22:40:18.511Z,1539729618.511 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2018-10-16T22:40:18.527Z,1539729618.527 [PAR_Licor] Loaded 2018-10-16T22:40:18.527Z,1539729618.527 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2018-10-16T22:40:18.579Z,1539729618.579 [WetLabsBB2FL] Loaded 2018-10-16T22:40:18.579Z,1539729618.579 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2018-10-16T22:40:18.580Z,1539729618.580 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4098A4E0 2018-10-16T22:40:18.581Z,1539729618.581 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8309 2018-10-16T22:40:18.582Z,1539729618.582 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2018-10-16T22:40:18.582Z,1539729618.582 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2018-10-16T22:40:18.659Z,1539729618.659 [VerticalControl](DEBUG): Construct VerticalControl. 2018-10-16T22:40:18.745Z,1539729618.745 [VerticalControl] Loaded 2018-10-16T22:40:18.746Z,1539729618.746 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2018-10-16T22:40:18.746Z,1539729618.746 [HorizontalControl](DEBUG): Construct HorizontalControl. 2018-10-16T22:40:18.806Z,1539729618.806 [HorizontalControl] Loaded 2018-10-16T22:40:18.806Z,1539729618.806 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2018-10-16T22:40:18.807Z,1539729618.807 [SpeedControl](DEBUG): Construct SpeedControl. 2018-10-16T22:40:18.809Z,1539729618.809 [SpeedControl] Loaded 2018-10-16T22:40:18.809Z,1539729618.809 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2018-10-16T22:40:18.810Z,1539729618.810 [LoopControl](DEBUG): Construct LoopControl. 2018-10-16T22:40:18.810Z,1539729618.810 [LoopControl] Loaded 2018-10-16T22:40:18.810Z,1539729618.810 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2018-10-16T22:40:18.811Z,1539729618.811 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2018-10-16T22:40:18.811Z,1539729618.811 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2018-10-16T22:40:18.838Z,1539729618.838 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2018-10-16T22:40:18.838Z,1539729618.838 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2018-10-16T22:40:18.934Z,1539729618.934 [DeadReckonUsingSpeedCalculator] Loaded 2018-10-16T22:40:18.934Z,1539729618.934 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2018-10-16T22:40:18.951Z,1539729618.951 [NavChart] Loaded 2018-10-16T22:40:18.951Z,1539729618.951 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2018-10-16T22:40:18.955Z,1539729618.955 [UniversalFixResidualReporter] Loaded 2018-10-16T22:40:18.955Z,1539729618.955 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2018-10-16T22:40:18.956Z,1539729618.956 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2018-10-16T22:40:18.959Z,1539729618.959 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2018-10-16T22:40:18.960Z,1539729618.960 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2018-10-16T22:40:18.967Z,1539729618.967 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2018-10-16T22:40:18.968Z,1539729618.968 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A164E0 2018-10-16T22:40:18.968Z,1539729618.968 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8310 2018-10-16T22:40:18.973Z,1539729618.973 [Supervisor](INFO): Main Thread ID is 8220 2018-10-16T22:40:18.973Z,1539729618.973 [Supervisor](DEBUG): Running supervisor. 2018-10-16T22:40:18.974Z,1539729618.974 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8311 2018-10-16T22:40:18.976Z,1539729618.976 [controlThread ThreadHandler](INFO): Handler Thread ID is 8312 2018-10-16T22:40:18.977Z,1539729618.977 [controlThread](DEBUG): Initializing ControlThread 2018-10-16T22:40:18.978Z,1539729618.978 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-10-16T22:40:18.978Z,1539729618.978 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2018-10-16T22:40:18.978Z,1539729618.978 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2018-10-16T22:40:18.979Z,1539729618.979 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2018-10-16T22:40:18.979Z,1539729618.979 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2018-10-16T22:40:18.980Z,1539729618.980 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2018-10-16T22:40:18.987Z,1539729618.987 [SBIT](INFO): Initialize SBIT Component. 2018-10-16T22:40:18.988Z,1539729618.988 [SBIT](IMPORTANT): git: 2018-10-09-25-gf1894f1 2018-10-16T22:40:18.988Z,1539729618.988 [SBIT](INFO): git hash: f1894f15ea8e4c49c3f23e64e2ef160a516712eb 2018-10-16T22:40:18.988Z,1539729618.988 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2018-10-16T22:40:18.988Z,1539729618.988 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018 2018-10-16T22:40:18.990Z,1539729618.990 [SBIT](INFO): Beginning SBIT in 36.000000 seconds. 2018-10-16T22:40:18.990Z,1539729618.990 [IBIT](INFO): Initialize IBIT Component. 2018-10-16T22:40:18.991Z,1539729618.991 [CBIT](DEBUG): Initialize CBIT Component. 2018-10-16T22:40:18.991Z,1539729618.991 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2018-10-16T22:40:18.992Z,1539729618.992 [logger ThreadHandler](INFO): Handler Thread ID is 8313 2018-10-16T22:40:19.009Z,1539729619.009 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8314 2018-10-16T22:40:19.015Z,1539729619.015 [Radio_Surface](INFO): Powering up 2018-10-16T22:40:19.021Z,1539729619.021 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 8315 2018-10-16T22:40:19.022Z,1539729619.022 [Rowe_600LCM](INFO): Initializing 2018-10-16T22:40:19.022Z,1539729619.022 [Rowe_600LCM](INFO): Checking LCM 2018-10-16T22:40:19.031Z,1539729619.031 [Rowe_600LCM](INFO): LCM OK 2018-10-16T22:40:19.032Z,1539729619.032 [Rowe_600LCM](INFO): Powering up 2018-10-16T22:40:19.037Z,1539729619.037 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8316 2018-10-16T22:40:19.039Z,1539729619.039 [WetLabsBB2FL](INFO): Powering down 2018-10-16T22:40:19.065Z,1539729619.065 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8317 2018-10-16T22:40:19.068Z,1539729619.068 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2018-10-16T22:40:19.069Z,1539729619.069 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2018-10-16T22:40:19.069Z,1539729619.069 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2018-10-16T22:40:19.069Z,1539729619.069 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2018-10-16T22:40:19.069Z,1539729619.069 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2018-10-16T22:40:19.070Z,1539729619.070 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2018-10-16T22:40:19.070Z,1539729619.070 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2018-10-16T22:40:19.070Z,1539729619.070 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2018-10-16T22:40:19.070Z,1539729619.070 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2018-10-16T22:40:19.070Z,1539729619.070 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2018-10-16T22:40:19.071Z,1539729619.071 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2018-10-16T22:40:19.071Z,1539729619.071 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2018-10-16T22:40:19.071Z,1539729619.071 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2018-10-16T22:40:19.071Z,1539729619.071 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2018-10-16T22:40:19.072Z,1539729619.072 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2018-10-16T22:40:19.072Z,1539729619.072 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2018-10-16T22:40:19.101Z,1539729619.101 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2018-10-16T22:40:19.103Z,1539729619.103 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2018-10-16T22:40:19.104Z,1539729619.104 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2018-10-16T22:40:19.104Z,1539729619.104 [LoopControl](DEBUG): Initialize LoopControlComponent. 2018-10-16T22:40:19.105Z,1539729619.105 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-16T22:40:19.105Z,1539729619.105 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-16T22:40:19.106Z,1539729619.106 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-16T22:40:19.106Z,1539729619.106 [NavChart](DEBUG): Initialize NavChart Navigation. 2018-10-16T22:40:19.107Z,1539729619.107 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2018-10-16T22:40:19.108Z,1539729619.108 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2018-10-16T22:40:19.134Z,1539729619.134 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2018-10-16T22:40:19.175Z,1539729619.175 [MissionManager](DEBUG): 2018-10-16T22:40:19.176Z,1539729619.176 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2018-10-16T22:40:19.250Z,1539729619.250 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2018-10-16T22:40:19.251Z,1539729619.251 [Default:A.Wait](DEBUG): Construct Wait. 2018-10-16T22:40:19.267Z,1539729619.267 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2018-10-16T22:40:19.298Z,1539729619.298 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2018-10-16T22:40:19.317Z,1539729619.317 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2018-10-16T22:40:19.334Z,1539729619.334 [Default:E.Execute](DEBUG): Construct Execute. 2018-10-16T22:40:19.338Z,1539729619.338 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2018-10-16T22:40:19.353Z,1539729619.353 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-10-16T22:40:19.365Z,1539729619.365 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2018-10-16T22:40:19.374Z,1539729619.374 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2018-10-16T22:40:19.673Z,1539729619.673 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-10-16T22:40:19.877Z,1539729619.877 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-10-16T22:40:19.885Z,1539729619.885 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-10-16T22:40:19.891Z,1539729619.891 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-10-16T22:40:19.897Z,1539729619.897 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-10-16T22:40:19.903Z,1539729619.903 [MassServo](DEBUG): Initializing EZServoServo. 2018-10-16T22:40:19.909Z,1539729619.909 [MassServo](DEBUG): Initializing MassServo. 2018-10-16T22:40:19.915Z,1539729619.915 [RudderServo](DEBUG): Initializing EZServoServo. 2018-10-16T22:40:19.921Z,1539729619.921 [RudderServo](DEBUG): Initializing RudderServo. 2018-10-16T22:40:19.943Z,1539729619.943 [ThrusterServo](DEBUG): Initializing EZServoServo. 2018-10-16T22:40:19.949Z,1539729619.949 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2018-10-16T22:40:23.319Z,1539729623.319 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-10-16T22:40:23.440Z,1539729623.440 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null & 2018-10-16T22:40:23.506Z,1539729623.506 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-10-16T22:40:23.507Z,1539729623.507 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-10-16T22:40:23.507Z,1539729623.507 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-10-16T22:40:30.953Z,1539729630.953 [Aanderaa_O2](INFO): Powering down 2018-10-16T22:40:31.310Z,1539729631.310 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003972 2018-10-16T22:40:48.111Z,1539729648.111 [NAL9602](INFO): Powering up NAL9602 2018-10-16T22:40:55.447Z,1539729655.447 [SBIT](IMPORTANT): Beginning Startup BIT 2018-10-16T22:40:55.478Z,1539729655.478 [CBIT](IMPORTANT): Beginning ground fault scan 2018-10-16T22:40:59.123Z,1539729659.123 [NAL9602](INFO): NAL9602 initialized 2018-10-16T22:41:06.842Z,1539729666.842 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.004694 CHAN A1 (24V): -0.008788 CHAN A2 (12V): -0.002280 CHAN A3 (5V): -0.001642 CHAN B0 (3.3V): 0.000078 CHAN B1 (3.15aV): -0.000622 CHAN B2 (3.15bV): -0.000279 CHAN B3 (GND): 0.000043 OPEN: -0.000612 Full Scale Calc: 4.765 mA, -1.589 mA 2018-10-16T22:41:49.327Z,1539729709.327 [SBIT](IMPORTANT): SBIT PASSED 2018-10-16T22:41:49.369Z,1539729709.369 [CommandLine](IMPORTANT): got command configSet list 2018-10-16T22:41:49.370Z,1539729709.370 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2018-10-16T22:41:49.370Z,1539729709.370 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=25 count; 2018-10-16T22:41:49.371Z,1539729709.371 [CommandLine](IMPORTANT): BPC1.batteryMuxCycleTime=10 minute; 2018-10-16T22:41:49.371Z,1539729709.371 [CommandLine](IMPORTANT): BPC1.batterySamplingInterval=1 minute; 2018-10-16T22:41:49.371Z,1539729709.371 [CommandLine](IMPORTANT): BPC1.loadAtStartup=0 bool; 2018-10-16T22:41:49.371Z,1539729709.371 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool; 2018-10-16T22:41:49.371Z,1539729709.371 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool; 2018-10-16T22:41:49.371Z,1539729709.371 [CommandLine](IMPORTANT): Express none VerticalTemperatureHomogeneityIndexCalculator.vertical_temperature_homogeneity_index; 2018-10-16T22:41:49.371Z,1539729709.371 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter; 2018-10-16T22:41:49.371Z,1539729709.371 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=1 bool; 2018-10-16T22:41:49.372Z,1539729709.372 [CommandLine](IMPORTANT): StratificationFrontDetector.loadAtStartup=0 bool; 2018-10-16T22:41:49.372Z,1539729709.372 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=213 cubic_centimeter; 2018-10-16T22:41:49.372Z,1539729709.372 [CommandLine](IMPORTANT): VerticalControl.massDefault=4 millimeter; 2018-10-16T22:41:49.736Z,1539729709.736 [MissionManager](IMPORTANT): Started mission Startup 2018-10-16T22:41:49.737Z,1539729709.737 [Startup] Running Loop=1 2018-10-16T22:41:49.737Z,1539729709.737 [Startup](DEBUG): Aggregate::initialize Startup 2018-10-16T22:41:49.737Z,1539729709.737 [Startup:A.GoToSurface] Running Loop=1 2018-10-16T22:41:49.737Z,1539729709.737 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-10-16T22:41:49.738Z,1539729709.738 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-10-16T22:41:49.738Z,1539729709.738 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-10-16T22:41:49.739Z,1539729709.739 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-10-16T22:41:49.739Z,1539729709.739 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-10-16T22:41:49.740Z,1539729709.740 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-10-16T22:41:49.746Z,1539729709.746 [Startup:StartupSatComms] Running Loop=1 2018-10-16T22:41:49.746Z,1539729709.746 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2018-10-16T22:41:49.746Z,1539729709.746 [Startup:StartupSatComms:A] Running Loop=1 2018-10-16T22:41:50.140Z,1539729710.140 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2018-10-16T22:42:49.845Z,1539729769.845 [Startup:StartupSatComms:A](INFO): Timed out from 2018-10-16T22:41:49.7Z 2018-10-16T22:42:49.845Z,1539729769.845 [Startup:StartupSatComms:A] Stopped 2018-10-16T22:42:49.845Z,1539729769.845 [Startup:StartupSatComms:B] Running Loop=1 2018-10-16T22:42:50.255Z,1539729770.255 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-10-16T22:42:59.571Z,1539729779.571 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181016T192750/Courier0004.lzma 2018-10-16T22:43:00.359Z,1539729780.359 [DataOverHttps](INFO): Moved sent file to Logs/20181016T192750/Courier0004.lzma.bak 2018-10-16T22:43:00.359Z,1539729780.359 [DataOverHttps](INFO): SBD MOMSN=8721685 2018-10-16T22:43:09.751Z,1539729789.751 [DataOverHttps](INFO): Sending 518 bytes from file Logs/20181016T192750/Express0005.lzma 2018-10-16T22:43:10.550Z,1539729790.550 [DataOverHttps](INFO): Moved sent file to Logs/20181016T192750/Express0005.lzma.bak 2018-10-16T22:43:10.551Z,1539729790.551 [DataOverHttps](INFO): SBD MOMSN=8721688 2018-10-16T22:43:19.979Z,1539729799.979 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-16T22:43:19.979Z,1539729799.979 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2018-10-16T22:43:19.979Z,1539729799.979 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-16T22:43:19.992Z,1539729799.992 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-16T22:43:20.146Z,1539729800.146 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-16T22:43:20.146Z,1539729800.146 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2018-10-16T22:43:20.486Z,1539729800.486 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-16T22:43:20.487Z,1539729800.487 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-16T22:43:20.487Z,1539729800.487 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-16T22:43:25.416Z,1539729805.416 [DataOverHttps](INFO): Sending 925 bytes from file Logs/20181016T224010/Express0001.lzma 2018-10-16T22:43:26.188Z,1539729806.188 [DataOverHttps](INFO): Moved sent file to Logs/20181016T224010/Express0001.lzma.bak 2018-10-16T22:43:26.188Z,1539729806.188 [DataOverHttps](INFO): SBD MOMSN=8721703 2018-10-16T22:43:26.783Z,1539729806.783 [Startup:StartupSatComms:B] Stopped 2018-10-16T22:43:26.784Z,1539729806.784 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2018-10-16T22:43:26.784Z,1539729806.784 [Startup:StartupSatComms] Stopped 2018-10-16T22:43:26.784Z,1539729806.784 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2018-10-16T22:43:26.785Z,1539729806.785 [Startup](INFO): Completed Startup 2018-10-16T22:43:26.785Z,1539729806.785 [MissionManager](INFO): Startup is completed. 2018-10-16T22:43:26.785Z,1539729806.785 [MissionManager](INFO): Uninitializing Mission Startup 2018-10-16T22:43:26.785Z,1539729806.785 [Startup] Stopped 2018-10-16T22:43:26.786Z,1539729806.786 [Startup](DEBUG): Aggregate::uninitialize Startup 2018-10-16T22:43:26.786Z,1539729806.786 [Startup:A.GoToSurface] Stopped 2018-10-16T22:43:26.786Z,1539729806.786 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-10-16T22:43:27.088Z,1539729807.088 [MissionManager](IMPORTANT): Started mission Default 2018-10-16T22:43:27.088Z,1539729807.088 [Default] Running Loop=1 2018-10-16T22:43:27.088Z,1539729807.088 [Default](DEBUG): Aggregate::initialize Default 2018-10-16T22:43:27.093Z,1539729807.093 [Default:B.GoToSurface] Running Loop=1 2018-10-16T22:43:27.094Z,1539729807.094 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-10-16T22:43:27.094Z,1539729807.094 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-10-16T22:43:27.094Z,1539729807.094 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-10-16T22:43:27.095Z,1539729807.095 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-10-16T22:43:27.095Z,1539729807.095 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-10-16T22:43:27.096Z,1539729807.096 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-10-16T22:43:27.096Z,1539729807.096 [Default:A.Wait] Running Loop=1 2018-10-16T22:43:27.096Z,1539729807.096 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-10-16T22:43:40.464Z,1539729820.464 [Default:A.Wait](INFO): Done Waiting. 2018-10-16T22:43:40.464Z,1539729820.464 [Default:A.Wait] Stopped 2018-10-16T22:43:40.464Z,1539729820.464 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-10-16T22:43:40.856Z,1539729820.856 [Default:CheckIn] Running Loop=1 2018-10-16T22:43:40.856Z,1539729820.856 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-10-16T22:43:40.856Z,1539729820.856 [Default:CheckIn:Read_GPS] Running Loop=1 2018-10-16T22:43:41.251Z,1539729821.251 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2018-10-16T22:46:02.603Z,1539729962.603 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-10-16T22:46:20.656Z,1539729980.656 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-16T22:46:20.656Z,1539729980.656 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2018-10-16T22:46:20.656Z,1539729980.656 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-16T22:46:20.708Z,1539729980.708 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-16T22:46:21.070Z,1539729981.070 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-16T22:46:21.070Z,1539729981.070 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2018-10-16T22:46:21.463Z,1539729981.463 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-16T22:46:21.463Z,1539729981.463 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-16T22:46:21.464Z,1539729981.464 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-16T22:48:41.177Z,1539730121.177 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-10-16T22:43:40.9Z 2018-10-16T22:48:41.177Z,1539730121.177 [Default:CheckIn:Read_GPS] Stopped 2018-10-16T22:48:41.177Z,1539730121.177 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-10-16T22:48:41.576Z,1539730121.576 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-10-16T22:48:45.918Z,1539730125.918 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20181016T224010/Courier0004.lzma 2018-10-16T22:48:46.702Z,1539730126.702 [DataOverHttps](INFO): Moved sent file to Logs/20181016T224010/Courier0004.lzma.bak 2018-10-16T22:48:46.703Z,1539730126.703 [DataOverHttps](INFO): SBD MOMSN=8721766 2018-10-16T22:48:56.151Z,1539730136.151 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20181016T224010/Express0005.lzma 2018-10-16T22:48:56.942Z,1539730136.942 [DataOverHttps](INFO): Moved sent file to Logs/20181016T224010/Express0005.lzma.bak 2018-10-16T22:48:56.943Z,1539730136.943 [DataOverHttps](INFO): SBD MOMSN=8721768 2018-10-16T22:48:57.543Z,1539730137.543 [Default:CheckIn:Read_Iridium] Stopped 2018-10-16T22:48:57.543Z,1539730137.543 [Default:CheckIn:C.Wait] Running Loop=1 2018-10-16T22:48:57.543Z,1539730137.543 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-10-16T22:49:21.751Z,1539730161.751 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-16T22:49:21.751Z,1539730161.751 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2018-10-16T22:49:21.751Z,1539730161.751 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-16T22:49:21.797Z,1539730161.797 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-16T22:49:22.192Z,1539730162.192 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-16T22:49:22.192Z,1539730162.192 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2018-10-16T22:49:22.566Z,1539730162.566 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-16T22:49:22.566Z,1539730162.566 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-16T22:49:22.567Z,1539730162.567 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-16T22:51:02.005Z,1539730262.005 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-10-16T22:51:02.005Z,1539730262.005 [NAL9602] Data Fault, FailCount= 1 2018-10-16T22:51:02.005Z,1539730262.005 [NAL9602](ERROR): Data Fault 2018-10-16T22:51:02.103Z,1539730262.103 [CBIT](ERROR): Data Fault in component: NAL9602 2018-10-16T22:51:02.170Z,1539730262.170 [NAL9602](INFO): Powering down 2018-10-16T22:51:03.005Z,1539730263.005 [CBIT](INFO): Clearing failed state for component NAL9602 2018-10-16T22:51:03.005Z,1539730263.005 [NAL9602] No Fault, FailCount= 1 2018-10-16T22:51:32.518Z,1539730292.518 [NAL9602](INFO): Powering up NAL9602 2018-10-16T22:51:43.718Z,1539730303.718 [NAL9602](INFO): NAL9602 initialized 2018-10-16T22:52:22.830Z,1539730342.830 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-16T22:52:22.830Z,1539730342.830 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4 2018-10-16T22:52:22.830Z,1539730342.830 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-16T22:52:22.843Z,1539730342.843 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-16T22:52:23.304Z,1539730343.304 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-16T22:52:23.313Z,1539730343.313 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4 2018-10-16T22:52:23.617Z,1539730343.617 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-16T22:52:23.618Z,1539730343.618 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-16T22:52:23.618Z,1539730343.618 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-16T22:53:57.840Z,1539730437.840 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-10-16T22:53:57.841Z,1539730437.841 [Default:CheckIn:C.Wait] Stopped 2018-10-16T22:53:57.841Z,1539730437.841 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-10-16T22:53:57.841Z,1539730437.841 [Default:CheckIn:D] Running Loop=1 2018-10-16T22:53:58.238Z,1539730438.238 [Default:CheckIn:D] Stopped 2018-10-16T22:53:58.238Z,1539730438.238 [Default:CheckIn:E] Running Loop=1 2018-10-16T22:53:58.651Z,1539730438.651 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.519132 min 2018-10-16T22:53:58.653Z,1539730438.653 [Default:CheckIn:E] Stopped 2018-10-16T22:53:58.654Z,1539730438.654 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-10-16T22:53:58.654Z,1539730438.654 [Default:CheckIn] Stopped 2018-10-16T22:53:58.654Z,1539730438.654 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-10-16T22:53:58.654Z,1539730438.654 [Default:CheckIn](INFO): Running loop #2 2018-10-16T22:53:58.654Z,1539730438.654 [Default:CheckIn] Running Loop=2 2018-10-16T22:53:58.654Z,1539730438.654 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-10-16T22:53:58.654Z,1539730438.654 [Default:CheckIn:Read_GPS] Running Loop=1 2018-10-16T22:55:23.672Z,1539730523.672 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-16T22:55:23.673Z,1539730523.673 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5 2018-10-16T22:55:23.673Z,1539730523.673 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-16T22:55:23.685Z,1539730523.685 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-16T22:55:24.087Z,1539730524.087 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-16T22:55:24.087Z,1539730524.087 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5 2018-10-16T22:55:24.458Z,1539730524.458 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-16T22:55:24.459Z,1539730524.459 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-16T22:55:24.459Z,1539730524.459 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-16T22:58:24.459Z,1539730704.459 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-10-16T22:58:24.459Z,1539730704.459 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6 2018-10-16T22:58:24.460Z,1539730704.460 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-10-16T22:58:24.472Z,1539730704.472 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-10-16T22:58:24.876Z,1539730704.876 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-10-16T22:58:24.876Z,1539730704.876 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6 2018-10-16T22:58:25.334Z,1539730705.334 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-10-16T22:58:25.334Z,1539730705.334 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-10-16T22:58:25.335Z,1539730705.335 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-10-16T