2015-04-16T23:41:25.571Z,1429227685.571 [Supervisor](DEBUG): Initializing supervisor.
2015-04-16T23:41:25.574Z,1429227685.574 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-04-16T23:41:25.575Z,1429227685.575 [SyncHandler](INFO): Protected caller Thread ID is 770
2015-04-16T23:41:25.575Z,1429227685.575 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-04-16T23:41:25.578Z,1429227685.578 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-04-16T23:41:25.578Z,1429227685.578 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 771
2015-04-16T23:41:25.581Z,1429227685.581 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-04-16T23:41:25.593Z,1429227685.593 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-04-16T23:41:25.598Z,1429227685.598 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-04-16T23:41:25.598Z,1429227685.598 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 772
2015-04-16T23:41:25.599Z,1429227685.599 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-04-16T23:41:25.602Z,1429227685.602 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-04-16T23:41:25.602Z,1429227685.602 [logger ThreadHandler](INFO): Protected caller Thread ID is 773
2015-04-16T23:41:25.604Z,1429227685.604 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-04-16T23:41:25.605Z,1429227685.605 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-04-16T23:41:25.608Z,1429227685.608 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-04-16T23:41:25.992Z,1429227685.992 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-04-16T23:41:25.993Z,1429227685.993 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-04-16T23:41:26.184Z,1429227686.184 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-04-16T23:41:26.184Z,1429227686.184 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-04-16T23:41:26.312Z,1429227686.312 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-04-16T23:41:26.313Z,1429227686.313 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-04-16T23:41:26.455Z,1429227686.455 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-04-16T23:41:26.455Z,1429227686.455 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-04-16T23:41:26.555Z,1429227686.555 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-04-16T23:41:26.741Z,1429227686.741 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-04-16T23:41:26.741Z,1429227686.741 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-04-16T23:41:26.840Z,1429227686.840 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-04-16T23:41:26.841Z,1429227686.841 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-04-16T23:41:27.081Z,1429227687.081 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-04-16T23:41:27.083Z,1429227687.083 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-04-16T23:41:27.498Z,1429227687.498 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-04-16T23:41:27.499Z,1429227687.499 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-04-16T23:41:27.847Z,1429227687.847 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-04-16T23:41:27.847Z,1429227687.847 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-04-16T23:41:28.424Z,1429227688.424 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-04-16T23:41:28.425Z,1429227688.425 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-04-16T23:41:28.680Z,1429227688.680 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-04-16T23:41:28.680Z,1429227688.680 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-04-16T23:41:28.797Z,1429227688.797 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-04-16T23:41:28.798Z,1429227688.798 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-04-16T23:41:29.265Z,1429227689.265 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-04-16T23:41:29.266Z,1429227689.266 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-04-16T23:41:30.000Z,1429227690.000 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-04-16T23:41:30.002Z,1429227690.002 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2015-04-16T23:41:30.005Z,1429227690.005 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2015-04-16T23:41:30.127Z,1429227690.127 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2015-04-16T23:41:30.263Z,1429227690.263 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2015-04-16T23:41:30.375Z,1429227690.375 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2015-04-16T23:41:30.497Z,1429227690.497 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2015-04-16T23:41:30.603Z,1429227690.603 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2015-04-16T23:41:30.751Z,1429227690.751 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2015-04-16T23:41:30.932Z,1429227690.932 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2015-04-16T23:41:31.044Z,1429227691.044 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2015-04-16T23:41:31.148Z,1429227691.148 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2015-04-16T23:41:31.238Z,1429227691.238 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2015-04-16T23:41:31.348Z,1429227691.348 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2015-04-16T23:41:31.481Z,1429227691.480 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2015-04-16T23:41:31.753Z,1429227691.753 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-04-16T23:41:31.753Z,1429227691.753 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2015-04-16T23:41:31.758Z,1429227691.758 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-04-16T23:41:31.839Z,1429227691.839 [VerticalControl](DEBUG): Construct VerticalControl.
2015-04-16T23:41:31.977Z,1429227691.977 [VerticalControl] Loaded
2015-04-16T23:41:31.977Z,1429227691.977 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-04-16T23:41:31.978Z,1429227691.978 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-04-16T23:41:32.061Z,1429227692.061 [HorizontalControl] Loaded
2015-04-16T23:41:32.061Z,1429227692.061 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-04-16T23:41:32.062Z,1429227692.062 [SpeedControl](DEBUG): Construct SpeedControl.
2015-04-16T23:41:32.068Z,1429227692.068 [SpeedControl] Loaded
2015-04-16T23:41:32.069Z,1429227692.069 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-04-16T23:41:32.069Z,1429227692.069 [LoopControl](DEBUG): Construct LoopControl.
2015-04-16T23:41:32.070Z,1429227692.070 [LoopControl] Loaded
2015-04-16T23:41:32.070Z,1429227692.070 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-04-16T23:41:32.071Z,1429227692.071 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-04-16T23:41:32.071Z,1429227692.071 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-04-16T23:41:32.248Z,1429227692.248 [SBIT](DEBUG): Construct Startup Built In Test.
2015-04-16T23:41:32.260Z,1429227692.260 [SBIT] Loaded
2015-04-16T23:41:32.260Z,1429227692.260 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-04-16T23:41:32.261Z,1429227692.261 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-04-16T23:41:32.295Z,1429227692.295 [IBIT] Loaded
2015-04-16T23:41:32.296Z,1429227692.296 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-04-16T23:41:32.298Z,1429227692.298 [CBIT](DEBUG): Construct Continuous Built In Test.
2015-04-16T23:41:32.463Z,1429227692.463 [CBIT] Loaded
2015-04-16T23:41:32.464Z,1429227692.464 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-04-16T23:41:32.464Z,1429227692.464 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-04-16T23:41:32.465Z,1429227692.465 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-04-16T23:41:32.498Z,1429227692.498 [DepthRateCalculator] Loaded
2015-04-16T23:41:32.498Z,1429227692.498 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-04-16T23:41:32.504Z,1429227692.504 [PitchRateCalculator] Loaded
2015-04-16T23:41:32.504Z,1429227692.504 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-04-16T23:41:32.516Z,1429227692.516 [SpeedCalculator] Loaded
2015-04-16T23:41:32.517Z,1429227692.517 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-04-16T23:41:32.534Z,1429227692.534 [TempGradientCalculator] Loaded
2015-04-16T23:41:32.534Z,1429227692.534 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-04-16T23:41:32.540Z,1429227692.540 [YawRateCalculator] Loaded
2015-04-16T23:41:32.540Z,1429227692.540 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-04-16T23:41:32.541Z,1429227692.541 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-04-16T23:41:32.541Z,1429227692.541 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-04-16T23:41:32.639Z,1429227692.639 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-04-16T23:41:32.640Z,1429227692.640 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-04-16T23:41:32.950Z,1429227692.950 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-04-16T23:41:32.951Z,1429227692.951 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-04-16T23:41:33.073Z,1429227693.073 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-04-16T23:41:33.073Z,1429227693.073 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-04-16T23:41:33.124Z,1429227693.124 [DeadReckonUsingSpeedCalculator] Loaded
2015-04-16T23:41:33.125Z,1429227693.125 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2015-04-16T23:41:33.142Z,1429227693.142 [NavChart] Loaded
2015-04-16T23:41:33.143Z,1429227693.143 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-04-16T23:41:33.148Z,1429227693.148 [UniversalFixResidualReporter] Loaded
2015-04-16T23:41:33.148Z,1429227693.148 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-04-16T23:41:33.149Z,1429227693.149 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-04-16T23:41:33.149Z,1429227693.149 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-04-16T23:41:33.159Z,1429227693.159 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-04-16T23:41:33.160Z,1429227693.160 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-04-16T23:41:33.371Z,1429227693.371 [Aanderaa_O2] Loaded
2015-04-16T23:41:33.371Z,1429227693.371 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2015-04-16T23:41:33.460Z,1429227693.460 [CTD_NeilBrown] Loaded
2015-04-16T23:41:33.460Z,1429227693.460 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2015-04-16T23:41:33.462Z,1429227693.462 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 405764E0
2015-04-16T23:41:33.462Z,1429227693.462 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 858
2015-04-16T23:41:33.476Z,1429227693.476 [ISUS] Loaded
2015-04-16T23:41:33.476Z,1429227693.476 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2015-04-16T23:41:33.492Z,1429227693.492 [PAR_Licor] Loaded
2015-04-16T23:41:33.492Z,1429227693.492 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2015-04-16T23:41:33.550Z,1429227693.550 [WetLabsBB2FL] Loaded
2015-04-16T23:41:33.550Z,1429227693.550 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2015-04-16T23:41:33.554Z,1429227693.554 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405A64E0
2015-04-16T23:41:33.555Z,1429227693.555 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 859
2015-04-16T23:41:33.555Z,1429227693.555 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-04-16T23:41:33.556Z,1429227693.556 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-04-16T23:41:34.337Z,1429227694.337 [AHRS_sp3003D] Loaded
2015-04-16T23:41:34.338Z,1429227694.338 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2015-04-16T23:41:34.528Z,1429227694.528 [DataOverHttps] Loaded
2015-04-16T23:41:34.529Z,1429227694.529 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-04-16T23:41:34.549Z,1429227694.549 [Depth_Keller] Loaded
2015-04-16T23:41:34.549Z,1429227694.549 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-04-16T23:41:34.555Z,1429227694.555 [DropWeight] Loaded
2015-04-16T23:41:34.555Z,1429227694.555 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2015-04-16T23:41:34.720Z,1429227694.720 [DVL_micro] Loaded
2015-04-16T23:41:34.720Z,1429227694.720 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2015-04-16T23:41:34.833Z,1429227694.833 [NAL9602] Loaded
2015-04-16T23:41:34.834Z,1429227694.834 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-04-16T23:41:34.883Z,1429227694.883 [Onboard] Loaded
2015-04-16T23:41:34.884Z,1429227694.884 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-04-16T23:41:34.891Z,1429227694.891 [Radio_Surface] Loaded
2015-04-16T23:41:34.891Z,1429227694.891 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-04-16T23:41:34.896Z,1429227694.896 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407F64E0
2015-04-16T23:41:34.897Z,1429227694.897 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 860
2015-04-16T23:41:37.057Z,1429227697.057 [BPC1] Loaded
2015-04-16T23:41:37.057Z,1429227697.057 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-04-16T23:41:37.058Z,1429227697.058 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-04-16T23:41:37.058Z,1429227697.058 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-04-16T23:41:37.203Z,1429227697.203 [BuoyancyServo] Loaded
2015-04-16T23:41:37.204Z,1429227697.204 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-04-16T23:41:37.217Z,1429227697.217 [ElevatorServo] Loaded
2015-04-16T23:41:37.217Z,1429227697.217 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-04-16T23:41:37.230Z,1429227697.230 [MassServo] Loaded
2015-04-16T23:41:37.230Z,1429227697.230 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2015-04-16T23:41:37.247Z,1429227697.247 [RudderServo] Loaded
2015-04-16T23:41:37.247Z,1429227697.247 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-04-16T23:41:37.259Z,1429227697.259 [ThrusterServo] Loaded
2015-04-16T23:41:37.260Z,1429227697.260 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-04-16T23:41:37.260Z,1429227697.260 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-04-16T23:41:37.261Z,1429227697.261 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-04-16T23:41:37.412Z,1429227697.412 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-04-16T23:41:37.413Z,1429227697.413 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-04-16T23:41:37.458Z,1429227697.458 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-04-16T23:41:37.460Z,1429227697.460 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-04-16T23:41:37.461Z,1429227697.461 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-04-16T23:41:37.467Z,1429227697.467 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-04-16T23:41:37.472Z,1429227697.472 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408A74E0
2015-04-16T23:41:37.473Z,1429227697.473 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 861
2015-04-16T23:41:37.477Z,1429227697.477 [Supervisor](INFO): Main Thread ID is 766
2015-04-16T23:41:37.477Z,1429227697.477 [Supervisor](DEBUG): Running supervisor.
2015-04-16T23:41:37.478Z,1429227697.478 [CommandLine ThreadHandler](INFO): Handler Thread ID is 862
2015-04-16T23:41:37.485Z,1429227697.485 [controlThread ThreadHandler](INFO): Handler Thread ID is 863
2015-04-16T23:41:37.485Z,1429227697.485 [controlThread](DEBUG): Initializing ControlThread
2015-04-16T23:41:37.486Z,1429227697.486 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-04-16T23:41:37.488Z,1429227697.488 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-04-16T23:41:37.489Z,1429227697.489 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-04-16T23:41:37.489Z,1429227697.489 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-04-16T23:41:37.489Z,1429227697.489 [SBIT](INFO): Initialize SBIT Component.
2015-04-16T23:41:37.490Z,1429227697.490 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12068
2015-04-16T23:41:37.490Z,1429227697.490 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-04-16T23:41:37.490Z,1429227697.490 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-04-16T23:41:37.491Z,1429227697.491 [IBIT](INFO): Initialize IBIT Component.
2015-04-16T23:41:37.492Z,1429227697.492 [CBIT](DEBUG): Initialize CBIT Component.
2015-04-16T23:41:37.492Z,1429227697.492 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2015-04-16T23:41:37.492Z,1429227697.492 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-04-16T23:41:37.497Z,1429227697.497 [logger ThreadHandler](INFO): Handler Thread ID is 864
2015-04-16T23:41:37.516Z,1429227697.516 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-04-16T23:41:37.517Z,1429227697.517 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-04-16T23:41:37.517Z,1429227697.517 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-04-16T23:41:37.518Z,1429227697.518 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-04-16T23:41:37.518Z,1429227697.518 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-04-16T23:41:37.519Z,1429227697.519 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-04-16T23:41:37.519Z,1429227697.519 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-04-16T23:41:37.520Z,1429227697.520 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-04-16T23:41:37.520Z,1429227697.520 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-04-16T23:41:37.537Z,1429227697.537 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-04-16T23:41:37.550Z,1429227697.550 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 865
2015-04-16T23:41:37.551Z,1429227697.551 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2015-04-16T23:41:37.554Z,1429227697.554 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2015-04-16T23:41:37.577Z,1429227697.577 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 867
2015-04-16T23:41:37.578Z,1429227697.578 [WetLabsBB2FL](INFO): Powering down
2015-04-16T23:41:37.598Z,1429227697.598 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-04-16T23:41:37.609Z,1429227697.609 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 868
2015-04-16T23:41:37.616Z,1429227697.616 [Radio_Surface](INFO): Powering up
2015-04-16T23:41:37.634Z,1429227697.634 [MissionManager](DEBUG):
2015-04-16T23:41:37.635Z,1429227697.635 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-04-16T23:41:37.636Z,1429227697.636 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 869
2015-04-16T23:41:37.666Z,1429227697.666 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-04-16T23:41:37.669Z,1429227697.669 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-04-16T23:41:37.669Z,1429227697.669 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-04-16T23:41:37.670Z,1429227697.670 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-04-16T23:41:37.670Z,1429227697.670 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-04-16T23:41:37.670Z,1429227697.670 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-04-16T23:41:37.670Z,1429227697.670 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-04-16T23:41:37.671Z,1429227697.671 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-04-16T23:41:37.671Z,1429227697.671 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-04-16T23:41:37.701Z,1429227697.701 [CTD_NeilBrown](DEBUG): CTD uart timeout: serial timeout
2015-04-16T23:41:37.701Z,1429227697.701 [CTD_NeilBrown](ERROR): Could not get real or simulated CTD data. startTime.elapsed() = 0.146730
2015-04-16T23:41:37.787Z,1429227697.787 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-04-16T23:41:37.796Z,1429227697.796 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-04-16T23:41:37.800Z,1429227697.800 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-04-16T23:41:37.850Z,1429227697.850 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-04-16T23:41:37.868Z,1429227697.868 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-04-16T23:41:37.906Z,1429227697.906 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-04-16T23:41:37.928Z,1429227697.928 [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-04-16T23:41:37.942Z,1429227697.942 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ISUS,PAR_Licor,AHRS_sp3003D,DataOverHttps,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-04-16T23:41:38.077Z,1429227698.077 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2015-04-16T23:41:38.520Z,1429227698.520 [DVL_micro](INFO): Initializing
2015-04-16T23:41:38.831Z,1429227698.831 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:41:38.975Z,1429227698.975 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-04-16T23:41:38.983Z,1429227698.983 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-04-16T23:41:39.002Z,1429227699.002 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-04-16T23:41:39.007Z,1429227699.007 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-04-16T23:41:39.033Z,1429227699.033 [MassServo](DEBUG): Initializing EZServoServo.
2015-04-16T23:41:39.039Z,1429227699.039 [MassServo](DEBUG): Initializing MassServo.
2015-04-16T23:41:39.053Z,1429227699.053 [RudderServo](DEBUG): Initializing EZServoServo.
2015-04-16T23:41:39.059Z,1429227699.059 [RudderServo](DEBUG): Initializing RudderServo.
2015-04-16T23:41:39.073Z,1429227699.073 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-04-16T23:41:39.079Z,1429227699.079 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-04-16T23:41:39.532Z,1429227699.532 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:41:39.880Z,1429227699.880 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2015-04-16T23:41:39.880Z,1429227699.880 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2015-04-16T23:41:39.880Z,1429227699.880 [BuoyancyServo] Communications Fault, FailCount= 1
2015-04-16T23:41:39.880Z,1429227699.880 [BuoyancyServo](ERROR): Communications Fault
2015-04-16T23:41:40.127Z,1429227700.127 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2015-04-16T23:41:40.460Z,1429227700.460 [NAL9602](INFO): Powering up NAL9602
2015-04-16T23:41:40.488Z,1429227700.488 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:41:40.512Z,1429227700.512 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-04-16T23:41:40.521Z,1429227700.521 [BuoyancyServo](INFO): Powering down
2015-04-16T23:41:40.978Z,1429227700.978 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:41:41.442Z,1429227701.442 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:41:41.924Z,1429227701.924 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:41:42.967Z,1429227702.967 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2015-04-16T23:41:42.968Z,1429227702.968 [BuoyancyServo] No Fault, FailCount= 1
2015-04-16T23:41:43.337Z,1429227703.337 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-04-16T23:41:43.458Z,1429227703.458 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-04-16T23:41:48.287Z,1429227708.287 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:41:48.287Z,1429227708.287 [Aanderaa_O2] Communications Fault, FailCount= 1
2015-04-16T23:41:48.287Z,1429227708.287 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:41:48.693Z,1429227708.693 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:41:48.818Z,1429227708.818 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:41:49.607Z,1429227709.607 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-16T23:41:49.607Z,1429227709.607 [DVL_micro] Communications Fault, FailCount= 1
2015-04-16T23:41:49.607Z,1429227709.607 [DVL_micro](ERROR): Communications Fault
2015-04-16T23:41:49.691Z,1429227709.691 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-16T23:41:50.092Z,1429227710.092 [DVL_micro](INFO): uninitialize:Powering down
2015-04-16T23:41:50.247Z,1429227710.247 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-16T23:41:50.248Z,1429227710.248 [Aanderaa_O2] No Fault, FailCount= 1
2015-04-16T23:41:50.596Z,1429227710.596 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-16T23:41:51.153Z,1429227711.153 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-04-16T23:41:51.153Z,1429227711.153 [DVL_micro] No Fault, FailCount= 1
2015-04-16T23:41:51.502Z,1429227711.502 [DVL_micro](INFO): Initializing
2015-04-16T23:41:51.512Z,1429227711.512 [NAL9602](INFO): NAL9602 initialized
2015-04-16T23:41:53.159Z,1429227713.159 [SBIT](IMPORTANT): Beginning Startup BIT
2015-04-16T23:41:53.161Z,1429227713.161 [CBIT](IMPORTANT): Beginning GF scan
2015-04-16T23:42:00.537Z,1429227720.537 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:42:00.538Z,1429227720.538 [Aanderaa_O2] Communications Fault, FailCount= 2
2015-04-16T23:42:00.538Z,1429227720.538 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:42:00.969Z,1429227720.969 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:42:01.093Z,1429227721.093 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:42:02.341Z,1429227722.341 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-16T23:42:02.341Z,1429227722.341 [DVL_micro] Communications Fault, FailCount= 2
2015-04-16T23:42:02.341Z,1429227722.341 [DVL_micro](ERROR): Communications Fault
2015-04-16T23:42:02.543Z,1429227722.543 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-16T23:42:02.543Z,1429227722.543 [Aanderaa_O2] No Fault, FailCount= 2
2015-04-16T23:42:02.544Z,1429227722.544 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-16T23:42:02.968Z,1429227722.968 [DVL_micro](INFO): uninitialize:Powering down
2015-04-16T23:42:03.432Z,1429227723.432 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-16T23:42:03.944Z,1429227723.944 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-04-16T23:42:03.944Z,1429227723.944 [DVL_micro] No Fault, FailCount= 2
2015-04-16T23:42:04.342Z,1429227724.342 [DVL_micro](INFO): Initializing
2015-04-16T23:42:05.322Z,1429227725.322 [BPC1](ERROR): B bank expecting battery number:1 and read number: uart read:X
$S,01,270F,02,00,04,5E%57
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,FFFC%36
$B12,0A,FFFC%35
$B13,0A,0000%31
$B14,0A,FFFD%34
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,0000%3A
$S,01,270F,02,00,04,5E%57
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,02A8,03,0001,08,0B9B,09,3E78,0A,FFFC,0B,FFFC%3B
$B11,0C,0001,0D,0063,0E,0055,0F,1683,10,18E3,11,FFFF,12,FFFF%33
$B11,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%3B
$B11,1A,0031,1B,458B,1C,0095%46
$B12,02,000A,01,02A8,03,0001,08,0B8B,09,3E7A,0A,FFFC,0B,FFFC%40
$B12,0C,0001,0D,0063,0E,0056,0F,16C2,10,194F,11,FFFF,12,FFFF%4C
$B12,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%38
$B12,1A,0031,1B,458B,1C,00BE%4E
$B13,02,000A,01,02A8,03,0001,08,0B8C,09,3E72,0A,FFFD,0B,0000%31
$B13,0C,0001,0D,005A,0E,0055,0F,1659,10,18F7,11,FFFF,12,FFFF%40
$B13,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%39
$B13,1A,0031,1B,458B,1C,0086%46
$B14,02,000A,01,02A8,03,0001,08,0B8C,09,3E6F,0A,FFFD,0B,FFFD%41
$B14,0C,0001,0D,0058,0E,0053,0F,15E8,10,18EC,11,FFFF,12,FFFF%3D
$B14,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%3E
$B14,1A,0031,1B,458B,1C,00AE%4B
$B15,02,000A,01,02A8,03,0001,08,0B8B,09,3E7B,0A,0000,0B,0000%44
$B15,0C,0001,0D,005B,0E,0058,0F,174F,10,19A6,11,FFFF,12,FFFF%30
$B15,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%3F
$B15,1A,0031,1B,458C,1C,00CB%4E
$B16,02,000A,01,02A8,03,0001,08,0B8A,09,3E8C,0A,0000,0B,0000%4A
$B16,0C,0001,0D,005A,0E,0055,0F,1689,10,1942,11,FFFF,12,FFFF%3E
$B16,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%3C
$B16,1A,0031,1B,458C,1C,00F7%3D
$B17,02,000A,01,02A8,03,0001,08,0B90,09,3E9B,0A,0000,0B,0000%3B
$B17,0C,0001,0D,0063,0E,0054,0F,1641,10,18F1,11,FFFF,12,FFFF%3B
$B17,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%3D
$B17,1A,0031,1B,458B,1C,00A1%3C
$B18,02,000A,01,02A8,03,0001,08,0B87,09,3E4C,0A,0000,0B,0000%3E
$B18,0C,0001,0D,005C,0E,0056,0F,1696,10,1936,11,FFFF,12,FFFF%3C
$B18,13,FFFF,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%32
$B18,1A,0031,1B,458C,1C,00F0%34
2015-04-16T23:42:05.322Z,1429227725.322 [BPC1](ERROR): Failed to parse bank B battery data
2015-04-16T23:42:05.322Z,1429227725.322 [BPC1] Data Fault, FailCount= 1
2015-04-16T23:42:05.322Z,1429227725.322 [BPC1](ERROR): Data Fault
2015-04-16T23:42:05.473Z,1429227725.473 [CBIT](ERROR): Data Fault in component: BPC1
2015-04-16T23:42:06.784Z,1429227726.784 [CBIT](INFO): Clearing failed state for component BPC1
2015-04-16T23:42:06.784Z,1429227726.784 [BPC1] No Fault, FailCount= 1
2015-04-16T23:42:12.900Z,1429227732.900 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:42:12.900Z,1429227732.900 [Aanderaa_O2] Communications Fault, FailCount= 3
2015-04-16T23:42:12.900Z,1429227732.900 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:42:13.436Z,1429227733.436 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:42:13.436Z,1429227733.436 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2015-04-16T23:42:13.561Z,1429227733.561 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:42:15.012Z,1429227735.012 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-16T23:42:15.012Z,1429227735.012 [DVL_micro] Communications Fault, FailCount= 3
2015-04-16T23:42:15.012Z,1429227735.012 [DVL_micro](ERROR): Communications Fault
2015-04-16T23:42:15.359Z,1429227735.359 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-16T23:42:15.784Z,1429227735.784 [DVL_micro](INFO): uninitialize:Powering down
2015-04-16T23:42:16.218Z,1429227736.218 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-16T23:42:16.834Z,1429227736.834 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-04-16T23:42:16.834Z,1429227736.834 [DVL_micro] No Fault, FailCount= 3
2015-04-16T23:42:17.209Z,1429227737.209 [DVL_micro](INFO): Initializing
2015-04-16T23:42:20.200Z,1429227740.200 [CBIT](IMPORTANT): No ground fault detected
2015-04-16T23:42:28.132Z,1429227748.132 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-16T23:42:28.133Z,1429227748.133 [DVL_micro] Communications Fault, FailCount= 4
2015-04-16T23:42:28.133Z,1429227748.133 [DVL_micro](ERROR): Communications Fault
2015-04-16T23:42:28.237Z,1429227748.237 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-16T23:42:28.706Z,1429227748.706 [DVL_micro](INFO): uninitialize:Powering down
2015-04-16T23:42:29.138Z,1429227749.138 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-16T23:42:29.649Z,1429227749.649 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-04-16T23:42:29.649Z,1429227749.649 [DVL_micro] No Fault, FailCount= 4
2015-04-16T23:42:30.086Z,1429227750.086 [DVL_micro](INFO): Initializing
2015-04-16T23:42:40.820Z,1429227760.820 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-16T23:42:40.820Z,1429227760.820 [DVL_micro] Communications Fault, FailCount= 5
2015-04-16T23:42:40.820Z,1429227760.820 [DVL_micro](ERROR): Communications Fault
2015-04-16T23:42:40.927Z,1429227760.927 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-16T23:42:40.927Z,1429227760.927 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2015-04-16T23:42:41.352Z,1429227761.352 [DVL_micro](INFO): uninitialize:Powering down
2015-04-16T23:42:41.419Z,1429227761.419 [CommandLine](FAULT): Scheduling is paused
2015-04-16T23:42:41.778Z,1429227761.778 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-16T23:42:47.387Z,1429227767.387 [SBIT](IMPORTANT): SBIT PASSED
2015-04-16T23:42:47.810Z,1429227767.810 [MissionManager](IMPORTANT): Started mission Startup
2015-04-16T23:42:47.810Z,1429227767.810 [Startup] Running Loop=1
2015-04-16T23:42:47.810Z,1429227767.810 [Startup](INFO): Aggregate::initialize Startup
2015-04-16T23:42:47.810Z,1429227767.810 [Startup:A.GoToSurface] Running Loop=1
2015-04-16T23:42:47.810Z,1429227767.810 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-04-16T23:42:47.811Z,1429227767.811 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-04-16T23:42:47.811Z,1429227767.811 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-04-16T23:42:47.812Z,1429227767.812 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-04-16T23:42:47.818Z,1429227767.818 [Startup:StartupSatComms] Running Loop=1
2015-04-16T23:42:47.818Z,1429227767.818 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-04-16T23:42:47.818Z,1429227767.818 [Startup:StartupSatComms:A] Running Loop=1
2015-04-16T23:42:48.266Z,1429227768.266 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-04-16T23:43:48.210Z,1429227828.210 [Startup:StartupSatComms:A](INFO): Timed out from 2015-04-16T23:42:47.8Z
2015-04-16T23:43:48.210Z,1429227828.210 [Startup:StartupSatComms:A] Stopped
2015-04-16T23:43:48.210Z,1429227828.210 [Startup:StartupSatComms:B] Running Loop=1
2015-04-16T23:43:48.676Z,1429227828.676 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-04-16T23:44:37.597Z,1429227877.597 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-16T23:44:37.597Z,1429227877.597 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2015-04-16T23:44:37.598Z,1429227877.598 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-04-16T23:44:37.616Z,1429227877.616 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-16T23:44:37.616Z,1429227877.616 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2015-04-16T23:44:37.616Z,1429227877.616 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2015-04-16T23:44:37.650Z,1429227877.650 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-04-16T23:44:37.650Z,1429227877.650 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2015-04-16T23:44:38.035Z,1429227878.035 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-04-16T23:44:38.035Z,1429227878.035 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2015-04-16T23:44:38.035Z,1429227878.035 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2015-04-16T23:44:38.035Z,1429227878.035 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2015-04-16T23:44:38.435Z,1429227878.435 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-04-16T23:44:38.435Z,1429227878.435 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-04-16T23:44:38.876Z,1429227878.876 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:44:39.297Z,1429227879.297 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:44:39.690Z,1429227879.690 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:44:40.100Z,1429227880.100 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:44:40.524Z,1429227880.524 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:44:40.922Z,1429227880.922 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:44:42.985Z,1429227882.985 [CBIT](INFO): Clearing failed count for component Aanderaa_O2
2015-04-16T23:44:42.986Z,1429227882.986 [Aanderaa_O2] No Fault, FailCount= 3
2015-04-16T23:44:48.447Z,1429227888.447 [Startup:StartupSatComms:B](INFO): Timed out from 2015-04-16T23:43:48.2Z
2015-04-16T23:44:48.447Z,1429227888.447 [Startup:StartupSatComms:B] Stopped
2015-04-16T23:44:48.447Z,1429227888.447 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-04-16T23:44:48.447Z,1429227888.447 [Startup:StartupSatComms] Stopped
2015-04-16T23:44:48.447Z,1429227888.447 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-04-16T23:44:48.448Z,1429227888.448 [Startup](INFO): Completed Startup
2015-04-16T23:44:48.448Z,1429227888.448 [Startup] Stopped
2015-04-16T23:44:48.449Z,1429227888.449 [Startup](INFO): Aggregate::uninitialize Startup
2015-04-16T23:44:48.449Z,1429227888.449 [Startup:A.GoToSurface] Stopped
2015-04-16T23:44:48.449Z,1429227888.449 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-04-16T23:44:48.935Z,1429227888.935 [MissionManager](IMPORTANT): Started mission Default
2015-04-16T23:44:48.935Z,1429227888.935 [Default] Running Loop=1
2015-04-16T23:44:48.936Z,1429227888.936 [Default](INFO): Aggregate::initialize Default
2015-04-16T23:44:48.936Z,1429227888.936 [Default:B.GoToSurface] Running Loop=1
2015-04-16T23:44:48.936Z,1429227888.936 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-04-16T23:44:48.936Z,1429227888.936 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-04-16T23:44:48.936Z,1429227888.936 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-04-16T23:44:48.937Z,1429227888.937 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-04-16T23:44:48.937Z,1429227888.937 [Default:StartClock] Running Loop=1
2015-04-16T23:44:48.937Z,1429227888.937 [Default:StartClock](INFO): Aggregate::initialize Default:StartClock
2015-04-16T23:44:48.937Z,1429227888.937 [Default:StartClock:A] Running Loop=1
2015-04-16T23:44:48.938Z,1429227888.938 [Default:CheckIn] Running Loop=1
2015-04-16T23:44:48.938Z,1429227888.938 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-04-16T23:44:48.938Z,1429227888.938 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-04-16T23:44:48.938Z,1429227888.938 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-04-16T23:44:48.938Z,1429227888.938 [Default:CheckIn:Read_GPS] Running Loop=1
2015-04-16T23:44:48.939Z,1429227888.939 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-04-16T23:44:48.941Z,1429227888.941 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-04-16T23:44:48.954Z,1429227888.954 [Default:StartClock:A] Stopped
2015-04-16T23:44:48.955Z,1429227888.955 [Default:StartClock](INFO): Completed Default:StartClock
2015-04-16T23:44:48.955Z,1429227888.955 [Default:StartClock] Stopped
2015-04-16T23:44:48.955Z,1429227888.955 [Default:StartClock](INFO): Aggregate::uninitialize Default:StartClock
2015-04-16T23:44:49.355Z,1429227889.355 [Default:WaitAtTheSurface] Running Loop=1
2015-04-16T23:44:49.356Z,1429227889.356 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2015-04-16T23:44:49.356Z,1429227889.356 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-04-16T23:44:49.356Z,1429227889.356 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2015-04-16T23:44:49.830Z,1429227889.830 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-04-16T23:44:53.200Z,1429227893.200 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:44:53.200Z,1429227893.200 [Aanderaa_O2] Communications Fault, FailCount= 1
2015-04-16T23:44:53.200Z,1429227893.200 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:44:53.605Z,1429227893.605 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:44:53.725Z,1429227893.725 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:44:54.961Z,1429227894.961 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-16T23:44:54.961Z,1429227894.961 [Aanderaa_O2] No Fault, FailCount= 1
2015-04-16T23:45:05.163Z,1429227905.163 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:45:05.163Z,1429227905.163 [Aanderaa_O2] Communications Fault, FailCount= 2
2015-04-16T23:45:05.163Z,1429227905.163 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:45:05.600Z,1429227905.600 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:45:05.725Z,1429227905.725 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:45:06.909Z,1429227906.909 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-16T23:45:06.910Z,1429227906.910 [Aanderaa_O2] No Fault, FailCount= 2
2015-04-16T23:45:16.958Z,1429227916.958 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:45:16.958Z,1429227916.958 [Aanderaa_O2] Communications Fault, FailCount= 3
2015-04-16T23:45:16.958Z,1429227916.958 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:45:17.402Z,1429227917.402 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:45:17.402Z,1429227917.402 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2015-04-16T23:45:17.522Z,1429227917.522 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:45:53.284Z,1429227953.284 [BPC1](ERROR): Failed to parse message.
2015-04-16T23:45:53.285Z,1429227953.285 [BPC1](ERROR): Failed to parse bank B battery data
2015-04-16T23:45:53.285Z,1429227953.285 [BPC1] Data Fault, FailCount= 1
2015-04-16T23:45:53.285Z,1429227953.285 [BPC1](ERROR): Data Fault
2015-04-16T23:45:53.341Z,1429227953.341 [CBIT](ERROR): Data Fault in component: BPC1
2015-04-16T23:45:54.541Z,1429227954.541 [CBIT](INFO): Clearing failed state for component BPC1
2015-04-16T23:45:54.541Z,1429227954.541 [BPC1] No Fault, FailCount= 1
2015-04-16T23:46:38.086Z,1429227998.086 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-04-16T23:46:38.086Z,1429227998.086 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-16T23:46:38.087Z,1429227998.087 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-04-16T23:46:38.089Z,1429227998.089 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-04-16T23:46:38.089Z,1429227998.089 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-04-16T23:46:38.520Z,1429227998.520 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 1.820444 min
2015-04-16T23:46:38.522Z,1429227998.522 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-04-16T23:46:38.522Z,1429227998.522 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-16T23:46:38.522Z,1429227998.522 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-04-16T23:46:38.522Z,1429227998.522 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-16T23:46:55.892Z,1429228015.892 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2015-04-16T23:47:38.774Z,1429228058.774 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-16T23:47:38.774Z,1429228058.774 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2015-04-16T23:47:38.774Z,1429228058.774 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-04-16T23:47:38.776Z,1429228058.776 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-16T23:47:38.776Z,1429228058.776 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2015-04-16T23:47:38.777Z,1429228058.777 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2015-04-16T23:47:38.789Z,1429228058.789 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-04-16T23:47:38.789Z,1429228058.789 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2015-04-16T23:47:39.198Z,1429228059.198 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-04-16T23:47:39.198Z,1429228059.198 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2015-04-16T23:47:39.198Z,1429228059.198 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2015-04-16T23:47:39.199Z,1429228059.199 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2015-04-16T23:47:39.630Z,1429228059.630 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-04-16T23:47:39.630Z,1429228059.630 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-04-16T23:47:40.055Z,1429228060.055 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:47:40.491Z,1429228060.491 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:47:40.905Z,1429228060.905 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:47:41.357Z,1429228061.357 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:47:41.785Z,1429228061.785 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:47:42.187Z,1429228062.187 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:47:46.970Z,1429228066.970 [CBIT](INFO): Clearing failed count for component Aanderaa_O2
2015-04-16T23:47:46.970Z,1429228066.970 [Aanderaa_O2] No Fault, FailCount= 3
2015-04-16T23:47:57.487Z,1429228077.487 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:47:57.487Z,1429228077.487 [Aanderaa_O2] Communications Fault, FailCount= 1
2015-04-16T23:47:57.487Z,1429228077.487 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:47:57.911Z,1429228077.911 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:47:58.031Z,1429228078.031 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:47:59.309Z,1429228079.309 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-16T23:47:59.309Z,1429228079.309 [Aanderaa_O2] No Fault, FailCount= 1
2015-04-16T23:48:00.136Z,1429228080.136 [BPC1](DEBUG): Received data from all battery sticks
2015-04-16T23:48:09.371Z,1429228089.371 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:48:09.371Z,1429228089.371 [Aanderaa_O2] Communications Fault, FailCount= 2
2015-04-16T23:48:09.371Z,1429228089.371 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:48:09.777Z,1429228089.777 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:48:09.901Z,1429228089.901 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:48:11.121Z,1429228091.121 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-16T23:48:11.121Z,1429228091.121 [Aanderaa_O2] No Fault, FailCount= 2
2015-04-16T23:48:21.324Z,1429228101.324 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:48:21.324Z,1429228101.324 [Aanderaa_O2] Communications Fault, FailCount= 3
2015-04-16T23:48:21.324Z,1429228101.324 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:48:21.728Z,1429228101.728 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:48:21.729Z,1429228101.729 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2015-04-16T23:48:21.847Z,1429228101.847 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:49:49.080Z,1429228189.080 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-04-16T23:44:48.9Z
2015-04-16T23:49:49.080Z,1429228189.080 [Default:CheckIn:Read_GPS] Stopped
2015-04-16T23:49:49.080Z,1429228189.080 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-04-16T23:49:49.520Z,1429228189.520 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-04-16T23:50:19.628Z,1429228219.628 [NAL9602](FAULT): Queried for signal strength and failed to receive proper response. no error
2015-04-16T23:50:19.710Z,1429228219.710 [NAL9602](ERROR): received:
+CSQ:0
OK
2015-04-16T23:50:19.710Z,1429228219.710 [NAL9602] Data Fault, FailCount= 1
2015-04-16T23:50:19.710Z,1429228219.710 [NAL9602](ERROR): Data Fault
2015-04-16T23:50:19.739Z,1429228219.739 [CBIT](ERROR): Data Fault in component: NAL9602
2015-04-16T23:50:20.128Z,1429228220.128 [NAL9602](INFO): Powering down
2015-04-16T23:50:20.982Z,1429228220.982 [CBIT](INFO): Clearing failed state for component NAL9602
2015-04-16T23:50:20.982Z,1429228220.982 [NAL9602] No Fault, FailCount= 1
2015-04-16T23:50:25.131Z,1429228225.131 [NAL9602](INFO): Powering up NAL9602
2015-04-16T23:50:36.263Z,1429228236.263 [NAL9602](INFO): NAL9602 initialized
2015-04-16T23:50:39.747Z,1429228239.747 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-16T23:50:39.747Z,1429228239.747 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2015-04-16T23:50:39.747Z,1429228239.747 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-04-16T23:50:39.749Z,1429228239.749 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-16T23:50:39.749Z,1429228239.749 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2015-04-16T23:50:39.749Z,1429228239.749 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2015-04-16T23:50:39.785Z,1429228239.785 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-04-16T23:50:39.786Z,1429228239.786 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2015-04-16T23:50:40.245Z,1429228240.245 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-04-16T23:50:40.245Z,1429228240.245 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2015-04-16T23:50:40.245Z,1429228240.245 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2015-04-16T23:50:40.245Z,1429228240.245 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2015-04-16T23:50:40.654Z,1429228240.654 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-04-16T23:50:40.654Z,1429228240.654 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-04-16T23:50:41.351Z,1429228241.351 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:50:41.778Z,1429228241.778 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:50:42.205Z,1429228242.205 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:50:42.630Z,1429228242.630 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:50:43.054Z,1429228243.054 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:50:43.447Z,1429228243.447 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-04-16T23:50:51.697Z,1429228251.697 [CBIT](INFO): Clearing failed count for component Aanderaa_O2
2015-04-16T23:50:51.697Z,1429228251.697 [Aanderaa_O2] No Fault, FailCount= 3
2015-04-16T23:51:01.771Z,1429228261.771 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:51:01.771Z,1429228261.771 [Aanderaa_O2] Communications Fault, FailCount= 1
2015-04-16T23:51:01.771Z,1429228261.771 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:51:02.209Z,1429228262.209 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:51:02.328Z,1429228262.328 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:51:03.612Z,1429228263.612 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-16T23:51:03.612Z,1429228263.612 [Aanderaa_O2] No Fault, FailCount= 1
2015-04-16T23:51:13.704Z,1429228273.704 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:51:13.704Z,1429228273.704 [Aanderaa_O2] Communications Fault, FailCount= 2
2015-04-16T23:51:13.704Z,1429228273.704 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:51:14.115Z,1429228274.115 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:51:14.239Z,1429228274.239 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:51:15.543Z,1429228275.543 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-16T23:51:15.543Z,1429228275.543 [Aanderaa_O2] No Fault, FailCount= 2
2015-04-16T23:51:25.607Z,1429228285.607 [Aanderaa_O2](FAULT): Timed out starting
2015-04-16T23:51:25.607Z,1429228285.607 [Aanderaa_O2] Communications Fault, FailCount= 3
2015-04-16T23:51:25.607Z,1429228285.607 [Aanderaa_O2](ERROR): Communications Fault
2015-04-16T23:51:26.049Z,1429228286.049 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-16T23:51:26.049Z,1429228286.049 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2015-04-16T23:51:26.169Z,1429228286.169 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:51:38.346Z,1429228298.346 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-04-16T23:51:38.346Z,1429228298.346 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-16T23:51:38.346Z,1429228298.346 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-04-16T23:51:38.346Z,1429228298.346 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-04-16T23:51:38.347Z,1429228298.347 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-04-16T23:51:38.809Z,1429228298.809 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 6.824740 min
2015-04-16T23:51:38.809Z,1429228298.809 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-04-16T23:51:38.809Z,1429228298.809 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-16T23:51:38.809Z,1429228298.809 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-04-16T23:51:38.809Z,1429228298.809 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-16T23:51:54.963Z,1429228314.963 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-04-16T23:51:54.963Z,1429228314.963 [NAL9602] Data Fault, FailCount= 2
2015-04-16T23:51:54.964Z,1429228314.964 [NAL9602](ERROR): Data Fault
2015-04-16T23:51:55.025Z,1429228315.025 [CBIT](ERROR): Data Fault in component: NAL9602
2015-04-16T23:51:55.364Z,1429228315.364 [NAL9602](INFO): Powering down
2015-04-16T23:51:56.211Z,1429228316.211 [CBIT](INFO): Clearing failed state for component NAL9602
2015-04-16T23:51:56.212Z,1429228316.212 [NAL9602] No Fault, FailCount= 2
2015-04-16T23:52:00.673Z,1429228320.673 [NAL9602](INFO): Powering up NAL9602
2015-04-16T23:52:11.561Z,1429228331.561 [NAL9602](INFO): NAL9602 initialized
2015-04-16T23:52:41.267Z,1429228361.267 [CBIT](INFO): Clearing failed count for component DVL_micro
2015-04-16T23:52:41.267Z,1429228361.267 [DVL_micro] No Fault, FailCount= 5
2015-04-16T23:52:41.663Z,1429228361.663 [DVL_micro](INFO): Initializing
2015-04-16T23:52:52.392Z,1429228372.392 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-16T23:52:52.392Z,1429228372.392 [DVL_micro] Communications Fault, FailCount= 1
2015-04-16T23:52:52.393Z,1429228372.393 [DVL_micro](ERROR): Communications Fault
2015-04-16T23:52:52.476Z,1429228372.476 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-16T23:52:52.932Z,1429228372.932 [DVL_micro](INFO): uninitialize:Powering down
2015-04-16T23:52:53.374Z,1429228373.374 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-16T23:52:53.846Z,1429228373.846 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-04-16T23:52:53.846Z,1429228373.846 [DVL_micro] No Fault, FailCount= 1
2015-04-16T23:52:54.209Z,1429228374.209 [DVL_micro](INFO): Initializing
2015-04-16T23:53:04.659Z,1429228384.659 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-16T23:53:04.659Z,1429228384.659 [DVL_micro] Communications Fault, FailCount= 2
2015-04-16T23:53:04.660Z,1429228384.660 [DVL_micro](ERROR): Communications Fault
2015-04-16T23:53:04.685Z,1429228384.685 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-16T23:53:05.155Z,1429228385.155 [DVL_micro](INFO): uninitialize:Powering down
2015-04-16T23:53:05.629Z,1429228385.629 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-16T23:53:06.092Z,1429228386.092 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-04-16T23:53:06.092Z,1429228386.092 [DVL_micro] No Fault, FailCount= 2
2015-04-16T23:53:06.482Z,1429228386.482 [DVL_micro](INFO): Initializing
2015-04-16T23:53:09.437Z,1429228389.437 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=52234, MT Status=1, MTMSN=70
2015-04-16T23:53:09.486Z,1429228389.486 [NAL9602](INFO): Sent 18 bytes from file Logs/20150415T162149/Courier0108.lzma
2015-04-16T23:53:09.486Z,1429228389.486 [NAL9602](INFO): Packets left to send: 0
2015-04-16T23:53:09.488Z,1429228389.488 [NAL9602](INFO): Stored copy of sent data in Logs/20150415T162149/Courier0108.lzma.parts/0000.sbd
2015-04-16T23:53:09.488Z,1429228389.488 [NAL9602](INFO): Completed sending Logs/20150415T162149/Courier0108.lzma
2015-04-16T23:53:10.007Z,1429228390.007 [NAL9602](INFO): Received command:restart app
2015-04-16T23:53:10.043Z,1429228390.043 [CommandLine](IMPORTANT): got command restart application
2015-04-16T23:53:11.051Z,1429228391.051 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-16T23:53:11.051Z,1429228391.051 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.092Z,1429228391.092 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2015-04-16T23:53:11.092Z,1429228391.092 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.092Z,1429228391.092 [CommandLine](INFO): Join timeout helper Thread ID is 912
2015-04-16T23:53:11.094Z,1429228391.094 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-04-16T23:53:11.094Z,1429228391.094 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.094Z,1429228391.094 [NavChartDb](INFO): Join timeout helper Thread ID is 913
2015-04-16T23:53:11.260Z,1429228391.260 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-16T23:53:11.260Z,1429228391.260 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.272Z,1429228391.272 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-04-16T23:53:11.272Z,1429228391.272 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.272Z,1429228391.272 [Radio_Surface](INFO): Join timeout helper Thread ID is 914
2015-04-16T23:53:11.320Z,1429228391.320 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-16T23:53:11.320Z,1429228391.320 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.332Z,1429228391.332 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2015-04-16T23:53:11.332Z,1429228391.332 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.333Z,1429228391.333 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 915
2015-04-16T23:53:11.497Z,1429228391.497 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-16T23:53:11.497Z,1429228391.497 [WetLabsBB2FL](INFO): Powering down
2015-04-16T23:53:11.498Z,1429228391.498 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.500Z,1429228391.500 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2015-04-16T23:53:11.500Z,1429228391.500 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.501Z,1429228391.501 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 916
2015-04-16T23:53:11.677Z,1429228391.677 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-16T23:53:11.677Z,1429228391.677 [CTD_NeilBrown](INFO): Powering down
2015-04-16T23:53:11.678Z,1429228391.678 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.682Z,1429228391.682 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-04-16T23:53:11.682Z,1429228391.682 [logger ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.682Z,1429228391.682 [logger](INFO): Join timeout helper Thread ID is 917
2015-04-16T23:53:11.721Z,1429228391.721 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-16T23:53:11.721Z,1429228391.721 [logger ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.722Z,1429228391.722 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-04-16T23:53:11.723Z,1429228391.723 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.723Z,1429228391.723 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-04-16T23:53:11.723Z,1429228391.723 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:11.723Z,1429228391.723 [controlThread](INFO): Join timeout helper Thread ID is 918
2015-04-16T23:53:11.747Z,1429228391.747 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-16T23:53:11.747Z,1429228391.747 [controlThread](DEBUG): Uninitializing ControlThread
2015-04-16T23:53:11.748Z,1429228391.748 [Aanderaa_O2](INFO): Powering down
2015-04-16T23:53:11.750Z,1429228391.750 [AHRS_sp3003D](INFO): Powering down
2015-04-16T23:53:11.909Z,1429228391.909 [DVL_micro](INFO): uninitialize:Powering down
2015-04-16T23:53:11.910Z,1429228391.910 [NAL9602](INFO): Powering down
2015-04-16T23:53:11.912Z,1429228391.912 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-04-16T23:53:11.913Z,1429228391.913 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-04-16T23:53:11.914Z,1429228391.914 [Default] Stopped
2015-04-16T23:53:11.914Z,1429228391.914 [Default](INFO): Aggregate::uninitialize Default
2015-04-16T23:53:11.914Z,1429228391.914 [Default:B.GoToSurface] Stopped
2015-04-16T23:53:11.914Z,1429228391.914 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-04-16T23:53:11.914Z,1429228391.914 [Default:CheckIn] Stopped
2015-04-16T23:53:11.914Z,1429228391.914 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-04-16T23:53:11.914Z,1429228391.914 [Default:CheckIn:A.SetSpeed] Stopped
2015-04-16T23:53:11.914Z,1429228391.914 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-04-16T23:53:11.914Z,1429228391.914 [Default:CheckIn:Read_Iridium] Stopped
2015-04-16T23:53:11.914Z,1429228391.914 [Default:WaitAtTheSurface] Stopped
2015-04-16T23:53:11.915Z,1429228391.915 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2015-04-16T23:53:11.915Z,1429228391.915 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped
2015-04-16T23:53:11.915Z,1429228391.915 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2015-04-16T23:53:11.918Z,1429228391.918 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-04-16T23:53:11.919Z,1429228391.919 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-04-16T23:53:11.919Z,1429228391.919 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-04-16T23:53:11.919Z,1429228391.919 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-04-16T23:53:11.919Z,1429228391.919 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-04-16T23:53:11.919Z,1429228391.919 [BuoyancyServo](INFO): Powering down
2015-04-16T23:53:11.933Z,1429228391.933 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-04-16T23:53:11.933Z,1429228391.933 [ElevatorServo](INFO): Powering down
2015-04-16T23:53:11.934Z,1429228391.934 [MassServo](DEBUG): Uninitialize Mass Servo.
2015-04-16T23:53:11.934Z,1429228391.934 [MassServo](INFO): Powering down
2015-04-16T23:53:11.935Z,1429228391.935 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-04-16T23:53:11.935Z,1429228391.935 [RudderServo](INFO): Powering down
2015-04-16T23:53:11.936Z,1429228391.936 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-04-16T23:53:11.936Z,1429228391.936 [ThrusterServo](INFO): Powering down
2015-04-16T23:53:11.937Z,1429228391.937 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-04-16T23:53:11.937Z,1429228391.937 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-04-16T23:53:11.938Z,1429228391.938 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-04-16T23:53:11.970Z,1429228391.970 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:12.029Z,1429228392.029 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:12.034Z,1429228392.034 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:12.096Z,1429228392.096 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:12.142Z,1429228392.142 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-04-16T23:53:12.185Z,1429228392.185 [logger ThreadHandler](INFO): Thread cancelled.