2018-01-23T00:11:43.220Z,1516666303.220 [Supervisor](DEBUG): Initializing supervisor.
2018-01-23T00:11:43.223Z,1516666303.223 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-01-23T00:11:43.223Z,1516666303.223 [SyncHandler](INFO): Protected caller Thread ID is 4672
2018-01-23T00:11:43.224Z,1516666303.224 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-01-23T00:11:43.225Z,1516666303.225 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-01-23T00:11:43.225Z,1516666303.225 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4673
2018-01-23T00:11:43.228Z,1516666303.228 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-01-23T00:11:43.239Z,1516666303.239 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-01-23T00:11:43.240Z,1516666303.240 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-01-23T00:11:43.241Z,1516666303.241 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4674
2018-01-23T00:11:43.242Z,1516666303.242 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-01-23T00:11:43.242Z,1516666303.242 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-01-23T00:11:43.243Z,1516666303.243 [logger ThreadHandler](INFO): Protected caller Thread ID is 4675
2018-01-23T00:11:43.245Z,1516666303.245 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-01-23T00:11:43.245Z,1516666303.245 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-01-23T00:11:43.247Z,1516666303.247 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-01-23T00:11:43.540Z,1516666303.540 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-01-23T00:11:43.540Z,1516666303.540 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-01-23T00:11:43.715Z,1516666303.715 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-01-23T00:11:43.716Z,1516666303.716 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-01-23T00:11:43.973Z,1516666303.973 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-01-23T00:11:43.974Z,1516666303.974 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-01-23T00:11:44.107Z,1516666304.107 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-01-23T00:11:44.108Z,1516666304.108 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-01-23T00:11:44.202Z,1516666304.202 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-01-23T00:11:44.202Z,1516666304.202 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-01-23T00:11:44.622Z,1516666304.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-01-23T00:11:44.623Z,1516666304.623 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-01-23T00:11:44.937Z,1516666304.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-01-23T00:11:44.938Z,1516666304.938 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-01-23T00:11:45.348Z,1516666305.348 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-01-23T00:11:45.348Z,1516666305.348 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-01-23T00:11:45.449Z,1516666305.449 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-01-23T00:11:45.450Z,1516666305.450 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-01-23T00:11:45.544Z,1516666305.544 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-01-23T00:11:45.544Z,1516666305.544 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-01-23T00:11:45.731Z,1516666305.731 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-01-23T00:11:45.732Z,1516666305.732 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-01-23T00:11:45.916Z,1516666305.916 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-01-23T00:11:45.917Z,1516666305.917 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-01-23T00:11:46.224Z,1516666306.224 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-01-23T00:11:46.224Z,1516666306.224 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-01-23T00:11:46.357Z,1516666306.357 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-01-23T00:11:46.358Z,1516666306.358 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-01-23T00:11:46.438Z,1516666306.438 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2018-01-23T00:11:46.439Z,1516666306.439 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2018-01-23T00:11:46.536Z,1516666306.536 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2018-01-23T00:11:46.625Z,1516666306.625 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2018-01-23T00:11:46.716Z,1516666306.716 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2018-01-23T00:11:46.799Z,1516666306.799 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2018-01-23T00:11:46.939Z,1516666306.939 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2018-01-23T00:11:47.102Z,1516666307.102 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2018-01-23T00:11:47.176Z,1516666307.176 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2018-01-23T00:11:47.394Z,1516666307.394 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2018-01-23T00:11:47.395Z,1516666307.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2018-01-23T00:11:47.475Z,1516666307.475 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2018-01-23T00:11:47.562Z,1516666307.562 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2018-01-23T00:11:47.658Z,1516666307.658 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2018-01-23T00:11:47.775Z,1516666307.775 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-01-23T00:11:47.777Z,1516666307.777 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-01-23T00:11:48.311Z,1516666308.311 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-01-23T00:11:48.312Z,1516666308.312 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-01-23T00:11:48.438Z,1516666308.438 [DepthRateCalculator] Loaded
2018-01-23T00:11:48.438Z,1516666308.438 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-01-23T00:11:48.444Z,1516666308.444 [PitchRateCalculator] Loaded
2018-01-23T00:11:48.444Z,1516666308.444 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-01-23T00:11:48.459Z,1516666308.459 [SpeedCalculator] Loaded
2018-01-23T00:11:48.460Z,1516666308.460 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-01-23T00:11:48.480Z,1516666308.480 [TempGradientCalculator] Loaded
2018-01-23T00:11:48.480Z,1516666308.480 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-01-23T00:11:48.495Z,1516666308.495 [VerticalTemperatureHomogeneityIndexCalculator] Loaded
2018-01-23T00:11:48.495Z,1516666308.495 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread.
2018-01-23T00:11:48.500Z,1516666308.500 [YawRateCalculator] Loaded
2018-01-23T00:11:48.501Z,1516666308.501 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-01-23T00:11:48.501Z,1516666308.501 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-01-23T00:11:48.502Z,1516666308.502 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-01-23T00:11:48.584Z,1516666308.584 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC
2018-01-23T00:11:48.584Z,1516666308.584 [StratificationFrontDetector](DEBUG): (re)initializing
2018-01-23T00:11:48.584Z,1516666308.584 [StratificationFrontDetector] Loaded
2018-01-23T00:11:48.584Z,1516666308.584 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread.
2018-01-23T00:11:48.585Z,1516666308.585 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-01-23T00:11:48.586Z,1516666308.586 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-01-23T00:11:48.698Z,1516666308.698 [BuoyancyServo] Loaded
2018-01-23T00:11:48.698Z,1516666308.698 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-01-23T00:11:48.712Z,1516666308.712 [ElevatorServo] Loaded
2018-01-23T00:11:48.713Z,1516666308.713 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-01-23T00:11:48.726Z,1516666308.726 [MassServo] Loaded
2018-01-23T00:11:48.727Z,1516666308.727 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-01-23T00:11:48.741Z,1516666308.741 [RudderServo] Loaded
2018-01-23T00:11:48.742Z,1516666308.742 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-01-23T00:11:48.755Z,1516666308.755 [ThrusterServo] Loaded
2018-01-23T00:11:48.755Z,1516666308.755 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-01-23T00:11:48.756Z,1516666308.756 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-01-23T00:11:48.756Z,1516666308.756 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-01-23T00:11:48.770Z,1516666308.770 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-01-23T00:11:48.770Z,1516666308.770 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-01-23T00:11:48.866Z,1516666308.866 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-01-23T00:11:48.867Z,1516666308.867 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-01-23T00:11:49.204Z,1516666309.204 [DataOverHttps] Loaded
2018-01-23T00:11:49.205Z,1516666309.205 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2018-01-23T00:11:49.218Z,1516666309.218 [Depth_Keller] Loaded
2018-01-23T00:11:49.218Z,1516666309.218 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2018-01-23T00:11:49.223Z,1516666309.223 [DropWeight] Loaded
2018-01-23T00:11:49.223Z,1516666309.223 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2018-01-23T00:11:49.319Z,1516666309.319 [NAL9602] Loaded
2018-01-23T00:11:49.320Z,1516666309.320 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2018-01-23T00:11:49.335Z,1516666309.335 [Onboard] Loaded
2018-01-23T00:11:49.336Z,1516666309.336 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2018-01-23T00:11:49.346Z,1516666309.346 [Radio_Surface] Loaded
2018-01-23T00:11:49.346Z,1516666309.346 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2018-01-23T00:11:49.347Z,1516666309.347 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4086B4E0
2018-01-23T00:11:49.347Z,1516666309.347 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4758
2018-01-23T00:11:49.393Z,1516666309.393 [PNI_TCM] Loaded
2018-01-23T00:11:49.394Z,1516666309.394 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2018-01-23T00:11:49.451Z,1516666309.451 [Rowe_600LCM] Loaded
2018-01-23T00:11:49.451Z,1516666309.451 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2018-01-23T00:11:49.452Z,1516666309.452 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 4089B4E0
2018-01-23T00:11:49.453Z,1516666309.453 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 4759
2018-01-23T00:11:51.151Z,1516666311.151 [BPC1] Loaded
2018-01-23T00:11:51.152Z,1516666311.152 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2018-01-23T00:11:51.152Z,1516666311.152 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2018-01-23T00:11:51.153Z,1516666311.153 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-01-23T00:11:51.278Z,1516666311.278 [SBIT](DEBUG): Construct Startup Built In Test.
2018-01-23T00:11:51.302Z,1516666311.302 [SBIT] Loaded
2018-01-23T00:11:51.302Z,1516666311.302 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-01-23T00:11:51.303Z,1516666311.303 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-01-23T00:11:51.314Z,1516666311.314 [IBIT] Loaded
2018-01-23T00:11:51.314Z,1516666311.314 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-01-23T00:11:51.317Z,1516666311.317 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-01-23T00:11:51.466Z,1516666311.466 [CBIT] Loaded
2018-01-23T00:11:51.466Z,1516666311.466 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-01-23T00:11:51.467Z,1516666311.467 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-01-23T00:11:51.467Z,1516666311.467 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-01-23T00:11:51.607Z,1516666311.607 [Aanderaa_O2] Loaded
2018-01-23T00:11:51.607Z,1516666311.607 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2018-01-23T00:11:51.619Z,1516666311.619 [CANONSampler] Loaded
2018-01-23T00:11:51.619Z,1516666311.619 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2018-01-23T00:11:51.695Z,1516666311.695 [CTD_NeilBrown] Loaded
2018-01-23T00:11:51.696Z,1516666311.696 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-01-23T00:11:51.697Z,1516666311.697 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409614E0
2018-01-23T00:11:51.697Z,1516666311.697 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 4760
2018-01-23T00:11:51.729Z,1516666311.729 [CTD_Seabird] Loaded
2018-01-23T00:11:51.729Z,1516666311.729 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2018-01-23T00:11:51.730Z,1516666311.730 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409914E0
2018-01-23T00:11:51.731Z,1516666311.731 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4761
2018-01-23T00:11:51.744Z,1516666311.744 [PAR_Licor] Loaded
2018-01-23T00:11:51.744Z,1516666311.744 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-01-23T00:11:51.792Z,1516666311.792 [WetLabsBB2FL] Loaded
2018-01-23T00:11:51.792Z,1516666311.792 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-01-23T00:11:51.793Z,1516666311.793 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409C14E0
2018-01-23T00:11:51.793Z,1516666311.793 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4762
2018-01-23T00:11:51.835Z,1516666311.835 [WetLabsSeaOWL_UV_A] Loaded
2018-01-23T00:11:51.835Z,1516666311.835 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2018-01-23T00:11:51.836Z,1516666311.836 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409F14E0
2018-01-23T00:11:51.837Z,1516666311.837 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 4763
2018-01-23T00:11:51.837Z,1516666311.837 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-01-23T00:11:51.838Z,1516666311.838 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-01-23T00:11:51.903Z,1516666311.903 [VerticalControl](DEBUG): Construct VerticalControl.
2018-01-23T00:11:51.987Z,1516666311.987 [VerticalControl] Loaded
2018-01-23T00:11:51.987Z,1516666311.987 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-01-23T00:11:51.988Z,1516666311.988 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-01-23T00:11:52.044Z,1516666312.044 [HorizontalControl] Loaded
2018-01-23T00:11:52.044Z,1516666312.044 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-01-23T00:11:52.045Z,1516666312.045 [SpeedControl](DEBUG): Construct SpeedControl.
2018-01-23T00:11:52.046Z,1516666312.046 [SpeedControl] Loaded
2018-01-23T00:11:52.047Z,1516666312.047 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-01-23T00:11:52.047Z,1516666312.047 [LoopControl](DEBUG): Construct LoopControl.
2018-01-23T00:11:52.048Z,1516666312.048 [LoopControl] Loaded
2018-01-23T00:11:52.048Z,1516666312.048 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-01-23T00:11:52.048Z,1516666312.048 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-01-23T00:11:52.049Z,1516666312.049 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-01-23T00:11:52.073Z,1516666312.073 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-01-23T00:11:52.074Z,1516666312.074 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-01-23T00:11:52.163Z,1516666312.163 [DeadReckonUsingSpeedCalculator] Loaded
2018-01-23T00:11:52.163Z,1516666312.163 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-01-23T00:11:52.217Z,1516666312.217 [DeadReckonWithRespectToSeafloor] Loaded
2018-01-23T00:11:52.217Z,1516666312.217 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2018-01-23T00:11:52.233Z,1516666312.233 [NavChart] Loaded
2018-01-23T00:11:52.233Z,1516666312.233 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-01-23T00:11:52.237Z,1516666312.237 [UniversalFixResidualReporter] Loaded
2018-01-23T00:11:52.237Z,1516666312.237 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-01-23T00:11:52.238Z,1516666312.238 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-01-23T00:11:52.241Z,1516666312.241 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-01-23T00:11:52.242Z,1516666312.242 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-01-23T00:11:52.249Z,1516666312.249 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-01-23T00:11:52.250Z,1516666312.250 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A7C4E0
2018-01-23T00:11:52.250Z,1516666312.250 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4764
2018-01-23T00:11:52.255Z,1516666312.255 [Supervisor](INFO): Main Thread ID is 4671
2018-01-23T00:11:52.255Z,1516666312.255 [Supervisor](DEBUG): Running supervisor.
2018-01-23T00:11:52.256Z,1516666312.256 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4765
2018-01-23T00:11:52.259Z,1516666312.259 [controlThread ThreadHandler](INFO): Handler Thread ID is 4766
2018-01-23T00:11:52.259Z,1516666312.259 [controlThread](DEBUG): Initializing ControlThread
2018-01-23T00:11:52.260Z,1516666312.260 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-01-23T00:11:52.260Z,1516666312.260 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-01-23T00:11:52.261Z,1516666312.261 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-01-23T00:11:52.261Z,1516666312.261 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-01-23T00:11:52.262Z,1516666312.262 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing
2018-01-23T00:11:52.262Z,1516666312.262 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-01-23T00:11:52.268Z,1516666312.268 [SBIT](INFO): Initialize SBIT Component.
2018-01-23T00:11:52.268Z,1516666312.268 [SBIT](IMPORTANT): git: 2017-12-12
2018-01-23T00:11:52.268Z,1516666312.268 [SBIT](INFO): git hash: 18638d31f033e3fa0cb90b26256f5481d37f00cc
2018-01-23T00:11:52.269Z,1516666312.269 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2018-01-23T00:11:52.270Z,1516666312.270 [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-23T00:11:52.271Z,1516666312.271 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2018-01-23T00:11:52.271Z,1516666312.271 [IBIT](INFO): Initialize IBIT Component.
2018-01-23T00:11:52.272Z,1516666312.272 [CBIT](DEBUG): Initialize CBIT Component.
2018-01-23T00:11:52.272Z,1516666312.272 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-01-23T00:11:52.273Z,1516666312.273 [logger ThreadHandler](INFO): Handler Thread ID is 4767
2018-01-23T00:11:52.294Z,1516666312.294 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4768
2018-01-23T00:11:52.300Z,1516666312.300 [Radio_Surface](INFO): Powering up
2018-01-23T00:11:52.306Z,1516666312.306 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 4769
2018-01-23T00:11:52.306Z,1516666312.306 [Rowe_600LCM](INFO): Initializing
2018-01-23T00:11:52.307Z,1516666312.307 [Rowe_600LCM](INFO): Checking LCM
2018-01-23T00:11:52.316Z,1516666312.316 [Rowe_600LCM](INFO): LCM OK
2018-01-23T00:11:52.316Z,1516666312.316 [Rowe_600LCM](INFO): Powering up
2018-01-23T00:11:52.322Z,1516666312.322 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 4770
2018-01-23T00:11:52.323Z,1516666312.323 [CTD_NeilBrown](INFO): Powering down
2018-01-23T00:11:52.361Z,1516666312.361 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-01-23T00:11:52.363Z,1516666312.363 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-01-23T00:11:52.364Z,1516666312.364 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-01-23T00:11:52.364Z,1516666312.364 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-01-23T00:11:52.365Z,1516666312.365 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-01-23T00:11:52.366Z,1516666312.366 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4771
2018-01-23T00:11:52.366Z,1516666312.366 [CTD_Seabird](INFO): Initializing
2018-01-23T00:11:52.396Z,1516666312.396 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:11:52.396Z,1516666312.396 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:11:52.397Z,1516666312.397 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T00:11:52.397Z,1516666312.397 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:11:52.398Z,1516666312.398 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:11:52.398Z,1516666312.398 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-01-23T00:11:52.399Z,1516666312.399 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-01-23T00:11:52.400Z,1516666312.400 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-01-23T00:11:52.402Z,1516666312.402 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4773
2018-01-23T00:11:52.403Z,1516666312.403 [WetLabsBB2FL](INFO): Powering down
2018-01-23T00:11:52.450Z,1516666312.450 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 4774
2018-01-23T00:11:52.461Z,1516666312.461 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-01-23T00:11:52.466Z,1516666312.466 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4775
2018-01-23T00:11:52.472Z,1516666312.472 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-01-23T00:11:52.472Z,1516666312.472 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-01-23T00:11:52.473Z,1516666312.473 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-01-23T00:11:52.473Z,1516666312.473 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-01-23T00:11:52.473Z,1516666312.473 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-01-23T00:11:52.473Z,1516666312.473 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-01-23T00:11:52.473Z,1516666312.473 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-01-23T00:11:52.474Z,1516666312.474 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-01-23T00:11:52.474Z,1516666312.474 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-01-23T00:11:52.474Z,1516666312.474 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-01-23T00:11:52.474Z,1516666312.474 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-01-23T00:11:52.474Z,1516666312.474 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-01-23T00:11:52.475Z,1516666312.475 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-01-23T00:11:52.475Z,1516666312.475 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-01-23T00:11:52.475Z,1516666312.475 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-01-23T00:11:52.475Z,1516666312.475 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-01-23T00:11:52.527Z,1516666312.527 [MissionManager](DEBUG):
2018-01-23T00:11:52.528Z,1516666312.528 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-01-23T00:11:52.630Z,1516666312.630 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-01-23T00:11:52.631Z,1516666312.631 [Default:A.Wait](DEBUG): Construct Wait.
2018-01-23T00:11:52.633Z,1516666312.633 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-01-23T00:11:52.656Z,1516666312.656 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-01-23T00:11:52.668Z,1516666312.668 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-01-23T00:11:52.668Z,1516666312.668 [CTD_Seabird](INFO): Powering down
2018-01-23T00:11:52.704Z,1516666312.704 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-01-23T00:11:52.738Z,1516666312.738 [Default:E.Execute](DEBUG): Construct Execute.
2018-01-23T00:11:52.741Z,1516666312.741 [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-23T00:11:52.746Z,1516666312.746 [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-23T00:11:52.773Z,1516666312.773 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2018-01-23T00:11:53.075Z,1516666313.075 [CANONSampler](INFO): Powering down
2018-01-23T00:11:53.247Z,1516666313.247 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:11:53.274Z,1516666313.274 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:11:53.402Z,1516666313.402 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2018-01-23T00:11:53.405Z,1516666313.405 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-01-23T00:11:53.432Z,1516666313.432 [ElevatorServo](DEBUG): Initializing EZServoServo.
2018-01-23T00:11:53.437Z,1516666313.437 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-01-23T00:11:53.451Z,1516666313.451 [MassServo](DEBUG): Initializing EZServoServo.
2018-01-23T00:11:53.458Z,1516666313.458 [MassServo](DEBUG): Initializing MassServo.
2018-01-23T00:11:53.471Z,1516666313.471 [RudderServo](DEBUG): Initializing EZServoServo.
2018-01-23T00:11:53.477Z,1516666313.477 [RudderServo](DEBUG): Initializing RudderServo.
2018-01-23T00:11:53.496Z,1516666313.496 [ThrusterServo](DEBUG): Initializing EZServoServo.
2018-01-23T00:11:53.505Z,1516666313.505 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-01-23T00:11:53.777Z,1516666313.777 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:11:53.778Z,1516666313.778 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:11:56.635Z,1516666316.635 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-01-23T00:11:56.756Z,1516666316.756 [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-23T00:11:56.830Z,1516666316.830 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-01-23T00:11:56.831Z,1516666316.831 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-01-23T00:11:56.831Z,1516666316.831 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-01-23T00:12:03.320Z,1516666323.320 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:03.329Z,1516666323.329 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:03.754Z,1516666323.754 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:03.755Z,1516666323.755 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:04.067Z,1516666324.067 [Aanderaa_O2](INFO): Powering down
2018-01-23T00:12:04.148Z,1516666324.148 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:04.148Z,1516666324.148 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:04.433Z,1516666324.433 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003670
2018-01-23T00:12:04.465Z,1516666324.465 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:04.478Z,1516666324.478 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:04.914Z,1516666324.914 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:04.915Z,1516666324.915 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:05.289Z,1516666325.289 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:05.290Z,1516666325.290 [DeadReckonWithRespectToSeafloor](DEBUG): Starting up and don't have orientation data yet.
2018-01-23T00:12:15.759Z,1516666335.759 [SBIT](IMPORTANT): Beginning Startup BIT
2018-01-23T00:12:15.763Z,1516666335.763 [CBIT](IMPORTANT): Beginning ground fault scan
2018-01-23T00:12:18.660Z,1516666338.660 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:12:18.660Z,1516666338.660 [BPC1] Communications Fault, FailCount= 1
2018-01-23T00:12:18.660Z,1516666338.660 [BPC1](ERROR): Communications Fault
2018-01-23T00:12:18.813Z,1516666338.813 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:12:19.411Z,1516666339.411 [NAL9602](INFO): Powering up NAL9602
2018-01-23T00:12:19.955Z,1516666339.955 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:12:19.955Z,1516666339.955 [BPC1] No Fault, FailCount= 1
2018-01-23T00:12:26.714Z,1516666346.714 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): -0.004383
CHAN A1 (24V): 0.126554
CHAN A2 (12V): -0.001921
CHAN A3 (5V): -0.001539
CHAN B0 (3.3V): -0.000548
CHAN B1 (3.15aV): -0.000572
CHAN B2 (3.15bV): -0.000075
CHAN B3 (GND): 0.000333
OPEN: -0.000306
Full Scale Calc: 4.765 mA, -1.589 mA
2018-01-23T00:12:30.211Z,1516666350.211 [NAL9602](INFO): NAL9602 initialized
2018-01-23T00:12:36.104Z,1516666356.104 [PNI_TCM](ERROR): CRC does not match. Expected:0x43911 got:0x36891
2018-01-23T00:12:40.511Z,1516666360.511 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:12:40.511Z,1516666360.511 [BPC1] Communications Fault, FailCount= 2
2018-01-23T00:12:40.511Z,1516666360.511 [BPC1](ERROR): Communications Fault
2018-01-23T00:12:40.606Z,1516666360.606 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:12:41.791Z,1516666361.791 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:12:41.791Z,1516666361.791 [BPC1] No Fault, FailCount= 2
2018-01-23T00:12:50.518Z,1516666370.518 [PNI_TCM](ERROR): CRC does not match. Expected:0x34287 got:0x62640
2018-01-23T00:13:02.421Z,1516666382.421 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:13:02.421Z,1516666382.421 [BPC1] Communications Fault, FailCount= 3
2018-01-23T00:13:02.421Z,1516666382.421 [BPC1](ERROR): Communications Fault
2018-01-23T00:13:02.638Z,1516666382.638 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:13:03.694Z,1516666383.694 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:13:03.695Z,1516666383.695 [BPC1] No Fault, FailCount= 3
2018-01-23T00:13:11.655Z,1516666391.655 [SBIT](IMPORTANT): SBIT PASSED
2018-01-23T00:13:12.043Z,1516666392.043 [MissionManager](IMPORTANT): Started mission Startup
2018-01-23T00:13:12.043Z,1516666392.043 [Startup] Running Loop=1
2018-01-23T00:13:12.043Z,1516666392.043 [Startup](DEBUG): Aggregate::initialize Startup
2018-01-23T00:13:12.043Z,1516666392.043 [Startup:A.GoToSurface] Running Loop=1
2018-01-23T00:13:12.044Z,1516666392.044 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-01-23T00:13:12.044Z,1516666392.044 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-01-23T00:13:12.045Z,1516666392.045 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-01-23T00:13:12.049Z,1516666392.049 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-01-23T00:13:12.050Z,1516666392.050 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2018-01-23T00:13:12.050Z,1516666392.050 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-01-23T00:13:12.060Z,1516666392.060 [Startup:StartupSatComms] Running Loop=1
2018-01-23T00:13:12.060Z,1516666392.060 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2018-01-23T00:13:12.060Z,1516666392.060 [Startup:StartupSatComms:A] Running Loop=1
2018-01-23T00:13:12.450Z,1516666392.450 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2018-01-23T00:13:24.431Z,1516666404.431 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:13:24.431Z,1516666404.431 [BPC1] Communications Fault, FailCount= 4
2018-01-23T00:13:24.431Z,1516666404.431 [BPC1](ERROR): Communications Fault
2018-01-23T00:13:24.478Z,1516666404.478 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:13:25.642Z,1516666405.642 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:13:25.643Z,1516666405.643 [BPC1] No Fault, FailCount= 4
2018-01-23T00:13:46.424Z,1516666426.424 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:13:46.424Z,1516666426.424 [BPC1] Communications Fault, FailCount= 5
2018-01-23T00:13:46.424Z,1516666426.424 [BPC1](ERROR): Communications Fault
2018-01-23T00:13:46.484Z,1516666426.484 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:13:47.650Z,1516666427.650 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:13:47.650Z,1516666427.650 [BPC1] No Fault, FailCount= 5
2018-01-23T00:14:08.327Z,1516666448.327 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:14:08.327Z,1516666448.327 [BPC1] Communications Fault, FailCount= 6
2018-01-23T00:14:08.327Z,1516666448.327 [BPC1](ERROR): Communications Fault
2018-01-23T00:14:08.399Z,1516666448.399 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:14:09.540Z,1516666449.540 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:14:09.540Z,1516666449.540 [BPC1] No Fault, FailCount= 6
2018-01-23T00:14:12.352Z,1516666452.352 [Startup:StartupSatComms:A](INFO): Timed out from 2018-01-23T00:13:12.1Z
2018-01-23T00:14:12.352Z,1516666452.352 [Startup:StartupSatComms:A] Stopped
2018-01-23T00:14:12.352Z,1516666452.352 [Startup:StartupSatComms:B] Running Loop=1
2018-01-23T00:14:12.748Z,1516666452.748 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-01-23T00:14:16.886Z,1516666456.886 [DataOverHttps](INFO): Sending 518 bytes from file Logs/20180123T001143/Express0001.lzma
2018-01-23T00:14:17.654Z,1516666457.654 [DataOverHttps](INFO): Moved sent file to Logs/20180123T001143/Express0001.lzma.bak
2018-01-23T00:14:17.654Z,1516666457.654 [DataOverHttps](INFO): SBD MOMSN=7753289
2018-01-23T00:14:18.132Z,1516666458.132 [Startup:StartupSatComms:B] Stopped
2018-01-23T00:14:18.132Z,1516666458.132 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2018-01-23T00:14:18.133Z,1516666458.133 [Startup:StartupSatComms] Stopped
2018-01-23T00:14:18.133Z,1516666458.133 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2018-01-23T00:14:18.133Z,1516666458.133 [Startup](INFO): Completed Startup
2018-01-23T00:14:18.134Z,1516666458.134 [MissionManager](INFO): Startup is completed.
2018-01-23T00:14:18.134Z,1516666458.134 [MissionManager](INFO): Uninitializing Mission Startup
2018-01-23T00:14:18.134Z,1516666458.134 [Startup] Stopped
2018-01-23T00:14:18.134Z,1516666458.134 [Startup](DEBUG): Aggregate::uninitialize Startup
2018-01-23T00:14:18.134Z,1516666458.134 [Startup:A.GoToSurface] Stopped
2018-01-23T00:14:18.134Z,1516666458.134 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-01-23T00:14:18.537Z,1516666458.537 [MissionManager](IMPORTANT): Started mission Default
2018-01-23T00:14:18.537Z,1516666458.537 [Default] Running Loop=1
2018-01-23T00:14:18.538Z,1516666458.538 [Default](DEBUG): Aggregate::initialize Default
2018-01-23T00:14:18.538Z,1516666458.538 [Default:B.GoToSurface] Running Loop=1
2018-01-23T00:14:18.538Z,1516666458.538 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2018-01-23T00:14:18.538Z,1516666458.538 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2018-01-23T00:14:18.538Z,1516666458.538 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2018-01-23T00:14:18.539Z,1516666458.539 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2018-01-23T00:14:18.539Z,1516666458.539 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds.
2018-01-23T00:14:18.539Z,1516666458.539 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2018-01-23T00:14:18.539Z,1516666458.539 [Default:A.Wait] Running Loop=1
2018-01-23T00:14:18.539Z,1516666458.539 [Default:A.Wait](DEBUG): Initialize Wait Component.
2018-01-23T00:14:31.599Z,1516666471.599 [Default:A.Wait](INFO): Done Waiting.
2018-01-23T00:14:31.599Z,1516666471.599 [Default:A.Wait] Stopped
2018-01-23T00:14:31.599Z,1516666471.599 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2018-01-23T00:14:31.975Z,1516666471.975 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:14:31.975Z,1516666471.975 [BPC1] Communications Fault, FailCount= 7
2018-01-23T00:14:31.975Z,1516666471.975 [BPC1](ERROR): Communications Fault
2018-01-23T00:14:31.995Z,1516666471.995 [Default:CheckIn] Running Loop=1
2018-01-23T00:14:31.995Z,1516666471.995 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2018-01-23T00:14:31.995Z,1516666471.995 [Default:CheckIn:Read_GPS] Running Loop=1
2018-01-23T00:14:32.021Z,1516666472.021 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:14:32.398Z,1516666472.398 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2018-01-23T00:14:33.225Z,1516666473.225 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:14:33.225Z,1516666473.225 [BPC1] No Fault, FailCount= 7
2018-01-23T00:14:52.380Z,1516666492.380 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T00:14:52.380Z,1516666492.380 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2018-01-23T00:14:52.380Z,1516666492.380 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-01-23T00:14:52.422Z,1516666492.422 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-01-23T00:14:52.786Z,1516666492.786 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T00:14:52.786Z,1516666492.786 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2018-01-23T00:14:52.786Z,1516666492.786 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T00:14:52.925Z,1516666492.925 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-01-23T00:14:52.925Z,1516666492.925 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2018-01-23T00:14:52.926Z,1516666492.926 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T00:14:53.196Z,1516666493.196 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-01-23T00:14:53.196Z,1516666493.196 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:14:53.196Z,1516666493.196 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:14:53.216Z,1516666493.216 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T00:14:53.216Z,1516666493.216 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2018-01-23T00:14:53.601Z,1516666493.601 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T00:14:53.602Z,1516666493.602 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:14:53.602Z,1516666493.602 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:14:53.995Z,1516666493.995 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:14:53.995Z,1516666493.995 [BPC1] Communications Fault, FailCount= 8
2018-01-23T00:14:53.995Z,1516666493.995 [BPC1](ERROR): Communications Fault
2018-01-23T00:14:54.045Z,1516666494.045 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:14:55.228Z,1516666495.228 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:14:55.228Z,1516666495.228 [BPC1] No Fault, FailCount= 8
2018-01-23T00:15:15.417Z,1516666515.417 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-01-23T00:15:15.417Z,1516666515.417 [Rowe_600LCM] Communications Fault, FailCount= 1
2018-01-23T00:15:15.417Z,1516666515.417 [Rowe_600LCM](ERROR): Communications Fault
2018-01-23T00:15:15.608Z,1516666515.608 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-01-23T00:15:15.821Z,1516666515.821 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-01-23T00:15:15.918Z,1516666515.918 [Rowe_600LCM](INFO): Powering down
2018-01-23T00:15:15.986Z,1516666515.986 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:15:15.987Z,1516666515.987 [BPC1] Communications Fault, FailCount= 9
2018-01-23T00:15:15.987Z,1516666515.987 [BPC1](ERROR): Communications Fault
2018-01-23T00:15:16.046Z,1516666516.046 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:15:17.208Z,1516666517.208 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-01-23T00:15:17.208Z,1516666517.208 [Rowe_600LCM] No Fault, FailCount= 1
2018-01-23T00:15:17.208Z,1516666517.208 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:15:17.208Z,1516666517.208 [BPC1] No Fault, FailCount= 9
2018-01-23T00:15:17.536Z,1516666517.536 [Rowe_600LCM](INFO): Initializing
2018-01-23T00:15:17.536Z,1516666517.536 [Rowe_600LCM](INFO): Checking LCM
2018-01-23T00:15:17.536Z,1516666517.536 [Rowe_600LCM](INFO): LCM OK
2018-01-23T00:15:17.537Z,1516666517.537 [Rowe_600LCM](INFO): Powering up
2018-01-23T00:15:21.717Z,1516666521.717 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-01-23T00:15:21.820Z,1516666521.820 [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-23T00:15:21.822Z,1516666521.822 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-01-23T00:15:21.823Z,1516666521.823 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-01-23T00:15:21.823Z,1516666521.823 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-01-23T00:15:37.987Z,1516666537.987 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:15:37.987Z,1516666537.987 [BPC1] Communications Fault, FailCount= 10
2018-01-23T00:15:37.987Z,1516666537.987 [BPC1](ERROR): Communications Fault
2018-01-23T00:15:38.008Z,1516666538.008 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:15:38.009Z,1516666538.009 [CBIT](CRITICAL): Communications Fault in component: BPC1
2018-01-23T00:15:38.470Z,1516666538.470 [CommandLine](FAULT): Scheduling is paused
2018-01-23T00:15:38.471Z,1516666538.471 [CBIT](INFO): Critical error at 20180123T001538
2018-01-23T00:15:38.471Z,1516666538.471 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2018-01-23T00:17:18.005Z,1516666638.005 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-01-23T00:17:18.005Z,1516666638.005 [Rowe_600LCM] Communications Fault, FailCount= 2
2018-01-23T00:17:18.005Z,1516666638.005 [Rowe_600LCM](ERROR): Communications Fault
2018-01-23T00:17:18.236Z,1516666638.236 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-01-23T00:17:18.410Z,1516666638.410 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-01-23T00:17:18.517Z,1516666638.517 [Rowe_600LCM](INFO): Powering down
2018-01-23T00:17:22.600Z,1516666642.600 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-01-23T00:17:22.600Z,1516666642.600 [Rowe_600LCM] No Fault, FailCount= 2
2018-01-23T00:17:22.961Z,1516666642.961 [Rowe_600LCM](INFO): Initializing
2018-01-23T00:17:22.962Z,1516666642.962 [Rowe_600LCM](INFO): Checking LCM
2018-01-23T00:17:22.962Z,1516666642.962 [Rowe_600LCM](INFO): LCM OK
2018-01-23T00:17:22.962Z,1516666642.962 [Rowe_600LCM](INFO): Powering up
2018-01-23T00:17:27.171Z,1516666647.171 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-01-23T00:17:27.280Z,1516666647.280 [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-23T00:17:27.281Z,1516666647.281 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-01-23T00:17:27.282Z,1516666647.282 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-01-23T00:17:27.283Z,1516666647.283 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-01-23T00:17:33.815Z,1516666653.815 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2018-01-23T00:17:53.464Z,1516666673.464 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T00:17:53.464Z,1516666673.464 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2018-01-23T00:17:53.464Z,1516666673.464 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-01-23T00:17:53.495Z,1516666673.495 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-01-23T00:17:53.868Z,1516666673.868 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T00:17:53.868Z,1516666673.868 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2
2018-01-23T00:17:53.868Z,1516666673.868 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T00:17:53.881Z,1516666673.881 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-01-23T00:17:53.881Z,1516666673.881 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2018-01-23T00:17:53.882Z,1516666673.882 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T00:17:54.266Z,1516666674.266 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-01-23T00:17:54.266Z,1516666674.266 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:17:54.267Z,1516666674.267 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:17:54.279Z,1516666674.279 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T00:17:54.279Z,1516666674.279 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2
2018-01-23T00:17:54.643Z,1516666674.643 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T00:17:54.643Z,1516666674.643 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:17:54.644Z,1516666674.644 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:18:36.215Z,1516666716.215 [CommandLine](IMPORTANT): got command get CBIT.stopDepth
2018-01-23T00:18:36.216Z,1516666716.216 [CommandLine](IMPORTANT): CBIT.stopDepth 205.000000 m
2018-01-23T00:18:46.774Z,1516666726.774 [CommandLine](INFO): End of History
2018-01-23T00:18:52.946Z,1516666732.946 [CommandLine](IMPORTANT): got command get CBIT.abortDepth
2018-01-23T00:18:52.947Z,1516666732.947 [CommandLine](IMPORTANT): CBIT.abortDepth 250.000000 m
2018-01-23T00:19:23.045Z,1516666763.045 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-01-23T00:19:23.045Z,1516666763.045 [Rowe_600LCM] Communications Fault, FailCount= 3
2018-01-23T00:19:23.045Z,1516666763.045 [Rowe_600LCM](ERROR): Communications Fault
2018-01-23T00:19:23.119Z,1516666763.119 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-01-23T00:19:23.449Z,1516666763.449 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-01-23T00:19:23.657Z,1516666763.657 [Rowe_600LCM](INFO): Powering down
2018-01-23T00:19:25.182Z,1516666765.182 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-01-23T00:19:25.182Z,1516666765.182 [Rowe_600LCM] No Fault, FailCount= 3
2018-01-23T00:19:25.273Z,1516666765.273 [Rowe_600LCM](INFO): Initializing
2018-01-23T00:19:25.274Z,1516666765.274 [Rowe_600LCM](INFO): Checking LCM
2018-01-23T00:19:25.274Z,1516666765.274 [Rowe_600LCM](INFO): LCM OK
2018-01-23T00:19:25.274Z,1516666765.274 [Rowe_600LCM](INFO): Powering up
2018-01-23T00:19:27.967Z,1516666767.967 [CommandLine](IMPORTANT): got command get VerticalControl.buoyancyNeutral
2018-01-23T00:19:27.968Z,1516666767.968 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral 315.000012 cc
2018-01-23T00:19:29.403Z,1516666769.403 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-01-23T00:19:29.466Z,1516666769.466 [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-23T00:19:29.467Z,1516666769.467 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-01-23T00:19:29.468Z,1516666769.468 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-01-23T00:19:29.470Z,1516666769.470 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-01-23T00:19:32.391Z,1516666772.391 [Default:CheckIn:Read_GPS](INFO): Timed out from 2018-01-23T00:14:31.0Z
2018-01-23T00:19:32.391Z,1516666772.391 [Default:CheckIn:Read_GPS] Stopped
2018-01-23T00:19:32.391Z,1516666772.391 [Default:CheckIn:Read_Iridium] Running Loop=1
2018-01-23T00:19:32.779Z,1516666772.779 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2018-01-23T00:19:42.252Z,1516666782.252 [DataOverHttps](INFO): Sending 98 bytes from file Logs/20180123T001143/Courier0004.lzma
2018-01-23T00:19:43.038Z,1516666783.038 [DataOverHttps](INFO): Moved sent file to Logs/20180123T001143/Courier0004.lzma.bak
2018-01-23T00:19:43.038Z,1516666783.038 [DataOverHttps](INFO): SBD MOMSN=7753310
2018-01-23T00:19:50.307Z,1516666790.307 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault
2018-01-23T00:19:50.308Z,1516666790.308 [CommandLine](IMPORTANT): VerticalControl.massDefault -0.075000 cm
2018-01-23T00:19:52.374Z,1516666792.374 [DataOverHttps](INFO): Sending 428 bytes from file Logs/20180123T001143/Express0005.lzma
2018-01-23T00:19:53.166Z,1516666793.166 [DataOverHttps](INFO): Moved sent file to Logs/20180123T001143/Express0005.lzma.bak
2018-01-23T00:19:53.166Z,1516666793.166 [DataOverHttps](INFO): SBD MOMSN=7753318
2018-01-23T00:19:53.629Z,1516666793.629 [Default:CheckIn:Read_Iridium] Stopped
2018-01-23T00:19:53.630Z,1516666793.630 [Default:CheckIn:C.Wait] Running Loop=1
2018-01-23T00:19:53.630Z,1516666793.630 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2018-01-23T00:20:00.656Z,1516666800.656 [CommandLine](IMPORTANT): got command get VerticalControl.massDefault millimeter
2018-01-23T00:20:00.656Z,1516666800.656 [CommandLine](IMPORTANT): VerticalControl.massDefault -0.750000 mm
2018-01-23T00:20:38.247Z,1516666838.247 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:20:38.247Z,1516666838.247 [BPC1] No Fault, FailCount= 10
2018-01-23T00:20:57.586Z,1516666857.586 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T00:20:57.586Z,1516666857.586 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2018-01-23T00:20:57.586Z,1516666857.586 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2018-01-23T00:20:57.588Z,1516666857.588 [DeadReckonWithRespectToSeafloor](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2018-01-23T00:20:57.588Z,1516666857.588 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 3
2018-01-23T00:20:57.588Z,1516666857.588 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2018-01-23T00:20:57.616Z,1516666857.616 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2018-01-23T00:20:57.616Z,1516666857.616 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2018-01-23T00:20:57.775Z,1516666857.775 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2018-01-23T00:20:57.775Z,1516666857.775 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2018-01-23T00:20:57.776Z,1516666857.776 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2018-01-23T00:20:57.776Z,1516666857.776 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 3
2018-01-23T00:20:58.094Z,1516666858.094 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-01-23T00:20:58.094Z,1516666858.094 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:20:58.095Z,1516666858.095 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:20:58.095Z,1516666858.095 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2018-01-23T00:20:58.095Z,1516666858.095 [DeadReckonWithRespectToSeafloor](INFO): Will consider orientation measurement stale after 120s.
2018-01-23T00:20:58.096Z,1516666858.096 [DeadReckonWithRespectToSeafloor](INFO): Will consider velocity measurement stale after 20s.
2018-01-23T00:20:58.902Z,1516666858.902 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:20:58.902Z,1516666858.902 [BPC1] Communications Fault, FailCount= 1
2018-01-23T00:20:58.902Z,1516666858.902 [BPC1](ERROR): Communications Fault
2018-01-23T00:20:58.959Z,1516666858.959 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:21:00.107Z,1516666860.107 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:21:00.107Z,1516666860.107 [BPC1] No Fault, FailCount= 1
2018-01-23T00:21:20.878Z,1516666880.878 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:21:20.878Z,1516666880.878 [BPC1] Communications Fault, FailCount= 2
2018-01-23T00:21:20.878Z,1516666880.878 [BPC1](ERROR): Communications Fault
2018-01-23T00:21:20.934Z,1516666880.934 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:21:22.098Z,1516666882.098 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:21:22.099Z,1516666882.099 [BPC1] No Fault, FailCount= 2
2018-01-23T00:21:43.571Z,1516666903.571 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitAft millimeter
2018-01-23T00:21:43.572Z,1516666903.572 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitAft -35.000000 mm
2018-01-23T00:21:52.545Z,1516666912.545 [CBIT](DEBUG): EFC running - data check-sum false
2018-01-23T00:21:58.275Z,1516666918.275 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd millimeter
2018-01-23T00:21:58.276Z,1516666918.276 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 26.000001 mm
2018-01-23T00:22:02.008Z,1516666922.008 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:22:02.008Z,1516666922.008 [BPC1] Communications Fault, FailCount= 1
2018-01-23T00:22:02.008Z,1516666922.008 [BPC1](ERROR): Communications Fault
2018-01-23T00:22:02.067Z,1516666922.067 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:22:03.261Z,1516666923.261 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:22:03.261Z,1516666923.261 [BPC1] No Fault, FailCount= 1
2018-01-23T00:22:24.028Z,1516666944.028 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:22:24.028Z,1516666944.028 [BPC1] Communications Fault, FailCount= 2
2018-01-23T00:22:24.028Z,1516666944.028 [BPC1](ERROR): Communications Fault
2018-01-23T00:22:24.049Z,1516666944.049 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:22:25.239Z,1516666945.239 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:22:25.239Z,1516666945.239 [BPC1] No Fault, FailCount= 2
2018-01-23T00:22:33.179Z,1516666953.179 [NAL9602](FAULT): GPS failed to acquire within timeout.
2018-01-23T00:22:33.179Z,1516666953.179 [NAL9602] Data Fault, FailCount= 1
2018-01-23T00:22:33.179Z,1516666953.179 [NAL9602](ERROR): Data Fault
2018-01-23T00:22:33.259Z,1516666953.259 [CBIT](ERROR): Data Fault in component: NAL9602
2018-01-23T00:22:33.583Z,1516666953.583 [NAL9602](INFO): Powering down
2018-01-23T00:22:34.449Z,1516666954.449 [CBIT](INFO): Clearing failed state for component NAL9602
2018-01-23T00:22:34.449Z,1516666954.449 [NAL9602] No Fault, FailCount= 1
2018-01-23T00:22:46.011Z,1516666966.011 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:22:46.011Z,1516666966.011 [BPC1] Communications Fault, FailCount= 3
2018-01-23T00:22:46.011Z,1516666966.011 [BPC1](ERROR): Communications Fault
2018-01-23T00:22:46.033Z,1516666966.033 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:22:47.251Z,1516666967.251 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:22:47.251Z,1516666967.251 [BPC1] No Fault, FailCount= 3
2018-01-23T00:22:51.677Z,1516666971.677 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2018-01-23T00:22:51.677Z,1516666971.677 [Rowe_600LCM] Communications Fault, FailCount= 4
2018-01-23T00:22:51.677Z,1516666971.677 [Rowe_600LCM](ERROR): Communications Fault
2018-01-23T00:22:52.045Z,1516666972.045 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2018-01-23T00:22:52.082Z,1516666972.082 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-01-23T00:22:52.204Z,1516666972.204 [Rowe_600LCM](INFO): Powering down
2018-01-23T00:22:53.651Z,1516666973.651 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2018-01-23T00:22:53.651Z,1516666973.651 [Rowe_600LCM] No Fault, FailCount= 4
2018-01-23T00:22:53.821Z,1516666973.821 [Rowe_600LCM](INFO): Initializing
2018-01-23T00:22:53.822Z,1516666973.822 [Rowe_600LCM](INFO): Checking LCM
2018-01-23T00:22:53.822Z,1516666973.822 [Rowe_600LCM](INFO): LCM OK
2018-01-23T00:22:53.822Z,1516666973.822 [Rowe_600LCM](INFO): Powering up
2018-01-23T00:22:58.029Z,1516666978.029 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2018-01-23T00:22:58.128Z,1516666978.128 [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-23T00:22:58.130Z,1516666978.130 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2018-01-23T00:22:58.131Z,1516666978.131 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2018-01-23T00:22:58.132Z,1516666978.132 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2018-01-23T00:23:03.927Z,1516666983.927 [NAL9602](INFO): Powering up NAL9602
2018-01-23T00:23:07.966Z,1516666987.966 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:23:07.966Z,1516666987.966 [BPC1] Communications Fault, FailCount= 4
2018-01-23T00:23:07.966Z,1516666987.966 [BPC1](ERROR): Communications Fault
2018-01-23T00:23:08.023Z,1516666988.023 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:23:09.187Z,1516666989.187 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:23:09.187Z,1516666989.187 [BPC1] No Fault, FailCount= 4
2018-01-23T00:23:15.123Z,1516666995.123 [NAL9602](INFO): NAL9602 initialized
2018-01-23T00:23:29.956Z,1516667009.956 [BPC1](ERROR): Failed to receive battery data
2018-01-23T00:23:29.956Z,1516667009.956 [BPC1] Communications Fault, FailCount= 5
2018-01-23T00:23:29.956Z,1516667009.956 [BPC1](ERROR): Communications Fault
2018-01-23T00:23:30.010Z,1516667010.010 [CBIT](ERROR): Communications Fault in component: BPC1
2018-01-23T00:23:30.230Z,1516667010.230 [CommandLine](IMPORTANT): got command quit
2018-01-23T00:23:31.188Z,1516667011.188 [CBIT](INFO): Clearing failed state for component BPC1
2018-01-23T00:23:31.188Z,1516667011.188 [BPC1] No Fault, FailCount= 5
2018-01-23T00:23:31.237Z,1516667011.237 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:23:31.237Z,1516667011.237 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:31.238Z,1516667011.238 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2018-01-23T00:23:31.238Z,1516667011.238 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:31.239Z,1516667011.239 [CommandLine](INFO): Join timeout helper Thread ID is 4815
2018-01-23T00:23:31.245Z,1516667011.245 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-01-23T00:23:31.245Z,1516667011.245 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:31.246Z,1516667011.246 [NavChartDb](INFO): Join timeout helper Thread ID is 4816
2018-01-23T00:23:31.469Z,1516667011.469 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:23:31.469Z,1516667011.469 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:31.473Z,1516667011.473 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2018-01-23T00:23:31.473Z,1516667011.473 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:31.474Z,1516667011.474 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 4817
2018-01-23T00:23:31.529Z,1516667011.529 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:23:31.530Z,1516667011.530 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:31.533Z,1516667011.533 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-01-23T00:23:31.533Z,1516667011.533 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:31.534Z,1516667011.534 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4818
2018-01-23T00:23:31.743Z,1516667011.743 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:23:31.743Z,1516667011.743 [WetLabsBB2FL](INFO): Powering down
2018-01-23T00:23:31.744Z,1516667011.744 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:31.745Z,1516667011.745 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2018-01-23T00:23:31.745Z,1516667011.745 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:31.746Z,1516667011.746 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4819
2018-01-23T00:23:31.934Z,1516667011.934 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:23:32.127Z,1516667012.127 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface
2018-01-23T00:23:32.128Z,1516667012.128 [CTD_Seabird](INFO): Powering down
2018-01-23T00:23:32.129Z,1516667012.129 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.146Z,1516667012.146 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-01-23T00:23:32.146Z,1516667012.146 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.147Z,1516667012.147 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 4821
2018-01-23T00:23:32.148Z,1516667012.148 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:23:32.148Z,1516667012.148 [CTD_NeilBrown](INFO): Powering down
2018-01-23T00:23:32.149Z,1516667012.149 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.150Z,1516667012.150 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2018-01-23T00:23:32.151Z,1516667012.151 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.151Z,1516667012.151 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 4822
2018-01-23T00:23:32.270Z,1516667012.270 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:23:32.270Z,1516667012.270 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2018-01-23T00:23:32.474Z,1516667012.474 [Rowe_600LCM](INFO): Powering down
2018-01-23T00:23:32.476Z,1516667012.476 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.478Z,1516667012.478 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2018-01-23T00:23:32.478Z,1516667012.478 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.479Z,1516667012.479 [Radio_Surface](INFO): Join timeout helper Thread ID is 4824
2018-01-23T00:23:32.514Z,1516667012.514 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:23:32.514Z,1516667012.514 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.518Z,1516667012.518 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-01-23T00:23:32.518Z,1516667012.518 [logger ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.519Z,1516667012.519 [logger](INFO): Join timeout helper Thread ID is 4825
2018-01-23T00:23:32.521Z,1516667012.521 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:23:32.522Z,1516667012.522 [logger ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.538Z,1516667012.538 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-01-23T00:23:32.538Z,1516667012.538 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.538Z,1516667012.538 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-01-23T00:23:32.538Z,1516667012.538 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.539Z,1516667012.539 [controlThread](INFO): Join timeout helper Thread ID is 4826
2018-01-23T00:23:32.717Z,1516667012.717 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-01-23T00:23:32.718Z,1516667012.718 [controlThread](DEBUG): Uninitializing ControlThread
2018-01-23T00:23:32.719Z,1516667012.719 [NAL9602](INFO): Powering down
2018-01-23T00:23:32.720Z,1516667012.720 [PNI_TCM](INFO): Powering down
2018-01-23T00:23:32.806Z,1516667012.806 [Aanderaa_O2](INFO): Powering down
2018-01-23T00:23:32.808Z,1516667012.808 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-01-23T00:23:32.810Z,1516667012.810 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-01-23T00:23:32.810Z,1516667012.810 [MissionManager](INFO): Uninitializing Mission Default
2018-01-23T00:23:32.810Z,1516667012.810 [Default] Stopped
2018-01-23T00:23:32.810Z,1516667012.810 [Default](DEBUG): Aggregate::uninitialize Default
2018-01-23T00:23:32.811Z,1516667012.811 [Default:B.GoToSurface] Stopped
2018-01-23T00:23:32.811Z,1516667012.811 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2018-01-23T00:23:32.811Z,1516667012.811 [Default:CheckIn] Stopped
2018-01-23T00:23:32.811Z,1516667012.811 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2018-01-23T00:23:32.811Z,1516667012.811 [Default:CheckIn:C.Wait] Stopped
2018-01-23T00:23:32.811Z,1516667012.811 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2018-01-23T00:23:32.814Z,1516667012.814 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-01-23T00:23:32.815Z,1516667012.815 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-01-23T00:23:32.815Z,1516667012.815 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-01-23T00:23:32.815Z,1516667012.815 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-01-23T00:23:32.816Z,1516667012.816 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-01-23T00:23:32.816Z,1516667012.816 [BuoyancyServo](INFO): Powering down
2018-01-23T00:23:32.829Z,1516667012.829 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-01-23T00:23:32.830Z,1516667012.830 [ElevatorServo](INFO): Powering down
2018-01-23T00:23:32.830Z,1516667012.830 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-01-23T00:23:32.830Z,1516667012.830 [MassServo](INFO): Powering down
2018-01-23T00:23:32.831Z,1516667012.831 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-01-23T00:23:32.831Z,1516667012.831 [RudderServo](INFO): Powering down
2018-01-23T00:23:32.832Z,1516667012.832 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-01-23T00:23:32.832Z,1516667012.832 [ThrusterServo](INFO): Powering down
2018-01-23T00:23:32.833Z,1516667012.833 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-01-23T00:23:32.834Z,1516667012.834 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-01-23T00:23:32.834Z,1516667012.834 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-01-23T00:23:32.835Z,1516667012.835 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.937Z,1516667012.937 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.943Z,1516667012.943 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.978Z,1516667012.978 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.980Z,1516667012.980 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.983Z,1516667012.983 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:32.985Z,1516667012.985 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:33.012Z,1516667013.012 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-01-23T00:23:33.053Z,1516667013.053 [logger ThreadHandler](INFO): Thread cancelled.