2018-06-04T05:10:05.451Z,1528089005.451 [Supervisor](DEBUG): Initializing supervisor. 2018-06-04T05:10:05.454Z,1528089005.454 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2018-06-04T05:10:05.454Z,1528089005.454 [SyncHandler](INFO): Protected caller Thread ID is 798 2018-06-04T05:10:05.455Z,1528089005.455 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2018-06-04T05:10:05.456Z,1528089005.456 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2018-06-04T05:10:05.456Z,1528089005.456 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 799 2018-06-04T05:10:05.459Z,1528089005.459 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2018-06-04T05:10:05.470Z,1528089005.470 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2018-06-04T05:10:05.471Z,1528089005.471 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2018-06-04T05:10:05.472Z,1528089005.472 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 800 2018-06-04T05:10:05.472Z,1528089005.472 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2018-06-04T05:10:05.473Z,1528089005.473 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2018-06-04T05:10:05.474Z,1528089005.474 [logger ThreadHandler](INFO): Protected caller Thread ID is 801 2018-06-04T05:10:05.476Z,1528089005.476 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2018-06-04T05:10:05.476Z,1528089005.476 [Supervisor](INFO): Looking for Config files in directory: Config/ 2018-06-04T05:10:05.480Z,1528089005.480 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2018-06-04T05:10:05.825Z,1528089005.825 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2018-06-04T05:10:05.827Z,1528089005.827 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2018-06-04T05:10:06.035Z,1528089006.035 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2018-06-04T05:10:06.035Z,1528089006.035 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2018-06-04T05:10:06.335Z,1528089006.335 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2018-06-04T05:10:06.337Z,1528089006.337 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2018-06-04T05:10:06.479Z,1528089006.479 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2018-06-04T05:10:06.480Z,1528089006.480 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2018-06-04T05:10:06.579Z,1528089006.579 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2018-06-04T05:10:06.579Z,1528089006.579 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2018-06-04T05:10:07.064Z,1528089007.064 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2018-06-04T05:10:07.066Z,1528089007.066 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2018-06-04T05:10:07.466Z,1528089007.466 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2018-06-04T05:10:07.468Z,1528089007.468 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2018-06-04T05:10:07.929Z,1528089007.929 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2018-06-04T05:10:07.931Z,1528089007.931 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2018-06-04T05:10:08.037Z,1528089008.037 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2018-06-04T05:10:08.038Z,1528089008.038 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2018-06-04T05:10:08.137Z,1528089008.137 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2018-06-04T05:10:08.138Z,1528089008.138 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2018-06-04T05:10:08.348Z,1528089008.348 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2018-06-04T05:10:08.349Z,1528089008.349 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2018-06-04T05:10:08.564Z,1528089008.564 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2018-06-04T05:10:08.565Z,1528089008.565 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2018-06-04T05:10:08.925Z,1528089008.925 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2018-06-04T05:10:08.925Z,1528089008.925 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2018-06-04T05:10:09.069Z,1528089009.069 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2018-06-04T05:10:09.070Z,1528089009.070 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2018-06-04T05:10:09.165Z,1528089009.165 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2018-06-04T05:10:09.855Z,1528089009.855 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2018-06-04T05:10:09.962Z,1528089009.962 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2018-06-04T05:10:10.083Z,1528089010.083 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2018-06-04T05:10:10.179Z,1528089010.179 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2018-06-04T05:10:10.265Z,1528089010.265 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2018-06-04T05:10:10.421Z,1528089010.421 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2018-06-04T05:10:10.604Z,1528089010.604 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2018-06-04T05:10:10.681Z,1528089010.681 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2018-06-04T05:10:10.914Z,1528089010.914 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2018-06-04T05:10:10.914Z,1528089010.914 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2018-06-04T05:10:10.999Z,1528089010.999 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2018-06-04T05:10:11.089Z,1528089011.089 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2018-06-04T05:10:11.191Z,1528089011.191 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2018-06-04T05:10:11.319Z,1528089011.319 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2018-06-04T05:10:11.327Z,1528089011.327 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2018-06-04T05:10:11.609Z,1528089011.609 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2018-06-04T05:10:11.611Z,1528089011.611 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2018-06-04T05:10:11.667Z,1528089011.667 [DepthRateCalculator] Loaded 2018-06-04T05:10:11.667Z,1528089011.667 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2018-06-04T05:10:11.673Z,1528089011.673 [PitchRateCalculator] Loaded 2018-06-04T05:10:11.673Z,1528089011.673 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2018-06-04T05:10:11.689Z,1528089011.689 [SpeedCalculator] Loaded 2018-06-04T05:10:11.690Z,1528089011.690 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2018-06-04T05:10:11.711Z,1528089011.711 [TempGradientCalculator] Loaded 2018-06-04T05:10:11.711Z,1528089011.711 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2018-06-04T05:10:11.727Z,1528089011.727 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2018-06-04T05:10:11.727Z,1528089011.727 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2018-06-04T05:10:11.733Z,1528089011.733 [YawRateCalculator] Loaded 2018-06-04T05:10:11.733Z,1528089011.733 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2018-06-04T05:10:11.773Z,1528089011.773 [ElevatorOffsetCalculator] Loaded 2018-06-04T05:10:11.773Z,1528089011.773 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2018-06-04T05:10:11.773Z,1528089011.773 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2018-06-04T05:10:11.774Z,1528089011.774 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2018-06-04T05:10:11.895Z,1528089011.895 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2018-06-04T05:10:11.895Z,1528089011.895 [StratificationFrontDetector](DEBUG): (re)initializing 2018-06-04T05:10:11.895Z,1528089011.895 [StratificationFrontDetector] Loaded 2018-06-04T05:10:11.895Z,1528089011.895 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2018-06-04T05:10:11.896Z,1528089011.896 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2018-06-04T05:10:11.896Z,1528089011.896 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2018-06-04T05:10:12.030Z,1528089012.030 [BuoyancyServo] Loaded 2018-06-04T05:10:12.030Z,1528089012.030 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2018-06-04T05:10:12.046Z,1528089012.046 [ElevatorServo] Loaded 2018-06-04T05:10:12.046Z,1528089012.046 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2018-06-04T05:10:12.061Z,1528089012.061 [MassServo] Loaded 2018-06-04T05:10:12.061Z,1528089012.061 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2018-06-04T05:10:12.076Z,1528089012.076 [RudderServo] Loaded 2018-06-04T05:10:12.076Z,1528089012.076 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2018-06-04T05:10:12.091Z,1528089012.091 [ThrusterServo] Loaded 2018-06-04T05:10:12.091Z,1528089012.091 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2018-06-04T05:10:12.092Z,1528089012.092 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2018-06-04T05:10:12.092Z,1528089012.092 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2018-06-04T05:10:12.116Z,1528089012.116 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2018-06-04T05:10:12.117Z,1528089012.117 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2018-06-04T05:10:12.320Z,1528089012.320 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2018-06-04T05:10:12.321Z,1528089012.321 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2018-06-04T05:10:12.881Z,1528089012.881 [DataOverHttps] Loaded 2018-06-04T05:10:12.881Z,1528089012.881 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2018-06-04T05:10:12.895Z,1528089012.895 [Depth_Keller] Loaded 2018-06-04T05:10:12.895Z,1528089012.895 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2018-06-04T05:10:12.900Z,1528089012.900 [DropWeight] Loaded 2018-06-04T05:10:12.901Z,1528089012.901 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2018-06-04T05:10:12.998Z,1528089012.998 [NAL9602] Loaded 2018-06-04T05:10:12.999Z,1528089012.999 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2018-06-04T05:10:13.015Z,1528089013.015 [Onboard] Loaded 2018-06-04T05:10:13.015Z,1528089013.015 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2018-06-04T05:10:13.025Z,1528089013.025 [Radio_Surface] Loaded 2018-06-04T05:10:13.026Z,1528089013.026 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2018-06-04T05:10:13.027Z,1528089013.027 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408844E0 2018-06-04T05:10:13.027Z,1528089013.027 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 884 2018-06-04T05:10:13.154Z,1528089013.154 [DAT] Loaded 2018-06-04T05:10:13.155Z,1528089013.155 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2018-06-04T05:10:13.308Z,1528089013.308 [PNI_TCM] Loaded 2018-06-04T05:10:13.309Z,1528089013.309 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2018-06-04T05:10:13.370Z,1528089013.370 [Rowe_600LCM] Loaded 2018-06-04T05:10:13.370Z,1528089013.370 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2018-06-04T05:10:13.371Z,1528089013.371 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408B44E0 2018-06-04T05:10:13.371Z,1528089013.371 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 885 2018-06-04T05:10:15.447Z,1528089015.447 [BPC1] Loaded 2018-06-04T05:10:15.448Z,1528089015.448 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2018-06-04T05:10:15.448Z,1528089015.448 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2018-06-04T05:10:15.449Z,1528089015.449 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2018-06-04T05:10:15.605Z,1528089015.605 [SBIT](DEBUG): Construct Startup Built In Test. 2018-06-04T05:10:15.627Z,1528089015.627 [SBIT] Loaded 2018-06-04T05:10:15.627Z,1528089015.627 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2018-06-04T05:10:15.628Z,1528089015.628 [IBIT](DEBUG): Construct Initiated Built In Test. 2018-06-04T05:10:15.640Z,1528089015.640 [IBIT] Loaded 2018-06-04T05:10:15.640Z,1528089015.640 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2018-06-04T05:10:15.643Z,1528089015.643 [CBIT](DEBUG): Construct Continuous Built In Test. 2018-06-04T05:10:15.795Z,1528089015.795 [CBIT] Loaded 2018-06-04T05:10:15.795Z,1528089015.795 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2018-06-04T05:10:15.795Z,1528089015.795 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2018-06-04T05:10:15.796Z,1528089015.796 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2018-06-04T05:10:15.983Z,1528089015.983 [Aanderaa_O2] Loaded 2018-06-04T05:10:15.983Z,1528089015.983 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2018-06-04T05:10:16.062Z,1528089016.062 [CTD_NeilBrown] Loaded 2018-06-04T05:10:16.063Z,1528089016.063 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2018-06-04T05:10:16.064Z,1528089016.064 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409754E0 2018-06-04T05:10:16.064Z,1528089016.064 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 886 2018-06-04T05:10:16.111Z,1528089016.111 [CTD_Seabird] Loaded 2018-06-04T05:10:16.111Z,1528089016.111 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2018-06-04T05:10:16.112Z,1528089016.112 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409A54E0 2018-06-04T05:10:16.112Z,1528089016.112 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 887 2018-06-04T05:10:16.127Z,1528089016.127 [PAR_Licor] Loaded 2018-06-04T05:10:16.127Z,1528089016.127 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2018-06-04T05:10:16.176Z,1528089016.176 [WetLabsBB2FL] Loaded 2018-06-04T05:10:16.177Z,1528089016.177 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2018-06-04T05:10:16.178Z,1528089016.178 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409D54E0 2018-06-04T05:10:16.178Z,1528089016.178 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 888 2018-06-04T05:10:16.179Z,1528089016.179 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2018-06-04T05:10:16.179Z,1528089016.179 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2018-06-04T05:10:16.267Z,1528089016.267 [VerticalControl](DEBUG): Construct VerticalControl. 2018-06-04T05:10:16.352Z,1528089016.352 [VerticalControl] Loaded 2018-06-04T05:10:16.352Z,1528089016.352 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2018-06-04T05:10:16.353Z,1528089016.353 [HorizontalControl](DEBUG): Construct HorizontalControl. 2018-06-04T05:10:16.411Z,1528089016.411 [HorizontalControl] Loaded 2018-06-04T05:10:16.411Z,1528089016.411 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2018-06-04T05:10:16.411Z,1528089016.411 [SpeedControl](DEBUG): Construct SpeedControl. 2018-06-04T05:10:16.413Z,1528089016.413 [SpeedControl] Loaded 2018-06-04T05:10:16.413Z,1528089016.413 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2018-06-04T05:10:16.414Z,1528089016.414 [LoopControl](DEBUG): Construct LoopControl. 2018-06-04T05:10:16.415Z,1528089016.415 [LoopControl] Loaded 2018-06-04T05:10:16.415Z,1528089016.415 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2018-06-04T05:10:16.415Z,1528089016.415 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2018-06-04T05:10:16.416Z,1528089016.416 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2018-06-04T05:10:16.453Z,1528089016.453 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2018-06-04T05:10:16.454Z,1528089016.454 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2018-06-04T05:10:16.561Z,1528089016.561 [DeadReckonUsingSpeedCalculator] Loaded 2018-06-04T05:10:16.562Z,1528089016.562 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2018-06-04T05:10:16.578Z,1528089016.578 [NavChart] Loaded 2018-06-04T05:10:16.578Z,1528089016.578 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2018-06-04T05:10:16.582Z,1528089016.582 [UniversalFixResidualReporter] Loaded 2018-06-04T05:10:16.583Z,1528089016.583 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2018-06-04T05:10:16.583Z,1528089016.583 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2018-06-04T05:10:16.587Z,1528089016.587 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2018-06-04T05:10:16.587Z,1528089016.587 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2018-06-04T05:10:16.594Z,1528089016.594 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2018-06-04T05:10:16.595Z,1528089016.595 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A614E0 2018-06-04T05:10:16.596Z,1528089016.596 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 889 2018-06-04T05:10:16.600Z,1528089016.600 [Supervisor](INFO): Main Thread ID is 797 2018-06-04T05:10:16.600Z,1528089016.600 [Supervisor](DEBUG): Running supervisor. 2018-06-04T05:10:16.601Z,1528089016.601 [CommandLine ThreadHandler](INFO): Handler Thread ID is 890 2018-06-04T05:10:16.603Z,1528089016.603 [controlThread ThreadHandler](INFO): Handler Thread ID is 891 2018-06-04T05:10:16.604Z,1528089016.604 [controlThread](DEBUG): Initializing ControlThread 2018-06-04T05:10:16.605Z,1528089016.605 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-06-04T05:10:16.605Z,1528089016.605 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2018-06-04T05:10:16.605Z,1528089016.605 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2018-06-04T05:10:16.606Z,1528089016.606 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2018-06-04T05:10:16.606Z,1528089016.606 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2018-06-04T05:10:16.607Z,1528089016.607 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2018-06-04T05:10:16.607Z,1528089016.607 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2018-06-04T05:10:16.615Z,1528089016.615 [SBIT](INFO): Initialize SBIT Component. 2018-06-04T05:10:16.616Z,1528089016.616 [SBIT](IMPORTANT): git: 2018-06-03 2018-06-04T05:10:16.616Z,1528089016.616 [SBIT](INFO): git hash: e89e4219fcae2edd415aee450018ea5d8b44159b 2018-06-04T05:10:16.617Z,1528089016.617 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2018-06-04T05:10:16.618Z,1528089016.618 [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-06-04T05:10:16.619Z,1528089016.619 [SBIT](INFO): Beginning SBIT in 23.000000 seconds. 2018-06-04T05:10:16.619Z,1528089016.619 [IBIT](INFO): Initialize IBIT Component. 2018-06-04T05:10:16.620Z,1528089016.620 [CBIT](DEBUG): Initialize CBIT Component. 2018-06-04T05:10:16.621Z,1528089016.621 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2018-06-04T05:10:16.622Z,1528089016.622 [logger ThreadHandler](INFO): Handler Thread ID is 892 2018-06-04T05:10:16.641Z,1528089016.641 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 893 2018-06-04T05:10:16.651Z,1528089016.651 [Radio_Surface](INFO): Powering up 2018-06-04T05:10:16.658Z,1528089016.658 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 894 2018-06-04T05:10:16.658Z,1528089016.658 [Rowe_600LCM](INFO): Initializing 2018-06-04T05:10:16.659Z,1528089016.659 [Rowe_600LCM](INFO): Checking LCM 2018-06-04T05:10:16.733Z,1528089016.733 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2018-06-04T05:10:16.735Z,1528089016.735 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2018-06-04T05:10:16.736Z,1528089016.736 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2018-06-04T05:10:16.736Z,1528089016.736 [LoopControl](DEBUG): Initialize LoopControlComponent. 2018-06-04T05:10:16.737Z,1528089016.737 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-06-04T05:10:16.737Z,1528089016.737 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-06-04T05:10:16.767Z,1528089016.767 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-06-04T05:10:16.768Z,1528089016.768 [NavChart](DEBUG): Initialize NavChart Navigation. 2018-06-04T05:10:16.768Z,1528089016.768 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2018-06-04T05:10:16.769Z,1528089016.769 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2018-06-04T05:10:16.780Z,1528089016.780 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 895 2018-06-04T05:10:16.782Z,1528089016.782 [CTD_NeilBrown](INFO): Powering down 2018-06-04T05:10:16.893Z,1528089016.893 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 896 2018-06-04T05:10:16.897Z,1528089016.897 [CTD_Seabird](INFO): Initializing 2018-06-04T05:10:16.898Z,1528089016.898 [CTD_Seabird](INFO): Checking LCM 2018-06-04T05:10:16.901Z,1528089016.901 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 897 2018-06-04T05:10:16.902Z,1528089016.902 [WetLabsBB2FL](INFO): Powering down 2018-06-04T05:10:16.991Z,1528089016.991 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 898 2018-06-04T05:10:16.999Z,1528089016.999 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2018-06-04T05:10:16.999Z,1528089016.999 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2018-06-04T05:10:16.999Z,1528089016.999 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2018-06-04T05:10:16.999Z,1528089016.999 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2018-06-04T05:10:16.000Z,1528089017.000 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2018-06-04T05:10:16.000Z,1528089017.000 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2018-06-04T05:10:16.000Z,1528089017.000 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2018-06-04T05:10:17.000Z,1528089017.000 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2018-06-04T05:10:17.000Z,1528089017.000 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2018-06-04T05:10:17.001Z,1528089017.001 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2018-06-04T05:10:17.001Z,1528089017.001 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2018-06-04T05:10:17.001Z,1528089017.001 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2018-06-04T05:10:17.001Z,1528089017.001 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2018-06-04T05:10:17.002Z,1528089017.002 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2018-06-04T05:10:17.002Z,1528089017.002 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2018-06-04T05:10:17.002Z,1528089017.002 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2018-06-04T05:10:17.004Z,1528089017.004 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2018-06-04T05:10:17.077Z,1528089017.077 [MissionManager](DEBUG): 2018-06-04T05:10:17.078Z,1528089017.078 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2018-06-04T05:10:17.098Z,1528089017.098 [CTD_Seabird](INFO): LCM OK 2018-06-04T05:10:17.098Z,1528089017.098 [CTD_Seabird](INFO): Powering up 2018-06-04T05:10:17.105Z,1528089017.105 [Rowe_600LCM](INFO): LCM OK 2018-06-04T05:10:17.105Z,1528089017.105 [Rowe_600LCM](INFO): Powering up 2018-06-04T05:10:17.180Z,1528089017.180 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2018-06-04T05:10:17.182Z,1528089017.182 [Default:A.Wait](DEBUG): Construct Wait. 2018-06-04T05:10:17.184Z,1528089017.184 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2018-06-04T05:10:17.223Z,1528089017.223 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2018-06-04T05:10:17.226Z,1528089017.226 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2018-06-04T05:10:17.259Z,1528089017.260 [Default:E.Execute](DEBUG): Construct Execute. 2018-06-04T05:10:17.263Z,1528089017.263 [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-06-04T05:10:17.273Z,1528089017.273 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,PNI_TCM,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-06-04T05:10:17.314Z,1528089017.314 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2018-06-04T05:10:17.338Z,1528089017.338 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2018-06-04T05:10:17.431Z,1528089017.431 [DAT](INFO): Powering up 2018-06-04T05:10:17.432Z,1528089017.432 [DAT](DEBUG): Initializing DAT. 2018-06-04T05:10:17.706Z,1528089017.706 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-06-04T05:10:17.825Z,1528089017.825 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-06-04T05:10:18.065Z,1528089018.065 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-06-04T05:10:18.069Z,1528089018.069 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-06-04T05:10:18.076Z,1528089018.076 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-06-04T05:10:18.077Z,1528089018.077 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-06-04T05:10:18.116Z,1528089018.116 [MassServo](DEBUG): Initializing EZServoServo. 2018-06-04T05:10:18.117Z,1528089018.117 [MassServo](DEBUG): Initializing MassServo. 2018-06-04T05:10:18.139Z,1528089018.139 [RudderServo](DEBUG): Initializing EZServoServo. 2018-06-04T05:10:18.145Z,1528089018.145 [RudderServo](DEBUG): Initializing RudderServo. 2018-06-04T05:10:18.151Z,1528089018.151 [ThrusterServo](DEBUG): Initializing EZServoServo. 2018-06-04T05:10:18.157Z,1528089018.157 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2018-06-04T05:10:18.461Z,1528089018.461 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-06-04T05:10:18.688Z,1528089018.688 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-06-04T05:10:19.037Z,1528089019.037 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2018-06-04T05:10:19.037Z,1528089019.037 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2018-06-04T05:10:19.037Z,1528089019.037 [BuoyancyServo] Communications Fault, FailCount= 1 2018-06-04T05:10:19.037Z,1528089019.037 [BuoyancyServo](ERROR): Communications Fault 2018-06-04T05:10:19.237Z,1528089019.237 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2018-06-04T05:10:19.288Z,1528089019.288 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-06-04T05:10:19.310Z,1528089019.310 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-06-04T05:10:19.311Z,1528089019.311 [BuoyancyServo](INFO): Powering down 2018-06-04T05:10:19.702Z,1528089019.702 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-06-04T05:10:20.117Z,1528089020.117 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-06-04T05:10:20.517Z,1528089020.517 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-06-04T05:10:20.895Z,1528089020.895 [Aanderaa_O2](INFO): Powering down 2018-06-04T05:10:20.976Z,1528089020.976 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-06-04T05:10:21.229Z,1528089021.229 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-06-04T05:10:21.377Z,1528089021.377 [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-06-04T05:10:21.526Z,1528089021.526 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2018-06-04T05:10:21.526Z,1528089021.526 [BuoyancyServo] No Fault, FailCount= 1 2018-06-04T05:10:21.550Z,1528089021.550 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-06-04T05:10:21.551Z,1528089021.551 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-06-04T05:10:21.552Z,1528089021.552 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-06-04T05:10:21.759Z,1528089021.759 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-06-04T05:10:21.759Z,1528089021.759 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-06-04T05:10:22.601Z,1528089022.601 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-06-04T05:10:22.629Z,1528089022.629 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2018-06-04T05:10:22.629Z,1528089022.629 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2018-06-04T05:10:22.629Z,1528089022.629 [BuoyancyServo] Communications Fault, FailCount= 2 2018-06-04T05:10:22.630Z,1528089022.630 [BuoyancyServo](ERROR): Communications Fault 2018-06-04T05:10:22.743Z,1528089022.743 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null & 2018-06-04T05:10:22.745Z,1528089022.745 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd 2018-06-04T05:10:23.074Z,1528089023.074 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2018-06-04T05:10:23.591Z,1528089023.591 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-06-04T05:10:23.592Z,1528089023.592 [BuoyancyServo](INFO): Powering down 2018-06-04T05:10:23.731Z,1528089023.731 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-06-04T05:10:23.731Z,1528089023.731 [CTD_Seabird](INFO): Powering down 2018-06-04T05:10:25.834Z,1528089025.834 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2018-06-04T05:10:25.834Z,1528089025.834 [BuoyancyServo] No Fault, FailCount= 2 2018-06-04T05:10:26.140Z,1528089026.140 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-06-04T05:10:26.140Z,1528089026.140 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-06-04T05:10:30.897Z,1528089030.897 [DAT](INFO): setting local address to 2 2018-06-04T05:10:31.288Z,1528089031.288 [DAT](INFO): set local address to 2 2018-06-04T05:10:40.159Z,1528089040.159 [SBIT](IMPORTANT): Beginning Startup BIT 2018-06-04T05:10:40.171Z,1528089040.171 [CBIT](IMPORTANT): Beginning ground fault scan 2018-06-04T05:10:43.123Z,1528089043.123 [NAL9602](INFO): Powering up NAL9602 2018-06-04T05:10:52.135Z,1528089052.135 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.004004 CHAN A1 (24V): -0.007997 CHAN A2 (12V): -0.002725 CHAN A3 (5V): -0.001524 CHAN B0 (3.3V): 4.766929 CHAN B1 (3.15aV): 0.000124 CHAN B2 (3.15bV): -0.000322 CHAN B3 (GND): 0.000079 OPEN: -0.000304 Full Scale Calc: 4.765 mA, -1.589 mA 2018-06-04T05:10:53.987Z,1528089053.987 [NAL9602](INFO): NAL9602 initialized 2018-06-04T05:11:33.487Z,1528089093.487 [SBIT](IMPORTANT): SBIT PASSED 2018-06-04T05:11:33.548Z,1528089093.548 [CommandLine](IMPORTANT): got command configSet list 2018-06-04T05:11:33.549Z,1528089093.549 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2018-06-04T05:11:33.550Z,1528089093.550 [CommandLine](IMPORTANT): DAT.loadAtStartup=1 bool; 2018-06-04T05:11:33.842Z,1528089093.842 [MissionManager](IMPORTANT): Started mission Startup 2018-06-04T05:11:33.842Z,1528089093.842 [Startup] Running Loop=1 2018-06-04T05:11:33.843Z,1528089093.843 [Startup](DEBUG): Aggregate::initialize Startup 2018-06-04T05:11:33.843Z,1528089093.843 [Startup:A.GoToSurface] Running Loop=1 2018-06-04T05:11:33.843Z,1528089093.843 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-06-04T05:11:33.843Z,1528089093.843 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-06-04T05:11:33.844Z,1528089093.844 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-06-04T05:11:33.844Z,1528089093.844 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-06-04T05:11:33.849Z,1528089093.849 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-06-04T05:11:33.849Z,1528089093.849 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-06-04T05:11:33.880Z,1528089093.880 [Startup:StartupSatComms] Running Loop=1 2018-06-04T05:11:33.880Z,1528089093.880 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2018-06-04T05:11:33.880Z,1528089093.880 [Startup:StartupSatComms:A] Running Loop=1 2018-06-04T05:11:34.256Z,1528089094.256 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2018-06-04T05:11:35.878Z,1528089095.878 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:11:36.674Z,1528089096.674 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:12:01.562Z,1528089121.562 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:12:02.358Z,1528089122.358 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:12:17.455Z,1528089137.455 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-06-04T05:12:17.455Z,1528089137.455 [Rowe_600LCM] Communications Fault, FailCount= 1 2018-06-04T05:12:17.456Z,1528089137.456 [Rowe_600LCM](ERROR): Communications Fault 2018-06-04T05:12:17.525Z,1528089137.525 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-06-04T05:12:17.861Z,1528089137.861 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-06-04T05:12:17.983Z,1528089137.983 [Rowe_600LCM](INFO): Powering down 2018-06-04T05:12:19.454Z,1528089139.454 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-06-04T05:12:19.455Z,1528089139.455 [Rowe_600LCM] No Fault, FailCount= 1 2018-06-04T05:12:19.597Z,1528089139.597 [Rowe_600LCM](INFO): Initializing 2018-06-04T05:12:19.597Z,1528089139.597 [Rowe_600LCM](INFO): Checking LCM 2018-06-04T05:12:19.597Z,1528089139.597 [Rowe_600LCM](INFO): LCM OK 2018-06-04T05:12:19.598Z,1528089139.598 [Rowe_600LCM](INFO): Powering up 2018-06-04T05:12:23.720Z,1528089143.720 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-06-04T05:12:23.868Z,1528089143.868 [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-06-04T05:12:23.870Z,1528089143.870 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-06-04T05:12:23.871Z,1528089143.871 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-06-04T05:12:23.872Z,1528089143.872 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-06-04T05:12:34.223Z,1528089154.223 [Startup:StartupSatComms:A](INFO): Timed out from 2018-06-04T05:11:33.9Z 2018-06-04T05:12:34.223Z,1528089154.223 [Startup:StartupSatComms:A] Stopped 2018-06-04T05:12:34.223Z,1528089154.223 [Startup:StartupSatComms:B] Running Loop=1 2018-06-04T05:12:34.627Z,1528089154.627 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-06-04T05:12:39.558Z,1528089159.558 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:12:40.353Z,1528089160.353 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:12:49.211Z,1528089169.211 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004335 2018-06-04T05:12:53.572Z,1528089173.572 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180604T050354/Courier0004.lzma 2018-06-04T05:12:54.356Z,1528089174.356 [DataOverHttps](INFO): Moved sent file to Logs/20180604T050354/Courier0004.lzma.bak 2018-06-04T05:12:54.356Z,1528089174.356 [DataOverHttps](INFO): SBD MOMSN=8311143 2018-06-04T05:13:03.751Z,1528089183.751 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20180604T050354/Express0005.lzma 2018-06-04T05:13:04.539Z,1528089184.539 [DataOverHttps](INFO): Moved sent file to Logs/20180604T050354/Express0005.lzma.bak 2018-06-04T05:13:04.539Z,1528089184.539 [DataOverHttps](INFO): SBD MOMSN=8311145 2018-06-04T05:13:14.317Z,1528089194.317 [DataOverHttps](INFO): Sending 719 bytes from file Logs/20180604T051005/Express0001.lzma 2018-06-04T05:13:15.067Z,1528089195.067 [DataOverHttps](INFO): Moved sent file to Logs/20180604T051005/Express0001.lzma.bak 2018-06-04T05:13:15.068Z,1528089195.068 [DataOverHttps](INFO): SBD MOMSN=8311152 2018-06-04T05:13:15.562Z,1528089195.562 [Startup:StartupSatComms:B] Stopped 2018-06-04T05:13:15.563Z,1528089195.563 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2018-06-04T05:13:15.563Z,1528089195.563 [Startup:StartupSatComms] Stopped 2018-06-04T05:13:15.563Z,1528089195.563 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2018-06-04T05:13:15.564Z,1528089195.564 [Startup](INFO): Completed Startup 2018-06-04T05:13:15.564Z,1528089195.564 [MissionManager](INFO): Startup is completed. 2018-06-04T05:13:15.564Z,1528089195.564 [MissionManager](INFO): Uninitializing Mission Startup 2018-06-04T05:13:15.564Z,1528089195.564 [Startup] Stopped 2018-06-04T05:13:15.569Z,1528089195.569 [Startup](DEBUG): Aggregate::uninitialize Startup 2018-06-04T05:13:15.569Z,1528089195.569 [Startup:A.GoToSurface] Stopped 2018-06-04T05:13:15.569Z,1528089195.569 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-06-04T05:13:15.929Z,1528089195.929 [MissionManager](IMPORTANT): Started mission Default 2018-06-04T05:13:15.930Z,1528089195.930 [Default] Running Loop=1 2018-06-04T05:13:15.930Z,1528089195.930 [Default](DEBUG): Aggregate::initialize Default 2018-06-04T05:13:15.930Z,1528089195.930 [Default:B.GoToSurface] Running Loop=1 2018-06-04T05:13:15.930Z,1528089195.930 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-06-04T05:13:15.930Z,1528089195.930 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-06-04T05:13:15.931Z,1528089195.931 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-06-04T05:13:15.931Z,1528089195.931 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-06-04T05:13:15.931Z,1528089195.931 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-06-04T05:13:15.932Z,1528089195.932 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-06-04T05:13:15.932Z,1528089195.932 [Default:A.Wait] Running Loop=1 2018-06-04T05:13:15.932Z,1528089195.932 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-06-04T05:13:19.651Z,1528089199.651 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-06-04T05:13:19.651Z,1528089199.651 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2018-06-04T05:13:19.652Z,1528089199.652 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-06-04T05:13:19.685Z,1528089199.685 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-06-04T05:13:19.818Z,1528089199.818 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-06-04T05:13:19.818Z,1528089199.818 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2018-06-04T05:13:20.167Z,1528089200.167 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-06-04T05:13:20.167Z,1528089200.167 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-06-04T05:13:20.168Z,1528089200.168 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-06-04T05:13:27.642Z,1528089207.642 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyNeutral 2018-06-04T05:13:27.643Z,1528089207.643 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral 315.000012 cc 2018-06-04T05:13:28.992Z,1528089208.992 [Default:A.Wait](INFO): Done Waiting. 2018-06-04T05:13:28.992Z,1528089208.992 [Default:A.Wait] Stopped 2018-06-04T05:13:28.992Z,1528089208.992 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-06-04T05:13:29.375Z,1528089209.375 [Default:CheckIn] Running Loop=1 2018-06-04T05:13:29.375Z,1528089209.375 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-06-04T05:13:29.375Z,1528089209.375 [Default:CheckIn:Read_GPS] Running Loop=1 2018-06-04T05:13:29.773Z,1528089209.773 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2018-06-04T05:14:20.245Z,1528089260.245 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-06-04T05:14:20.245Z,1528089260.245 [Rowe_600LCM] Communications Fault, FailCount= 2 2018-06-04T05:14:20.245Z,1528089260.245 [Rowe_600LCM](ERROR): Communications Fault 2018-06-04T05:14:20.577Z,1528089260.577 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-06-04T05:14:20.649Z,1528089260.649 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-06-04T05:14:20.750Z,1528089260.750 [Rowe_600LCM](INFO): Powering down 2018-06-04T05:14:22.154Z,1528089262.154 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-06-04T05:14:22.154Z,1528089262.154 [Rowe_600LCM] No Fault, FailCount= 2 2018-06-04T05:14:22.365Z,1528089262.365 [Rowe_600LCM](INFO): Initializing 2018-06-04T05:14:22.365Z,1528089262.365 [Rowe_600LCM](INFO): Checking LCM 2018-06-04T05:14:22.366Z,1528089262.366 [Rowe_600LCM](INFO): LCM OK 2018-06-04T05:14:22.366Z,1528089262.366 [Rowe_600LCM](INFO): Powering up 2018-06-04T05:14:26.605Z,1528089266.605 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-06-04T05:14:26.684Z,1528089266.684 [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-06-04T05:14:26.685Z,1528089266.685 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-06-04T05:14:26.686Z,1528089266.686 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-06-04T05:14:26.687Z,1528089266.687 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-06-04T05:15:56.827Z,1528089356.827 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2018-06-04T05:16:20.337Z,1528089380.337 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-06-04T05:16:20.337Z,1528089380.337 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2018-06-04T05:16:20.337Z,1528089380.337 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-06-04T05:16:20.351Z,1528089380.351 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-06-04T05:16:20.500Z,1528089380.500 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-06-04T05:16:20.500Z,1528089380.500 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2018-06-04T05:16:20.558Z,1528089380.558 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:16:20.835Z,1528089380.835 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-06-04T05:16:20.835Z,1528089380.835 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-06-04T05:16:20.836Z,1528089380.836 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-06-04T05:16:21.354Z,1528089381.354 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:16:22.445Z,1528089382.445 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-06-04T05:16:22.445Z,1528089382.445 [Rowe_600LCM] Communications Fault, FailCount= 3 2018-06-04T05:16:22.445Z,1528089382.445 [Rowe_600LCM](ERROR): Communications Fault 2018-06-04T05:16:22.497Z,1528089382.497 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-06-04T05:16:22.849Z,1528089382.849 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-06-04T05:16:22.964Z,1528089382.964 [Rowe_600LCM](INFO): Powering down 2018-06-04T05:16:24.440Z,1528089384.440 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-06-04T05:16:24.440Z,1528089384.440 [Rowe_600LCM] No Fault, FailCount= 3 2018-06-04T05:16:24.582Z,1528089384.582 [Rowe_600LCM](INFO): Initializing 2018-06-04T05:16:24.583Z,1528089384.583 [Rowe_600LCM](INFO): Checking LCM 2018-06-04T05:16:24.583Z,1528089384.583 [Rowe_600LCM](INFO): LCM OK 2018-06-04T05:16:24.583Z,1528089384.583 [Rowe_600LCM](INFO): Powering up 2018-06-04T05:16:28.704Z,1528089388.704 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-06-04T05:16:28.828Z,1528089388.828 [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-06-04T05:16:28.829Z,1528089388.829 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-06-04T05:16:28.830Z,1528089388.830 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-06-04T05:16:28.831Z,1528089388.831 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-06-04T05:18:22.574Z,1528089502.574 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:18:23.369Z,1528089503.369 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:18:25.241Z,1528089505.241 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-06-04T05:18:25.241Z,1528089505.241 [Rowe_600LCM] Communications Fault, FailCount= 4 2018-06-04T05:18:25.241Z,1528089505.241 [Rowe_600LCM](ERROR): Communications Fault 2018-06-04T05:18:25.457Z,1528089505.457 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-06-04T05:18:25.645Z,1528089505.645 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-06-04T05:18:25.745Z,1528089505.745 [Rowe_600LCM](INFO): Powering down 2018-06-04T05:18:26.604Z,1528089506.604 [BPC1](ERROR): Failed to receive data from both battery packs 2018-06-04T05:18:26.605Z,1528089506.605 [BPC1] Communications Fault, FailCount= 1 2018-06-04T05:18:26.605Z,1528089506.605 [BPC1](ERROR): Communications Fault 2018-06-04T05:18:26.677Z,1528089506.677 [CBIT](ERROR): Communications Fault in component: BPC1 2018-06-04T05:18:27.041Z,1528089507.041 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-06-04T05:18:27.041Z,1528089507.041 [Rowe_600LCM] No Fault, FailCount= 4 2018-06-04T05:18:27.369Z,1528089507.369 [Rowe_600LCM](INFO): Initializing 2018-06-04T05:18:27.369Z,1528089507.369 [Rowe_600LCM](INFO): Checking LCM 2018-06-04T05:18:27.369Z,1528089507.369 [Rowe_600LCM](INFO): LCM OK 2018-06-04T05:18:27.370Z,1528089507.370 [Rowe_600LCM](INFO): Powering up 2018-06-04T05:18:27.858Z,1528089507.858 [CBIT](INFO): Clearing failed state for component BPC1 2018-06-04T05:18:27.858Z,1528089507.858 [BPC1] No Fault, FailCount= 1 2018-06-04T05:18:29.422Z,1528089509.422 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-04T05:13:29.4Z 2018-06-04T05:18:29.422Z,1528089509.422 [Default:CheckIn:Read_GPS] Stopped 2018-06-04T05:18:29.423Z,1528089509.423 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-06-04T05:18:29.807Z,1528089509.807 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-06-04T05:18:31.548Z,1528089511.548 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-06-04T05:18:31.651Z,1528089511.651 [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-06-04T05:18:31.653Z,1528089511.653 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-06-04T05:18:31.654Z,1528089511.654 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-06-04T05:18:31.654Z,1528089511.654 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-06-04T05:18:34.751Z,1528089514.751 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180604T051005/Courier0004.lzma 2018-06-04T05:18:35.543Z,1528089515.543 [DataOverHttps](INFO): Moved sent file to Logs/20180604T051005/Courier0004.lzma.bak 2018-06-04T05:18:35.544Z,1528089515.544 [DataOverHttps](INFO): SBD MOMSN=8311169 2018-06-04T05:18:44.956Z,1528089524.956 [DataOverHttps](INFO): Sending 312 bytes from file Logs/20180604T051005/Express0005.lzma 2018-06-04T05:18:45.699Z,1528089525.699 [DataOverHttps](INFO): Moved sent file to Logs/20180604T051005/Express0005.lzma.bak 2018-06-04T05:18:45.700Z,1528089525.700 [DataOverHttps](INFO): SBD MOMSN=8311171 2018-06-04T05:18:46.178Z,1528089526.178 [Default:CheckIn:Read_Iridium] Stopped 2018-06-04T05:18:46.178Z,1528089526.178 [Default:CheckIn:C.Wait] Running Loop=1 2018-06-04T05:18:46.178Z,1528089526.178 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-06-04T05:19:20.959Z,1528089560.959 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-06-04T05:19:20.959Z,1528089560.959 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2018-06-04T05:19:20.959Z,1528089560.959 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-06-04T05:19:20.972Z,1528089560.972 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-06-04T05:19:21.352Z,1528089561.352 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-06-04T05:19:21.352Z,1528089561.352 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2018-06-04T05:19:21.713Z,1528089561.713 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-06-04T05:19:21.714Z,1528089561.714 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-06-04T05:19:21.715Z,1528089561.715 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-06-04T05:20:27.439Z,1528089627.439 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-06-04T05:20:27.439Z,1528089627.439 [Rowe_600LCM] Communications Fault, FailCount= 5 2018-06-04T05:20:27.439Z,1528089627.439 [Rowe_600LCM](ERROR): Communications Fault 2018-06-04T05:20:27.722Z,1528089627.722 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-06-04T05:20:27.722Z,1528089627.722 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM 2018-06-04T05:20:27.846Z,1528089627.846 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-06-04T05:20:27.949Z,1528089627.949 [Rowe_600LCM](INFO): Powering down 2018-06-04T05:20:56.454Z,1528089656.454 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-06-04T05:20:56.454Z,1528089656.454 [NAL9602] Data Fault, FailCount= 1 2018-06-04T05:20:56.455Z,1528089656.455 [NAL9602](ERROR): Data Fault 2018-06-04T05:20:56.528Z,1528089656.528 [CBIT](ERROR): Data Fault in component: NAL9602 2018-06-04T05:20:56.858Z,1528089656.858 [NAL9602](INFO): Powering down 2018-06-04T05:20:57.726Z,1528089657.726 [CBIT](INFO): Clearing failed state for component NAL9602 2018-06-04T05:20:57.726Z,1528089657.726 [NAL9602] No Fault, FailCount= 1 2018-06-04T05:21:27.251Z,1528089687.251 [NAL9602](INFO): Powering up NAL9602 2018-06-04T05:21:38.451Z,1528089698.451 [NAL9602](INFO): NAL9602 initialized 2018-06-04T05:22:22.133Z,1528089742.133 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-06-04T05:22:22.133Z,1528089742.133 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4 2018-06-04T05:22:22.133Z,1528089742.133 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-06-04T05:22:22.155Z,1528089742.155 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-06-04T05:22:22.560Z,1528089742.560 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-06-04T05:22:22.560Z,1528089742.560 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4 2018-06-04T05:22:22.914Z,1528089742.914 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-06-04T05:22:22.914Z,1528089742.914 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-06-04T05:22:22.915Z,1528089742.915 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-06-04T05:23:46.913Z,1528089826.913 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-06-04T05:23:46.913Z,1528089826.913 [Default:CheckIn:C.Wait] Stopped 2018-06-04T05:23:46.913Z,1528089826.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-06-04T05:23:46.913Z,1528089826.913 [Default:CheckIn:D] Running Loop=1 2018-06-04T05:23:47.330Z,1528089827.330 [Default:CheckIn:D] Stopped 2018-06-04T05:23:47.330Z,1528089827.330 [Default:CheckIn:E] Running Loop=1 2018-06-04T05:23:50.430Z,1528089830.430 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.523304 min 2018-06-04T05:23:50.432Z,1528089830.432 [Default:CheckIn:E] Stopped 2018-06-04T05:23:50.432Z,1528089830.432 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-06-04T05:23:50.432Z,1528089830.432 [Default:CheckIn] Stopped 2018-06-04T05:23:50.432Z,1528089830.432 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-06-04T05:23:50.432Z,1528089830.432 [Default:CheckIn](INFO): Running loop #2 2018-06-04T05:23:50.433Z,1528089830.433 [Default:CheckIn] Running Loop=2 2018-06-04T05:23:50.433Z,1528089830.433 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-06-04T05:23:50.433Z,1528089830.433 [Default:CheckIn:Read_GPS] Running Loop=1 2018-06-04T05:25:22.962Z,1528089922.962 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-06-04T05:25:22.962Z,1528089922.962 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5 2018-06-04T05:25:22.962Z,1528089922.962 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-06-04T05:25:22.975Z,1528089922.975 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-06-04T05:25:23.397Z,1528089923.397 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-06-04T05:25:23.397Z,1528089923.397 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5 2018-06-04T05:25:23.795Z,1528089923.795 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-06-04T05:25:23.795Z,1528089923.795 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-06-04T05:25:23.795Z,1528089923.795 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-06-04T05:26:21.785Z,1528089981.785 [BPC1](ERROR): Failed to receive data from both battery packs 2018-06-04T05:26:21.786Z,1528089981.786 [BPC1] Communications Fault, FailCount= 2 2018-06-04T05:26:21.786Z,1528089981.786 [BPC1](ERROR): Communications Fault 2018-06-04T05:26:21.833Z,1528089981.833 [CBIT](ERROR): Communications Fault in component: BPC1 2018-06-04T05:26:23.015Z,1528089983.015 [CBIT](INFO): Clearing failed state for component BPC1 2018-06-04T05:26:23.015Z,1528089983.015 [BPC1] No Fault, FailCount= 2 2018-06-04T05:26:36.959Z,1528089996.959 [DAT](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:26:37.380Z,1528089997.380 [DAT](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:26:37.784Z,1528089997.784 [DAT](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:28:23.847Z,1528090103.847 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-06-04T05:28:23.848Z,1528090103.848 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6 2018-06-04T05:28:23.848Z,1528090103.848 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-06-04T05:28:23.869Z,1528090103.869 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-06-04T05:28:24.260Z,1528090104.260 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-06-04T05:28:24.260Z,1528090104.260 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6 2018-06-04T05:28:24.650Z,1528090104.650 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-06-04T05:28:24.651Z,1528090104.651 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-06-04T05:28:24.651Z,1528090104.651 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-06-04T05:28:50.563Z,1528090130.563 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-06-04T05:23:50.4Z 2018-06-04T05:28:50.563Z,1528090130.563 [Default:CheckIn:Read_GPS] Stopped 2018-06-04T05:28:50.563Z,1528090130.563 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-06-04T05:28:55.414Z,1528090135.414 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180604T051005/Courier0007.lzma 2018-06-04T05:28:56.207Z,1528090136.207 [DataOverHttps](INFO): Moved sent file to Logs/20180604T051005/Courier0007.lzma.bak 2018-06-04T05:28:56.208Z,1528090136.208 [DataOverHttps](INFO): SBD MOMSN=8311188 2018-06-04T05:29:05.019Z,1528090145.019 [DataOverHttps](INFO): Sending 281 bytes from file Logs/20180604T051005/Express0008.lzma 2018-06-04T05:29:05.799Z,1528090145.799 [DataOverHttps](INFO): Moved sent file to Logs/20180604T051005/Express0008.lzma.bak 2018-06-04T05:29:05.800Z,1528090145.800 [DataOverHttps](INFO): SBD MOMSN=8311190 2018-06-04T05:29:06.283Z,1528090146.283 [Default:CheckIn:Read_Iridium] Stopped 2018-06-04T05:29:06.283Z,1528090146.283 [Default:CheckIn:C.Wait] Running Loop=1 2018-06-04T05:29:06.283Z,1528090146.283 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-06-04T05:30:27.485Z,1528090227.485 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-06-04T05:30:27.485Z,1528090227.485 [Rowe_600LCM] No Fault, FailCount= 5 2018-06-04T05:30:27.785Z,1528090227.785 [Rowe_600LCM](INFO): Initializing 2018-06-04T05:30:27.785Z,1528090227.785 [Rowe_600LCM](INFO): Checking LCM 2018-06-04T05:30:27.785Z,1528090227.785 [Rowe_600LCM](INFO): LCM OK 2018-06-04T05:30:27.785Z,1528090227.785 [Rowe_600LCM](INFO): Powering up 2018-06-04T05:30:32.010Z,1528090232.010 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-06-04T05:30:32.072Z,1528090232.072 [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-06-04T05:30:32.079Z,1528090232.079 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-06-04T05:30:32.080Z,1528090232.080 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-06-04T05:30:32.080Z,1528090232.080 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-06-04T05:31:24.896Z,1528090284.896 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-06-04T05:31:24.896Z,1528090284.896 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7 2018-06-04T05:31:24.896Z,1528090284.896 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-06-04T05:31:24.949Z,1528090284.949 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-06-04T05:31:25.274Z,1528090285.274 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-06-04T05:31:25.274Z,1528090285.274 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7 2018-06-04T05:31:25.653Z,1528090285.653 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-06-04T05:31:25.653Z,1528090285.653 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-06-04T05:31:25.654Z,1528090285.654 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-06-04T05:31:29.546Z,1528090289.546 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:31:30.341Z,1528090290.341 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-06-04T05:31:40.391Z,1528090300.391 [NAL9602](FAULT): GPS failed to acquire within timeout. 2018-06-04T05:31:40.391Z,1528090300.391 [NAL9602] Data Fault, FailCount= 2 2018-06-04T05:31:40.391Z,1528090300.391 [NAL9602](ERROR): Data Fault 2018-06-04T05:31:40.481Z,1528090300.481 [CBIT](ERROR): Data Fault in component: NAL9602 2018-06-04T05:31:40.794Z,1528090300.794 [NAL9602](INFO): Powering down 2018-06-04T05:31:41.647Z,1528090301.647 [CBIT](INFO): Clearing failed state for component NAL9602 2018-06-04T05:31:41.647Z,1528090301.647 [NAL9602] No Fault, FailCount= 2 2018-06-04T05:32:10.991Z,1528090330.991 [NAL9602](INFO): Powering up NAL9602 2018-06-04T05:32:22.183Z,1528090342.183 [NAL9602](INFO): NAL9602 initialized 2018-06-04T05:32:23.823Z,1528090343.823 [BPC1](ERROR): Failed to receive data from both battery packs 2018-06-04T05:32:23.823Z,1528090343.823 [BPC1] Communications Fault, FailCount= 3 2018-06-04T05:32:23.823Z,1528090343.823 [BPC1](ERROR): Communications Fault 2018-06-04T05:32:23.870Z,1528090343.870 [CBIT](ERROR): Communications Fault in component: BPC1 2018-06-04T05:32:25.140Z,1528090345.140 [CBIT](INFO): Clearing failed state for compo