2015-02-17T19:19:03.833Z,1424200743.833 [Supervisor](DEBUG): Initializing supervisor.
2015-02-17T19:19:03.835Z,1424200743.835 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-02-17T19:19:03.836Z,1424200743.836 [SyncHandler](INFO): Protected caller Thread ID is 1652
2015-02-17T19:19:03.836Z,1424200743.836 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-02-17T19:19:03.837Z,1424200743.837 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-02-17T19:19:03.838Z,1424200743.838 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1653
2015-02-17T19:19:03.840Z,1424200743.840 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-02-17T19:19:03.859Z,1424200743.859 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-02-17T19:19:03.860Z,1424200743.860 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-02-17T19:19:03.861Z,1424200743.861 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1654
2015-02-17T19:19:03.861Z,1424200743.861 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-02-17T19:19:03.862Z,1424200743.862 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-02-17T19:19:03.863Z,1424200743.863 [logger ThreadHandler](INFO): Protected caller Thread ID is 1655
2015-02-17T19:19:03.865Z,1424200743.865 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-02-17T19:19:03.865Z,1424200743.865 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-02-17T19:19:03.867Z,1424200743.867 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-02-17T19:19:14.028Z,1424200754.028 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-02-17T19:19:14.029Z,1424200754.029 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-02-17T19:19:14.200Z,1424200754.200 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-02-17T19:19:14.201Z,1424200754.201 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-02-17T19:19:14.311Z,1424200754.311 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-02-17T19:19:14.312Z,1424200754.312 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-02-17T19:19:14.435Z,1424200754.435 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-02-17T19:19:14.436Z,1424200754.436 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-02-17T19:19:14.550Z,1424200754.550 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-02-17T19:19:14.766Z,1424200754.766 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-02-17T19:19:14.766Z,1424200754.766 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-02-17T19:19:14.867Z,1424200754.867 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-02-17T19:19:14.868Z,1424200754.868 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-02-17T19:19:15.754Z,1424200755.754 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-02-17T19:19:15.755Z,1424200755.755 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-02-17T19:19:16.138Z,1424200756.138 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-02-17T19:19:16.139Z,1424200756.139 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-02-17T19:19:16.495Z,1424200756.495 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-02-17T19:19:16.496Z,1424200756.496 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-02-17T19:19:17.068Z,1424200757.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-02-17T19:19:17.069Z,1424200757.069 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-02-17T19:19:17.333Z,1424200757.333 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-02-17T19:19:17.334Z,1424200757.334 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-02-17T19:19:17.447Z,1424200757.447 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-02-17T19:19:17.447Z,1424200757.447 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-02-17T19:19:17.880Z,1424200757.880 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-02-17T19:19:17.881Z,1424200757.881 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-02-17T19:19:18.016Z,1424200758.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-02-17T19:19:18.018Z,1424200758.018 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-02-17T19:19:18.019Z,1424200758.019 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-02-17T19:19:18.357Z,1424200758.357 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-02-17T19:19:18.358Z,1424200758.358 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-02-17T19:19:18.502Z,1424200758.502 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-02-17T19:19:18.610Z,1424200758.610 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-02-17T19:19:18.719Z,1424200758.719 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-02-17T19:19:18.828Z,1424200758.828 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-02-17T19:19:18.971Z,1424200758.971 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-02-17T19:19:19.152Z,1424200759.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-02-17T19:19:19.261Z,1424200759.261 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-02-17T19:19:19.352Z,1424200759.352 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-02-17T19:19:19.453Z,1424200759.453 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-02-17T19:19:19.551Z,1424200759.551 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-02-17T19:19:19.751Z,1424200759.751 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2015-02-17T19:19:19.752Z,1424200759.752 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2015-02-17T19:19:19.766Z,1424200759.766 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-02-17T19:19:19.819Z,1424200759.819 [VerticalControl](DEBUG): Construct VerticalControl.
2015-02-17T19:19:19.944Z,1424200759.944 [VerticalControl] Loaded
2015-02-17T19:19:19.945Z,1424200759.945 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-02-17T19:19:19.945Z,1424200759.945 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-02-17T19:19:20.055Z,1424200760.055 [HorizontalControl] Loaded
2015-02-17T19:19:20.055Z,1424200760.055 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-02-17T19:19:20.056Z,1424200760.056 [SpeedControl](DEBUG): Construct SpeedControl.
2015-02-17T19:19:20.062Z,1424200760.062 [SpeedControl] Loaded
2015-02-17T19:19:20.062Z,1424200760.062 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-02-17T19:19:20.063Z,1424200760.063 [LoopControl](DEBUG): Construct LoopControl.
2015-02-17T19:19:20.063Z,1424200760.063 [LoopControl] Loaded
2015-02-17T19:19:20.064Z,1424200760.064 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-02-17T19:19:20.064Z,1424200760.064 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-02-17T19:19:20.065Z,1424200760.065 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-02-17T19:19:20.171Z,1424200760.171 [SBIT](DEBUG): Construct Startup Built In Test.
2015-02-17T19:19:20.192Z,1424200760.192 [SBIT] Loaded
2015-02-17T19:19:20.192Z,1424200760.192 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-02-17T19:19:20.193Z,1424200760.193 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-02-17T19:19:20.224Z,1424200760.224 [IBIT] Loaded
2015-02-17T19:19:20.225Z,1424200760.225 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-02-17T19:19:20.227Z,1424200760.227 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-02-17T19:19:20.376Z,1424200760.376 [CBIT] Loaded
2015-02-17T19:19:20.377Z,1424200760.377 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-02-17T19:19:20.377Z,1424200760.377 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-02-17T19:19:20.378Z,1424200760.378 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-02-17T19:19:20.397Z,1424200760.397 [DepthRateCalculator] Loaded
2015-02-17T19:19:20.397Z,1424200760.397 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-02-17T19:19:20.403Z,1424200760.403 [PitchRateCalculator] Loaded
2015-02-17T19:19:20.403Z,1424200760.403 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-02-17T19:19:20.417Z,1424200760.417 [SpeedCalculator] Loaded
2015-02-17T19:19:20.417Z,1424200760.417 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-02-17T19:19:20.434Z,1424200760.434 [TempGradientCalculator] Loaded
2015-02-17T19:19:20.434Z,1424200760.434 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-02-17T19:19:20.440Z,1424200760.440 [YawRateCalculator] Loaded
2015-02-17T19:19:20.440Z,1424200760.440 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-02-17T19:19:20.440Z,1424200760.440 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-02-17T19:19:20.441Z,1424200760.441 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-02-17T19:19:21.510Z,1424200761.510 [HFRCMReconstructedInterpolator] Loaded
2015-02-17T19:19:21.510Z,1424200761.510 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2015-02-17T19:19:21.510Z,1424200761.510 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-02-17T19:19:21.511Z,1424200761.511 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-02-17T19:19:21.818Z,1424200761.818 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-02-17T19:19:21.818Z,1424200761.818 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-02-17T19:19:21.907Z,1424200761.907 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-02-17T19:19:21.908Z,1424200761.908 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-02-17T19:19:21.925Z,1424200761.925 [NavChart] Loaded
2015-02-17T19:19:21.926Z,1424200761.926 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-02-17T19:19:21.930Z,1424200761.930 [UniversalFixResidualReporter] Loaded
2015-02-17T19:19:21.931Z,1424200761.931 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-02-17T19:19:21.931Z,1424200761.931 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-02-17T19:19:21.932Z,1424200761.932 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-02-17T19:19:21.937Z,1424200761.937 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-02-17T19:19:21.938Z,1424200761.938 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-02-17T19:19:22.035Z,1424200762.035 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-02-17T19:19:22.036Z,1424200762.036 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-02-17T19:19:22.422Z,1424200762.422 [DataOverHttps] Loaded
2015-02-17T19:19:22.423Z,1424200762.423 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-02-17T19:19:22.511Z,1424200762.511 [Depth_Keller] Loaded
2015-02-17T19:19:22.511Z,1424200762.511 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-02-17T19:19:22.630Z,1424200762.630 [NAL9602] Loaded
2015-02-17T19:19:22.630Z,1424200762.630 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-02-17T19:19:22.702Z,1424200762.702 [Onboard] Loaded
2015-02-17T19:19:22.702Z,1424200762.702 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-02-17T19:19:22.710Z,1424200762.710 [Radio_Surface] Loaded
2015-02-17T19:19:22.711Z,1424200762.711 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-02-17T19:19:22.712Z,1424200762.712 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408074E0
2015-02-17T19:19:22.712Z,1424200762.712 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1738
2015-02-17T19:19:24.805Z,1424200764.805 [BPC1] Loaded
2015-02-17T19:19:24.805Z,1424200764.805 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-02-17T19:19:24.805Z,1424200764.805 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-02-17T19:19:24.806Z,1424200764.806 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-02-17T19:19:24.911Z,1424200764.911 [BuoyancyServo] Loaded
2015-02-17T19:19:24.911Z,1424200764.911 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-02-17T19:19:24.924Z,1424200764.924 [ElevatorServo] Loaded
2015-02-17T19:19:24.924Z,1424200764.924 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-02-17T19:19:24.936Z,1424200764.936 [MassServo] Loaded
2015-02-17T19:19:24.936Z,1424200764.936 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2015-02-17T19:19:24.948Z,1424200764.948 [RudderServo] Loaded
2015-02-17T19:19:24.949Z,1424200764.949 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-02-17T19:19:24.972Z,1424200764.972 [ThrusterServo] Loaded
2015-02-17T19:19:24.973Z,1424200764.973 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-02-17T19:19:24.973Z,1424200764.973 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-02-17T19:19:24.974Z,1424200764.974 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-02-17T19:19:25.227Z,1424200765.227 [ExternalSim] Loaded
2015-02-17T19:19:25.227Z,1424200765.227 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread.
2015-02-17T19:19:25.228Z,1424200765.228 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-02-17T19:19:25.229Z,1424200765.229 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-02-17T19:19:25.264Z,1424200765.264 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-02-17T19:19:25.266Z,1424200765.266 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-02-17T19:19:25.267Z,1424200765.267 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-02-17T19:19:25.273Z,1424200765.273 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-02-17T19:19:25.274Z,1424200765.274 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408B84E0
2015-02-17T19:19:25.275Z,1424200765.275 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1739
2015-02-17T19:19:25.280Z,1424200765.280 [Supervisor](INFO): Main Thread ID is 1651
2015-02-17T19:19:25.280Z,1424200765.280 [Supervisor](DEBUG): Running supervisor.
2015-02-17T19:19:25.280Z,1424200765.280 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1740
2015-02-17T19:19:25.285Z,1424200765.285 [controlThread ThreadHandler](INFO): Handler Thread ID is 1741
2015-02-17T19:19:25.285Z,1424200765.285 [controlThread](DEBUG): Initializing ControlThread
2015-02-17T19:19:25.286Z,1424200765.286 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-02-17T19:19:25.288Z,1424200765.288 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-02-17T19:19:25.288Z,1424200765.288 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-02-17T19:19:25.289Z,1424200765.289 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-02-17T19:19:25.289Z,1424200765.289 [SBIT](INFO): Initialize SBIT Component.
2015-02-17T19:19:25.290Z,1424200765.290 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12012
2015-02-17T19:19:25.290Z,1424200765.290 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-02-17T19:19:25.290Z,1424200765.290 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-02-17T19:19:25.291Z,1424200765.291 [IBIT](INFO): Initialize IBIT Component.
2015-02-17T19:19:25.292Z,1424200765.292 [CBIT](DEBUG): Initialize CBIT Component.
2015-02-17T19:19:25.292Z,1424200765.292 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-02-17T19:19:25.293Z,1424200765.293 [logger ThreadHandler](INFO): Handler Thread ID is 1742
2015-02-17T19:19:25.312Z,1424200765.312 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1743
2015-02-17T19:19:25.318Z,1424200765.318 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-02-17T19:19:25.318Z,1424200765.318 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-02-17T19:19:25.319Z,1424200765.319 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-02-17T19:19:25.319Z,1424200765.319 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-02-17T19:19:25.320Z,1424200765.320 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-02-17T19:19:25.321Z,1424200765.321 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2015-02-17T19:19:25.322Z,1424200765.322 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-02-17T19:19:25.323Z,1424200765.323 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-02-17T19:19:25.323Z,1424200765.323 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-02-17T19:19:25.330Z,1424200765.330 [ExternalSim](INFO): ExternalSim initializing...
2015-02-17T19:19:25.336Z,1424200765.336 [Radio_Surface](INFO): Powering up
2015-02-17T19:19:25.357Z,1424200765.357 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1744
2015-02-17T19:19:25.360Z,1424200765.360 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-02-17T19:19:25.361Z,1424200765.361 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-02-17T19:19:25.361Z,1424200765.361 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-02-17T19:19:25.361Z,1424200765.361 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-02-17T19:19:25.362Z,1424200765.362 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-02-17T19:19:25.362Z,1424200765.362 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-02-17T19:19:25.362Z,1424200765.362 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-02-17T19:19:25.362Z,1424200765.362 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-02-17T19:19:25.363Z,1424200765.363 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-02-17T19:19:28.003Z,1424200768.003 [ExternalSim](DEBUG): beaconLat = 36.80340
2015-02-17T19:19:28.003Z,1424200768.003 [ExternalSim](DEBUG): beaconLon = -121.82230
2015-02-17T19:19:28.003Z,1424200768.003 [ExternalSim](DEBUG): beaconDepth = 25.00
2015-02-17T19:19:29.808Z,1424200769.808 [ExternalSim](DEBUG): Simulator initialized
2015-02-17T19:19:29.814Z,1424200769.814 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-02-17T19:19:29.845Z,1424200769.845 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-02-17T19:19:29.911Z,1424200769.911 [MissionManager](DEBUG):
2015-02-17T19:19:29.912Z,1424200769.912 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-02-17T19:19:30.117Z,1424200770.117 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-02-17T19:19:30.121Z,1424200770.121 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-02-17T19:19:30.154Z,1424200770.154 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-02-17T19:19:30.188Z,1424200770.188 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-02-17T19:19:30.194Z,1424200770.194 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-02-17T19:19:30.219Z,1424200770.219 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-02-17T19:19:30.241Z,1424200770.241 [MissionManager](DEBUG):
0
0
5.0
1.0
400
Burn 300
Dropped drop weight due to communications timeout
5.0
Default mission has been running for
5
2015-02-17T19:19:30.264Z,1424200770.264 [controlThread](DEBUG): Component order: CycleStarter,ExternalSim,DataOverHttps,Depth_Keller,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRCMReconstructedInterpolator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-02-17T19:19:31.922Z,1424200771.922 [NAL9602](INFO): Powering up NAL9602
2015-02-17T19:19:32.275Z,1424200772.275 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:19:32.287Z,1424200772.287 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:19:32.459Z,1424200772.459 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-02-17T19:19:32.471Z,1424200772.471 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-02-17T19:19:32.493Z,1424200772.493 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-02-17T19:19:32.512Z,1424200772.512 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-02-17T19:19:32.535Z,1424200772.535 [MassServo](DEBUG): Initializing EZServoServo.
2015-02-17T19:19:32.547Z,1424200772.547 [MassServo](DEBUG): Initializing MassServo.
2015-02-17T19:19:32.612Z,1424200772.612 [RudderServo](DEBUG): Initializing EZServoServo.
2015-02-17T19:19:32.635Z,1424200772.635 [RudderServo](DEBUG): Initializing RudderServo.
2015-02-17T19:19:32.653Z,1424200772.653 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-02-17T19:19:32.659Z,1424200772.659 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-02-17T19:19:35.727Z,1424200775.727 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:19:35.728Z,1424200775.728 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:19:46.831Z,1424200786.831 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:19:46.832Z,1424200786.832 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:19:48.394Z,1424200788.394 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:19:48.395Z,1424200788.395 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:19:48.564Z,1424200788.564 [SBIT](IMPORTANT): Beginning Startup BIT
2015-02-17T19:19:48.567Z,1424200788.567 [CBIT](IMPORTANT): Beginning GF scan
2015-02-17T19:19:50.246Z,1424200790.246 [NAL9602](INFO): NAL9602 initialized
2015-02-17T19:19:50.260Z,1424200790.260 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:19:50.261Z,1424200790.261 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:19:52.285Z,1424200792.285 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003806
2015-02-17T19:19:52.336Z,1424200792.336 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:19:52.337Z,1424200792.337 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:19:53.766Z,1424200793.766 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:19:55.410Z,1424200795.410 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:19:57.412Z,1424200797.412 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:19:59.516Z,1424200799.516 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:01.535Z,1424200801.535 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:01.663Z,1424200801.663 [SBIT](FAULT): Mass: EXPECTED:0.006000 ACTUAL:0.005522
2015-02-17T19:20:02.390Z,1424200802.390 [CommandLine](IMPORTANT): got command get platform_orientation degree
2015-02-17T19:20:02.391Z,1424200802.391 [CommandLine](FAULT): Element has no value
2015-02-17T19:20:03.988Z,1424200803.988 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:05.368Z,1424200805.368 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:07.492Z,1424200807.492 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:10.138Z,1424200810.138 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:11.844Z,1424200811.844 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T19:20:11.919Z,1424200811.919 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:14.171Z,1424200814.171 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:15.793Z,1424200815.793 [CommandLine](IMPORTANT): got command show best platform_orientation
2015-02-17T19:20:15.793Z,1424200815.793 [CommandLine](IMPORTANT): platform_orientation best is null
2015-02-17T19:20:16.231Z,1424200816.231 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T19:20:16.294Z,1424200816.294 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:18.509Z,1424200818.509 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:20.261Z,1424200820.261 [NAL9602](INFO): Flushing. SigQuality: 2
2015-02-17T19:20:20.336Z,1424200820.336 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:20.422Z,1424200820.422 [CBIT](IMPORTANT): No ground fault detected
2015-02-17T19:20:23.016Z,1424200823.016 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:25.027Z,1424200825.027 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:26.334Z,1424200826.334 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:26.335Z,1424200826.335 [DeadReckonUsingMultipleVelocitySources](FAULT): The allowance for input measurements to start up has expired, but I still cannot determine the rotation from vehicle frame to navigation frame.
2015-02-17T19:20:26.335Z,1424200826.335 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2015-02-17T19:20:26.335Z,1424200826.335 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-02-17T19:20:26.336Z,1424200826.336 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-02-17T19:20:26.449Z,1424200826.449 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-02-17T19:20:27.163Z,1424200827.163 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:27.244Z,1424200827.244 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-02-17T19:20:27.244Z,1424200827.244 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2015-02-17T19:20:29.078Z,1424200829.078 [NAL9602](INFO): SBD MO Status=0, MOMSN=7168, MT Status=0, MTMSN=0
2015-02-17T19:20:29.078Z,1424200829.078 [NAL9602](INFO): No messages in MT queue
2015-02-17T19:20:29.093Z,1424200829.093 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:29.093Z,1424200829.093 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-02-17T19:20:31.197Z,1424200831.197 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:31.198Z,1424200831.198 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:20:33.197Z,1424200833.197 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:33.198Z,1424200833.198 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:20:35.420Z,1424200835.420 [NAL9602](IMPORTANT): GPS fix at: 1424200835.40
2015-02-17T19:20:35.431Z,1424200835.431 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:35.433Z,1424200835.433 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:20:37.644Z,1424200837.644 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:37.645Z,1424200837.645 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:20:44.284Z,1424200844.284 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:44.285Z,1424200844.285 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:20:46.997Z,1424200846.997 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:46.999Z,1424200846.999 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:20:47.610Z,1424200847.610 [SBIT](FAULT): Mass: EXPECTED:0.000000 ACTUAL:-0.002576
2015-02-17T19:20:47.610Z,1424200847.610 [SBIT](FAULT): Rudder: EXPECTED:0.000000 ACTUAL:-14.973630
2015-02-17T19:20:47.610Z,1424200847.610 [SBIT](FAULT): Control surface position failure.
2015-02-17T19:20:49.306Z,1424200849.306 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:49.384Z,1424200849.384 [SBIT](CRITICAL): SBIT FAILED
2015-02-17T19:20:49.385Z,1424200849.385 [CommandLine](FAULT): Scheduling is paused
2015-02-17T19:20:51.720Z,1424200851.720 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:51.723Z,1424200851.723 [MissionManager](IMPORTANT): Started mission Startup
2015-02-17T19:20:51.723Z,1424200851.723 [Startup] Running Loop=1
2015-02-17T19:20:51.723Z,1424200851.723 [Startup](INFO): Aggregate::initialize Startup
2015-02-17T19:20:51.723Z,1424200851.723 [Startup:A.GoToSurface] Running Loop=1
2015-02-17T19:20:51.723Z,1424200851.723 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-02-17T19:20:51.724Z,1424200851.724 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-02-17T19:20:51.724Z,1424200851.724 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-02-17T19:20:51.724Z,1424200851.724 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-02-17T19:20:51.747Z,1424200851.747 [Startup:StartupSatComms] Running Loop=1
2015-02-17T19:20:51.747Z,1424200851.747 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-02-17T19:20:51.748Z,1424200851.748 [Startup:StartupSatComms:A] Running Loop=1
2015-02-17T19:20:53.854Z,1424200853.854 [NAL9602](INFO): Powering down
2015-02-17T19:20:53.957Z,1424200853.957 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:53.960Z,1424200853.960 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-02-17T19:20:55.637Z,1424200855.637 [NAL9602](INFO): Powering up
2015-02-17T19:20:55.723Z,1424200855.723 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:57.788Z,1424200857.788 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:20:59.620Z,1424200859.620 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:01.120Z,1424200861.120 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:02.531Z,1424200862.531 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:03.909Z,1424200863.909 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:04.157Z,1424200864.157 [CommandLine](IMPORTANT): got command get platform_orientation degree
2015-02-17T19:21:04.157Z,1424200864.157 [CommandLine](FAULT): Element has no value
2015-02-17T19:21:04.946Z,1424200864.946 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:05.959Z,1424200865.959 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:07.210Z,1424200867.210 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:08.313Z,1424200868.313 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:09.076Z,1424200869.076 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:09.994Z,1424200869.994 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:11.383Z,1424200871.383 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:12.920Z,1424200872.920 [NAL9602](INFO): NAL9602 initialized
2015-02-17T19:21:12.929Z,1424200872.929 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:14.933Z,1424200874.933 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:16.351Z,1424200876.351 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:17.525Z,1424200877.525 [NAL9602](IMPORTANT): GPS fix at: 1424200877.52
2015-02-17T19:21:17.582Z,1424200877.582 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:17.599Z,1424200877.599 [Startup:StartupSatComms:A] Stopped
2015-02-17T19:21:17.599Z,1424200877.599 [Startup:StartupSatComms:B] Running Loop=1
2015-02-17T19:21:18.859Z,1424200878.859 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:18.873Z,1424200878.873 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: allowance for input measurements to start up has not expired, but velocity or orientation is invalid, and horizontal path length since last fix is nonzero.
2015-02-17T19:21:18.881Z,1424200878.881 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-02-17T19:21:20.546Z,1424200880.546 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:20.551Z,1424200880.551 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: allowance for input measurements to start up has not expired, but velocity or orientation is invalid, and horizontal path length since last fix is nonzero.
2015-02-17T19:21:22.429Z,1424200882.429 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:22.430Z,1424200882.430 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: allowance for input measurements to start up has not expired, but velocity or orientation is invalid, and horizontal path length since last fix is nonzero.
2015-02-17T19:21:28.638Z,1424200888.638 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:28.639Z,1424200888.639 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: allowance for input measurements to start up has not expired, but velocity or orientation is invalid, and horizontal path length since last fix is nonzero.
2015-02-17T19:21:31.704Z,1424200891.704 [NAL9602](INFO): Flushing. SigQuality: 3
2015-02-17T19:21:31.779Z,1424200891.779 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:31.780Z,1424200891.780 [DeadReckonUsingMultipleVelocitySources](FAULT): The allowance for input measurements to start up has expired, but I still cannot determine the rotation from vehicle frame to navigation frame.
2015-02-17T19:21:31.780Z,1424200891.780 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2015-02-17T19:21:31.780Z,1424200891.780 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-02-17T19:21:31.781Z,1424200891.781 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: allowance for input measurements to start up has expired, velocity or orientation is invalid, and horizontal path length since last fix is nonzero.
2015-02-17T19:21:31.840Z,1424200891.840 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-02-17T19:21:34.107Z,1424200894.107 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20150217T185205/Courier0008.lzma
2015-02-17T19:21:34.244Z,1424200894.244 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:34.282Z,1424200894.282 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-02-17T19:21:34.282Z,1424200894.282 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2015-02-17T19:21:36.790Z,1424200896.790 [NAL9602](INFO): SBD MO Status=1, MOMSN=7170, MT Status=0, MTMSN=0
2015-02-17T19:21:36.790Z,1424200896.790 [NAL9602](INFO): No messages in MT queue
2015-02-17T19:21:36.861Z,1424200896.861 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:36.861Z,1424200896.861 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-02-17T19:21:38.604Z,1424200898.604 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:38.604Z,1424200898.604 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:21:40.683Z,1424200900.683 [DataOverHttps](INFO): Moved sent file to Logs/20150217T185205/Courier0008.lzma.bak
2015-02-17T19:21:40.683Z,1424200900.683 [DataOverHttps](INFO): SBD MOMSN=3043678
2015-02-17T19:21:40.709Z,1424200900.709 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:40.710Z,1424200900.710 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:21:42.585Z,1424200902.585 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:42.586Z,1424200902.586 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:21:44.265Z,1424200904.265 [NAL9602](INFO): Powering down
2015-02-17T19:21:44.320Z,1424200904.320 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:44.321Z,1424200904.321 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:21:46.108Z,1424200906.108 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:46.109Z,1424200906.109 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:21:50.627Z,1424200910.627 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:50.628Z,1424200910.628 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:21:52.111Z,1424200912.111 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:53.976Z,1424200913.976 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:54.749Z,1424200914.749 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:55.360Z,1424200915.360 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:21:56.457Z,1424200916.457 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:00.707Z,1424200920.707 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:01.629Z,1424200921.629 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:02.293Z,1424200922.293 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20150217T191903/Courier0000.lzma
2015-02-17T19:22:02.364Z,1424200922.364 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:02.944Z,1424200922.944 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:13.285Z,1424200933.285 [DataOverHttps](INFO): Moved sent file to Logs/20150217T191903/Courier0000.lzma.bak
2015-02-17T19:22:13.285Z,1424200933.285 [DataOverHttps](INFO): SBD MOMSN=3043680
2015-02-17T19:22:13.330Z,1424200933.330 [BPC1](ERROR): Failed to receive battery data
2015-02-17T19:22:13.330Z,1424200933.330 [BPC1] Communications Fault, FailCount= 1
2015-02-17T19:22:13.330Z,1424200933.330 [BPC1](ERROR): Communications Fault
2015-02-17T19:22:13.335Z,1424200933.335 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:13.347Z,1424200933.347 [CBIT](ERROR): Communications Fault in component: BPC1
2015-02-17T19:22:15.027Z,1424200935.027 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:15.912Z,1424200935.912 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:17.485Z,1424200937.485 [CommandLine](IMPORTANT): got command get platform_orientation degree
2015-02-17T19:22:17.485Z,1424200937.485 [CommandLine](FAULT): Element has no value
2015-02-17T19:22:20.278Z,1424200940.278 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:20.281Z,1424200940.281 [Startup:StartupSatComms:B](INFO): Timed out from 2015-02-17T19:21:17.6Z
2015-02-17T19:22:20.281Z,1424200940.281 [Startup:StartupSatComms:B] Stopped
2015-02-17T19:22:20.281Z,1424200940.281 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-02-17T19:22:20.281Z,1424200940.281 [Startup:StartupSatComms] Stopped
2015-02-17T19:22:20.281Z,1424200940.281 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-02-17T19:22:20.282Z,1424200940.282 [Startup](INFO): Completed Startup
2015-02-17T19:22:20.282Z,1424200940.282 [Startup] Stopped
2015-02-17T19:22:20.282Z,1424200940.282 [Startup](INFO): Aggregate::uninitialize Startup
2015-02-17T19:22:20.282Z,1424200940.282 [Startup:A.GoToSurface] Stopped
2015-02-17T19:22:20.282Z,1424200940.282 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-02-17T19:22:20.293Z,1424200940.293 [CBIT](INFO): Clearing failed state for component BPC1
2015-02-17T19:22:20.293Z,1424200940.293 [BPC1] No Fault, FailCount= 1
2015-02-17T19:22:20.911Z,1424200940.911 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:20.913Z,1424200940.913 [MissionManager](IMPORTANT): Started mission Default
2015-02-17T19:22:20.913Z,1424200940.913 [Default] Running Loop=1
2015-02-17T19:22:20.913Z,1424200940.913 [Default](INFO): Aggregate::initialize Default
2015-02-17T19:22:20.914Z,1424200940.914 [Default:B.GoToSurface] Running Loop=1
2015-02-17T19:22:20.914Z,1424200940.914 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-02-17T19:22:20.914Z,1424200940.914 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-02-17T19:22:20.914Z,1424200940.914 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-02-17T19:22:20.915Z,1424200940.915 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-02-17T19:22:20.915Z,1424200940.915 [Default:StartClock] Running Loop=1
2015-02-17T19:22:20.915Z,1424200940.915 [Default:StartClock](INFO): Aggregate::initialize Default:StartClock
2015-02-17T19:22:20.915Z,1424200940.915 [Default:StartClock:A] Running Loop=1
2015-02-17T19:22:20.915Z,1424200940.915 [Default:CheckIn] Running Loop=1
2015-02-17T19:22:20.916Z,1424200940.916 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-02-17T19:22:20.916Z,1424200940.916 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-02-17T19:22:20.916Z,1424200940.916 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-02-17T19:22:20.916Z,1424200940.916 [Default:CheckIn:Read_GPS] Running Loop=1
2015-02-17T19:22:20.917Z,1424200940.917 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-02-17T19:22:20.919Z,1424200940.919 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-02-17T19:22:20.931Z,1424200940.931 [Default:StartClock:A] Stopped
2015-02-17T19:22:20.931Z,1424200940.931 [Default:StartClock](INFO): Completed Default:StartClock
2015-02-17T19:22:20.932Z,1424200940.932 [Default:StartClock] Stopped
2015-02-17T19:22:20.932Z,1424200940.932 [Default:StartClock](INFO): Aggregate::uninitialize Default:StartClock
2015-02-17T19:22:22.003Z,1424200942.003 [NAL9602](INFO): Powering up
2015-02-17T19:22:22.072Z,1424200942.072 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:22.076Z,1424200942.076 [Default:WaitAtTheSurface] Running Loop=1
2015-02-17T19:22:22.077Z,1424200942.077 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2015-02-17T19:22:22.077Z,1424200942.077 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-02-17T19:22:22.077Z,1424200942.077 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2015-02-17T19:22:24.334Z,1424200944.334 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:24.337Z,1424200944.337 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-02-17T19:22:25.841Z,1424200945.841 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:26.628Z,1424200946.628 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:27.766Z,1424200947.766 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:33.056Z,1424200953.056 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:33.955Z,1424200953.955 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:34.711Z,1424200954.711 [DataOverHttps](INFO): Sending 541 bytes from file Logs/20150217T185205/Express0009.lzma
2015-02-17T19:22:34.717Z,1424200954.717 [NAL9602](INFO): NAL9602 initialized
2015-02-17T19:22:34.786Z,1424200954.786 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:35.548Z,1424200955.548 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:36.165Z,1424200956.165 [DataOverHttps](INFO): Moved sent file to Logs/20150217T185205/Express0009.lzma.bak
2015-02-17T19:22:36.166Z,1424200956.166 [DataOverHttps](IMPORTANT): SBD MOMSN=3043686, MTMSN=20150217T192153
2015-02-17T19:22:36.268Z,1424200956.268 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:37.200Z,1424200957.200 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:37.201Z,1424200957.201 [DeadReckonUsingMultipleVelocitySources](FAULT): The allowance for input measurements to start up has expired, but I still cannot determine the rotation from vehicle frame to navigation frame.
2015-02-17T19:22:37.201Z,1424200957.201 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2015-02-17T19:22:37.201Z,1424200957.201 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-02-17T19:22:37.202Z,1424200957.202 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-02-17T19:22:37.214Z,1424200957.214 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-02-17T19:22:38.121Z,1424200958.121 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:38.133Z,1424200958.133 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-02-17T19:22:38.133Z,1424200958.133 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2015-02-17T19:22:39.826Z,1424200959.826 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:39.827Z,1424200959.827 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-02-17T19:22:45.541Z,1424200965.541 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:45.542Z,1424200965.542 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:22:47.168Z,1424200967.168 [DataOverHttps](INFO): Received command:restart app
2015-02-17T19:22:47.189Z,1424200967.189 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:47.199Z,1424200967.199 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:22:47.218Z,1424200967.218 [CommandLine](IMPORTANT): got command restart application
2015-02-17T19:22:48.226Z,1424200968.226 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T19:22:48.226Z,1424200968.226 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:48.243Z,1424200968.243 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2015-02-17T19:22:48.243Z,1424200968.243 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:48.244Z,1424200968.244 [CommandLine](INFO): Join timeout helper Thread ID is 1780
2015-02-17T19:22:48.251Z,1424200968.251 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-02-17T19:22:48.251Z,1424200968.251 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:48.252Z,1424200968.252 [NavChartDb](INFO): Join timeout helper Thread ID is 1781
2015-02-17T19:22:48.300Z,1424200968.300 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T19:22:48.300Z,1424200968.300 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:48.304Z,1424200968.304 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-02-17T19:22:48.304Z,1424200968.304 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:48.304Z,1424200968.304 [Radio_Surface](INFO): Join timeout helper Thread ID is 1782
2015-02-17T19:22:48.346Z,1424200968.346 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:48.351Z,1424200968.351 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:22:48.608Z,1424200968.608 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T19:22:48.608Z,1424200968.608 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:48.620Z,1424200968.620 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-02-17T19:22:48.620Z,1424200968.620 [logger ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:48.620Z,1424200968.620 [logger](INFO): Join timeout helper Thread ID is 1783
2015-02-17T19:22:48.660Z,1424200968.660 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T19:22:48.660Z,1424200968.660 [logger ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:48.680Z,1424200968.680 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-02-17T19:22:48.680Z,1424200968.680 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:48.680Z,1424200968.680 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-02-17T19:22:48.680Z,1424200968.680 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:48.681Z,1424200968.681 [controlThread](INFO): Join timeout helper Thread ID is 1784
2015-02-17T19:22:50.290Z,1424200970.290 [NAL9602](INFO): Flushing. SigQuality: 0
2015-02-17T19:22:50.301Z,1424200970.301 [HFRCMReconstructedInterpolator](DEBUG): no valid forecast
2015-02-17T19:22:50.302Z,1424200970.302 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-02-17T19:22:50.335Z,1424200970.335 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-02-17T19:22:50.335Z,1424200970.335 [controlThread](DEBUG): Uninitializing ControlThread
2015-02-17T19:22:50.336Z,1424200970.336 [NAL9602](INFO): Powering down
2015-02-17T19:22:50.338Z,1424200970.338 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-02-17T19:22:50.340Z,1424200970.340 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-02-17T19:22:50.341Z,1424200970.341 [Default] Stopped
2015-02-17T19:22:50.341Z,1424200970.341 [Default](INFO): Aggregate::uninitialize Default
2015-02-17T19:22:50.341Z,1424200970.341 [Default:B.GoToSurface] Stopped
2015-02-17T19:22:50.341Z,1424200970.341 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-02-17T19:22:50.341Z,1424200970.341 [Default:CheckIn] Stopped
2015-02-17T19:22:50.341Z,1424200970.341 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-02-17T19:22:50.341Z,1424200970.341 [Default:CheckIn:A.SetSpeed] Stopped
2015-02-17T19:22:50.341Z,1424200970.341 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-02-17T19:22:50.341Z,1424200970.341 [Default:CheckIn:Read_GPS] Stopped
2015-02-17T19:22:50.341Z,1424200970.341 [Default:WaitAtTheSurface] Stopped
2015-02-17T19:22:50.342Z,1424200970.342 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2015-02-17T19:22:50.342Z,1424200970.342 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped
2015-02-17T19:22:50.342Z,1424200970.342 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2015-02-17T19:22:50.349Z,1424200970.349 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-02-17T19:22:50.349Z,1424200970.349 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-02-17T19:22:50.350Z,1424200970.350 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-02-17T19:22:50.350Z,1424200970.350 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-02-17T19:22:50.350Z,1424200970.350 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-02-17T19:22:50.351Z,1424200970.351 [BuoyancyServo](INFO): Powering down
2015-02-17T19:22:50.363Z,1424200970.363 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-02-17T19:22:50.363Z,1424200970.363 [ElevatorServo](INFO): Powering down
2015-02-17T19:22:50.364Z,1424200970.364 [MassServo](DEBUG): Uninitialize Mass Servo.
2015-02-17T19:22:50.364Z,1424200970.364 [MassServo](INFO): Powering down
2015-02-17T19:22:50.365Z,1424200970.365 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-02-17T19:22:50.365Z,1424200970.365 [RudderServo](INFO): Powering down
2015-02-17T19:22:50.365Z,1424200970.365 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-02-17T19:22:50.366Z,1424200970.366 [ThrusterServo](INFO): Powering down
2015-02-17T19:22:50.367Z,1424200970.367 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-02-17T19:22:50.367Z,1424200970.367 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-02-17T19:22:50.367Z,1424200970.367 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-02-17T19:22:50.404Z,1424200970.404 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:50.526Z,1424200970.526 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:50.606Z,1424200970.606 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-02-17T19:22:50.685Z,1424200970.685 [logger ThreadHandler](INFO): Thread cancelled.