2015-01-29T01:15:33.527Z,1422494133.527 [Supervisor](DEBUG): Initializing supervisor.
2015-01-29T01:15:33.530Z,1422494133.530 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-01-29T01:15:33.531Z,1422494133.531 [SyncHandler](INFO): Protected caller Thread ID is 769
2015-01-29T01:15:33.531Z,1422494133.531 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-01-29T01:15:33.532Z,1422494133.532 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-01-29T01:15:33.533Z,1422494133.533 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 770
2015-01-29T01:15:33.536Z,1422494133.536 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-01-29T01:15:33.548Z,1422494133.548 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-01-29T01:15:33.550Z,1422494133.550 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-01-29T01:15:33.550Z,1422494133.550 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 771
2015-01-29T01:15:33.551Z,1422494133.551 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-01-29T01:15:33.552Z,1422494133.552 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-01-29T01:15:33.553Z,1422494133.553 [logger ThreadHandler](INFO): Protected caller Thread ID is 772
2015-01-29T01:15:33.555Z,1422494133.555 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-01-29T01:15:33.555Z,1422494133.555 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-01-29T01:15:33.559Z,1422494133.559 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-01-29T01:15:33.916Z,1422494133.916 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-01-29T01:15:33.918Z,1422494133.918 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-01-29T01:15:34.088Z,1422494134.088 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-01-29T01:15:34.088Z,1422494134.088 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-01-29T01:15:34.200Z,1422494134.200 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-01-29T01:15:34.201Z,1422494134.201 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-01-29T01:15:34.329Z,1422494134.329 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-01-29T01:15:34.329Z,1422494134.329 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-01-29T01:15:34.418Z,1422494134.418 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-01-29T01:15:34.587Z,1422494134.587 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-01-29T01:15:34.587Z,1422494134.587 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-01-29T01:15:34.676Z,1422494134.676 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-01-29T01:15:34.677Z,1422494134.677 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-01-29T01:15:34.894Z,1422494134.894 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-01-29T01:15:34.895Z,1422494134.895 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-01-29T01:15:35.289Z,1422494135.289 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-01-29T01:15:35.290Z,1422494135.290 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-01-29T01:15:35.629Z,1422494135.629 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-01-29T01:15:35.630Z,1422494135.630 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-01-29T01:15:36.152Z,1422494136.152 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-01-29T01:15:36.153Z,1422494136.153 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-01-29T01:15:36.369Z,1422494136.369 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-01-29T01:15:36.369Z,1422494136.369 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-01-29T01:15:36.478Z,1422494136.478 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-01-29T01:15:36.479Z,1422494136.479 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-01-29T01:15:36.927Z,1422494136.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-01-29T01:15:36.927Z,1422494136.927 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-01-29T01:15:37.043Z,1422494137.043 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-01-29T01:15:37.045Z,1422494137.045 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2015-01-29T01:15:37.049Z,1422494137.049 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2015-01-29T01:15:37.300Z,1422494137.300 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-01-29T01:15:50.515Z,1422494150.515 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2015-01-29T01:15:50.950Z,1422494150.950 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg
2015-01-29T01:15:51.852Z,1422494151.852 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2015-01-29T01:15:51.955Z,1422494151.955 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2015-01-29T01:15:52.076Z,1422494152.076 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2015-01-29T01:15:52.226Z,1422494152.226 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2015-01-29T01:15:52.408Z,1422494152.408 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2015-01-29T01:15:52.516Z,1422494152.516 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2015-01-29T01:15:52.609Z,1422494152.609 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2015-01-29T01:15:52.715Z,1422494152.715 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2015-01-29T01:15:52.815Z,1422494152.815 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2015-01-29T01:15:53.008Z,1422494153.008 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2015-01-29T01:15:53.015Z,1422494153.015 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-01-29T01:15:53.090Z,1422494153.090 [VerticalControl](DEBUG): Construct VerticalControl.
2015-01-29T01:15:53.212Z,1422494153.212 [VerticalControl] Loaded
2015-01-29T01:15:53.212Z,1422494153.212 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-01-29T01:15:53.213Z,1422494153.213 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-01-29T01:15:53.285Z,1422494153.285 [HorizontalControl] Loaded
2015-01-29T01:15:53.286Z,1422494153.286 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-01-29T01:15:53.286Z,1422494153.286 [SpeedControl](DEBUG): Construct SpeedControl.
2015-01-29T01:15:53.292Z,1422494153.292 [SpeedControl] Loaded
2015-01-29T01:15:53.293Z,1422494153.293 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-01-29T01:15:53.293Z,1422494153.293 [LoopControl](DEBUG): Construct LoopControl.
2015-01-29T01:15:53.294Z,1422494153.294 [LoopControl] Loaded
2015-01-29T01:15:53.294Z,1422494153.294 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-01-29T01:15:53.295Z,1422494153.295 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-01-29T01:15:53.296Z,1422494153.296 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-01-29T01:15:53.419Z,1422494153.419 [SBIT](DEBUG): Construct Startup Built In Test.
2015-01-29T01:15:53.431Z,1422494153.431 [SBIT] Loaded
2015-01-29T01:15:53.431Z,1422494153.431 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-01-29T01:15:53.432Z,1422494153.432 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-01-29T01:15:53.461Z,1422494153.461 [IBIT] Loaded
2015-01-29T01:15:53.462Z,1422494153.462 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-01-29T01:15:53.464Z,1422494153.464 [CBIT](DEBUG): Construct CBIT Built In Test.
2015-01-29T01:15:53.584Z,1422494153.584 [CBIT] Loaded
2015-01-29T01:15:53.584Z,1422494153.584 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-01-29T01:15:53.585Z,1422494153.585 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-01-29T01:15:53.586Z,1422494153.586 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-01-29T01:15:53.615Z,1422494153.615 [DepthRateCalculator] Loaded
2015-01-29T01:15:53.616Z,1422494153.616 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-01-29T01:15:53.621Z,1422494153.621 [PitchRateCalculator] Loaded
2015-01-29T01:15:53.622Z,1422494153.622 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-01-29T01:15:53.634Z,1422494153.634 [SpeedCalculator] Loaded
2015-01-29T01:15:53.634Z,1422494153.634 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-01-29T01:15:53.651Z,1422494153.651 [TempGradientCalculator] Loaded
2015-01-29T01:15:53.651Z,1422494153.651 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-01-29T01:15:53.657Z,1422494153.657 [YawRateCalculator] Loaded
2015-01-29T01:15:53.657Z,1422494153.657 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-01-29T01:15:53.657Z,1422494153.657 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-01-29T01:15:53.658Z,1422494153.658 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-01-29T01:15:53.750Z,1422494153.750 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-01-29T01:15:53.752Z,1422494153.752 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-01-29T01:15:54.026Z,1422494154.026 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-01-29T01:15:54.027Z,1422494154.027 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-01-29T01:15:54.136Z,1422494154.136 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-01-29T01:15:54.136Z,1422494154.136 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-01-29T01:15:54.153Z,1422494154.153 [NavChart] Loaded
2015-01-29T01:15:54.154Z,1422494154.154 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-01-29T01:15:54.158Z,1422494154.158 [UniversalFixResidualReporter] Loaded
2015-01-29T01:15:54.158Z,1422494154.158 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-01-29T01:15:54.159Z,1422494154.159 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-01-29T01:15:54.160Z,1422494154.160 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-01-29T01:15:54.169Z,1422494154.169 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-01-29T01:15:54.170Z,1422494154.170 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-01-29T01:15:54.286Z,1422494154.286 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-01-29T01:15:54.287Z,1422494154.287 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-01-29T01:15:54.925Z,1422494154.925 [DataOverHttps] Loaded
2015-01-29T01:15:54.925Z,1422494154.925 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-01-29T01:15:55.007Z,1422494155.007 [Depth_Keller] Loaded
2015-01-29T01:15:55.007Z,1422494155.007 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-01-29T01:15:55.101Z,1422494155.101 [NAL9602] Loaded
2015-01-29T01:15:55.102Z,1422494155.102 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-01-29T01:15:55.145Z,1422494155.145 [Onboard] Loaded
2015-01-29T01:15:55.145Z,1422494155.145 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-01-29T01:15:55.152Z,1422494155.152 [Radio_Surface] Loaded
2015-01-29T01:15:55.153Z,1422494155.153 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-01-29T01:15:55.154Z,1422494155.154 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2015-01-29T01:15:55.154Z,1422494155.154 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 854
2015-01-29T01:15:55.342Z,1422494155.342 [PNI_TCM] Loaded
2015-01-29T01:15:55.342Z,1422494155.342 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2015-01-29T01:15:57.192Z,1422494157.192 [BPC1] Loaded
2015-01-29T01:15:57.192Z,1422494157.192 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-01-29T01:15:57.192Z,1422494157.192 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-01-29T01:15:57.193Z,1422494157.193 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-01-29T01:16:05.907Z,1422494165.907 [BuoyancyServo] Loaded
2015-01-29T01:16:05.908Z,1422494165.908 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-01-29T01:16:05.920Z,1422494165.920 [ElevatorServo] Loaded
2015-01-29T01:16:05.921Z,1422494165.921 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-01-29T01:16:05.933Z,1422494165.933 [RudderServo] Loaded
2015-01-29T01:16:05.933Z,1422494165.933 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-01-29T01:16:05.945Z,1422494165.945 [ThrusterServo] Loaded
2015-01-29T01:16:05.945Z,1422494165.945 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-01-29T01:16:05.946Z,1422494165.946 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-01-29T01:16:05.946Z,1422494165.946 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-01-29T01:16:06.221Z,1422494166.221 [ExternalSim] Loaded
2015-01-29T01:16:06.221Z,1422494166.221 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread.
2015-01-29T01:16:06.222Z,1422494166.222 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-01-29T01:16:06.223Z,1422494166.223 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-01-29T01:16:06.264Z,1422494166.264 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-01-29T01:16:06.266Z,1422494166.266 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-01-29T01:16:06.267Z,1422494166.267 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-01-29T01:16:06.274Z,1422494166.274 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-01-29T01:16:06.275Z,1422494166.275 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083C4E0
2015-01-29T01:16:06.275Z,1422494166.275 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 855
2015-01-29T01:16:06.280Z,1422494166.280 [Supervisor](INFO): Main Thread ID is 767
2015-01-29T01:16:06.281Z,1422494166.281 [Supervisor](DEBUG): Running supervisor.
2015-01-29T01:16:06.281Z,1422494166.281 [CommandLine ThreadHandler](INFO): Handler Thread ID is 856
2015-01-29T01:16:06.284Z,1422494166.284 [controlThread ThreadHandler](INFO): Handler Thread ID is 857
2015-01-29T01:16:06.285Z,1422494166.285 [controlThread](DEBUG): Initializing ControlThread
2015-01-29T01:16:06.285Z,1422494166.285 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-01-29T01:16:06.287Z,1422494166.287 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-01-29T01:16:06.288Z,1422494166.288 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-01-29T01:16:06.288Z,1422494166.288 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-01-29T01:16:06.289Z,1422494166.289 [SBIT](INFO): Initialize SBIT Component.
2015-01-29T01:16:06.289Z,1422494166.289 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:11963
2015-01-29T01:16:06.289Z,1422494166.289 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-01-29T01:16:06.290Z,1422494166.290 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-01-29T01:16:06.290Z,1422494166.290 [IBIT](INFO): Initialize IBIT Component.
2015-01-29T01:16:06.291Z,1422494166.291 [CBIT](DEBUG): Initialize CBIT Component.
2015-01-29T01:16:06.291Z,1422494166.291 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2015-01-29T01:16:06.292Z,1422494166.292 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2015-01-29T01:16:06.293Z,1422494166.293 [logger ThreadHandler](INFO): Handler Thread ID is 858
2015-01-29T01:16:06.313Z,1422494166.313 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 859
2015-01-29T01:16:06.317Z,1422494166.317 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-29T01:16:06.318Z,1422494166.318 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-01-29T01:16:06.318Z,1422494166.318 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-01-29T01:16:06.318Z,1422494166.318 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-01-29T01:16:06.319Z,1422494166.319 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-01-29T01:16:06.319Z,1422494166.319 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-29T01:16:06.319Z,1422494166.319 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-01-29T01:16:06.320Z,1422494166.320 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-01-29T01:16:06.323Z,1422494166.323 [ExternalSim](INFO): ExternalSim initializing...
2015-01-29T01:16:06.337Z,1422494166.337 [Radio_Surface](INFO): Powering up
2015-01-29T01:16:06.357Z,1422494166.357 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 860
2015-01-29T01:16:06.371Z,1422494166.371 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-01-29T01:16:06.374Z,1422494166.374 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-01-29T01:16:06.374Z,1422494166.374 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-01-29T01:16:06.374Z,1422494166.374 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-01-29T01:16:06.375Z,1422494166.375 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-01-29T01:16:06.375Z,1422494166.375 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-01-29T01:16:06.375Z,1422494166.375 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-01-29T01:16:06.376Z,1422494166.376 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-01-29T01:16:06.376Z,1422494166.376 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-01-29T01:19:15.669Z,1422494355.669 [ExternalSim](ERROR): Error making socket connection to simulation server at tellum.shore.mbari.org: Could not connect due to error: Connection timed out
2015-01-29T01:19:15.702Z,1422494355.702 [ExternalSim](DEBUG): beaconLat = 36.80340
2015-01-29T01:19:15.702Z,1422494355.702 [ExternalSim](DEBUG): beaconLon = -121.82230
2015-01-29T01:19:15.702Z,1422494355.702 [ExternalSim](DEBUG): beaconDepth = 25.00
2015-01-29T01:19:15.746Z,1422494355.746 [ExternalSim](DEBUG): Simulator initialized
2015-01-29T01:19:15.794Z,1422494355.794 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-01-29T01:19:15.830Z,1422494355.830 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-29T01:19:15.839Z,1422494355.839 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2015-01-29T01:19:15.840Z,1422494355.840 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-01-29T01:19:15.896Z,1422494355.896 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-01-29T01:19:15.899Z,1422494355.899 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-01-29T01:19:15.903Z,1422494355.903 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-01-29T01:19:15.940Z,1422494355.940 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-01-29T01:19:15.957Z,1422494355.957 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-01-29T01:19:15.965Z,1422494355.965 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-01-29T01:19:15.971Z,1422494355.971 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="TimeMissionWasStarted"><Units:hour/><Value>0</Value></DefineArg>

    <DefineArg Name="ElapsedSinceMissionWasStarted"><Units:hour/><Value>0</Value></DefineArg>

    <Aggregate Id="StartClock">

        <Sequence/>

        <Assign><Arg Name="TimeMissionWasStarted"/><Universal:time/></Assign>

    </Aggregate>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
            <And><Universal:platform_conversation/><Eq><True/></Eq></And>
            <Or><Elapsed><Universal:platform_communications/></Elapsed><Gt><Units:hour/><Value>1.0</Value></Gt></Or>
        </When>

<!-- TODO: Do we really want this When operating on platform_communications? or on something else like time_fix? -->

<!-- Run application at high speed -->

        <Guidance:SetSpeed>
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:millisecond/><Value>400</Value></Setting>
        </Guidance:SetSpeed>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
<!-- NOTE: Original Default.xml didn't have a timeout on the GPS read, so theoretically could have hung indefinitely there... -->
            <Universal:latitude_fix/>
        </ReadDatum>

<!-- Do data comms -->

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn 300</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped drop weight due to communications timeout</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

    <Aggregate Id="UpdateAndReportMinutesSinceMissionStarted">

        <When>
            <Elapsed><Arg Name="ElapsedSinceMissionWasStarted"/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
        </When>

        <Assign><Arg Name="ElapsedSinceMissionWasStarted"/><Universal:time/><Sub><Arg Name="TimeMissionWasStarted"/></Sub></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceMissionWasStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

        <Guidance:SetSpeed Id="RunApplicationAtLowSpeed">
            <Parallel/>
            <Setting><Guidance:SetSpeed.period/><Units:second/><Value>5</Value></Setting>
        </Guidance:SetSpeed>

    </Aggregate>

</Mission>


2015-01-29T01:19:15.988Z,1422494355.988 [controlThread](DEBUG): Component order: CycleStarter,ExternalSim,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-01-29T01:19:16.106Z,1422494356.106 [NAL9602](INFO): Start
2015-01-29T01:19:16.107Z,1422494356.107 [NAL9602](INFO): Powering up NAL9602
2015-01-29T01:19:16.253Z,1422494356.253 [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-01-29T01:19:16.254Z,1422494356.254 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2015-01-29T01:19:16.254Z,1422494356.254 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-29T01:19:16.254Z,1422494356.254 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:19:16.261Z,1422494356.261 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-29T01:19:16.365Z,1422494356.365 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-29T01:19:16.373Z,1422494356.373 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-29T01:19:16.379Z,1422494356.379 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-01-29T01:19:16.380Z,1422494356.380 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-01-29T01:19:16.386Z,1422494356.386 [RudderServo](DEBUG): Initializing EZServoServo.
2015-01-29T01:19:16.387Z,1422494356.387 [RudderServo](DEBUG): Initializing RudderServo.
2015-01-29T01:19:16.409Z,1422494356.409 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-01-29T01:19:16.414Z,1422494356.414 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-01-29T01:19:16.431Z,1422494356.431 [CommandLine](FAULT): Scheduling is paused
2015-01-29T01:19:16.432Z,1422494356.432 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-29T01:19:16.526Z,1422494356.526 [SBIT](IMPORTANT): Beginning Startup BIT
2015-01-29T01:19:16.528Z,1422494356.528 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-29T01:19:16.528Z,1422494356.528 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2015-01-29T01:19:16.529Z,1422494356.529 [CBIT](IMPORTANT): Beginning GF scan
2015-01-29T01:19:16.917Z,1422494356.917 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-29T01:19:17.250Z,1422494357.250 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2015-01-29T01:19:17.250Z,1422494357.250 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2015-01-29T01:19:17.250Z,1422494357.250 [BuoyancyServo] Communications Fault, FailCount= 1
2015-01-29T01:19:17.250Z,1422494357.250 [BuoyancyServo](ERROR): Communications Fault
2015-01-29T01:19:17.461Z,1422494357.461 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2015-01-29T01:19:17.552Z,1422494357.552 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:19:17.627Z,1422494357.627 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-01-29T01:19:17.628Z,1422494357.628 [BuoyancyServo](INFO): Powering down
2015-01-29T01:19:17.905Z,1422494357.905 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:19:18.304Z,1422494358.304 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:19:18.702Z,1422494358.702 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:19:19.103Z,1422494359.103 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:19:19.504Z,1422494359.504 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:19:20.033Z,1422494360.033 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2015-01-29T01:19:20.033Z,1422494360.033 [BuoyancyServo] No Fault, FailCount= 1
2015-01-29T01:19:20.311Z,1422494360.311 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-01-29T01:19:20.432Z,1422494360.432 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-01-29T01:19:27.078Z,1422494367.078 [NAL9602](INFO): ************** CMDMODE **************

2015-01-29T01:19:27.078Z,1422494367.078 [NAL9602](INFO): NAL9602 initialized
2015-01-29T01:19:27.880Z,1422494367.880 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:19:27.920Z,1422494367.920 [PNI_TCM](FAULT): Failed to acquire valid data within timeout.
2015-01-29T01:19:27.920Z,1422494367.920 [PNI_TCM] Data Fault, FailCount= 1
2015-01-29T01:19:27.920Z,1422494367.920 [PNI_TCM](ERROR): Data Fault
2015-01-29T01:19:28.006Z,1422494368.006 [CBIT](ERROR): Data Fault in component: PNI_TCM
2015-01-29T01:19:28.006Z,1422494368.006 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2015-01-29T01:19:28.277Z,1422494368.277 [NAL9602](INFO): ************** GetFix **************

2015-01-29T01:19:29.575Z,1422494369.575 [SBIT](ERROR): Could not read massPosReader_.
2015-01-29T01:19:32.284Z,1422494372.284 [BPC1](FAULT): Failed to receive battery data
2015-01-29T01:19:32.284Z,1422494372.284 [BPC1] Communications Fault, FailCount= 1
2015-01-29T01:19:32.284Z,1422494372.284 [BPC1](ERROR): Communications Fault
2015-01-29T01:19:32.368Z,1422494372.368 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-29T01:19:33.566Z,1422494373.566 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-29T01:19:33.566Z,1422494373.566 [BPC1] No Fault, FailCount= 1
2015-01-29T01:19:42.774Z,1422494382.774 [CBIT](IMPORTANT): No ground fault detected
2015-01-29T01:19:55.972Z,1422494395.972 [SBIT](ERROR): Could not read massPosReader_.
2015-01-29T01:19:55.972Z,1422494395.972 [SBIT](FAULT): Control surface position failure.
2015-01-29T01:19:59.081Z,1422494399.081 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:19:59.473Z,1422494399.473 [NAL9602](INFO): MT Sig Qty requested
2015-01-29T01:20:09.513Z,1422494409.513 [SBIT](ERROR): Could not read massPosReader_.
2015-01-29T01:20:09.513Z,1422494409.513 [SBIT](FAULT): Control surface position failure.
2015-01-29T01:20:09.895Z,1422494409.895 [SBIT](CRITICAL): SBIT FAILED
2015-01-29T01:20:10.289Z,1422494410.289 [MissionManager](IMPORTANT): Started mission Startup
2015-01-29T01:20:10.289Z,1422494410.289 [Startup] Running Loop=1
2015-01-29T01:20:10.289Z,1422494410.289 [Startup](INFO): Aggregate::initialize Startup
2015-01-29T01:20:10.289Z,1422494410.289 [Startup:A.GoToSurface] Running Loop=1
2015-01-29T01:20:10.289Z,1422494410.289 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-29T01:20:10.290Z,1422494410.290 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-29T01:20:10.290Z,1422494410.290 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-29T01:20:10.290Z,1422494410.290 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-29T01:20:10.328Z,1422494410.328 [Startup:StartupSatComms] Running Loop=1
2015-01-29T01:20:10.328Z,1422494410.328 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-01-29T01:20:10.328Z,1422494410.328 [Startup:StartupSatComms:A] Running Loop=1
2015-01-29T01:20:10.686Z,1422494410.686 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-29T01:20:29.479Z,1422494429.479 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2015-01-29T01:20:29.995Z,1422494429.995 [NAL9602](FAULT): received: 
2015-01-29T01:20:29.995Z,1422494429.995 [NAL9602] Data Fault, FailCount= 1
2015-01-29T01:20:29.995Z,1422494429.995 [NAL9602](ERROR): Data Fault
2015-01-29T01:20:30.030Z,1422494430.030 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-29T01:20:30.100Z,1422494430.100 [NAL9602](INFO): Stop
2015-01-29T01:20:30.100Z,1422494430.100 [NAL9602](INFO): Uninitialize
2015-01-29T01:20:30.100Z,1422494430.100 [NAL9602](INFO): Powering down
2015-01-29T01:20:30.451Z,1422494430.451 [NAL9602](INFO): Stopping
2015-01-29T01:20:30.871Z,1422494430.871 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-29T01:20:30.871Z,1422494430.871 [NAL9602] No Fault, FailCount= 1
2015-01-29T01:20:31.248Z,1422494431.248 [NAL9602](INFO): Start
2015-01-29T01:20:31.642Z,1422494431.642 [NAL9602](INFO): Start
2015-01-29T01:20:32.045Z,1422494432.045 [NAL9602](INFO): Start
2015-01-29T01:20:32.451Z,1422494432.451 [NAL9602](INFO): Start
2015-01-29T01:20:32.846Z,1422494432.846 [NAL9602](INFO): Start
2015-01-29T01:20:33.251Z,1422494433.251 [NAL9602](INFO): Start
2015-01-29T01:20:33.638Z,1422494433.638 [NAL9602](INFO): Start
2015-01-29T01:20:34.048Z,1422494434.048 [NAL9602](INFO): Start
2015-01-29T01:20:34.449Z,1422494434.449 [NAL9602](INFO): Start
2015-01-29T01:20:34.849Z,1422494434.849 [NAL9602](INFO): Start
2015-01-29T01:20:35.250Z,1422494435.250 [NAL9602](INFO): Start
2015-01-29T01:20:35.250Z,1422494435.250 [NAL9602](INFO): Powering up NAL9602
2015-01-29T01:20:46.439Z,1422494446.439 [NAL9602](INFO): ************** CMDMODE **************

2015-01-29T01:20:46.439Z,1422494446.439 [NAL9602](INFO): NAL9602 initialized
2015-01-29T01:20:47.249Z,1422494447.249 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:20:47.651Z,1422494447.651 [NAL9602](INFO): ************** GetFix **************

2015-01-29T01:21:10.466Z,1422494470.466 [Startup:StartupSatComms:A](INFO): Timed out from 2015-01-29T01:20:10.3Z
2015-01-29T01:21:10.466Z,1422494470.466 [Startup:StartupSatComms:A] Stopped
2015-01-29T01:21:10.466Z,1422494470.466 [Startup:StartupSatComms:B] Running Loop=1
2015-01-29T01:21:10.863Z,1422494470.863 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-29T01:21:18.441Z,1422494478.441 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:21:18.863Z,1422494478.863 [NAL9602](INFO): Sig Qty requested
2015-01-29T01:21:49.250Z,1422494509.250 [NAL9602](FAULT): Queried for signal strength and failed to receive proper response. serial timeout
2015-01-29T01:21:49.771Z,1422494509.771 [NAL9602](ERROR): received: 
2015-01-29T01:21:49.771Z,1422494509.771 [NAL9602] Data Fault, FailCount= 2
2015-01-29T01:21:49.771Z,1422494509.771 [NAL9602](ERROR): Data Fault
2015-01-29T01:21:49.820Z,1422494509.820 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-29T01:21:49.864Z,1422494509.864 [NAL9602](INFO): Stop
2015-01-29T01:21:49.864Z,1422494509.864 [NAL9602](INFO): Uninitialize
2015-01-29T01:21:49.864Z,1422494509.864 [NAL9602](INFO): Powering down
2015-01-29T01:21:50.233Z,1422494510.233 [NAL9602](INFO): Stopping
2015-01-29T01:21:50.664Z,1422494510.664 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-29T01:21:50.664Z,1422494510.664 [NAL9602] No Fault, FailCount= 2
2015-01-29T01:21:51.038Z,1422494511.038 [NAL9602](INFO): Start
2015-01-29T01:21:51.438Z,1422494511.438 [NAL9602](INFO): Start
2015-01-29T01:21:51.835Z,1422494511.835 [NAL9602](INFO): Start
2015-01-29T01:21:52.236Z,1422494512.236 [NAL9602](INFO): Start
2015-01-29T01:21:52.636Z,1422494512.636 [NAL9602](INFO): Start
2015-01-29T01:21:53.037Z,1422494513.037 [NAL9602](INFO): Start
2015-01-29T01:21:53.438Z,1422494513.438 [NAL9602](INFO): Start
2015-01-29T01:21:53.838Z,1422494513.838 [NAL9602](INFO): Start
2015-01-29T01:21:54.235Z,1422494514.235 [NAL9602](INFO): Start
2015-01-29T01:21:54.635Z,1422494514.635 [NAL9602](INFO): Start
2015-01-29T01:21:55.036Z,1422494515.036 [NAL9602](INFO): Start
2015-01-29T01:21:55.037Z,1422494515.037 [NAL9602](INFO): Powering up NAL9602
2015-01-29T01:22:06.238Z,1422494526.238 [NAL9602](INFO): ************** CMDMODE **************

2015-01-29T01:22:06.238Z,1422494526.238 [NAL9602](INFO): NAL9602 initialized
2015-01-29T01:22:07.031Z,1422494527.031 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:22:07.436Z,1422494527.436 [NAL9602](INFO): ************** GetFix **************

2015-01-29T01:22:10.685Z,1422494530.685 [Startup:StartupSatComms:B](INFO): Timed out from 2015-01-29T01:21:10.5Z
2015-01-29T01:22:10.685Z,1422494530.685 [Startup:StartupSatComms:B] Stopped
2015-01-29T01:22:10.685Z,1422494530.685 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-01-29T01:22:10.685Z,1422494530.685 [Startup:StartupSatComms] Stopped
2015-01-29T01:22:10.685Z,1422494530.685 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-01-29T01:22:10.686Z,1422494530.686 [Startup](INFO): Completed Startup
2015-01-29T01:22:10.686Z,1422494530.686 [Startup] Stopped
2015-01-29T01:22:10.686Z,1422494530.686 [Startup](INFO): Aggregate::uninitialize Startup
2015-01-29T01:22:10.686Z,1422494530.686 [Startup:A.GoToSurface] Stopped
2015-01-29T01:22:10.686Z,1422494530.686 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-29T01:22:11.055Z,1422494531.055 [MissionManager](IMPORTANT): Started mission Default
2015-01-29T01:22:11.055Z,1422494531.055 [Default] Running Loop=1
2015-01-29T01:22:11.055Z,1422494531.055 [Default](INFO): Aggregate::initialize Default
2015-01-29T01:22:11.056Z,1422494531.056 [Default:B.GoToSurface] Running Loop=1
2015-01-29T01:22:11.056Z,1422494531.056 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-01-29T01:22:11.056Z,1422494531.056 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-01-29T01:22:11.056Z,1422494531.056 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-01-29T01:22:11.057Z,1422494531.057 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-01-29T01:22:11.057Z,1422494531.057 [Default:StartClock] Running Loop=1
2015-01-29T01:22:11.057Z,1422494531.057 [Default:StartClock](INFO): Aggregate::initialize Default:StartClock
2015-01-29T01:22:11.057Z,1422494531.057 [Default:StartClock:A] Running Loop=1
2015-01-29T01:22:11.058Z,1422494531.058 [Default:CheckIn] Running Loop=1
2015-01-29T01:22:11.058Z,1422494531.058 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-01-29T01:22:11.058Z,1422494531.058 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-29T01:22:11.058Z,1422494531.058 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-01-29T01:22:11.058Z,1422494531.058 [Default:CheckIn:Read_GPS] Running Loop=1
2015-01-29T01:22:11.059Z,1422494531.059 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-01-29T01:22:11.061Z,1422494531.061 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-01-29T01:22:11.074Z,1422494531.074 [Default:StartClock:A] Stopped
2015-01-29T01:22:11.074Z,1422494531.074 [Default:StartClock](INFO): Completed Default:StartClock
2015-01-29T01:22:11.074Z,1422494531.074 [Default:StartClock] Stopped
2015-01-29T01:22:11.074Z,1422494531.074 [Default:StartClock](INFO): Aggregate::uninitialize Default:StartClock
2015-01-29T01:22:11.487Z,1422494531.487 [Default:WaitAtTheSurface] Running Loop=1
2015-01-29T01:22:11.487Z,1422494531.487 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2015-01-29T01:22:11.487Z,1422494531.487 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-29T01:22:11.487Z,1422494531.487 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2015-01-29T01:22:11.860Z,1422494531.860 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-01-29T01:22:17.059Z,1422494537.059 [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-01-29T01:22:17.059Z,1422494537.059 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2015-01-29T01:22:17.059Z,1422494537.059 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-29T01:22:17.061Z,1422494537.061 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-29T01:22:17.072Z,1422494537.072 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-29T01:22:17.469Z,1422494537.469 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-29T01:22:17.469Z,1422494537.469 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2015-01-29T01:22:17.845Z,1422494537.845 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-29T01:22:18.246Z,1422494538.246 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:22:18.646Z,1422494538.646 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:22:19.047Z,1422494539.047 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:22:19.448Z,1422494539.448 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:22:19.859Z,1422494539.859 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:22:20.245Z,1422494540.245 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:22:37.845Z,1422494557.845 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5C%51
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,0000%33
$B12,0A,FFFD%32
$B13,0A,FFFD%33
$B14,0A,FFFC%33
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,0000%3A
$S,01,270F,02,00,04,5C%51
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,026C,03,0001,08,0B83,09,3C0B,0A,0000,0B,0001%3D
$B11,0C,0001,0D,0064,0E,005B,0F,15DC,10,1641,11,FFFF,12,FFFF%31
$B11,13,17AC,14,0000,15,41A0,16,00E0,17,0002,18,1838,19,3840%4B
$B11,1A,0031,1B,4357,1C,009D%49
$B12,02,000A,01,026C,03,0001,08,0B8B,09,3C1D,0A,FFFC,0B,FFFD%4E
$B12,0C,0001,0D,0052,0E,0050,0F,135D,10,17B2,11,FFFF,12,FFFF%41
$B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%42
$B12,1A,0031,1B,4357,1C,0093%3D
$B13,02,000A,01,026C,03,0001,08,0B90,09,3C1D,0A,FFFC,0B,FFFD%3C
$B13,0C,0001,0D,005B,0E,004E,0F,12B3,10,16D7,11,FFFF,12,FFFF%47
$B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%43
$B13,1A,0031,1B,4333,1C,0068%3A
$B14,02,000A,01,026C,03,0001,08,0B8C,09,3C1D,0A,FFFC,0B,FFFD%49
$B14,0C,0001,0D,0052,0E,004C,0F,1266,10,168C,11,FFFF,12,FFFF%4F
$B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%44
$B14,1A,0031,1B,4357,1C,008D%4D
$B15,02,000A,01,026C,03,0001,08,0B8C,09,3C06,0A,0000,0B,0001%3D
$B15,0C,0001,0D,0064,0E,005B,0F,1602,10,16B6,11,FFFF,12,FFFF%42
$B15,13,2A30,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%38
$B15,1A,0031,1B,4357,1C,008A%49
$B16,02,000A,01,026C,03,0001,08,0B88,09,3C0E,0A,0000,0B,0001%36
$B16,0C,0001,0D,0064,0E,005E,0F,16AB,10,16AB,11,FFFF,12,FFFF%30
$B16,13,0000,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%4B
$B16,1A,0031,1B,4357,1C,00B9%48
$B17,02,000A,01,026C,03,0001,08,0B8F,09,3C09,0A,0000,0B,0001%35
$B17,0C,0001,0D,0064,0E,005F,0F,16DB,10,1701,11,FFFF,12,FFFF%34
$B17,13,08E8,14,0000,15,41A0,16,00E0,17,0001,18,1838,19,3840%3F
$B17,1A,0031,1B,4357,1C,00A5%46
$B18,02,000A,01,026C,03,0001,08,0B93,09,3BB4,0A,0000,0B,0000%31
$B18,0C,0001,0D,0056,0E,004F,0F,12E5,10,16A5,11,FFFF,12,FFFF%3D
$B18,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0002,18,1838,19,3840%48
$B18,1A,0031,1B,4357,1C,00AE%39

2015-01-29T01:22:37.845Z,1422494557.845 [BPC1](FAULT): Failed to parse bank A battery data
2015-01-29T01:22:37.845Z,1422494557.845 [BPC1] Data Fault, FailCount= 1
2015-01-29T01:22:37.845Z,1422494557.845 [BPC1](ERROR): Data Fault
2015-01-29T01:22:37.928Z,1422494557.928 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-29T01:22:38.232Z,1422494558.232 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:22:38.636Z,1422494558.636 [NAL9602](INFO): MT Sig Qty requested
2015-01-29T01:22:39.057Z,1422494559.057 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-29T01:22:39.057Z,1422494559.057 [BPC1] No Fault, FailCount= 1
2015-01-29T01:23:09.035Z,1422494589.035 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2015-01-29T01:23:09.551Z,1422494589.551 [NAL9602](FAULT): received: 
2015-01-29T01:23:09.551Z,1422494589.551 [NAL9602] Data Fault, FailCount= 3
2015-01-29T01:23:09.551Z,1422494589.551 [NAL9602](ERROR): Data Fault
2015-01-29T01:23:09.590Z,1422494589.590 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-29T01:23:09.652Z,1422494589.652 [NAL9602](INFO): Stop
2015-01-29T01:23:09.652Z,1422494589.652 [NAL9602](INFO): Uninitialize
2015-01-29T01:23:09.652Z,1422494589.652 [NAL9602](INFO): Powering down
2015-01-29T01:23:10.009Z,1422494590.009 [NAL9602](INFO): Stopping
2015-01-29T01:23:10.433Z,1422494590.433 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-29T01:23:10.433Z,1422494590.433 [NAL9602] No Fault, FailCount= 3
2015-01-29T01:23:10.806Z,1422494590.806 [NAL9602](INFO): Start
2015-01-29T01:23:11.207Z,1422494591.207 [NAL9602](INFO): Start
2015-01-29T01:23:11.603Z,1422494591.603 [NAL9602](INFO): Start
2015-01-29T01:23:12.008Z,1422494592.008 [NAL9602](INFO): Start
2015-01-29T01:23:12.404Z,1422494592.404 [NAL9602](INFO): Start
2015-01-29T01:23:12.802Z,1422494592.802 [NAL9602](INFO): Start
2015-01-29T01:23:13.198Z,1422494593.198 [NAL9602](INFO): Start
2015-01-29T01:23:13.606Z,1422494593.606 [NAL9602](INFO): Start
2015-01-29T01:23:14.007Z,1422494594.007 [NAL9602](INFO): Start
2015-01-29T01:23:14.401Z,1422494594.401 [NAL9602](INFO): Start
2015-01-29T01:23:14.804Z,1422494594.804 [NAL9602](INFO): Start
2015-01-29T01:23:14.805Z,1422494594.805 [NAL9602](INFO): Powering up NAL9602
2015-01-29T01:23:25.605Z,1422494605.605 [NAL9602](INFO): ************** CMDMODE **************

2015-01-29T01:23:25.605Z,1422494605.605 [NAL9602](INFO): NAL9602 initialized
2015-01-29T01:23:26.399Z,1422494606.399 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:23:26.808Z,1422494606.808 [NAL9602](INFO): ************** GetFix **************

2015-01-29T01:23:57.604Z,1422494637.604 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:23:58.004Z,1422494638.004 [NAL9602](INFO): MT Sig Qty requested
2015-01-29T01:24:16.024Z,1422494656.024 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-29T01:24:16.025Z,1422494656.025 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-29T01:24:16.025Z,1422494656.025 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-29T01:24:16.027Z,1422494656.027 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-29T01:24:16.027Z,1422494656.027 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-29T01:24:16.433Z,1422494656.433 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 2.082840 min 
2015-01-29T01:24:16.435Z,1422494656.435 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-29T01:24:16.436Z,1422494656.436 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-29T01:24:16.436Z,1422494656.436 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-29T01:24:16.436Z,1422494656.436 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-29T01:24:28.407Z,1422494668.407 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2015-01-29T01:24:28.922Z,1422494668.922 [NAL9602](FAULT): received: 
2015-01-29T01:24:28.922Z,1422494668.922 [NAL9602] Data Fault, FailCount= 4
2015-01-29T01:24:28.922Z,1422494668.922 [NAL9602](ERROR): Data Fault
2015-01-29T01:24:28.948Z,1422494668.948 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-29T01:24:29.013Z,1422494669.013 [NAL9602](INFO): Stop
2015-01-29T01:24:29.013Z,1422494669.013 [NAL9602](INFO): Uninitialize
2015-01-29T01:24:29.013Z,1422494669.013 [NAL9602](INFO): Powering down
2015-01-29T01:24:29.367Z,1422494669.367 [NAL9602](INFO): Stopping
2015-01-29T01:24:29.790Z,1422494669.790 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-29T01:24:29.790Z,1422494669.790 [NAL9602] No Fault, FailCount= 4
2015-01-29T01:24:30.164Z,1422494670.164 [NAL9602](INFO): Start
2015-01-29T01:24:30.564Z,1422494670.564 [NAL9602](INFO): Start
2015-01-29T01:24:30.966Z,1422494670.966 [NAL9602](INFO): Start
2015-01-29T01:24:31.359Z,1422494671.359 [NAL9602](INFO): Start
2015-01-29T01:24:31.757Z,1422494671.757 [NAL9602](INFO): Start
2015-01-29T01:24:32.167Z,1422494672.167 [NAL9602](INFO): Start
2015-01-29T01:24:32.567Z,1422494672.567 [NAL9602](INFO): Start
2015-01-29T01:24:32.964Z,1422494672.964 [NAL9602](INFO): Start
2015-01-29T01:24:33.365Z,1422494673.365 [NAL9602](INFO): Start
2015-01-29T01:24:33.765Z,1422494673.765 [NAL9602](INFO): Start
2015-01-29T01:24:34.160Z,1422494674.160 [NAL9602](INFO): Start
2015-01-29T01:24:34.160Z,1422494674.160 [NAL9602](INFO): Powering up NAL9602
2015-01-29T01:24:34.568Z,1422494674.568 [BPC1](FAULT): Failed to receive battery data
2015-01-29T01:24:34.568Z,1422494674.568 [BPC1] Communications Fault, FailCount= 1
2015-01-29T01:24:34.568Z,1422494674.568 [BPC1](ERROR): Communications Fault
2015-01-29T01:24:34.584Z,1422494674.584 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-29T01:24:35.783Z,1422494675.783 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-29T01:24:35.783Z,1422494675.783 [BPC1] No Fault, FailCount= 1
2015-01-29T01:24:44.967Z,1422494684.967 [NAL9602](INFO): ************** CMDMODE **************

2015-01-29T01:24:44.967Z,1422494684.967 [NAL9602](INFO): NAL9602 initialized
2015-01-29T01:24:45.768Z,1422494685.768 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:24:46.166Z,1422494686.166 [NAL9602](INFO): ************** GetFix **************

2015-01-29T01:25:16.966Z,1422494716.966 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:25:17.370Z,1422494717.370 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2015-01-29T01:25:18.168Z,1422494718.168 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:25:18.188Z,1422494718.188 [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-01-29T01:25:18.188Z,1422494718.188 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2015-01-29T01:25:18.188Z,1422494718.188 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-29T01:25:18.189Z,1422494718.189 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-29T01:25:18.200Z,1422494718.200 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-29T01:25:18.631Z,1422494718.631 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-29T01:25:18.631Z,1422494718.631 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2015-01-29T01:25:19.000Z,1422494719.000 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-29T01:25:19.379Z,1422494719.379 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:25:19.779Z,1422494719.779 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:25:20.177Z,1422494720.177 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:25:20.576Z,1422494720.576 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:25:20.977Z,1422494720.977 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:25:21.379Z,1422494721.379 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:25:49.071Z,1422494749.071 [NAL9602](ERROR): getFix uart error: serial timeout
2015-01-29T01:26:19.541Z,1422494779.541 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:26:20.345Z,1422494780.345 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:26:51.252Z,1422494811.252 [NAL9602](ERROR): getFix uart error: serial timeout
2015-01-29T01:27:11.325Z,1422494831.325 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-01-29T01:22:11.1Z
2015-01-29T01:27:11.325Z,1422494831.325 [Default:CheckIn:Read_GPS] Stopped
2015-01-29T01:27:11.325Z,1422494831.325 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-01-29T01:27:11.724Z,1422494831.724 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-01-29T01:27:21.709Z,1422494841.709 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:27:22.115Z,1422494842.115 [NAL9602](INFO): Sig Qty requested
2015-01-29T01:27:27.712Z,1422494847.712 [BPC1](DEBUG): Received data from all battery sticks
2015-01-29T01:27:52.509Z,1422494872.509 [NAL9602](FAULT): Queried for signal strength and failed to receive proper response. serial timeout
2015-01-29T01:27:53.028Z,1422494873.028 [NAL9602](ERROR): received: 
2015-01-29T01:27:53.028Z,1422494873.028 [NAL9602] Data Fault, FailCount= 5
2015-01-29T01:27:53.028Z,1422494873.028 [NAL9602](ERROR): Data Fault
2015-01-29T01:27:53.053Z,1422494873.053 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-29T01:27:53.054Z,1422494873.054 [CBIT](CRITICAL): Data Fault in component: NAL9602
2015-01-29T01:27:53.118Z,1422494873.118 [NAL9602](INFO): Stop
2015-01-29T01:27:53.118Z,1422494873.118 [NAL9602](INFO): Uninitialize
2015-01-29T01:27:53.118Z,1422494873.118 [NAL9602](INFO): Powering down
2015-01-29T01:27:53.472Z,1422494873.472 [NAL9602](INFO): Stopping
2015-01-29T01:28:19.078Z,1422494899.078 [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-01-29T01:28:19.078Z,1422494899.078 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2015-01-29T01:28:19.079Z,1422494899.079 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-29T01:28:19.080Z,1422494899.080 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-29T01:28:19.092Z,1422494899.092 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-29T01:28:19.492Z,1422494899.492 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-29T01:28:19.492Z,1422494899.492 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2015-01-29T01:28:19.878Z,1422494899.878 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-29T01:28:20.281Z,1422494900.281 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:28:20.681Z,1422494900.681 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:28:21.082Z,1422494901.082 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:28:21.479Z,1422494901.479 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:28:21.881Z,1422494901.881 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:28:22.282Z,1422494902.282 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:29:16.285Z,1422494956.285 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-29T01:29:16.285Z,1422494956.285 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-29T01:29:16.286Z,1422494956.286 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-29T01:29:16.287Z,1422494956.287 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-29T01:29:16.287Z,1422494956.287 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-29T01:29:16.685Z,1422494956.685 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 7.087225 min 
2015-01-29T01:29:16.685Z,1422494956.685 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-29T01:29:16.685Z,1422494956.685 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-29T01:29:16.685Z,1422494956.685 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-29T01:29:16.686Z,1422494956.686 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-29T01:29:45.478Z,1422494985.478 [BPC1](ERROR): Failed to parse message.
2015-01-29T01:29:45.478Z,1422494985.478 [BPC1](FAULT): Failed to parse bank B battery data
2015-01-29T01:29:45.478Z,1422494985.478 [BPC1] Data Fault, FailCount= 1
2015-01-29T01:29:45.478Z,1422494985.478 [BPC1](ERROR): Data Fault
2015-01-29T01:29:45.495Z,1422494985.495 [CBIT](ERROR): Data Fault in component: BPC1
2015-01-29T01:29:46.692Z,1422494986.692 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-29T01:29:46.692Z,1422494986.692 [BPC1] No Fault, FailCount= 1
2015-01-29T01:29:53.095Z,1422494993.095 [CBIT](INFO): Clearing failed count for component NAL9602
2015-01-29T01:29:53.095Z,1422494993.095 [NAL9602] No Fault, FailCount= 5
2015-01-29T01:29:53.468Z,1422494993.468 [NAL9602](INFO): Start
2015-01-29T01:29:53.469Z,1422494993.469 [NAL9602](INFO): Powering up NAL9602
2015-01-29T01:30:02.675Z,1422495002.675 [BPC1](FAULT): Failed to receive battery data
2015-01-29T01:30:02.675Z,1422495002.675 [BPC1] Communications Fault, FailCount= 2
2015-01-29T01:30:02.675Z,1422495002.675 [BPC1](ERROR): Communications Fault
2015-01-29T01:30:02.692Z,1422495002.692 [CBIT](ERROR): Communications Fault in component: BPC1
2015-01-29T01:30:03.914Z,1422495003.914 [CBIT](INFO): Clearing failed state for component BPC1
2015-01-29T01:30:03.914Z,1422495003.914 [BPC1] No Fault, FailCount= 2
2015-01-29T01:30:04.268Z,1422495004.268 [NAL9602](INFO): ************** CMDMODE **************

2015-01-29T01:30:04.268Z,1422495004.268 [NAL9602](INFO): NAL9602 initialized
2015-01-29T01:30:05.073Z,1422495005.073 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-01-29T01:30:05.073Z,1422495005.073 [NAL9602] Data Fault, FailCount= 1
2015-01-29T01:30:05.073Z,1422495005.073 [NAL9602](ERROR): Data Fault
2015-01-29T01:30:05.096Z,1422495005.096 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-29T01:30:05.473Z,1422495005.473 [NAL9602](INFO): Stop
2015-01-29T01:30:05.473Z,1422495005.473 [NAL9602](INFO): Uninitialize
2015-01-29T01:30:05.473Z,1422495005.473 [NAL9602](INFO): Powering down
2015-01-29T01:30:05.870Z,1422495005.870 [NAL9602](INFO): Stopping
2015-01-29T01:30:06.291Z,1422495006.291 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-29T01:30:06.291Z,1422495006.291 [NAL9602] No Fault, FailCount= 1
2015-01-29T01:30:06.671Z,1422495006.671 [NAL9602](INFO): Start
2015-01-29T01:30:07.072Z,1422495007.072 [NAL9602](INFO): Start
2015-01-29T01:30:07.473Z,1422495007.473 [NAL9602](INFO): Start
2015-01-29T01:30:07.873Z,1422495007.873 [NAL9602](INFO): Start
2015-01-29T01:30:08.264Z,1422495008.264 [NAL9602](INFO): Start
2015-01-29T01:30:08.674Z,1422495008.674 [NAL9602](INFO): Start
2015-01-29T01:30:09.073Z,1422495009.073 [NAL9602](INFO): Start
2015-01-29T01:30:09.467Z,1422495009.467 [NAL9602](INFO): Start
2015-01-29T01:30:09.868Z,1422495009.868 [NAL9602](INFO): Start
2015-01-29T01:30:10.269Z,1422495010.269 [NAL9602](INFO): Start
2015-01-29T01:30:10.664Z,1422495010.664 [NAL9602](INFO): Start
2015-01-29T01:30:10.664Z,1422495010.664 [NAL9602](INFO): Powering up NAL9602
2015-01-29T01:30:21.474Z,1422495021.474 [NAL9602](INFO): ************** CMDMODE **************

2015-01-29T01:30:21.474Z,1422495021.474 [NAL9602](INFO): NAL9602 initialized
2015-01-29T01:30:22.272Z,1422495022.272 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:30:22.669Z,1422495022.669 [NAL9602](INFO): ************** GetFix **************

2015-01-29T01:30:53.463Z,1422495053.463 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:30:53.886Z,1422495053.886 [NAL9602](INFO): Sig Qty requested
2015-01-29T01:31:19.883Z,1422495079.883 [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-01-29T01:31:19.883Z,1422495079.883 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2015-01-29T01:31:19.883Z,1422495079.883 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-29T01:31:19.885Z,1422495079.885 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-29T01:31:19.896Z,1422495079.896 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-29T01:31:20.299Z,1422495080.299 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-29T01:31:20.299Z,1422495080.299 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2015-01-29T01:31:20.685Z,1422495080.685 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-29T01:31:21.089Z,1422495081.089 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:31:24.262Z,1422495084.262 [NAL9602](FAULT): Queried for signal strength and failed to receive proper response. serial timeout
2015-01-29T01:31:24.777Z,1422495084.777 [NAL9602](ERROR): received: 
2015-01-29T01:31:24.777Z,1422495084.777 [NAL9602] Data Fault, FailCount= 2
2015-01-29T01:31:24.777Z,1422495084.777 [NAL9602](ERROR): Data Fault
2015-01-29T01:31:24.792Z,1422495084.792 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:31:24.803Z,1422495084.803 [CBIT](ERROR): Data Fault in component: NAL9602
2015-01-29T01:31:24.871Z,1422495084.871 [NAL9602](INFO): Stop
2015-01-29T01:31:24.871Z,1422495084.871 [NAL9602](INFO): Uninitialize
2015-01-29T01:31:24.871Z,1422495084.871 [NAL9602](INFO): Powering down
2015-01-29T01:31:24.881Z,1422495084.881 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:31:25.221Z,1422495085.221 [NAL9602](INFO): Stopping
2015-01-29T01:31:25.237Z,1422495085.237 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:31:25.615Z,1422495085.615 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003606
2015-01-29T01:31:25.637Z,1422495085.637 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:31:25.649Z,1422495085.649 [CBIT](INFO): Clearing failed state for component NAL9602
2015-01-29T01:31:25.649Z,1422495085.649 [NAL9602] No Fault, FailCount= 2
2015-01-29T01:31:26.744Z,1422495086.744 [NAL9602](INFO): Start
2015-01-29T01:31:26.754Z,1422495086.754 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:31:26.830Z,1422495086.830 [NAL9602](INFO): Start
2015-01-29T01:31:27.202Z,1422495087.202 [NAL9602](INFO): Start
2015-01-29T01:31:30.399Z,1422495090.399 [NAL9602](INFO): Start
2015-01-29T01:31:30.399Z,1422495090.399 [NAL9602](INFO): Powering up NAL9602
2015-01-29T01:31:30.490Z,1422495090.490 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20150129T010156/Courier0004.lzma
2015-01-29T01:31:31.289Z,1422495091.289 [DataOverHttps](INFO): Moved sent file to Logs/20150129T010156/Courier0004.lzma.bak
2015-01-29T01:31:31.290Z,1422495091.290 [DataOverHttps](INFO): SBD MOMSN=1510572
2015-01-29T01:31:41.042Z,1422495101.042 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20150129T011533/Courier0000.lzma
2015-01-29T01:31:41.052Z,1422495101.052 [NAL9602](INFO): ************** CMDMODE **************

2015-01-29T01:31:41.052Z,1422495101.052 [NAL9602](INFO): NAL9602 initialized
2015-01-29T01:31:41.841Z,1422495101.841 [DataOverHttps](INFO): Moved sent file to Logs/20150129T011533/Courier0000.lzma.bak
2015-01-29T01:31:41.841Z,1422495101.841 [DataOverHttps](INFO): SBD MOMSN=1510574
2015-01-29T01:31:41.854Z,1422495101.854 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:31:42.480Z,1422495102.480 [NAL9602](INFO): ************** GetFix **************

2015-01-29T01:31:51.566Z,1422495111.566 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20150129T011533/Courier0004.lzma
2015-01-29T01:31:52.366Z,1422495112.366 [DataOverHttps](INFO): Moved sent file to Logs/20150129T011533/Courier0004.lzma.bak
2015-01-29T01:31:52.366Z,1422495112.366 [DataOverHttps](INFO): SBD MOMSN=1510580
2015-01-29T01:32:02.668Z,1422495122.668 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20150129T010156/Express0005.lzma
2015-01-29T01:32:03.463Z,1422495123.463 [DataOverHttps](INFO): Moved sent file to Logs/20150129T010156/Express0005.lzma.bak
2015-01-29T01:32:03.463Z,1422495123.463 [DataOverHttps](INFO): SBD MOMSN=1510582
2015-01-29T01:32:12.902Z,1422495132.902 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:32:13.338Z,1422495133.338 [DataOverHttps](INFO): Sending 863 bytes from file Logs/20150129T011533/Express0001.lzma
2015-01-29T01:32:13.358Z,1422495133.358 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:32:14.131Z,1422495134.131 [DataOverHttps](INFO): Moved sent file to Logs/20150129T011533/Express0001.lzma.bak
2015-01-29T01:32:14.132Z,1422495134.132 [DataOverHttps](INFO): SBD MOMSN=1510584
2015-01-29T01:32:24.315Z,1422495144.315 [DataOverHttps](INFO): Sending 636 bytes from file Logs/20150129T011533/Express0005.lzma
2015-01-29T01:32:25.112Z,1422495145.112 [DataOverHttps](INFO): Moved sent file to Logs/20150129T011533/Express0005.lzma.bak
2015-01-29T01:32:25.113Z,1422495145.113 [DataOverHttps](INFO): SBD MOMSN=1510604
2015-01-29T01:32:26.010Z,1422495146.010 [Default:CheckIn:Read_Iridium] Stopped
2015-01-29T01:32:26.011Z,1422495146.011 [Default:CheckIn](INFO): Completed Default:CheckIn
2015-01-29T01:32:26.011Z,1422495146.011 [Default:CheckIn] Stopped
2015-01-29T01:32:26.011Z,1422495146.011 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-01-29T01:32:26.011Z,1422495146.011 [Default:CheckIn:A.SetSpeed] Stopped
2015-01-29T01:32:26.011Z,1422495146.011 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-01-29T01:32:46.544Z,1422495166.544 [NAL9602](ERROR): getFix uart error: serial timeout
2015-01-29T01:33:26.032Z,1422495206.032 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:33:26.758Z,1422495206.758 [CommandLine](IMPORTANT): got command get latitude
2015-01-29T01:33:26.759Z,1422495206.759 [CommandLine](FAULT): Element has no value
2015-01-29T01:33:38.867Z,1422495218.867 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:34:11.541Z,1422495251.541 [NAL9602](ERROR): getFix uart error: serial timeout
2015-01-29T01:34:21.052Z,1422495261.052 [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-01-29T01:34:21.052Z,1422495261.052 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2015-01-29T01:34:21.052Z,1422495261.052 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-01-29T01:34:21.054Z,1422495261.054 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-01-29T01:34:21.056Z,1422495261.056 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-01-29T01:34:21.056Z,1422495261.056 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-29T01:34:21.056Z,1422495261.056 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-01-29T01:34:21.056Z,1422495261.056 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-01-29T01:34:21.057Z,1422495261.057 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-01-29T01:34:21.065Z,1422495261.065 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-01-29T01:34:26.080Z,1422495266.080 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 12.166660 min 
2015-01-29T01:34:26.081Z,1422495266.081 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-01-29T01:34:26.081Z,1422495266.081 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-29T01:34:26.081Z,1422495266.081 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-01-29T01:34:26.081Z,1422495266.081 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-01-29T01:34:26.090Z,1422495266.090 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-01-29T01:34:26.090Z,1422495266.090 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2015-01-29T01:34:31.071Z,1422495271.071 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-01-29T01:34:31.082Z,1422495271.082 [CBIT](INFO): Clearing failed count for component PNI_TCM
2015-01-29T01:34:31.082Z,1422495271.082 [PNI_TCM] No Fault, FailCount= 1
2015-01-29T01:34:38.959Z,1422495278.959 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:34:39.846Z,1422495279.846 [CommandLine](IMPORTANT): got command failComponent
2015-01-29T01:34:39.847Z,1422495279.847 [CommandLine](IMPORTANT): Failed components:
2015-01-29T01:34:39.847Z,1422495279.847 [CommandLine](IMPORTANT): No failed Components.
2015-01-29T01:34:41.062Z,1422495281.062 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:34:45.406Z,1422495285.406 [CommandLine](IMPORTANT): got command get platform_orientation
2015-01-29T01:34:45.406Z,1422495285.406 [CommandLine](FAULT): Element has no value
2015-01-29T01:34:46.086Z,1422495286.086 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:34:51.036Z,1422495291.036 [NAL9602](ERROR): parseGSV uart error: serial timeout
2015-01-29T01:34:51.070Z,1422495291.070 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:34:56.057Z,1422495296.057 [PNI_TCM](FAULT): Failed to acquire valid data within timeout.
2015-01-29T01:34:56.057Z,1422495296.057 [PNI_TCM] Data Fault, FailCount= 1
2015-01-29T01:34:56.057Z,1422495296.057 [PNI_TCM](ERROR): Data Fault
2015-01-29T01:34:56.093Z,1422495296.093 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:34:56.125Z,1422495296.125 [CBIT](ERROR): Data Fault in component: PNI_TCM
2015-01-29T01:34:56.125Z,1422495296.125 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2015-01-29T01:35:01.031Z,1422495301.031 [NAL9602](INFO): ************** Request Fix **************

2015-01-29T01:35:01.072Z,1422495301.072 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-01-29T01:35:16.049Z,1422495316.049 [BPC1](DEBUG): Received data from all battery sticks
2015-01-29T01:35:39.045Z,1422495339.045 [CommandLine](IMPORTANT): got command restart system
2015-01-29T01:35:39.405Z,1422495339.405 [NAL9602](ERROR): getFix uart error: serial timeout
2015-01-29T01:35:43.007Z,1422495343.007 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-29T01:35:43.007Z,1422495343.007 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:43.139Z,1422495343.139 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-01-29T01:35:43.139Z,1422495343.139 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:43.140Z,1422495343.140 [CommandLine](INFO): Join timeout helper Thread ID is 888
2015-01-29T01:35:43.140Z,1422495343.140 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-01-29T01:35:43.141Z,1422495343.141 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:43.141Z,1422495343.141 [NavChartDb](INFO): Join timeout helper Thread ID is 889
2015-01-29T01:35:43.488Z,1422495343.488 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-29T01:35:43.488Z,1422495343.488 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:43.500Z,1422495343.500 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-01-29T01:35:43.500Z,1422495343.500 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:43.500Z,1422495343.500 [Radio_Surface](INFO): Join timeout helper Thread ID is 890
2015-01-29T01:35:43.616Z,1422495343.616 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-29T01:35:43.616Z,1422495343.616 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:43.620Z,1422495343.620 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-01-29T01:35:43.620Z,1422495343.620 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:43.620Z,1422495343.620 [logger](INFO): Join timeout helper Thread ID is 891
2015-01-29T01:35:43.644Z,1422495343.644 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-29T01:35:43.644Z,1422495343.644 [logger ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:43.660Z,1422495343.660 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-01-29T01:35:43.660Z,1422495343.660 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:43.660Z,1422495343.660 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-01-29T01:35:43.660Z,1422495343.660 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:43.661Z,1422495343.661 [controlThread](INFO): Join timeout helper Thread ID is 892
2015-01-29T01:35:46.024Z,1422495346.024 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-01-29T01:35:46.024Z,1422495346.024 [controlThread](DEBUG): Uninitializing ControlThread
2015-01-29T01:35:46.028Z,1422495346.028 [NAL9602](INFO): Uninitialize
2015-01-29T01:35:46.028Z,1422495346.028 [NAL9602](INFO): Powering down
2015-01-29T01:35:46.030Z,1422495346.030 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-01-29T01:35:46.031Z,1422495346.031 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-01-29T01:35:46.032Z,1422495346.032 [Default] Stopped
2015-01-29T01:35:46.032Z,1422495346.032 [Default](INFO): Aggregate::uninitialize Default
2015-01-29T01:35:46.032Z,1422495346.032 [Default:B.GoToSurface] Stopped
2015-01-29T01:35:46.032Z,1422495346.032 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-01-29T01:35:46.032Z,1422495346.032 [Default:WaitAtTheSurface] Stopped
2015-01-29T01:35:46.032Z,1422495346.032 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2015-01-29T01:35:46.032Z,1422495346.032 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped
2015-01-29T01:35:46.033Z,1422495346.033 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2015-01-29T01:35:46.036Z,1422495346.036 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-01-29T01:35:46.037Z,1422495346.037 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-01-29T01:35:46.037Z,1422495346.037 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-01-29T01:35:46.037Z,1422495346.037 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-01-29T01:35:46.037Z,1422495346.037 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-01-29T01:35:46.037Z,1422495346.037 [BuoyancyServo](INFO): Powering down
2015-01-29T01:35:46.052Z,1422495346.052 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-01-29T01:35:46.052Z,1422495346.052 [ElevatorServo](INFO): Powering down
2015-01-29T01:35:46.053Z,1422495346.053 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-01-29T01:35:46.053Z,1422495346.053 [RudderServo](INFO): Powering down
2015-01-29T01:35:46.054Z,1422495346.054 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-01-29T01:35:46.054Z,1422495346.054 [ThrusterServo](INFO): Powering down
2015-01-29T01:35:46.055Z,1422495346.055 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-01-29T01:35:46.055Z,1422495346.055 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-01-29T01:35:46.055Z,1422495346.055 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-01-29T01:35:46.088Z,1422495346.088 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:46.217Z,1422495346.217 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:46.265Z,1422495346.265 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-01-29T01:35:46.325Z,1422495346.325 [logger ThreadHandler](INFO): Thread cancelled.