2017-08-05T17:32:22.833Z,1501954342.833 [Supervisor](DEBUG): Initializing supervisor. 2017-08-05T17:32:22.836Z,1501954342.836 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0 2017-08-05T17:32:22.836Z,1501954342.836 [SyncHandler](INFO): Protected caller Thread ID is 7678 2017-08-05T17:32:22.837Z,1501954342.837 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2017-08-05T17:32:22.838Z,1501954342.838 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0 2017-08-05T17:32:22.838Z,1501954342.838 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7679 2017-08-05T17:32:22.841Z,1501954342.841 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2017-08-05T17:32:22.853Z,1501954342.853 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2017-08-05T17:32:22.854Z,1501954342.854 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0 2017-08-05T17:32:22.854Z,1501954342.854 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7680 2017-08-05T17:32:22.855Z,1501954342.855 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2017-08-05T17:32:22.856Z,1501954342.856 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0 2017-08-05T17:32:22.856Z,1501954342.856 [logger ThreadHandler](INFO): Protected caller Thread ID is 7681 2017-08-05T17:32:22.858Z,1501954342.858 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2017-08-05T17:32:22.859Z,1501954342.859 [Supervisor](INFO): Looking for Config files in directory: Config/ 2017-08-05T17:32:22.860Z,1501954342.860 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2017-08-05T17:32:23.048Z,1501954343.048 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2017-08-05T17:32:23.048Z,1501954343.048 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2017-08-05T17:32:23.181Z,1501954343.181 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2017-08-05T17:32:23.181Z,1501954343.181 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2017-08-05T17:32:23.520Z,1501954343.520 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2017-08-05T17:32:23.520Z,1501954343.520 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2017-08-05T17:32:23.660Z,1501954343.660 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2017-08-05T17:32:23.660Z,1501954343.660 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2017-08-05T17:32:23.745Z,1501954343.745 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2017-08-05T17:32:23.946Z,1501954343.946 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2017-08-05T17:32:23.946Z,1501954343.946 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2017-08-05T17:32:24.032Z,1501954344.032 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2017-08-05T17:32:24.032Z,1501954344.032 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2017-08-05T17:32:24.322Z,1501954344.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2017-08-05T17:32:24.323Z,1501954344.323 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2017-08-05T17:32:24.682Z,1501954344.682 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2017-08-05T17:32:24.683Z,1501954344.683 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2017-08-05T17:32:24.989Z,1501954344.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2017-08-05T17:32:24.990Z,1501954344.990 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2017-08-05T17:32:25.587Z,1501954345.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2017-08-05T17:32:25.588Z,1501954345.588 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2017-08-05T17:32:25.786Z,1501954345.786 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2017-08-05T17:32:25.787Z,1501954345.787 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2017-08-05T17:32:25.889Z,1501954345.889 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2017-08-05T17:32:25.890Z,1501954345.890 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2017-08-05T17:32:26.356Z,1501954346.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2017-08-05T17:32:26.356Z,1501954346.356 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2017-08-05T17:32:26.467Z,1501954346.467 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2017-08-05T17:32:26.469Z,1501954346.469 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2017-08-05T17:32:26.470Z,1501954346.470 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2017-08-05T17:32:26.710Z,1501954346.710 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2017-08-05T17:32:26.710Z,1501954346.710 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2017-08-05T17:32:26.814Z,1501954346.814 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2017-08-05T17:32:26.907Z,1501954346.907 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2017-08-05T17:32:27.011Z,1501954347.011 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2017-08-05T17:32:27.100Z,1501954347.100 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2017-08-05T17:32:27.230Z,1501954347.230 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2017-08-05T17:32:27.386Z,1501954347.386 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2017-08-05T17:32:27.484Z,1501954347.484 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2017-08-05T17:32:27.579Z,1501954347.579 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2017-08-05T17:32:27.665Z,1501954347.665 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2017-08-05T17:32:27.861Z,1501954347.861 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2017-08-05T17:32:27.994Z,1501954347.994 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2017-08-05T17:32:27.995Z,1501954347.995 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2017-08-05T17:32:28.006Z,1501954348.006 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2017-08-05T17:32:28.134Z,1501954348.134 [SBIT](DEBUG): Construct Startup Built In Test. 2017-08-05T17:32:28.164Z,1501954348.164 [SBIT] Loaded 2017-08-05T17:32:28.164Z,1501954348.164 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2017-08-05T17:32:28.165Z,1501954348.165 [IBIT](DEBUG): Construct Initiated Built In Test. 2017-08-05T17:32:28.194Z,1501954348.194 [IBIT] Loaded 2017-08-05T17:32:28.194Z,1501954348.194 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2017-08-05T17:32:28.198Z,1501954348.198 [CBIT](DEBUG): Construct Continuous Built In Test. 2017-08-05T17:32:28.348Z,1501954348.348 [CBIT] Loaded 2017-08-05T17:32:28.348Z,1501954348.348 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2017-08-05T17:32:28.348Z,1501954348.348 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2017-08-05T17:32:28.349Z,1501954348.349 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2017-08-05T17:32:28.416Z,1501954348.416 [VerticalControl](DEBUG): Construct VerticalControl. 2017-08-05T17:32:28.515Z,1501954348.515 [VerticalControl] Loaded 2017-08-05T17:32:28.516Z,1501954348.516 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2017-08-05T17:32:28.516Z,1501954348.516 [HorizontalControl](DEBUG): Construct HorizontalControl. 2017-08-05T17:32:28.579Z,1501954348.579 [HorizontalControl] Loaded 2017-08-05T17:32:28.579Z,1501954348.579 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2017-08-05T17:32:28.580Z,1501954348.580 [SpeedControl](DEBUG): Construct SpeedControl. 2017-08-05T17:32:28.586Z,1501954348.586 [SpeedControl] Loaded 2017-08-05T17:32:28.586Z,1501954348.586 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2017-08-05T17:32:28.587Z,1501954348.587 [BackSeatDriver](DEBUG): Construct BackSeatDriver. 2017-08-05T17:32:28.589Z,1501954348.589 [BackSeatDriver] Loaded 2017-08-05T17:32:28.589Z,1501954348.589 [ComponentRegistry](DEBUG): SyncComponent "BackSeatDriver" handled in the control thread. 2017-08-05T17:32:28.590Z,1501954348.590 [LoopControl](DEBUG): Construct LoopControl. 2017-08-05T17:32:28.590Z,1501954348.590 [LoopControl] Loaded 2017-08-05T17:32:28.590Z,1501954348.590 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2017-08-05T17:32:28.591Z,1501954348.591 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2017-08-05T17:32:28.591Z,1501954348.591 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2017-08-05T17:32:28.616Z,1501954348.616 [DepthRateCalculator] Loaded 2017-08-05T17:32:28.616Z,1501954348.616 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2017-08-05T17:32:28.622Z,1501954348.622 [PitchRateCalculator] Loaded 2017-08-05T17:32:28.622Z,1501954348.622 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2017-08-05T17:32:28.637Z,1501954348.637 [SpeedCalculator] Loaded 2017-08-05T17:32:28.638Z,1501954348.638 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2017-08-05T17:32:28.659Z,1501954348.659 [TempGradientCalculator] Loaded 2017-08-05T17:32:28.659Z,1501954348.659 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2017-08-05T17:32:28.675Z,1501954348.675 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2017-08-05T17:32:28.675Z,1501954348.675 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2017-08-05T17:32:28.680Z,1501954348.680 [YawRateCalculator] Loaded 2017-08-05T17:32:28.681Z,1501954348.681 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2017-08-05T17:32:28.681Z,1501954348.681 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2017-08-05T17:32:28.681Z,1501954348.681 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2017-08-05T17:32:28.760Z,1501954348.760 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2017-08-05T17:32:28.760Z,1501954348.760 [StratificationFrontDetector](DEBUG): (re)initializing 2017-08-05T17:32:28.761Z,1501954348.761 [StratificationFrontDetector] Loaded 2017-08-05T17:32:28.761Z,1501954348.761 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2017-08-05T17:32:28.762Z,1501954348.762 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2017-08-05T17:32:28.762Z,1501954348.762 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2017-08-05T17:32:28.995Z,1501954348.995 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2017-08-05T17:32:28.996Z,1501954348.996 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2017-08-05T17:32:29.092Z,1501954349.092 [DeadReckonUsingMultipleVelocitySources] Loaded 2017-08-05T17:32:29.092Z,1501954349.092 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2017-08-05T17:32:29.146Z,1501954349.146 [DeadReckonUsingSpeedCalculator] Loaded 2017-08-05T17:32:29.147Z,1501954349.147 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2017-08-05T17:32:29.164Z,1501954349.164 [NavChart] Loaded 2017-08-05T17:32:29.164Z,1501954349.164 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2017-08-05T17:32:29.168Z,1501954349.168 [UniversalFixResidualReporter] Loaded 2017-08-05T17:32:29.169Z,1501954349.169 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2017-08-05T17:32:29.169Z,1501954349.169 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2017-08-05T17:32:29.170Z,1501954349.170 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2017-08-05T17:32:29.176Z,1501954349.176 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2017-08-05T17:32:29.177Z,1501954349.177 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2017-08-05T17:32:29.320Z,1501954349.320 [Aanderaa_O2] Loaded 2017-08-05T17:32:29.320Z,1501954349.320 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2017-08-05T17:32:29.332Z,1501954349.332 [CANONSampler] Loaded 2017-08-05T17:32:29.332Z,1501954349.332 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2017-08-05T17:32:29.413Z,1501954349.413 [CTD_NeilBrown] Loaded 2017-08-05T17:32:29.413Z,1501954349.413 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2017-08-05T17:32:29.414Z,1501954349.414 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0 2017-08-05T17:32:29.415Z,1501954349.415 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 7764 2017-08-05T17:32:29.449Z,1501954349.449 [CTD_Seabird] Loaded 2017-08-05T17:32:29.449Z,1501954349.449 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2017-08-05T17:32:29.450Z,1501954349.450 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0 2017-08-05T17:32:29.451Z,1501954349.451 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7765 2017-08-05T17:32:29.466Z,1501954349.466 [PAR_Licor] Loaded 2017-08-05T17:32:29.466Z,1501954349.466 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2017-08-05T17:32:29.515Z,1501954349.515 [WetLabsBB2FL] Loaded 2017-08-05T17:32:29.515Z,1501954349.515 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2017-08-05T17:32:29.516Z,1501954349.516 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0 2017-08-05T17:32:29.517Z,1501954349.517 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7766 2017-08-05T17:32:29.517Z,1501954349.517 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2017-08-05T17:32:29.518Z,1501954349.518 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2017-08-05T17:32:29.782Z,1501954349.782 [DataOverHttps] Loaded 2017-08-05T17:32:29.782Z,1501954349.782 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2017-08-05T17:32:29.796Z,1501954349.796 [Depth_Keller] Loaded 2017-08-05T17:32:29.796Z,1501954349.796 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2017-08-05T17:32:29.801Z,1501954349.801 [DropWeight] Loaded 2017-08-05T17:32:29.801Z,1501954349.801 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2017-08-05T17:32:29.893Z,1501954349.893 [NAL9602] Loaded 2017-08-05T17:32:29.893Z,1501954349.893 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2017-08-05T17:32:29.902Z,1501954349.902 [Onboard] Loaded 2017-08-05T17:32:29.902Z,1501954349.902 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2017-08-05T17:32:29.910Z,1501954349.910 [Radio_Surface] Loaded 2017-08-05T17:32:29.910Z,1501954349.910 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2017-08-05T17:32:29.911Z,1501954349.911 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A254E0 2017-08-05T17:32:29.911Z,1501954349.911 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7767 2017-08-05T17:32:29.959Z,1501954349.959 [PNI_TCM] Loaded 2017-08-05T17:32:29.960Z,1501954349.960 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2017-08-05T17:32:30.021Z,1501954350.021 [Rowe_600LCM] Loaded 2017-08-05T17:32:30.022Z,1501954350.022 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2017-08-05T17:32:30.023Z,1501954350.023 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40A554E0 2017-08-05T17:32:30.023Z,1501954350.023 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 7768 2017-08-05T17:32:31.849Z,1501954351.849 [BPC1] Loaded 2017-08-05T17:32:31.849Z,1501954351.849 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2017-08-05T17:32:31.849Z,1501954351.849 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2017-08-05T17:32:31.850Z,1501954351.850 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2017-08-05T17:32:31.946Z,1501954351.946 [BuoyancyServo] Loaded 2017-08-05T17:32:31.946Z,1501954351.946 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2017-08-05T17:32:31.958Z,1501954351.958 [ElevatorServo] Loaded 2017-08-05T17:32:31.958Z,1501954351.958 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2017-08-05T17:32:31.970Z,1501954351.970 [MassServo] Loaded 2017-08-05T17:32:31.970Z,1501954351.970 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2017-08-05T17:32:31.982Z,1501954351.982 [RudderServo] Loaded 2017-08-05T17:32:31.983Z,1501954351.983 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2017-08-05T17:32:31.994Z,1501954351.994 [ThrusterServo] Loaded 2017-08-05T17:32:31.995Z,1501954351.995 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2017-08-05T17:32:31.995Z,1501954351.995 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2017-08-05T17:32:31.996Z,1501954351.996 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2017-08-05T17:32:32.093Z,1501954352.093 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2017-08-05T17:32:32.094Z,1501954352.094 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2017-08-05T17:32:32.118Z,1501954352.118 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2017-08-05T17:32:32.122Z,1501954352.122 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2017-08-05T17:32:32.123Z,1501954352.123 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2017-08-05T17:32:32.130Z,1501954352.130 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2017-08-05T17:32:32.131Z,1501954352.131 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B064E0 2017-08-05T17:32:32.131Z,1501954352.131 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7769 2017-08-05T17:32:32.136Z,1501954352.136 [Supervisor](INFO): Main Thread ID is 7677 2017-08-05T17:32:32.136Z,1501954352.136 [Supervisor](DEBUG): Running supervisor. 2017-08-05T17:32:32.137Z,1501954352.137 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7770 2017-08-05T17:32:32.140Z,1501954352.140 [controlThread ThreadHandler](INFO): Handler Thread ID is 7771 2017-08-05T17:32:32.140Z,1501954352.140 [controlThread](DEBUG): Initializing ControlThread 2017-08-05T17:32:32.141Z,1501954352.141 [SBIT](INFO): Initialize SBIT Component. 2017-08-05T17:32:32.141Z,1501954352.141 [SBIT](IMPORTANT): git: 2017-08-02 2017-08-05T17:32:32.142Z,1501954352.142 [SBIT](INFO): git hash: b8bd19726fcc84d3133bb9e1cbad184cc93bb52c 2017-08-05T17:32:32.143Z,1501954352.143 [SBIT](INFO): Kernel Reporting Different Release From Configuration. Kernel Expected: 2.6.27.8 Kernel Reported: 2.6.27.8-00011-g2bc81df-dirty 2017-08-05T17:32:32.144Z,1501954352.144 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #646 PREEMPT Thu Feb 11 17:01:12 PST 2016 2017-08-05T17:32:32.145Z,1501954352.145 [SBIT](INFO): Beginning SBIT in 59.000000 seconds. 2017-08-05T17:32:32.145Z,1501954352.145 [IBIT](INFO): Initialize IBIT Component. 2017-08-05T17:32:32.146Z,1501954352.146 [CBIT](DEBUG): Initialize CBIT Component. 2017-08-05T17:32:32.146Z,1501954352.146 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2017-08-05T17:32:32.147Z,1501954352.147 [logger ThreadHandler](INFO): Handler Thread ID is 7772 2017-08-05T17:32:32.173Z,1501954352.173 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 7773 2017-08-05T17:32:32.174Z,1501954352.174 [CTD_NeilBrown](INFO): Powering down 2017-08-05T17:32:32.202Z,1501954352.202 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7774 2017-08-05T17:32:32.203Z,1501954352.203 [CTD_Seabird](INFO): Initializing 2017-08-05T17:32:32.246Z,1501954352.246 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2017-08-05T17:32:32.248Z,1501954352.248 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2017-08-05T17:32:32.249Z,1501954352.249 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2017-08-05T17:32:32.250Z,1501954352.250 [BackSeatDriver](DEBUG): Initialize BackSeatDriver Component. 2017-08-05T17:32:32.266Z,1501954352.266 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7776 2017-08-05T17:32:32.267Z,1501954352.267 [WetLabsBB2FL](INFO): Powering down 2017-08-05T17:32:32.290Z,1501954352.290 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7777 2017-08-05T17:32:32.296Z,1501954352.296 [Radio_Surface](INFO): Powering up 2017-08-05T17:32:32.311Z,1501954352.311 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 7778 2017-08-05T17:32:32.312Z,1501954352.312 [Rowe_600LCM](INFO): Initializing 2017-08-05T17:32:32.313Z,1501954352.313 [Rowe_600LCM](INFO): Checking LCM 2017-08-05T17:32:32.313Z,1501954352.313 [Rowe_600LCM](INFO): LCM OK 2017-08-05T17:32:32.313Z,1501954352.313 [Rowe_600LCM](INFO): Powering up 2017-08-05T17:32:32.338Z,1501954352.338 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7780 2017-08-05T17:32:32.341Z,1501954352.341 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2017-08-05T17:32:32.341Z,1501954352.341 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2017-08-05T17:32:32.341Z,1501954352.341 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2017-08-05T17:32:32.342Z,1501954352.342 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2017-08-05T17:32:32.342Z,1501954352.342 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2017-08-05T17:32:32.342Z,1501954352.342 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2017-08-05T17:32:32.342Z,1501954352.342 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2017-08-05T17:32:32.342Z,1501954352.342 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2017-08-05T17:32:32.342Z,1501954352.342 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2017-08-05T17:32:32.343Z,1501954352.343 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2017-08-05T17:32:32.343Z,1501954352.343 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2017-08-05T17:32:32.343Z,1501954352.343 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2017-08-05T17:32:32.343Z,1501954352.343 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2017-08-05T17:32:32.343Z,1501954352.343 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2017-08-05T17:32:32.343Z,1501954352.343 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2017-08-05T17:32:32.344Z,1501954352.344 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2017-08-05T17:32:32.368Z,1501954352.368 [LoopControl](DEBUG): Initialize LoopControlComponent. 2017-08-05T17:32:32.368Z,1501954352.368 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2017-08-05T17:32:32.369Z,1501954352.369 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2017-08-05T17:32:32.381Z,1501954352.381 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2017-08-05T17:32:32.382Z,1501954352.382 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2017-08-05T17:32:32.382Z,1501954352.382 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2017-08-05T17:32:32.383Z,1501954352.383 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2017-08-05T17:32:32.384Z,1501954352.384 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-08-05T17:32:32.409Z,1501954352.409 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-08-05T17:32:32.410Z,1501954352.410 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-08-05T17:32:32.410Z,1501954352.410 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-08-05T17:32:32.411Z,1501954352.411 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-08-05T17:32:32.411Z,1501954352.411 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-08-05T17:32:32.412Z,1501954352.412 [NavChart](DEBUG): Initialize NavChart Navigation. 2017-08-05T17:32:32.412Z,1501954352.412 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2017-08-05T17:32:32.432Z,1501954352.432 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2017-08-05T17:32:32.478Z,1501954352.478 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2017-08-05T17:32:32.513Z,1501954352.513 [MissionManager](DEBUG): 2017-08-05T17:32:32.514Z,1501954352.514 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2017-08-05T17:32:32.540Z,1501954352.540 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2017-08-05T17:32:32.540Z,1501954352.540 [CTD_Seabird](INFO): Powering down 2017-08-05T17:32:32.631Z,1501954352.631 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2017-08-05T17:32:32.632Z,1501954352.632 [Default:A.Wait](DEBUG): Construct Wait. 2017-08-05T17:32:32.634Z,1501954352.634 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2017-08-05T17:32:32.645Z,1501954352.645 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2017-08-05T17:32:32.675Z,1501954352.675 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2017-08-05T17:32:32.699Z,1501954352.699 [Default:E.Execute](DEBUG): Construct Execute. 2017-08-05T17:32:32.702Z,1501954352.702 [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 2017-08-05T17:32:32.729Z,1501954352.729 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,CANONSampler,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,BackSeatDriver,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2017-08-05T17:32:32.766Z,1501954352.766 [CANONSampler](INFO): Powering down 2017-08-05T17:32:32.963Z,1501954352.963 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2017-08-05T17:32:33.271Z,1501954353.271 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:33.291Z,1501954353.291 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:33.490Z,1501954353.490 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-08-05T17:32:33.496Z,1501954353.496 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-08-05T17:32:33.509Z,1501954353.509 [ElevatorServo](DEBUG): Initializing EZServoServo. 2017-08-05T17:32:33.519Z,1501954353.519 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2017-08-05T17:32:33.541Z,1501954353.541 [MassServo](DEBUG): Initializing EZServoServo. 2017-08-05T17:32:33.547Z,1501954353.547 [MassServo](DEBUG): Initializing MassServo. 2017-08-05T17:32:33.553Z,1501954353.553 [RudderServo](DEBUG): Initializing EZServoServo. 2017-08-05T17:32:33.560Z,1501954353.560 [RudderServo](DEBUG): Initializing RudderServo. 2017-08-05T17:32:33.569Z,1501954353.569 [ThrusterServo](DEBUG): Initializing EZServoServo. 2017-08-05T17:32:33.579Z,1501954353.579 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2017-08-05T17:32:33.954Z,1501954353.954 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:33.955Z,1501954353.955 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:34.400Z,1501954354.400 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2017-08-05T17:32:34.401Z,1501954354.401 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2017-08-05T17:32:34.401Z,1501954354.401 [BuoyancyServo] Communications Fault, FailCount= 1 2017-08-05T17:32:34.401Z,1501954354.401 [BuoyancyServo](ERROR): Communications Fault 2017-08-05T17:32:34.608Z,1501954354.608 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2017-08-05T17:32:34.666Z,1501954354.666 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:34.667Z,1501954354.667 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:34.770Z,1501954354.770 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2017-08-05T17:32:34.770Z,1501954354.770 [BuoyancyServo](INFO): Powering down 2017-08-05T17:32:35.043Z,1501954355.043 [NAL9602](INFO): Powering up NAL9602 2017-08-05T17:32:35.094Z,1501954355.094 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:35.095Z,1501954355.095 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:35.474Z,1501954355.474 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:35.475Z,1501954355.475 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:35.936Z,1501954355.936 [Aanderaa_O2](INFO): Powering down 2017-08-05T17:32:36.066Z,1501954356.066 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:36.075Z,1501954356.075 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:36.393Z,1501954356.393 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:36.420Z,1501954356.420 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-08-05T17:32:36.593Z,1501954356.593 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2017-08-05T17:32:36.686Z,1501954356.686 [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 & 2017-08-05T17:32:36.688Z,1501954356.688 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2017-08-05T17:32:36.689Z,1501954356.689 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2017-08-05T17:32:36.690Z,1501954356.690 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2017-08-05T17:32:37.017Z,1501954357.017 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2017-08-05T17:32:37.018Z,1501954357.018 [BuoyancyServo] No Fault, FailCount= 1 2017-08-05T17:32:37.309Z,1501954357.309 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-08-05T17:32:37.310Z,1501954357.310 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-08-05T17:32:49.084Z,1501954369.084 [BPC1](ERROR): Failed to receive battery data 2017-08-05T17:32:49.084Z,1501954369.084 [BPC1] Communications Fault, FailCount= 1 2017-08-05T17:32:49.084Z,1501954369.084 [BPC1](ERROR): Communications Fault 2017-08-05T17:32:49.289Z,1501954369.289 [CBIT](ERROR): Communications Fault in component: BPC1 2017-08-05T17:32:50.668Z,1501954370.668 [CBIT](INFO): Clearing failed state for component BPC1 2017-08-05T17:32:50.669Z,1501954370.669 [BPC1] No Fault, FailCount= 1 2017-08-05T17:32:55.775Z,1501954375.775 [NAL9602](ERROR): NAL9602 initialization error. 2017-08-05T17:32:55.775Z,1501954375.775 [NAL9602] Communications Fault, FailCount= 1 2017-08-05T17:32:55.775Z,1501954375.775 [NAL9602](ERROR): Communications Fault 2017-08-05T17:32:56.122Z,1501954376.122 [CBIT](ERROR): Communications Fault in component: NAL9602 2017-08-05T17:32:56.208Z,1501954376.208 [NAL9602](INFO): Powering down 2017-08-05T17:32:57.306Z,1501954377.306 [CBIT](INFO): Clearing failed state for component NAL9602 2017-08-05T17:32:57.306Z,1501954377.306 [NAL9602] No Fault, FailCount= 1 2017-08-05T17:33:01.329Z,1501954381.329 [NAL9602](INFO): Powering up NAL9602 2017-08-05T17:33:02.855Z,1501954382.855 [BPC1](ERROR): Failed to parse bank B battery data 2017-08-05T17:33:02.855Z,1501954382.855 [BPC1] Data Fault, FailCount= 2 2017-08-05T17:33:02.856Z,1501954382.856 [BPC1](ERROR): Data Fault 2017-08-05T17:33:03.107Z,1501954383.107 [CBIT](ERROR): Data Fault in component: BPC1 2017-08-05T17:33:04.173Z,1501954384.173 [CBIT](INFO): Clearing failed state for component BPC1 2017-08-05T17:33:04.173Z,1501954384.173 [BPC1] No Fault, FailCount= 2 2017-08-05T17:33:06.758Z,1501954386.758 [CommandLine](IMPORTANT): got command configSet list 2017-08-05T17:33:06.758Z,1501954386.758 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2017-08-05T17:33:06.759Z,1501954386.759 [CommandLine](IMPORTANT): CANONSampler.loadAtStartup=1 bool; 2017-08-05T17:33:06.759Z,1501954386.759 [CommandLine](IMPORTANT): CANONSampler.simulateHardware=0 bool; 2017-08-05T17:33:06.759Z,1501954386.759 [CommandLine](IMPORTANT): CBIT.abortDepth=250 meter; 2017-08-05T17:33:06.759Z,1501954386.759 [CommandLine](IMPORTANT): CBIT.runFaultClassifier=1 bool; 2017-08-05T17:33:06.759Z,1501954386.759 [CommandLine](IMPORTANT): CBIT.stopDepth=205 meter; 2017-08-05T17:33:06.759Z,1501954386.759 [CommandLine](IMPORTANT): Normal linearApproximation Rowe_600LCM.height_above_sea_floor 5.000000 meter; 2017-08-05T17:33:06.759Z,1501954386.759 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=1 bool; 2017-08-05T17:33:06.760Z,1501954386.760 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=315 cubic_centimeter; 2017-08-05T17:33:06.760Z,1501954386.760 [CommandLine](IMPORTANT): VerticalControl.massDefault=-1 centimeter; 2017-08-05T17:33:06.760Z,1501954386.760 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft=-35 millimeter; 2017-08-05T17:33:06.760Z,1501954386.760 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd=26 millimeter; 2017-08-05T17:33:12.446Z,1501954392.446 [NAL9602](INFO): NAL9602 initialized 2017-08-05T17:33:31.923Z,1501954411.923 [SBIT](IMPORTANT): Beginning Startup BIT 2017-08-05T17:33:31.960Z,1501954411.960 [CBIT](IMPORTANT): Beginning ground fault scan 2017-08-05T17:33:42.521Z,1501954422.521 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.004783 CHAN A1 (24V): 4.792929 CHAN A2 (12V): -0.067692 CHAN A3 (5V): -0.000251 CHAN B0 (3.3V): 4.766929 CHAN B1 (3.15aV): 0.002608 CHAN B2 (3.15bV): 0.000117 CHAN B3 (GND): 0.000190 OPEN: -0.000362 Full Scale Calc: 4.765 mA, -1.589 mA 2017-08-05T17:33:48.973Z,1501954428.973 [NAL9602](INFO): SBD MO Status=2, MOMSN=65384, MT Status=2, MTMSN=0 2017-08-05T17:33:48.973Z,1501954428.973 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2017-08-05T17:33:50.292Z,1501954430.292 [BPC1](ERROR): Failed to receive battery data 2017-08-05T17:33:50.293Z,1501954430.293 [BPC1] Communications Fault, FailCount= 1 2017-08-05T17:33:50.293Z,1501954430.293 [BPC1](ERROR): Communications Fault 2017-08-05T17:33:50.554Z,1501954430.554 [CBIT](ERROR): Communications Fault in component: BPC1 2017-08-05T17:33:51.974Z,1501954431.974 [CBIT](INFO): Clearing failed state for component BPC1 2017-08-05T17:33:51.974Z,1501954431.974 [BPC1] No Fault, FailCount= 1 2017-08-05T17:34:04.164Z,1501954444.164 [BPC1](ERROR): Failed to parse message. 2017-08-05T17:34:04.164Z,1501954444.164 [BPC1](ERROR): Failed to parse bank A battery data 2017-08-05T17:34:04.164Z,1501954444.164 [BPC1] Data Fault, FailCount= 2 2017-08-05T17:34:04.164Z,1501954444.164 [BPC1](ERROR): Data Fault 2017-08-05T17:34:04.430Z,1501954444.430 [CBIT](ERROR): Data Fault in component: BPC1 2017-08-05T17:34:05.463Z,1501954445.463 [CBIT](INFO): Clearing failed state for component BPC1 2017-08-05T17:34:05.463Z,1501954445.463 [BPC1] No Fault, FailCount= 2 2017-08-05T17:34:17.823Z,1501954457.823 [BPC1](ERROR): Failed to parse message. 2017-08-05T17:34:17.823Z,1501954457.823 [BPC1](ERROR): Failed to parse bank B battery data 2017-08-05T17:34:17.823Z,1501954457.823 [BPC1] Data Fault, FailCount= 3 2017-08-05T17:34:17.823Z,1501954457.823 [BPC1](ERROR): Data Fault 2017-08-05T17:34:18.031Z,1501954458.031 [CBIT](ERROR): Data Fault in component: BPC1 2017-08-05T17:34:19.367Z,1501954459.367 [CBIT](INFO): Clearing failed state for component BPC1 2017-08-05T17:34:19.368Z,1501954459.368 [BPC1] No Fault, FailCount= 3 2017-08-05T17:34:25.849Z,1501954465.849 [SBIT](IMPORTANT): SBIT PASSED 2017-08-05T17:34:26.161Z,1501954466.161 [MissionManager](IMPORTANT): Started mission Startup 2017-08-05T17:34:26.166Z,1501954466.166 [Startup] Running Loop=1 2017-08-05T17:34:26.166Z,1501954466.166 [Startup](DEBUG): Aggregate::initialize Startup 2017-08-05T17:34:26.167Z,1501954466.167 [Startup:A.GoToSurface] Running Loop=1 2017-08-05T17:34:26.167Z,1501954466.167 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2017-08-05T17:34:26.169Z,1501954466.169 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2017-08-05T17:34:26.175Z,1501954466.175 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2017-08-05T17:34:26.175Z,1501954466.175 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2017-08-05T17:34:26.177Z,1501954466.177 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2017-08-05T17:34:26.182Z,1501954466.182 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2017-08-05T17:34:26.199Z,1501954466.199 [Startup:StartupSatComms] Running Loop=1 2017-08-05T17:34:26.199Z,1501954466.199 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2017-08-05T17:34:26.199Z,1501954466.199 [Startup:StartupSatComms:A] Running Loop=1 2017-08-05T17:34:26.438Z,1501954466.438 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2017-08-05T17:34:32.747Z,1501954472.747 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2017-08-05T17:34:32.747Z,1501954472.747 [Rowe_600LCM] Communications Fault, FailCount= 1 2017-08-05T17:34:32.748Z,1501954472.748 [Rowe_600LCM](ERROR): Communications Fault 2017-08-05T17:34:32.990Z,1501954472.990 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2017-08-05T17:34:33.152Z,1501954473.152 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2017-08-05T17:34:33.375Z,1501954473.375 [Rowe_600LCM](INFO): Powering down 2017-08-05T17:34:34.649Z,1501954474.649 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2017-08-05T17:34:34.649Z,1501954474.649 [Rowe_600LCM] No Fault, FailCount= 1 2017-08-05T17:34:34.983Z,1501954474.983 [Rowe_600LCM](INFO): Initializing 2017-08-05T17:34:34.984Z,1501954474.984 [Rowe_600LCM](INFO): Checking LCM 2017-08-05T17:34:34.984Z,1501954474.984 [Rowe_600LCM](INFO): LCM OK 2017-08-05T17:34:34.984Z,1501954474.984 [Rowe_600LCM](INFO): Powering up 2017-08-05T17:34:39.112Z,1501954479.112 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2017-08-05T17:34:39.189Z,1501954479.189 [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 & 2017-08-05T17:34:39.190Z,1501954479.190 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2017-08-05T17:34:39.191Z,1501954479.191 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2017-08-05T17:34:39.192Z,1501954479.192 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2017-08-05T17:35:01.017Z,1501954501.017 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2017-08-05T17:35:01.818Z,1501954501.818 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2017-08-05T17:35:04.198Z,1501954504.198 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2017-08-05T17:35:04.991Z,1501954504.991 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2017-08-05T17:35:26.509Z,1501954526.509 [Startup:StartupSatComms:A](INFO): Timed out from 2017-08-05T17:34:26.2Z 2017-08-05T17:35:26.509Z,1501954526.509 [Startup:StartupSatComms:A] Stopped 2017-08-05T17:35:26.509Z,1501954526.509 [Startup:StartupSatComms:B] Running Loop=1 2017-08-05T17:35:26.879Z,1501954526.879 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2017-08-05T17:35:32.528Z,1501954532.528 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-08-05T17:35:32.529Z,1501954532.529 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2017-08-05T17:35:32.529Z,1501954532.529 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2017-08-05T17:35:32.531Z,1501954532.531 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-08-05T17:35:32.531Z,1501954532.531 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2017-08-05T17:35:32.531Z,1501954532.531 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2017-08-05T17:35:32.640Z,1501954532.640 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2017-08-05T17:35:32.640Z,1501954532.640 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2017-08-05T17:35:32.992Z,1501954532.992 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2017-08-05T17:35:32.993Z,1501954532.993 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2017-08-05T17:35:32.993Z,1501954532.993 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2017-08-05T17:35:32.993Z,1501954532.993 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2017-08-05T17:35:33.280Z,1501954533.280 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-08-05T17:35:33.280Z,1501954533.280 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-08-05T17:35:33.281Z,1501954533.281 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-08-05T17:35:33.281Z,1501954533.281 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-08-05T17:35:33.282Z,1501954533.282 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-08-05T17:35:33.282Z,1501954533.282 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-08-05T17:35:33.682Z,1501954533.682 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s. 2017-08-05T17:35:34.083Z,1501954534.083 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s. 2017-08-05T17:35:34.483Z,1501954534.483 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s. 2017-08-05T17:35:34.876Z,1501954534.876 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.3 s old, using for 20.0 s. 2017-08-05T17:35:35.277Z,1501954535.277 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.7 s old, using for 20.0 s. 2017-08-05T17:35:35.672Z,1501954535.672 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.1 s old, using for 20.0 s. 2017-08-05T17:35:36.079Z,1501954536.079 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s. 2017-08-05T17:35:36.478Z,1501954536.478 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.9 s old, using for 20.0 s. 2017-08-05T17:35:36.875Z,1501954536.875 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.3 s old, using for 20.0 s. 2017-08-05T17:35:37.275Z,1501954537.275 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.7 s old, using for 20.0 s. 2017-08-05T17:35:37.714Z,1501954537.714 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s. 2017-08-05T17:35:38.075Z,1501954538.075 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.5 s old, using for 20.0 s. 2017-08-05T17:35:38.482Z,1501954538.482 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s. 2017-08-05T17:35:38.878Z,1501954538.878 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.3 s old, using for 20.0 s. 2017-08-05T17:35:39.261Z,1501954539.261 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.7 s old, using for 20.0 s. 2017-08-05T17:35:39.679Z,1501954539.679 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.2 s old, using for 20.0 s. 2017-08-05T17:35:40.080Z,1501954540.080 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.6 s old, using for 20.0 s. 2017-08-05T17:35:40.477Z,1501954540.477 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 7.9 s old, using for 20.0 s. 2017-08-05T17:35:40.901Z,1501954540.901 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.4 s old, using for 20.0 s. 2017-08-05T17:35:41.298Z,1501954541.298 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 8.8 s old, using for 20.0 s. 2017-08-05T17:35:41.682Z,1501954541.682 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.2 s old, using for 20.0 s. 2017-08-05T17:35:42.083Z,1501954542.083 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.6 s old, using for 20.0 s. 2017-08-05T17:35:42.478Z,1501954542.478 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 9.9 s old, using for 20.0 s. 2017-08-05T17:35:42.876Z,1501954542.876 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.3 s old, using for 20.0 s. 2017-08-05T17:35:43.289Z,1501954543.289 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 10.8 s old, using for 20.0 s. 2017-08-05T17:35:43.680Z,1501954543.680 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.2 s old, using for 20.0 s. 2017-08-05T17:35:44.074Z,1501954544.074 [BPC1](ERROR): Failed to parse bank A battery data 2017-08-05T17:35:44.074Z,1501954544.074 [BPC1] Data Fault, FailCount= 1 2017-08-05T17:35:44.074Z,1501954544.074 [BPC1](ERROR): Data Fault 2017-08-05T17:35:44.086Z,1501954544.086 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 11.6 s old, using for 20.0 s. 2017-08-05T17:35:44.199Z,1501954544.199 [CBIT](ERROR): Data Fault in component: BPC1 2017-08-05T17:35:44.478Z,1501954544.478 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 12.0 s old, using for 20.0 s