2018-01-23T16:19:14.377Z,1516724354.377 [Supervisor](DEBUG): Initializing supervisor. 2018-01-23T16:19:14.380Z,1516724354.380 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2018-01-23T16:19:14.380Z,1516724354.380 [SyncHandler](INFO): Protected caller Thread ID is 799 2018-01-23T16:19:14.381Z,1516724354.381 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2018-01-23T16:19:14.382Z,1516724354.382 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2018-01-23T16:19:14.382Z,1516724354.382 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 800 2018-01-23T16:19:14.385Z,1516724354.385 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2018-01-23T16:19:14.395Z,1516724354.395 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2018-01-23T16:19:14.396Z,1516724354.396 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2018-01-23T16:19:14.397Z,1516724354.397 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 801 2018-01-23T16:19:14.398Z,1516724354.398 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2018-01-23T16:19:14.398Z,1516724354.398 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2018-01-23T16:19:14.399Z,1516724354.399 [logger ThreadHandler](INFO): Protected caller Thread ID is 802 2018-01-23T16:19:14.401Z,1516724354.401 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2018-01-23T16:19:14.401Z,1516724354.401 [Supervisor](INFO): Looking for Config files in directory: Config/ 2018-01-23T16:19:14.405Z,1516724354.405 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2018-01-23T16:19:14.702Z,1516724354.702 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2018-01-23T16:19:14.704Z,1516724354.704 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2018-01-23T16:19:14.882Z,1516724354.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2018-01-23T16:19:14.884Z,1516724354.884 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2018-01-23T16:19:15.144Z,1516724355.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2018-01-23T16:19:15.144Z,1516724355.144 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2018-01-23T16:19:15.280Z,1516724355.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2018-01-23T16:19:15.280Z,1516724355.280 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2018-01-23T16:19:15.376Z,1516724355.376 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2018-01-23T16:19:15.378Z,1516724355.378 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2018-01-23T16:19:15.801Z,1516724355.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2018-01-23T16:19:15.802Z,1516724355.802 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2018-01-23T16:19:16.119Z,1516724356.119 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2018-01-23T16:19:16.120Z,1516724356.120 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2018-01-23T16:19:16.533Z,1516724356.533 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2018-01-23T16:19:16.535Z,1516724356.535 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2018-01-23T16:19:16.637Z,1516724356.637 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2018-01-23T16:19:16.639Z,1516724356.639 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2018-01-23T16:19:16.734Z,1516724356.734 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2018-01-23T16:19:16.735Z,1516724356.735 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2018-01-23T16:19:16.934Z,1516724356.934 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2018-01-23T16:19:16.936Z,1516724356.936 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2018-01-23T16:19:17.124Z,1516724357.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2018-01-23T16:19:17.124Z,1516724357.124 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2018-01-23T16:19:17.436Z,1516724357.436 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2018-01-23T16:19:17.436Z,1516724357.436 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2018-01-23T16:19:17.571Z,1516724357.571 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2018-01-23T16:19:17.571Z,1516724357.571 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2018-01-23T16:19:17.653Z,1516724357.653 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2018-01-23T16:19:17.656Z,1516724357.656 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2018-01-23T16:19:18.213Z,1516724358.213 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2018-01-23T16:19:18.489Z,1516724358.489 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2018-01-23T16:19:18.581Z,1516724358.581 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2018-01-23T16:19:18.665Z,1516724358.665 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2018-01-23T16:19:18.807Z,1516724358.807 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2018-01-23T16:19:18.971Z,1516724358.971 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2018-01-23T16:19:19.047Z,1516724359.047 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2018-01-23T16:19:19.267Z,1516724359.267 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2018-01-23T16:19:19.268Z,1516724359.268 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2018-01-23T16:19:19.350Z,1516724359.350 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2018-01-23T16:19:19.437Z,1516724359.437 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2018-01-23T16:19:19.534Z,1516724359.534 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2018-01-23T16:19:19.653Z,1516724359.653 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2018-01-23T16:19:19.659Z,1516724359.659 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2018-01-23T16:19:19.928Z,1516724359.928 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2018-01-23T16:19:19.928Z,1516724359.928 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2018-01-23T16:19:19.982Z,1516724359.982 [DepthRateCalculator] Loaded 2018-01-23T16:19:19.983Z,1516724359.983 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2018-01-23T16:19:19.988Z,1516724359.988 [PitchRateCalculator] Loaded 2018-01-23T16:19:19.989Z,1516724359.989 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2018-01-23T16:19:20.004Z,1516724360.004 [SpeedCalculator] Loaded 2018-01-23T16:19:20.004Z,1516724360.004 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2018-01-23T16:19:20.025Z,1516724360.025 [TempGradientCalculator] Loaded 2018-01-23T16:19:20.025Z,1516724360.025 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2018-01-23T16:19:20.040Z,1516724360.040 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2018-01-23T16:19:20.040Z,1516724360.040 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2018-01-23T16:19:20.045Z,1516724360.045 [YawRateCalculator] Loaded 2018-01-23T16:19:20.046Z,1516724360.046 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2018-01-23T16:19:20.046Z,1516724360.046 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2018-01-23T16:19:20.047Z,1516724360.047 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2018-01-23T16:19:20.162Z,1516724360.162 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2018-01-23T16:19:20.162Z,1516724360.162 [StratificationFrontDetector](DEBUG): (re)initializing 2018-01-23T16:19:20.163Z,1516724360.163 [StratificationFrontDetector] Loaded 2018-01-23T16:19:20.163Z,1516724360.163 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2018-01-23T16:19:20.163Z,1516724360.163 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2018-01-23T16:19:20.165Z,1516724360.165 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2018-01-23T16:19:20.294Z,1516724360.294 [BuoyancyServo] Loaded 2018-01-23T16:19:20.295Z,1516724360.295 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2018-01-23T16:19:20.309Z,1516724360.309 [ElevatorServo] Loaded 2018-01-23T16:19:20.309Z,1516724360.309 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2018-01-23T16:19:20.324Z,1516724360.324 [MassServo] Loaded 2018-01-23T16:19:20.324Z,1516724360.324 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2018-01-23T16:19:20.339Z,1516724360.339 [RudderServo] Loaded 2018-01-23T16:19:20.339Z,1516724360.339 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2018-01-23T16:19:20.353Z,1516724360.353 [ThrusterServo] Loaded 2018-01-23T16:19:20.353Z,1516724360.353 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2018-01-23T16:19:20.353Z,1516724360.353 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2018-01-23T16:19:20.354Z,1516724360.354 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2018-01-23T16:19:20.378Z,1516724360.378 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2018-01-23T16:19:20.378Z,1516724360.378 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2018-01-23T16:19:20.498Z,1516724360.498 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2018-01-23T16:19:20.499Z,1516724360.499 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2018-01-23T16:19:21.029Z,1516724361.029 [DataOverHttps] Loaded 2018-01-23T16:19:21.030Z,1516724361.030 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2018-01-23T16:19:21.043Z,1516724361.043 [Depth_Keller] Loaded 2018-01-23T16:19:21.043Z,1516724361.043 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2018-01-23T16:19:21.048Z,1516724361.048 [DropWeight] Loaded 2018-01-23T16:19:21.048Z,1516724361.048 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2018-01-23T16:19:21.141Z,1516724361.141 [NAL9602] Loaded 2018-01-23T16:19:21.142Z,1516724361.142 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2018-01-23T16:19:21.157Z,1516724361.157 [Onboard] Loaded 2018-01-23T16:19:21.157Z,1516724361.157 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2018-01-23T16:19:21.167Z,1516724361.167 [Radio_Surface] Loaded 2018-01-23T16:19:21.168Z,1516724361.168 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2018-01-23T16:19:21.169Z,1516724361.169 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4086B4E0 2018-01-23T16:19:21.169Z,1516724361.169 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 884 2018-01-23T16:19:21.321Z,1516724361.321 [PNI_TCM] Loaded 2018-01-23T16:19:21.321Z,1516724361.321 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2018-01-23T16:19:21.379Z,1516724361.379 [Rowe_600LCM] Loaded 2018-01-23T16:19:21.379Z,1516724361.379 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2018-01-23T16:19:21.380Z,1516724361.380 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 4089B4E0 2018-01-23T16:19:21.381Z,1516724361.381 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 885 2018-01-23T16:19:23.073Z,1516724363.073 [BPC1] Loaded 2018-01-23T16:19:23.074Z,1516724363.074 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2018-01-23T16:19:23.074Z,1516724363.074 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2018-01-23T16:19:23.076Z,1516724363.076 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2018-01-23T16:19:23.597Z,1516724363.597 [SBIT](DEBUG): Construct Startup Built In Test. 2018-01-23T16:19:23.622Z,1516724363.622 [SBIT] Loaded 2018-01-23T16:19:23.622Z,1516724363.622 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2018-01-23T16:19:23.623Z,1516724363.623 [IBIT](DEBUG): Construct Initiated Built In Test. 2018-01-23T16:19:23.634Z,1516724363.634 [IBIT] Loaded 2018-01-23T16:19:23.634Z,1516724363.634 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2018-01-23T16:19:23.637Z,1516724363.637 [CBIT](DEBUG): Construct Continuous Built In Test. 2018-01-23T16:19:23.786Z,1516724363.786 [CBIT] Loaded 2018-01-23T16:19:23.786Z,1516724363.786 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2018-01-23T16:19:23.787Z,1516724363.787 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2018-01-23T16:19:23.787Z,1516724363.787 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2018-01-23T16:19:23.965Z,1516724363.965 [Aanderaa_O2] Loaded 2018-01-23T16:19:23.966Z,1516724363.966 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2018-01-23T16:19:23.977Z,1516724363.977 [CANONSampler] Loaded 2018-01-23T16:19:23.977Z,1516724363.977 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2018-01-23T16:19:24.053Z,1516724364.053 [CTD_NeilBrown] Loaded 2018-01-23T16:19:24.053Z,1516724364.053 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2018-01-23T16:19:24.055Z,1516724364.055 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409614E0 2018-01-23T16:19:24.055Z,1516724364.055 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 886 2018-01-23T16:19:24.086Z,1516724364.086 [CTD_Seabird] Loaded 2018-01-23T16:19:24.087Z,1516724364.087 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2018-01-23T16:19:24.088Z,1516724364.088 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409914E0 2018-01-23T16:19:24.088Z,1516724364.088 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 887 2018-01-23T16:19:24.102Z,1516724364.102 [PAR_Licor] Loaded 2018-01-23T16:19:24.102Z,1516724364.102 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2018-01-23T16:19:24.149Z,1516724364.149 [WetLabsBB2FL] Loaded 2018-01-23T16:19:24.150Z,1516724364.150 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2018-01-23T16:19:24.151Z,1516724364.151 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409C14E0 2018-01-23T16:19:24.151Z,1516724364.151 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 888 2018-01-23T16:19:24.193Z,1516724364.193 [WetLabsSeaOWL_UV_A] Loaded 2018-01-23T16:19:24.193Z,1516724364.193 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread. 2018-01-23T16:19:24.194Z,1516724364.194 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409F14E0 2018-01-23T16:19:24.195Z,1516724364.195 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 889 2018-01-23T16:19:24.195Z,1516724364.195 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2018-01-23T16:19:24.196Z,1516724364.196 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2018-01-23T16:19:24.280Z,1516724364.280 [VerticalControl](DEBUG): Construct VerticalControl. 2018-01-23T16:19:24.364Z,1516724364.364 [VerticalControl] Loaded 2018-01-23T16:19:24.364Z,1516724364.364 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2018-01-23T16:19:24.365Z,1516724364.365 [HorizontalControl](DEBUG): Construct HorizontalControl. 2018-01-23T16:19:24.421Z,1516724364.421 [HorizontalControl] Loaded 2018-01-23T16:19:24.421Z,1516724364.421 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2018-01-23T16:19:24.422Z,1516724364.422 [SpeedControl](DEBUG): Construct SpeedControl. 2018-01-23T16:19:24.423Z,1516724364.423 [SpeedControl] Loaded 2018-01-23T16:19:24.424Z,1516724364.424 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2018-01-23T16:19:24.424Z,1516724364.424 [LoopControl](DEBUG): Construct LoopControl. 2018-01-23T16:19:24.425Z,1516724364.425 [LoopControl] Loaded 2018-01-23T16:19:24.425Z,1516724364.425 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2018-01-23T16:19:24.425Z,1516724364.425 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2018-01-23T16:19:24.426Z,1516724364.426 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2018-01-23T16:19:24.462Z,1516724364.462 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2018-01-23T16:19:24.463Z,1516724364.463 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2018-01-23T16:19:24.568Z,1516724364.568 [DeadReckonUsingSpeedCalculator] Loaded 2018-01-23T16:19:24.568Z,1516724364.568 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2018-01-23T16:19:24.621Z,1516724364.621 [DeadReckonWithRespectToSeafloor] Loaded 2018-01-23T16:19:24.622Z,1516724364.622 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread. 2018-01-23T16:19:24.637Z,1516724364.637 [NavChart] Loaded 2018-01-23T16:19:24.637Z,1516724364.637 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2018-01-23T16:19:24.641Z,1516724364.641 [UniversalFixResidualReporter] Loaded 2018-01-23T16:19:24.642Z,1516724364.642 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2018-01-23T16:19:24.642Z,1516724364.642 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2018-01-23T16:19:24.646Z,1516724364.646 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2018-01-23T16:19:24.647Z,1516724364.647 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2018-01-23T16:19:24.653Z,1516724364.653 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2018-01-23T16:19:24.654Z,1516724364.654 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A7C4E0 2018-01-23T16:19:24.655Z,1516724364.655 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 890 2018-01-23T16:19:24.659Z,1516724364.659 [Supervisor](INFO): Main Thread ID is 795 2018-01-23T16:19:24.659Z,1516724364.659 [Supervisor](DEBUG): Running supervisor. 2018-01-23T16:19:24.660Z,1516724364.660 [CommandLine ThreadHandler](INFO): Handler Thread ID is 891 2018-01-23T16:19:24.663Z,1516724364.663 [controlThread ThreadHandler](INFO): Handler Thread ID is 892 2018-01-23T16:19:24.663Z,1516724364.663 [controlThread](DEBUG): Initializing ControlThread 2018-01-23T16:19:24.664Z,1516724364.664 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-01-23T16:19:24.664Z,1516724364.664 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2018-01-23T16:19:24.665Z,1516724364.665 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2018-01-23T16:19:24.665Z,1516724364.665 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2018-01-23T16:19:24.665Z,1516724364.665 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2018-01-23T16:19:24.666Z,1516724364.666 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2018-01-23T16:19:24.672Z,1516724364.672 [SBIT](INFO): Initialize SBIT Component. 2018-01-23T16:19:24.673Z,1516724364.673 [SBIT](IMPORTANT): git: 2017-12-12 2018-01-23T16:19:24.673Z,1516724364.673 [SBIT](INFO): git hash: 18638d31f033e3fa0cb90b26256f5481d37f00cc 2018-01-23T16:19:24.673Z,1516724364.673 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2018-01-23T16:19:24.675Z,1516724364.675 [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-01-23T16:19:24.675Z,1516724364.675 [SBIT](INFO): Beginning SBIT in 23.000000 seconds. 2018-01-23T16:19:24.676Z,1516724364.676 [IBIT](INFO): Initialize IBIT Component. 2018-01-23T16:19:24.677Z,1516724364.677 [CBIT](DEBUG): Initialize CBIT Component. 2018-01-23T16:19:24.677Z,1516724364.677 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2018-01-23T16:19:24.678Z,1516724364.678 [logger ThreadHandler](INFO): Handler Thread ID is 893 2018-01-23T16:19:24.698Z,1516724364.698 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 894 2018-01-23T16:19:24.704Z,1516724364.704 [Radio_Surface](INFO): Powering up 2018-01-23T16:19:24.710Z,1516724364.710 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 895 2018-01-23T16:19:24.711Z,1516724364.711 [Rowe_600LCM](INFO): Initializing 2018-01-23T16:19:24.712Z,1516724364.712 [Rowe_600LCM](INFO): Checking LCM 2018-01-23T16:19:24.762Z,1516724364.762 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2018-01-23T16:19:24.764Z,1516724364.764 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2018-01-23T16:19:24.765Z,1516724364.765 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2018-01-23T16:19:24.765Z,1516724364.765 [LoopControl](DEBUG): Initialize LoopControlComponent. 2018-01-23T16:19:24.766Z,1516724364.766 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-01-23T16:19:24.766Z,1516724364.766 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-01-23T16:19:24.811Z,1516724364.811 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-01-23T16:19:24.811Z,1516724364.811 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component. 2018-01-23T16:19:24.812Z,1516724364.812 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s. 2018-01-23T16:19:24.812Z,1516724364.812 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s. 2018-01-23T16:19:24.812Z,1516724364.812 [NavChart](DEBUG): Initialize NavChart Navigation. 2018-01-23T16:19:24.813Z,1516724364.813 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2018-01-23T16:19:24.814Z,1516724364.814 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2018-01-23T16:19:24.815Z,1516724364.815 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 896 2018-01-23T16:19:24.815Z,1516724364.815 [CTD_NeilBrown](INFO): Powering down 2018-01-23T16:19:24.839Z,1516724364.839 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 897 2018-01-23T16:19:24.840Z,1516724364.840 [CTD_Seabird](INFO): Initializing 2018-01-23T16:19:25.004Z,1516724365.004 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2018-01-23T16:19:25.008Z,1516724365.008 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 899 2018-01-23T16:19:25.009Z,1516724365.009 [WetLabsBB2FL](INFO): Powering down 2018-01-23T16:19:25.050Z,1516724365.050 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 900 2018-01-23T16:19:25.091Z,1516724365.091 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-01-23T16:19:25.091Z,1516724365.091 [CTD_Seabird](INFO): Powering down 2018-01-23T16:19:25.150Z,1516724365.150 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 901 2018-01-23T16:19:25.164Z,1516724365.164 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2018-01-23T16:19:25.164Z,1516724365.164 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2018-01-23T16:19:25.165Z,1516724365.165 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2018-01-23T16:19:25.165Z,1516724365.165 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2018-01-23T16:19:25.165Z,1516724365.165 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2018-01-23T16:19:25.165Z,1516724365.165 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2018-01-23T16:19:25.165Z,1516724365.165 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2018-01-23T16:19:25.166Z,1516724365.166 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2018-01-23T16:19:25.166Z,1516724365.166 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2018-01-23T16:19:25.166Z,1516724365.166 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2018-01-23T16:19:25.166Z,1516724365.166 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2018-01-23T16:19:25.166Z,1516724365.166 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2018-01-23T16:19:25.167Z,1516724365.167 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2018-01-23T16:19:25.167Z,1516724365.167 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2018-01-23T16:19:25.167Z,1516724365.167 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2018-01-23T16:19:25.167Z,1516724365.167 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2018-01-23T16:19:25.182Z,1516724365.182 [MissionManager](DEBUG): 2018-01-23T16:19:25.184Z,1516724365.184 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2018-01-23T16:19:25.281Z,1516724365.281 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2018-01-23T16:19:25.286Z,1516724365.286 [Rowe_600LCM](INFO): LCM OK 2018-01-23T16:19:25.286Z,1516724365.286 [Rowe_600LCM](INFO): Powering up 2018-01-23T16:19:25.290Z,1516724365.290 [Default:A.Wait](DEBUG): Construct Wait. 2018-01-23T16:19:25.292Z,1516724365.292 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2018-01-23T16:19:25.301Z,1516724365.301 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2018-01-23T16:19:25.324Z,1516724365.324 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2018-01-23T16:19:25.329Z,1516724365.329 [Default:E.Execute](DEBUG): Construct Execute. 2018-01-23T16:19:25.349Z,1516724365.349 [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-01-23T16:19:25.362Z,1516724365.362 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-01-23T16:19:25.391Z,1516724365.391 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2018-01-23T16:19:25.405Z,1516724365.405 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2018-01-23T16:19:25.640Z,1516724365.640 [CANONSampler](INFO): Powering down 2018-01-23T16:19:25.771Z,1516724365.771 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-01-23T16:19:25.859Z,1516724365.859 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:25.964Z,1516724365.964 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:26.082Z,1516724366.082 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-01-23T16:19:26.090Z,1516724366.090 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-01-23T16:19:26.114Z,1516724366.114 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-01-23T16:19:26.122Z,1516724366.122 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-01-23T16:19:26.148Z,1516724366.148 [MassServo](DEBUG): Initializing EZServoServo. 2018-01-23T16:19:26.154Z,1516724366.154 [MassServo](DEBUG): Initializing MassServo. 2018-01-23T16:19:26.164Z,1516724366.164 [RudderServo](DEBUG): Initializing EZServoServo. 2018-01-23T16:19:26.170Z,1516724366.170 [RudderServo](DEBUG): Initializing RudderServo. 2018-01-23T16:19:26.192Z,1516724366.192 [ThrusterServo](DEBUG): Initializing EZServoServo. 2018-01-23T16:19:26.199Z,1516724366.199 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2018-01-23T16:19:26.483Z,1516724366.483 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:26.483Z,1516724366.483 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:26.741Z,1516724366.741 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:26.750Z,1516724366.750 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:27.090Z,1516724367.090 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2018-01-23T16:19:27.090Z,1516724367.090 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2018-01-23T16:19:27.090Z,1516724367.090 [BuoyancyServo] Communications Fault, FailCount= 1 2018-01-23T16:19:27.090Z,1516724367.090 [BuoyancyServo](ERROR): Communications Fault 2018-01-23T16:19:27.289Z,1516724367.289 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2018-01-23T16:19:27.369Z,1516724367.369 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:27.370Z,1516724367.370 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:27.375Z,1516724367.375 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-01-23T16:19:27.376Z,1516724367.376 [BuoyancyServo](INFO): Powering down 2018-01-23T16:19:27.745Z,1516724367.745 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:27.746Z,1516724367.746 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:28.169Z,1516724368.169 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:28.170Z,1516724368.170 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:28.538Z,1516724368.538 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:28.546Z,1516724368.546 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:28.949Z,1516724368.949 [Aanderaa_O2](INFO): Powering down 2018-01-23T16:19:29.045Z,1516724369.045 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:29.046Z,1516724369.046 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet. 2018-01-23T16:19:29.330Z,1516724369.330 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-01-23T16:19:29.493Z,1516724369.493 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2018-01-23T16:19:29.493Z,1516724369.493 [BuoyancyServo] No Fault, FailCount= 1 2018-01-23T16:19:29.497Z,1516724369.497 [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 38400 >& /dev/null & 2018-01-23T16:19:29.652Z,1516724369.652 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-01-23T16:19:29.653Z,1516724369.653 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-01-23T16:19:29.655Z,1516724369.655 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-01-23T16:19:29.792Z,1516724369.792 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-01-23T16:19:29.793Z,1516724369.793 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-01-23T16:19:48.199Z,1516724388.199 [SBIT](IMPORTANT): Beginning Startup BIT 2018-01-23T16:19:48.204Z,1516724388.204 [CBIT](IMPORTANT): Beginning ground fault scan 2018-01-23T16:19:51.452Z,1516724391.452 [NAL9602](INFO): Powering up NAL9602 2018-01-23T16:19:59.540Z,1516724399.540 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.012402 CHAN A1 (24V): 0.119394 CHAN A2 (12V): -0.001774 CHAN A3 (5V): -0.001587 CHAN B0 (3.3V): 0.000031 CHAN B1 (3.15aV): -0.000257 CHAN B2 (3.15bV): 0.000257 CHAN B3 (GND): -0.000348 OPEN: -0.000357 Full Scale Calc: 4.765 mA, -1.589 mA 2018-01-23T16:20:02.652Z,1516724402.652 [NAL9602](INFO): NAL9602 initialized 2018-01-23T16:20:25.705Z,1516724425.705 [NAL9602](INFO): SBD MO Status=2, MOMSN=3905, MT Status=2, MTMSN=0 2018-01-23T16:20:25.705Z,1516724425.705 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-01-23T16:20:34.273Z,1516724434.273 [NAL9602](INFO): SBD MO Status=0, MOMSN=3905, MT Status=0, MTMSN=0 2018-01-23T16:20:34.273Z,1516724434.273 [NAL9602](INFO): No messages in MT queue 2018-01-23T16:20:42.034Z,1516724442.034 [SBIT](IMPORTANT): SBIT PASSED 2018-01-23T16:20:42.317Z,1516724442.317 [MissionManager](IMPORTANT): Started mission Startup 2018-01-23T16:20:42.317Z,1516724442.317 [Startup] Running Loop=1 2018-01-23T16:20:42.318Z,1516724442.318 [Startup](DEBUG): Aggregate::initialize Startup 2018-01-23T16:20:42.318Z,1516724442.318 [Startup:A.GoToSurface] Running Loop=1 2018-01-23T16:20:42.318Z,1516724442.318 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-01-23T16:20:42.319Z,1516724442.319 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-01-23T16:20:42.319Z,1516724442.319 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-01-23T16:20:42.319Z,1516724442.319 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-01-23T16:20:42.320Z,1516724442.320 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2018-01-23T16:20:42.320Z,1516724442.320 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-01-23T16:20:42.326Z,1516724442.326 [Startup:StartupSatComms] Running Loop=1 2018-01-23T16:20:42.326Z,1516724442.326 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2018-01-23T16:20:42.326Z,1516724442.326 [Startup:StartupSatComms:A] Running Loop=1 2018-01-23T16:20:42.713Z,1516724442.713 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2018-01-23T16:21:11.524Z,1516724471.524 [BPC1](ERROR): Failed to receive battery data 2018-01-23T16:21:11.524Z,1516724471.524 [BPC1] Communications Fault, FailCount= 1 2018-01-23T16:21:11.525Z,1516724471.525 [BPC1](ERROR): Communications Fault 2018-01-23T16:21:11.610Z,1516724471.610 [CBIT](ERROR): Communications Fault in component: BPC1 2018-01-23T16:21:12.818Z,1516724472.818 [CBIT](INFO): Clearing failed state for component BPC1 2018-01-23T16:21:12.818Z,1516724472.818 [BPC1] No Fault, FailCount= 1 2018-01-23T16:21:25.710Z,1516724485.710 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-01-23T16:21:25.710Z,1516724485.710 [Rowe_600LCM] Communications Fault, FailCount= 1 2018-01-23T16:21:25.710Z,1516724485.710 [Rowe_600LCM](ERROR): Communications Fault 2018-01-23T16:21:26.042Z,1516724486.042 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-01-23T16:21:26.114Z,1516724486.114 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-01-23T16:21:26.221Z,1516724486.221 [Rowe_600LCM](INFO): Powering down 2018-01-23T16:21:27.612Z,1516724487.612 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-01-23T16:21:27.612Z,1516724487.612 [Rowe_600LCM] No Fault, FailCount= 1 2018-01-23T16:21:27.838Z,1516724487.838 [Rowe_600LCM](INFO): Initializing 2018-01-23T16:21:27.839Z,1516724487.839 [Rowe_600LCM](INFO): Checking LCM 2018-01-23T16:21:27.839Z,1516724487.839 [Rowe_600LCM](INFO): LCM OK 2018-01-23T16:21:27.839Z,1516724487.839 [Rowe_600LCM](INFO): Powering up 2018-01-23T16:21:32.139Z,1516724492.139 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-01-23T16:21:32.213Z,1516724492.213 [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 38400 >& /dev/null & 2018-01-23T16:21:32.214Z,1516724492.214 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-01-23T16:21:32.216Z,1516724492.216 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-01-23T16:21:32.217Z,1516724492.217 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-01-23T16:21:33.507Z,1516724493.507 [BPC1](ERROR): Failed to receive battery data 2018-01-23T16:21:33.507Z,1516724493.507 [BPC1] Communications Fault, FailCount= 2 2018-01-23T16:21:33.507Z,1516724493.507 [BPC1](ERROR): Communications Fault 2018-01-23T16:21:33.606Z,1516724493.606 [CBIT](ERROR): Communications Fault in component: BPC1 2018-01-23T16:21:34.802Z,1516724494.802 [CBIT](INFO): Clearing failed state for component BPC1 2018-01-23T16:21:34.802Z,1516724494.802 [BPC1] No Fault, FailCount= 2 2018-01-23T16:21:42.391Z,1516724502.391 [Startup:StartupSatComms:A](INFO): Timed out from 2018-01-23T16:20:42.3Z 2018-01-23T16:21:42.391Z,1516724502.391 [Startup:StartupSatComms:A] Stopped 2018-01-23T16:21:42.391Z,1516724502.391 [Startup:StartupSatComms:B] Running Loop=1 2018-01-23T16:21:42.731Z,1516724502.731 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-01-23T16:21:58.740Z,1516724518.740 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003797 2018-01-23T16:22:03.039Z,1516724523.039 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20180123T002446/Courier0004.lzma 2018-01-23T16:22:03.831Z,1516724523.831 [DataOverHttps](INFO): Moved sent file to Logs/20180123T002446/Courier0004.lzma.bak 2018-01-23T16:22:03.831Z,1516724523.831 [DataOverHttps](INFO): SBD MOMSN=7755853 2018-01-23T16:22:13.276Z,1516724533.276 [DataOverHttps](INFO): Sending 316 bytes from file Logs/20180123T002446/Express0005.lzma 2018-01-23T16:22:13.673Z,1516724533.673 [NAL9602](INFO): SBD MO Status=2, MOMSN=3906, MT Status=2, MTMSN=0 2018-01-23T16:22:13.673Z,1516724533.673 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-01-23T16:22:14.066Z,1516724534.066 [DataOverHttps](INFO): Moved sent file to Logs/20180123T002446/Express0005.lzma.bak 2018-01-23T16:22:14.067Z,1516724534.067 [DataOverHttps](INFO): SBD MOMSN=7755857 2018-01-23T16:22:23.464Z,1516724543.464 [DataOverHttps](INFO): Sending 645 bytes from file Logs/20180123T161914/Express0001.lzma 2018-01-23T16:22:24.263Z,1516724544.263 [DataOverHttps](INFO): Moved sent file to Logs/20180123T161914/Express0001.lzma.bak 2018-01-23T16:22:24.263Z,1516724544.263 [DataOverHttps](INFO): SBD MOMSN=7755865 2018-01-23T16:22:24.712Z,1516724544.712 [Startup:StartupSatComms:B] Stopped 2018-01-23T16:22:24.712Z,1516724544.712 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2018-01-23T16:22:24.712Z,1516724544.712 [Startup:StartupSatComms] Stopped 2018-01-23T16:22:24.712Z,1516724544.712 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2018-01-23T16:22:24.713Z,1516724544.713 [Startup](INFO): Completed Startup 2018-01-23T16:22:24.713Z,1516724544.713 [MissionManager](INFO): Startup is completed. 2018-01-23T16:22:24.713Z,1516724544.713 [MissionManager](INFO): Uninitializing Mission Startup 2018-01-23T16:22:24.713Z,1516724544.713 [Startup] Stopped 2018-01-23T16:22:24.713Z,1516724544.713 [Startup](DEBUG): Aggregate::uninitialize Startup 2018-01-23T16:22:24.713Z,1516724544.713 [Startup:A.GoToSurface] Stopped 2018-01-23T16:22:24.713Z,1516724544.713 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-01-23T16:22:25.107Z,1516724545.107 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-01-23T16:22:25.108Z,1516724545.108 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2018-01-23T16:22:25.108Z,1516724545.108 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-01-23T16:22:25.109Z,1516724545.109 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-01-23T16:22:25.109Z,1516724545.109 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1 2018-01-23T16:22:25.109Z,1516724545.109 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault 2018-01-23T16:22:25.111Z,1516724545.111 [MissionManager](IMPORTANT): Started mission Default 2018-01-23T16:22:25.111Z,1516724545.111 [Default] Running Loop=1 2018-01-23T16:22:25.111Z,1516724545.111 [Default](DEBUG): Aggregate::initialize Default 2018-01-23T16:22:25.112Z,1516724545.112 [Default:B.GoToSurface] Running Loop=1 2018-01-23T16:22:25.112Z,1516724545.112 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-01-23T16:22:25.112Z,1516724545.112 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-01-23T16:22:25.112Z,1516724545.112 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-01-23T16:22:25.113Z,1516724545.113 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-01-23T16:22:25.113Z,1516724545.113 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2018-01-23T16:22:25.113Z,1516724545.113 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-01-23T16:22:25.113Z,1516724545.113 [Default:A.Wait] Running Loop=1 2018-01-23T16:22:25.113Z,1516724545.113 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-01-23T16:22:25.226Z,1516724545.226 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-01-23T16:22:25.227Z,1516724545.227 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor 2018-01-23T16:22:28.482Z,1516724548.482 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-01-23T16:22:28.482Z,1516724548.482 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2018-01-23T16:22:28.483Z,1516724548.483 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor 2018-01-23T16:22:28.483Z,1516724548.483 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1 2018-01-23T16:22:28.637Z,1516724548.637 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-01-23T16:22:28.637Z,1516724548.637 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-01-23T16:22:28.643Z,1516724548.643 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-01-23T16:22:28.644Z,1516724548.644 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component. 2018-01-23T16:22:28.644Z,1516724548.644 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s. 2018-01-23T16:22:28.644Z,1516724548.644 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s. 2018-01-23T16:22:38.142Z,1516724558.142 [Default:A.Wait](INFO): Done Waiting. 2018-01-23T16:22:38.142Z,1516724558.142 [Default:A.Wait] Stopped 2018-01-23T16:22:38.142Z,1516724558.142 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-01-23T16:22:38.543Z,1516724558.543 [Default:CheckIn] Running Loop=1 2018-01-23T16:22:38.543Z,1516724558.543 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-01-23T16:22:38.543Z,1516724558.543 [Default:CheckIn:Read_GPS] Running Loop=1 2018-01-23T16:22:38.955Z,1516724558.955 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2018-01-23T16:23:11.716Z,1516724591.716 [BPC1](ERROR): Failed to receive battery data 2018-01-23T16:23:11.716Z,1516724591.716 [BPC1] Communications Fault, FailCount= 1 2018-01-23T16:23:11.716Z,1516724591.716 [BPC1](ERROR): Communications Fault 2018-01-23T16:23:11.831Z,1516724591.831 [CBIT](ERROR): Communications Fault in component: BPC1 2018-01-23T16:23:13.054Z,1516724593.054 [CBIT](INFO): Clearing failed state for component BPC1 2018-01-23T16:23:13.054Z,1516724593.054 [BPC1] No Fault, FailCount= 1 2018-01-23T16:24:05.230Z,1516724645.230 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-01-23T16:24:05.230Z,1516724645.230 [Rowe_600LCM] Communications Fault, FailCount= 2 2018-01-23T16:24:05.230Z,1516724645.230 [Rowe_600LCM](ERROR): Communications Fault 2018-01-23T16:24:05.274Z,1516724645.274 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-01-23T16:24:05.634Z,1516724645.634 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-01-23T16:24:05.796Z,1516724645.796 [Rowe_600LCM](INFO): Powering down 2018-01-23T16:24:07.274Z,1516724647.274 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-01-23T16:24:07.274Z,1516724647.274 [Rowe_600LCM] No Fault, FailCount= 2 2018-01-23T16:24:07.411Z,1516724647.411 [Rowe_600LCM](INFO): Initializing 2018-01-23T16:24:07.411Z,1516724647.411 [Rowe_600LCM](INFO): Checking LCM 2018-01-23T16:24:07.411Z,1516724647.411 [Rowe_600LCM](INFO): LCM OK 2018-01-23T16:24:07.411Z,1516724647.411 [Rowe_600LCM](INFO): Powering up 2018-01-23T16:24:08.375Z,1516724648.375 [BPC1](ERROR): Failed to receive battery data 2018-01-23T16:24:08.376Z,1516724648.376 [BPC1] Communications Fault, FailCount= 1 2018-01-23T16:24:08.376Z,1516724648.376 [BPC1](ERROR): Communications Fault 2018-01-23T16:24:08.506Z,1516724648.506 [CBIT](ERROR): Communications Fault in component: BPC1 2018-01-23T16:24:09.670Z,1516724649.670 [CBIT](INFO): Clearing failed state for component BPC1 2018-01-23T16:24:09.670Z,1516724649.670 [BPC1] No Fault, FailCount= 1 2018-01-23T16:24:11.570Z,1516724651.570 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-01-23T16:24:11.739Z,1516724651.739 [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 38400 >& /dev/null & 2018-01-23T16:24:11.740Z,1516724651.740 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-01-23T16:24:11.741Z,1516724651.741 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-01-23T16:24:11.741Z,1516724651.741 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-01-23T16:24:20.729Z,1516724660.729 [CommandLine](IMPORTANT): got command get Onboard.Pressure pound_per_square_inch 2018-01-23T16:24:20.739Z,1516724660.739 [CommandLine](IMPORTANT): Onboard.Pressure 9.463606 psi 2018-01-23T16:24:30.473Z,1516724670.473 [CommandLine](IMPORTANT): got command get Onboard.Humidity 2018-01-23T16:24:30.474Z,1516724670.474 [CommandLine](IMPORTANT): Onboard.Humidity 15.187401 % 2018-01-23T16:25:03.835Z,1516724703.835 [BPC1](ERROR): Failed to receive battery data 2018-01-23T16:25:03.835Z,1516724703.835 [BPC1] Communications Fault, FailCount= 1 2018-01-23T16:25:03.835Z,1516724703.835 [BPC1](ERROR): Communications Fault 2018-01-23T16:25:03.922Z,1516724703.922 [CBIT](ERROR): Communications Fault in component: BPC1 2018-01-23T16:25:05.158Z,1516724705.158 [CBIT](INFO): Clearing failed state for component BPC1 2018-01-23T16:25:05.158Z,1516724705.158 [BPC1] No Fault, FailCount= 1 2018-01-23T16:25:29.174Z,1516724729.174 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-01-23T16:25:29.174Z,1516724729.174 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2018-01-23T16:25:29.175Z,1516724729.174 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2018-01-23T16:25:29.176Z,1516724729.176 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2018-01-23T16:25:29.176Z,1516724729.176 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2 2018-01-23T16:25:29.176Z,1516724729.176 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault 2018-01-23T16:25:29.270Z,1516724729.270 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2018-01-23T16:25:29.270Z,1516724729.270 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor 2018-01-23T16:25:29.503Z,1516724729.503 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2018-01-23T16:25:29.503Z,1516724729.503 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2018-01-23T16:25:29.504Z,1516724729.504 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor 2018-01-23T16:25:29.504Z,1516724729.504 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2 2018-01-23T16:25:29.740Z,1516724729.740 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-01-23T16:25:29.740Z,1516724729.740 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-01-23T16:25:29.740Z,1516724729.740 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-01-23T16:25:29.741Z,1516724729.741 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component. 2018-01-23T16:25:29.741Z,1516724729.741 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s. 2018-01-23T16:25:29.741Z,1516724729.741 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s. 2018-01-23T16:25:40.117Z,1516724740.117 [BPC1](ERROR): Failed to parse bank A battery data 2018-01-23T16:25:40.118Z,1516724740.118 [BPC1] Data Fault, FailCount= 1 2018-01-23T16:25:40.118Z,1516724740.118 [BPC1](ERROR): Data Fault 2018-01-23T16:25:40.226Z,1516724740.226 [CBIT](ERROR): Data Fault in component: BPC1 2018-01-23T16:25:41.486Z,1516724741.486 [CBIT](INFO): Clearing failed state for component BPC1 2018-01-23T16:25:41.486Z,1516724741.486 [BPC1] No Fault, FailCount= 1 2018-01-23T16:26:02.123Z,1516724762.123 [BPC1](ERROR): Failed to receive battery data 2018-01-23T16:26:02.123Z,1516724762.123 [BPC1] Communications Fault, FailCount= 2 2018-01-23T16:26:02.123Z,1516724762.123 [BPC1](ERROR): Communications Fault 2018-01-23T16:26:02.242Z,1516724762.242 [CBIT](ERROR): Communications Fault in component: BPC1 2018-01-23T16:26:03.422Z,1516724763.422 [CBIT](INFO): Clearing failed state for component BPC1 2018-01-23T16:26:03.422Z,1516724763.422 [BPC1] No Fault, FailCount= 2 2018-01-23T16:26:07.482Z,1516724767.482 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-01-23T16:26:07.482Z,1516724767.482 [Rowe_600LCM] Communications Fault, FailCount= 3 2018-01-23T16:26:07.482Z,1516724767.482 [Rowe_600LCM](ERROR): Communications Fault 2018-01-23T16:26:07.814Z,1516724767.814 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-01-23T16:26:07.887Z,1516724767.887 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-01-23T16:26:07.995Z,1516724767.995 [Rowe_600LCM](INFO): Powering down 2018-01-23T16:26:09.414Z,1516724769.414 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-01-23T16:26:09.414Z,1516724769.414 [Rowe_600LCM] No Fault, FailCount= 3 2018-01-23T16:26:09.610Z,1516724769.610 [Rowe_600L