2015-07-27T19:25:37.311Z,1438025137.311 [Supervisor](DEBUG): Initializing supervisor. 2015-07-27T19:25:37.314Z,1438025137.314 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2015-07-27T19:25:37.314Z,1438025137.314 [SyncHandler](INFO): Protected caller Thread ID is 765 2015-07-27T19:25:37.315Z,1438025137.315 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2015-07-27T19:25:37.317Z,1438025137.317 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2015-07-27T19:25:37.317Z,1438025137.317 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 766 2015-07-27T19:25:37.320Z,1438025137.320 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2015-07-27T19:25:37.332Z,1438025137.332 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2015-07-27T19:25:37.337Z,1438025137.337 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2015-07-27T19:25:37.337Z,1438025137.337 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 767 2015-07-27T19:25:37.338Z,1438025137.338 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2015-07-27T19:25:37.341Z,1438025137.341 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2015-07-27T19:25:37.341Z,1438025137.341 [logger ThreadHandler](INFO): Protected caller Thread ID is 768 2015-07-27T19:25:37.343Z,1438025137.343 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2015-07-27T19:25:37.344Z,1438025137.344 [Supervisor](INFO): Looking for Config files in directory: Config/ 2015-07-27T19:25:37.348Z,1438025137.348 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2015-07-27T19:25:37.765Z,1438025137.765 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2015-07-27T19:25:37.767Z,1438025137.767 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2015-07-27T19:25:37.963Z,1438025137.963 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2015-07-27T19:25:37.965Z,1438025137.965 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2015-07-27T19:25:38.091Z,1438025138.091 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2015-07-27T19:25:38.092Z,1438025138.092 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2015-07-27T19:25:38.235Z,1438025138.235 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2015-07-27T19:25:38.236Z,1438025138.236 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2015-07-27T19:25:38.336Z,1438025138.336 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2015-07-27T19:25:38.564Z,1438025138.564 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2015-07-27T19:25:38.564Z,1438025138.564 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2015-07-27T19:25:38.664Z,1438025138.664 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2015-07-27T19:25:38.664Z,1438025138.664 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2015-07-27T19:25:38.977Z,1438025138.977 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2015-07-27T19:25:38.978Z,1438025138.978 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2015-07-27T19:25:39.377Z,1438025139.377 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2015-07-27T19:25:39.378Z,1438025139.378 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2015-07-27T19:25:39.748Z,1438025139.748 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2015-07-27T19:25:39.749Z,1438025139.749 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2015-07-27T19:25:40.359Z,1438025140.359 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2015-07-27T19:25:40.360Z,1438025140.360 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2015-07-27T19:25:40.609Z,1438025140.609 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2015-07-27T19:25:40.610Z,1438025140.610 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2015-07-27T19:25:40.723Z,1438025140.723 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2015-07-27T19:25:40.724Z,1438025140.724 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2015-07-27T19:25:41.258Z,1438025141.258 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2015-07-27T19:25:41.259Z,1438025141.259 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2015-07-27T19:25:41.388Z,1438025141.388 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2015-07-27T19:25:41.390Z,1438025141.390 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2015-07-27T19:25:41.393Z,1438025141.393 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2015-07-27T19:25:41.668Z,1438025141.668 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2015-07-27T19:25:41.669Z,1438025141.669 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2015-07-27T19:25:41.809Z,1438025141.809 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2015-07-27T19:25:41.921Z,1438025141.921 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2015-07-27T19:25:42.033Z,1438025142.033 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2015-07-27T19:25:42.210Z,1438025142.210 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2015-07-27T19:25:42.372Z,1438025142.372 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2015-07-27T19:25:42.486Z,1438025142.486 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2015-07-27T19:25:42.590Z,1438025142.590 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2015-07-27T19:25:42.685Z,1438025142.685 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2015-07-27T19:25:42.799Z,1438025142.799 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2015-07-27T19:25:43.015Z,1438025143.015 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2015-07-27T19:25:43.020Z,1438025143.020 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2015-07-27T19:25:43.091Z,1438025143.091 [VerticalControl](DEBUG): Construct VerticalControl. 2015-07-27T19:25:43.222Z,1438025143.222 [VerticalControl] Loaded 2015-07-27T19:25:43.222Z,1438025143.222 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2015-07-27T19:25:43.223Z,1438025143.223 [HorizontalControl](DEBUG): Construct HorizontalControl. 2015-07-27T19:25:43.297Z,1438025143.297 [HorizontalControl] Loaded 2015-07-27T19:25:43.297Z,1438025143.297 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2015-07-27T19:25:43.302Z,1438025143.302 [SpeedControl](DEBUG): Construct SpeedControl. 2015-07-27T19:25:43.308Z,1438025143.308 [SpeedControl] Loaded 2015-07-27T19:25:43.308Z,1438025143.308 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2015-07-27T19:25:43.309Z,1438025143.309 [LoopControl](DEBUG): Construct LoopControl. 2015-07-27T19:25:43.309Z,1438025143.309 [LoopControl] Loaded 2015-07-27T19:25:43.309Z,1438025143.309 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2015-07-27T19:25:43.310Z,1438025143.310 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2015-07-27T19:25:43.311Z,1438025143.311 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2015-07-27T19:25:43.465Z,1438025143.465 [SBIT](DEBUG): Construct Startup Built In Test. 2015-07-27T19:25:43.481Z,1438025143.481 [SBIT] Loaded 2015-07-27T19:25:43.481Z,1438025143.481 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2015-07-27T19:25:43.482Z,1438025143.482 [IBIT](DEBUG): Construct Initiated Built In Test. 2015-07-27T19:25:43.515Z,1438025143.515 [IBIT] Loaded 2015-07-27T19:25:43.516Z,1438025143.516 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2015-07-27T19:25:43.518Z,1438025143.518 [CBIT](DEBUG): Construct Continuous Built In Test. 2015-07-27T19:25:43.665Z,1438025143.665 [CBIT] Loaded 2015-07-27T19:25:43.665Z,1438025143.665 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2015-07-27T19:25:43.666Z,1438025143.666 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2015-07-27T19:25:43.666Z,1438025143.666 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2015-07-27T19:25:43.695Z,1438025143.695 [DepthRateCalculator] Loaded 2015-07-27T19:25:43.695Z,1438025143.695 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2015-07-27T19:25:43.704Z,1438025143.704 [PitchRateCalculator] Loaded 2015-07-27T19:25:43.705Z,1438025143.705 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2015-07-27T19:25:43.716Z,1438025143.716 [SpeedCalculator] Loaded 2015-07-27T19:25:43.716Z,1438025143.716 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2015-07-27T19:25:43.732Z,1438025143.732 [TempGradientCalculator] Loaded 2015-07-27T19:25:43.733Z,1438025143.733 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2015-07-27T19:25:43.742Z,1438025143.742 [YawRateCalculator] Loaded 2015-07-27T19:25:43.742Z,1438025143.742 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2015-07-27T19:25:43.743Z,1438025143.743 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2015-07-27T19:25:43.743Z,1438025143.743 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2015-07-27T19:25:43.834Z,1438025143.834 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2015-07-27T19:25:43.834Z,1438025143.834 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2015-07-27T19:25:44.116Z,1438025144.116 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2015-07-27T19:25:44.120Z,1438025144.120 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2015-07-27T19:25:44.243Z,1438025144.243 [DeadReckonUsingMultipleVelocitySources] Loaded 2015-07-27T19:25:44.243Z,1438025144.243 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2015-07-27T19:25:44.302Z,1438025144.302 [DeadReckonUsingSpeedCalculator] Loaded 2015-07-27T19:25:44.303Z,1438025144.303 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2015-07-27T19:25:44.324Z,1438025144.324 [NavChart] Loaded 2015-07-27T19:25:44.324Z,1438025144.324 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2015-07-27T19:25:44.328Z,1438025144.328 [UniversalFixResidualReporter] Loaded 2015-07-27T19:25:44.329Z,1438025144.329 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2015-07-27T19:25:44.329Z,1438025144.329 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2015-07-27T19:25:44.330Z,1438025144.330 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2015-07-27T19:25:44.338Z,1438025144.338 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2015-07-27T19:25:44.339Z,1438025144.339 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2015-07-27T19:25:44.555Z,1438025144.555 [Aanderaa_O2] Loaded 2015-07-27T19:25:44.555Z,1438025144.555 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2015-07-27T19:25:44.638Z,1438025144.638 [CTD_NeilBrown] Loaded 2015-07-27T19:25:44.638Z,1438025144.638 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2015-07-27T19:25:44.640Z,1438025144.640 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 405914E0 2015-07-27T19:25:44.640Z,1438025144.640 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 847 2015-07-27T19:25:44.656Z,1438025144.656 [ESPComponent] Loaded 2015-07-27T19:25:44.657Z,1438025144.657 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2015-07-27T19:25:44.675Z,1438025144.675 [PAR_Licor] Loaded 2015-07-27T19:25:44.676Z,1438025144.676 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2015-07-27T19:25:44.730Z,1438025144.730 [WetLabsBB2FL] Loaded 2015-07-27T19:25:44.730Z,1438025144.730 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2015-07-27T19:25:44.732Z,1438025144.732 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405C14E0 2015-07-27T19:25:44.733Z,1438025144.733 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 848 2015-07-27T19:25:44.733Z,1438025144.733 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2015-07-27T19:25:44.734Z,1438025144.734 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2015-07-27T19:25:45.256Z,1438025145.256 [AcousticModem_Benthos_ATM900] Loaded 2015-07-27T19:25:45.256Z,1438025145.256 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2015-07-27T19:25:45.444Z,1438025145.444 [DataOverHttps] Loaded 2015-07-27T19:25:45.445Z,1438025145.445 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2015-07-27T19:25:45.458Z,1438025145.458 [Depth_Keller] Loaded 2015-07-27T19:25:45.459Z,1438025145.459 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2015-07-27T19:25:45.463Z,1438025145.463 [DropWeight] Loaded 2015-07-27T19:25:45.464Z,1438025145.464 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2015-07-27T19:25:45.566Z,1438025145.566 [NAL9602] Loaded 2015-07-27T19:25:45.567Z,1438025145.567 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2015-07-27T19:25:45.612Z,1438025145.612 [Onboard] Loaded 2015-07-27T19:25:45.612Z,1438025145.612 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2015-07-27T19:25:45.619Z,1438025145.619 [Radio_Surface] Loaded 2015-07-27T19:25:45.619Z,1438025145.619 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2015-07-27T19:25:45.622Z,1438025145.622 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408054E0 2015-07-27T19:25:45.622Z,1438025145.622 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 849 2015-07-27T19:25:45.828Z,1438025145.828 [PNI_TCM] Loaded 2015-07-27T19:25:45.829Z,1438025145.829 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2015-07-27T19:25:46.033Z,1438025146.033 [Rowe_600] Loaded 2015-07-27T19:25:46.033Z,1438025146.033 [ComponentRegistry](DEBUG): Component "Rowe_600" handled in its own thread. 2015-07-27T19:25:46.038Z,1438025146.038 [Rowe_600 ThreadHandler](DEBUG): Created PCaller Thread at 408354E0 2015-07-27T19:25:46.039Z,1438025146.039 [Rowe_600 ThreadHandler](INFO): Protected caller Thread ID is 850 2015-07-27T19:25:48.060Z,1438025148.060 [BPC1] Loaded 2015-07-27T19:25:48.061Z,1438025148.061 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2015-07-27T19:25:48.061Z,1438025148.061 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2015-07-27T19:25:48.066Z,1438025148.066 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2015-07-27T19:25:48.203Z,1438025148.203 [BuoyancyServo] Loaded 2015-07-27T19:25:48.204Z,1438025148.204 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2015-07-27T19:25:48.217Z,1438025148.217 [ElevatorServo] Loaded 2015-07-27T19:25:48.217Z,1438025148.217 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2015-07-27T19:25:48.229Z,1438025148.229 [MassServo] Loaded 2015-07-27T19:25:48.234Z,1438025148.234 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2015-07-27T19:25:48.246Z,1438025148.246 [RudderServo] Loaded 2015-07-27T19:25:48.247Z,1438025148.247 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2015-07-27T19:25:48.258Z,1438025148.258 [ThrusterServo] Loaded 2015-07-27T19:25:48.259Z,1438025148.259 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2015-07-27T19:25:48.259Z,1438025148.259 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2015-07-27T19:25:48.260Z,1438025148.260 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2015-07-27T19:25:48.445Z,1438025148.445 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2015-07-27T19:25:48.446Z,1438025148.446 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2015-07-27T19:25:48.484Z,1438025148.484 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2015-07-27T19:25:48.492Z,1438025148.492 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2015-07-27T19:25:48.493Z,1438025148.493 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2015-07-27T19:25:48.500Z,1438025148.500 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2015-07-27T19:25:48.502Z,1438025148.502 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408E34E0 2015-07-27T19:25:48.503Z,1438025148.503 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 851 2015-07-27T19:25:48.508Z,1438025148.508 [Supervisor](INFO): Main Thread ID is 764 2015-07-27T19:25:48.508Z,1438025148.508 [Supervisor](DEBUG): Running supervisor. 2015-07-27T19:25:48.508Z,1438025148.508 [CommandLine ThreadHandler](INFO): Handler Thread ID is 852 2015-07-27T19:25:48.515Z,1438025148.515 [controlThread ThreadHandler](INFO): Handler Thread ID is 853 2015-07-27T19:25:48.515Z,1438025148.515 [controlThread](DEBUG): Initializing ControlThread 2015-07-27T19:25:48.516Z,1438025148.516 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2015-07-27T19:25:48.518Z,1438025148.518 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2015-07-27T19:25:48.519Z,1438025148.519 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2015-07-27T19:25:48.519Z,1438025148.519 [LoopControl](DEBUG): Initialize LoopControlComponent. 2015-07-27T19:25:48.519Z,1438025148.519 [SBIT](INFO): Initialize SBIT Component. 2015-07-27T19:25:48.520Z,1438025148.520 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12496 2015-07-27T19:25:48.520Z,1438025148.520 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2015-07-27T19:25:48.521Z,1438025148.521 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2015-07-27T19:25:48.522Z,1438025148.522 [SBIT](INFO): Beginning SBIT in 63.000000 seconds. 2015-07-27T19:25:48.522Z,1438025148.522 [IBIT](INFO): Initialize IBIT Component. 2015-07-27T19:25:48.523Z,1438025148.523 [CBIT](DEBUG): Initialize CBIT Component. 2015-07-27T19:25:48.523Z,1438025148.523 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2015-07-27T19:25:48.523Z,1438025148.523 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2015-07-27T19:25:48.527Z,1438025148.527 [logger ThreadHandler](INFO): Handler Thread ID is 854 2015-07-27T19:25:48.546Z,1438025148.546 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-07-27T19:25:48.547Z,1438025148.547 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2015-07-27T19:25:48.547Z,1438025148.547 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2015-07-27T19:25:48.547Z,1438025148.547 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2015-07-27T19:25:48.548Z,1438025148.548 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2015-07-27T19:25:48.549Z,1438025148.549 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-07-27T19:25:48.549Z,1438025148.549 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-07-27T19:25:48.549Z,1438025148.549 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-07-27T19:25:48.550Z,1438025148.550 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-07-27T19:25:48.550Z,1438025148.550 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-07-27T19:25:48.551Z,1438025148.551 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-07-27T19:25:48.551Z,1438025148.551 [NavChart](DEBUG): Initialize NavChart Navigation. 2015-07-27T19:25:48.551Z,1438025148.551 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2015-07-27T19:25:48.567Z,1438025148.567 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2015-07-27T19:25:48.580Z,1438025148.580 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 855 2015-07-27T19:25:48.581Z,1438025148.581 [CTD_NeilBrown](INFO): Powering down 2015-07-27T19:25:48.619Z,1438025148.619 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-07-27T19:25:48.623Z,1438025148.623 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 856 2015-07-27T19:25:48.624Z,1438025148.624 [WetLabsBB2FL](INFO): Powering down 2015-07-27T19:25:48.659Z,1438025148.659 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 857 2015-07-27T19:25:48.665Z,1438025148.665 [Radio_Surface](INFO): Powering up 2015-07-27T19:25:48.673Z,1438025148.673 [MissionManager](DEBUG): 2015-07-27T19:25:48.674Z,1438025148.674 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2015-07-27T19:25:48.683Z,1438025148.683 [Rowe_600 ThreadHandler](INFO): Handler Thread ID is 858 2015-07-27T19:25:48.703Z,1438025148.703 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 859 2015-07-27T19:25:48.711Z,1438025148.711 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2015-07-27T19:25:48.713Z,1438025148.713 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2015-07-27T19:25:48.713Z,1438025148.713 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2015-07-27T19:25:48.713Z,1438025148.713 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2015-07-27T19:25:48.714Z,1438025148.714 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2015-07-27T19:25:48.714Z,1438025148.714 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2015-07-27T19:25:48.714Z,1438025148.714 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2015-07-27T19:25:48.714Z,1438025148.714 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2015-07-27T19:25:48.715Z,1438025148.715 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2015-07-27T19:25:48.789Z,1438025148.789 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2015-07-27T19:25:48.790Z,1438025148.790 [Default:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-07-27T19:25:48.852Z,1438025148.852 [Default:SplitLargeDefaultLogs:A.Execute](DEBUG): Construct Execute. 2015-07-27T19:25:48.857Z,1438025148.857 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2015-07-27T19:25:48.877Z,1438025148.877 [Default:CheckIn:WaitAnHour:A.Wait](DEBUG): Construct Wait. 2015-07-27T19:25:48.879Z,1438025148.879 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2015-07-27T19:25:48.908Z,1438025148.908 [MissionManager](DEBUG): 0 10 500 Default mission has been running for 1 restart logs Burn 300 Dropped weight due to communications timeout. 1 5 2015-07-27T19:25:48.913Z,1438025148.913 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2015-07-27T19:25:48.947Z,1438025148.947 [Rowe_600](INFO): Powering down 2015-07-27T19:25:49.031Z,1438025149.031 [AcousticModem_Benthos_ATM900](INFO): Powering up 2015-07-27T19:25:49.032Z,1438025149.032 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2015-07-27T19:25:49.192Z,1438025149.192 [Rowe_600](INFO): Initializing 2015-07-27T19:25:49.248Z,1438025149.248 [Rowe_600](INFO): Powering up 2015-07-27T19:25:49.532Z,1438025149.532 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:49.816Z,1438025149.816 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:49.973Z,1438025149.973 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2015-07-27T19:25:49.985Z,1438025149.985 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2015-07-27T19:25:49.999Z,1438025149.999 [ElevatorServo](DEBUG): Initializing EZServoServo. 2015-07-27T19:25:50.005Z,1438025150.005 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2015-07-27T19:25:50.023Z,1438025150.023 [MassServo](DEBUG): Initializing EZServoServo. 2015-07-27T19:25:50.048Z,1438025150.048 [MassServo](DEBUG): Initializing MassServo. 2015-07-27T19:25:50.054Z,1438025150.054 [RudderServo](DEBUG): Initializing EZServoServo. 2015-07-27T19:25:50.065Z,1438025150.065 [RudderServo](DEBUG): Initializing RudderServo. 2015-07-27T19:25:50.070Z,1438025150.070 [ThrusterServo](DEBUG): Initializing EZServoServo. 2015-07-27T19:25:50.077Z,1438025150.077 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2015-07-27T19:25:50.121Z,1438025150.121 [CommandLine](FAULT): Scheduling is paused 2015-07-27T19:25:50.357Z,1438025150.357 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:50.358Z,1438025150.358 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:50.571Z,1438025150.571 [NAL9602](INFO): Powering up NAL9602 2015-07-27T19:25:50.607Z,1438025150.607 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:50.608Z,1438025150.608 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:50.938Z,1438025150.938 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2015-07-27T19:25:50.938Z,1438025150.938 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2015-07-27T19:25:50.938Z,1438025150.938 [BuoyancyServo] Communications Fault, FailCount= 1 2015-07-27T19:25:50.938Z,1438025150.938 [BuoyancyServo](ERROR): Communications Fault 2015-07-27T19:25:51.144Z,1438025151.144 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2015-07-27T19:25:51.214Z,1438025151.214 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:51.219Z,1438025151.219 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:51.236Z,1438025151.236 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2015-07-27T19:25:51.237Z,1438025151.237 [BuoyancyServo](INFO): Powering down 2015-07-27T19:25:51.667Z,1438025151.667 [Aanderaa_O2](INFO): Powering down 2015-07-27T19:25:51.797Z,1438025151.797 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:51.798Z,1438025151.798 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:51.987Z,1438025151.987 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:52.004Z,1438025152.004 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:52.427Z,1438025152.427 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:52.440Z,1438025152.440 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:52.816Z,1438025152.816 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:52.826Z,1438025152.826 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-07-27T19:25:53.422Z,1438025153.422 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2015-07-27T19:25:53.422Z,1438025153.422 [BuoyancyServo] No Fault, FailCount= 1 2015-07-27T19:25:53.665Z,1438025153.665 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2015-07-27T19:25:53.783Z,1438025153.783 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2015-07-27T19:25:56.356Z,1438025156.356 [AcousticModem_Benthos_ATM900](DEBUG): 2015-07-27T19:25:57.764Z,1438025157.764 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire 2015-07-27T19:25:57.774Z,1438025157.774 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band 2015-07-27T19:25:57.785Z,1438025157.785 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3 2015-07-27T19:25:58.381Z,1438025158.381 [AcousticModem_Benthos_ATM900](DEBUG): Jul 27 2015 19:29:28 2015-07-27T19:25:59.553Z,1438025159.553 [AcousticModem_Benthos_ATM900](INFO): entering command mode 2015-07-27T19:26:00.158Z,1438025160.158 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment 2015-07-27T19:26:00.169Z,1438025160.169 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1> 2015-07-27T19:26:00.170Z,1438025160.170 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged 2015-07-27T19:26:00.728Z,1438025160.728 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3 2015-07-27T19:26:01.233Z,1438025161.233 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment 2015-07-27T19:26:01.249Z,1438025161.249 [AcousticModem_Benthos_ATM900](INFO): set local address to 3 2015-07-27T19:26:01.822Z,1438025161.822 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2> 2015-07-27T19:26:02.038Z,1438025162.038 [NAL9602](INFO): NAL9602 initialized 2015-07-27T19:26:51.958Z,1438025211.958 [SBIT](IMPORTANT): Beginning Startup BIT 2015-07-27T19:26:51.966Z,1438025211.966 [CBIT](IMPORTANT): Beginning GF scan 2015-07-27T19:27:18.929Z,1438025238.929 [CBIT](FAULT): Chan 0 High side GF detected mA: CHAN 5 (24V): 0.287913 CHAN 4 (Batt): 0.173322 CHAN 2 (12V): 0.132383 CHAN 1 (5V): 0.046391 CHAN 0 (3.3V): 0.026783 OPEN: 0.000191 Full Scale Calc: 0.392 2015-07-27T19:27:45.534Z,1438025265.534 [SBIT](IMPORTANT): SBIT PASSED 2015-07-27T19:27:45.927Z,1438025265.927 [MissionManager](IMPORTANT): Started mission Startup 2015-07-27T19:27:45.928Z,1438025265.928 [Startup] Running Loop=1 2015-07-27T19:27:45.928Z,1438025265.928 [Startup](DEBUG): Aggregate::initialize Startup 2015-07-27T19:27:45.929Z,1438025265.929 [Startup:A.GoToSurface] Running Loop=1 2015-07-27T19:27:45.929Z,1438025265.929 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2015-07-27T19:27:45.930Z,1438025265.930 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2015-07-27T19:27:45.931Z,1438025265.931 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2015-07-27T19:27:45.931Z,1438025265.931 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s. 2015-07-27T19:27:45.981Z,1438025265.981 [Startup:StartupSatComms] Running Loop=1 2015-07-27T19:27:45.982Z,1438025265.982 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2015-07-27T19:27:45.982Z,1438025265.982 [Startup:StartupSatComms:A] Running Loop=1 2015-07-27T19:27:46.334Z,1438025266.334 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2015-07-27T19:28:22.224Z,1438025302.224 [BPC1](ERROR): Failed to receive battery data 2015-07-27T19:28:22.225Z,1438025302.225 [BPC1] Communications Fault, FailCount= 1 2015-07-27T19:28:22.225Z,1438025302.225 [BPC1](ERROR): Communications Fault 2015-07-27T19:28:22.355Z,1438025302.355 [CBIT](ERROR): Communications Fault in component: BPC1 2015-07-27T19:28:23.572Z,1438025303.572 [CBIT](INFO): Clearing failed state for component BPC1 2015-07-27T19:28:23.572Z,1438025303.572 [BPC1] No Fault, FailCount= 1 2015-07-27T19:28:46.329Z,1438025326.329 [Startup:StartupSatComms:A](INFO): Timed out from 2015-07-27T19:27:45.0Z 2015-07-27T19:28:46.329Z,1438025326.329 [Startup:StartupSatComms:A] Stopped 2015-07-27T19:28:46.330Z,1438025326.330 [Startup:StartupSatComms:B] Running Loop=1 2015-07-27T19:28:46.727Z,1438025326.727 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2015-07-27T19:28:48.061Z,1438025328.061 [PNI_TCM](ERROR): CRC does not match. Expected:0x64366 got:0x149 2015-07-27T19:28:48.070Z,1438025328.070 [PNI_TCM](ERROR): CRC does not match. Expected:0x20057 got:0x63 2015-07-27T19:28:48.071Z,1438025328.071 [PNI_TCM](ERROR): CRC does not match. Expected:0x42166 got:0x181 2015-07-27T19:28:48.449Z,1438025328.449 [PNI_TCM](ERROR): CRC does not match. Expected:0x30803 got:0x116 2015-07-27T19:28:48.858Z,1438025328.858 [PNI_TCM](ERROR): CRC does not match. Expected:0x38118 got:0x100 2015-07-27T19:28:48.908Z,1438025328.908 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-07-27T19:28:48.908Z,1438025328.908 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2015-07-27T19:28:48.909Z,1438025328.909 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-07-27T19:28:48.920Z,1438025328.920 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-07-27T19:28:48.920Z,1438025328.920 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2015-07-27T19:28:48.921Z,1438025328.921 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-07-27T19:28:48.966Z,1438025328.966 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-07-27T19:28:48.966Z,1438025328.966 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-07-27T19:28:49.283Z,1438025329.283 [PNI_TCM](ERROR): CRC does not match. Expected:0x4318 got:0x58 2015-07-27T19:28:49.396Z,1438025329.397 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-07-27T19:28:49.397Z,1438025329.397 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2015-07-27T19:28:49.398Z,1438025329.398 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-07-27T19:28:49.398Z,1438025329.398 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2015-07-27T19:28:49.670Z,1438025329.670 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-07-27T19:28:49.671Z,1438025329.671 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-07-27T19:28:49.671Z,1438025329.671 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-07-27T19:28:49.680Z,1438025329.680 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-07-27T19:28:49.681Z,1438025329.681 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-07-27T19:28:49.682Z,1438025329.682 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-07-27T19:28:50.080Z,1438025330.080 [PNI_TCM](ERROR): CRC does not match. Expected:0x29305 got:0x118 2015-07-27T19:28:50.089Z,1438025330.089 [PNI_TCM](ERROR): CRC does not match. Expected:0x6698 got:0x188 2015-07-27T19:28:50.125Z,1438025330.125 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1.218195 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:50.499Z,1438025330.499 [PNI_TCM](ERROR): CRC does not match. Expected:0x39205 got:0x36 2015-07-27T19:28:50.540Z,1438025330.540 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1.641055 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:50.888Z,1438025330.888 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1.988997 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:51.249Z,1438025331.249 [PNI_TCM](ERROR): CRC does not match. Expected:0x64899 got:0x150 2015-07-27T19:28:51.297Z,1438025331.297 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2.397833 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:51.656Z,1438025331.656 [PNI_TCM](ERROR): CRC does not match. Expected:0x3245 got:0x35 2015-07-27T19:28:51.657Z,1438025331.657 [PNI_TCM](ERROR): CRC does not match. Expected:0x39592 got:0x23 2015-07-27T19:28:51.703Z,1438025331.703 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2.792044 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:52.043Z,1438025332.043 [PNI_TCM](ERROR): CRC does not match. Expected:0x30748 got:0x103 2015-07-27T19:28:52.094Z,1438025332.094 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3.194873 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:52.482Z,1438025332.482 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3.582678 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:52.857Z,1438025332.857 [PNI_TCM](ERROR): CRC does not match. Expected:0x31980 got:0x32 2015-07-27T19:28:52.874Z,1438025332.874 [PNI_TCM](ERROR): CRC does not match. Expected:0x1006 got:0x251 2015-07-27T19:28:52.911Z,1438025332.911 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4.012345 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:53.257Z,1438025333.257 [PNI_TCM](ERROR): CRC does not match. Expected:0x1883 got:0x54 2015-07-27T19:28:53.302Z,1438025333.302 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4.394537 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:53.657Z,1438025333.657 [PNI_TCM](ERROR): CRC does not match. Expected:0x34885 got:0x32 2015-07-27T19:28:53.706Z,1438025333.706 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4.806979 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:54.076Z,1438025334.076 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5.172546 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:54.454Z,1438025334.454 [PNI_TCM](ERROR): CRC does not match. Expected:0x39014 got:0x36 2015-07-27T19:28:54.492Z,1438025334.492 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5.584588 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:54.895Z,1438025334.895 [PNI_TCM](ERROR): CRC does not match. Expected:0x12413 got:0x77 2015-07-27T19:28:54.896Z,1438025334.896 [PNI_TCM](ERROR): CRC does not match. Expected:0x46787 got:0x22 2015-07-27T19:28:54.958Z,1438025334.958 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 6.059129 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:55.247Z,1438025335.247 [PNI_TCM](ERROR): CRC does not match. Expected:0x56755 got:0x156 2015-07-27T19:28:55.327Z,1438025335.327 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 6.428503 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:55.726Z,1438025335.726 [PNI_TCM](ERROR): CRC does not match. Expected:0x12182 got:0x142 2015-07-27T19:28:55.777Z,1438025335.777 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 6.877601 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:56.084Z,1438025336.084 [PNI_TCM](ERROR): CRC does not match. Expected:0x77 got:0x162 2015-07-27T19:28:56.109Z,1438025336.109 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 7.209718 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:56.454Z,1438025336.454 [PNI_TCM](ERROR): CRC does not match. Expected:0x32179 got:0x254 2015-07-27T19:28:56.503Z,1438025336.503 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 7.603629 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:56.828Z,1438025336.828 [PNI_TCM](FAULT): Failed to acquire valid data within timeout. 2015-07-27T19:28:56.828Z,1438025336.828 [PNI_TCM] Data Fault, FailCount= 1 2015-07-27T19:28:56.829Z,1438025336.829 [PNI_TCM](ERROR): Data Fault 2015-07-27T19:28:56.866Z,1438025336.866 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.364367 seconds old. 2015-07-27T19:28:56.880Z,1438025336.880 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 7.968696 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:56.883Z,1438025336.883 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.374880 seconds old. 2015-07-27T19:28:56.958Z,1438025336.958 [CBIT](ERROR): Data Fault in component: PNI_TCM 2015-07-27T19:28:57.202Z,1438025337.202 [PNI_TCM](INFO): Powering down 2015-07-27T19:28:57.346Z,1438025337.346 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.843614 seconds old. 2015-07-27T19:28:57.347Z,1438025337.347 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 8.447843 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:57.349Z,1438025337.349 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.841209 seconds old. 2015-07-27T19:28:57.657Z,1438025337.657 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.154594 seconds old. 2015-07-27T19:28:57.658Z,1438025337.658 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 8.758930 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:57.665Z,1438025337.665 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.157401 seconds old. 2015-07-27T19:28:58.057Z,1438025338.057 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.542899 seconds old. 2015-07-27T19:28:58.058Z,1438025338.058 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 9.159553 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:58.060Z,1438025338.060 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.552612 seconds old. 2015-07-27T19:28:58.513Z,1438025338.513 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.010828 seconds old. 2015-07-27T19:28:58.528Z,1438025338.528 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 9.615057 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:58.530Z,1438025338.530 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.022647 seconds old. 2015-07-27T19:28:58.576Z,1438025338.576 [CBIT](INFO): Clearing failed state for component PNI_TCM 2015-07-27T19:28:58.576Z,1438025338.576 [PNI_TCM] No Fault, FailCount= 1 2015-07-27T19:28:58.978Z,1438025338.978 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.475751 seconds old. 2015-07-27T19:28:58.984Z,1438025338.984 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 10.080180 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:59.003Z,1438025339.003 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.478351 seconds old. 2015-07-27T19:28:59.320Z,1438025339.320 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.817887 seconds old. 2015-07-27T19:28:59.321Z,1438025339.321 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 10.422316 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:59.324Z,1438025339.324 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.816081 seconds old. 2015-07-27T19:28:59.701Z,1438025339.701 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 3.199079 seconds old. 2015-07-27T19:28:59.702Z,1438025339.702 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 10.803408 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:28:59.722Z,1438025339.722 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.213698 seconds old. 2015-07-27T19:29:00.141Z,1438025340.141 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 3.639164 seconds old. 2015-07-27T19:29:00.143Z,1438025340.143 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 11.243693 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:00.154Z,1438025340.154 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.645971 seconds old. 2015-07-27T19:29:00.572Z,1438025340.572 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 4.070031 seconds old. 2015-07-27T19:29:00.590Z,1438025340.590 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 11.674460 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:00.592Z,1438025340.592 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.084450 seconds old. 2015-07-27T19:29:00.953Z,1438025340.953 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 4.450623 seconds old. 2015-07-27T19:29:00.971Z,1438025340.971 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 12.055152 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:00.982Z,1438025340.982 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.465442 seconds old. 2015-07-27T19:29:01.407Z,1438025341.407 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 4.904428 seconds old. 2015-07-27T19:29:01.408Z,1438025341.408 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 12.509163 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:01.427Z,1438025341.427 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.902622 seconds old. 2015-07-27T19:29:01.720Z,1438025341.720 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 12.804518 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:02.178Z,1438025342.178 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 13.279259 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:02.752Z,1438025342.752 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 13.852651 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:03.074Z,1438025343.074 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 14.175255 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:03.455Z,1438025343.455 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 14.556447 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:03.866Z,1438025343.866 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 14.966683 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:04.269Z,1438025344.269 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 15.370212 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:04.705Z,1438025344.705 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 15.806192 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:05.114Z,1438025345.114 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 16.214527 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:05.491Z,1438025345.491 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 16.592513 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:05.844Z,1438025345.844 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 16.945162 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:06.239Z,1438025346.239 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 17.340379 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:06.597Z,1438025346.597 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 17.697633 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:07.020Z,1438025347.020 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 18.121394 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:07.476Z,1438025347.476 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 18.568986 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:07.844Z,1438025347.844 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 18.936859 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:08.419Z,1438025348.419 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 19.520069 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:08.675Z,1438025348.675 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 19.767349 seconds since last successful read, accepting data for 20.000000 seconds. 2015-07-27T19:29:38.697Z,1438025378.697 [BPC1](ERROR): Failed to receive battery data 2015-07-27T19:29:38.697Z,1438025378.697 [BPC1] Communications Fault, FailCount= 1 2015-07-27T19:29:38.697Z,1438025378.697 [BPC1](ERROR): Communications Fault 2015-07-27T19:29:38.819Z,1438025378.819 [CBIT](ERROR): Communications Fault in component: BPC1 2015-07-27T19:29:39.728Z,1438025379.728 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.027543 2015-07-27T19:29:39.980Z,1438025379.980 [CBIT](INFO): Clearing failed state for component BPC1 2015-07-27T19:29:39.981Z,1438025379.981 [BPC1] No Fault, FailCount= 1 2015-07-27T19:29:53.724Z,1438025393.724 [Startup:StartupSatComms:B](INFO): Timed out from 2015-07-27T19:28:46.3Z 2015-07-27T19:29:53.724Z,1438025393.724 [Startup:StartupSatComms:B] Stopped 2015-07-27T19:29:53.724Z,1438025393.724 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2015-07-27T19:29:53.725Z,1438025393.725 [Startup:StartupSatComms] Stopped 2015-07-27T19:29:53.725Z,1438025393.725 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2015-07-27T19:29:53.726Z,143