2015-04-15T16:11:18.861Z,1429114278.861 [Supervisor](DEBUG): Initializing supervisor.
2015-04-15T16:11:18.867Z,1429114278.867 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-04-15T16:11:18.868Z,1429114278.868 [SyncHandler](INFO): Protected caller Thread ID is 768
2015-04-15T16:11:18.868Z,1429114278.868 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-04-15T16:11:18.871Z,1429114278.871 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-04-15T16:11:18.872Z,1429114278.872 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 769
2015-04-15T16:11:18.874Z,1429114278.874 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-04-15T16:11:18.886Z,1429114278.886 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-04-15T16:11:18.891Z,1429114278.891 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-04-15T16:11:18.892Z,1429114278.892 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 770
2015-04-15T16:11:18.892Z,1429114278.892 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-04-15T16:11:18.895Z,1429114278.895 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-04-15T16:11:18.896Z,1429114278.896 [logger ThreadHandler](INFO): Protected caller Thread ID is 771
2015-04-15T16:11:18.898Z,1429114278.898 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-04-15T16:11:18.898Z,1429114278.898 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-04-15T16:11:18.901Z,1429114278.901 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-04-15T16:11:19.314Z,1429114279.314 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-04-15T16:11:19.314Z,1429114279.314 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-04-15T16:11:19.513Z,1429114279.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-04-15T16:11:19.514Z,1429114279.514 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-04-15T16:11:19.641Z,1429114279.641 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-04-15T16:11:19.642Z,1429114279.642 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-04-15T16:11:19.784Z,1429114279.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-04-15T16:11:19.785Z,1429114279.785 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-04-15T16:11:19.885Z,1429114279.885 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-04-15T16:11:20.074Z,1429114280.074 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-04-15T16:11:20.075Z,1429114280.075 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-04-15T16:11:20.173Z,1429114280.173 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-04-15T16:11:20.173Z,1429114280.173 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-04-15T16:11:20.421Z,1429114280.421 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-04-15T16:11:20.423Z,1429114280.423 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-04-15T16:11:20.856Z,1429114280.856 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-04-15T16:11:20.856Z,1429114280.856 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-04-15T16:11:21.220Z,1429114281.220 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-04-15T16:11:21.221Z,1429114281.221 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-04-15T16:11:21.830Z,1429114281.830 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-04-15T16:11:21.831Z,1429114281.831 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-04-15T16:11:22.100Z,1429114282.100 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-04-15T16:11:22.101Z,1429114282.101 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-04-15T16:11:22.341Z,1429114282.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-04-15T16:11:22.342Z,1429114282.342 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-04-15T16:11:23.704Z,1429114283.704 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-04-15T16:11:23.705Z,1429114283.705 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-04-15T16:11:24.011Z,1429114284.011 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-04-15T16:11:24.013Z,1429114284.013 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2015-04-15T16:11:24.016Z,1429114284.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2015-04-15T16:11:24.135Z,1429114284.135 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2015-04-15T16:11:24.277Z,1429114284.277 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2015-04-15T16:11:24.389Z,1429114284.389 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2015-04-15T16:11:24.518Z,1429114284.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2015-04-15T16:11:24.626Z,1429114284.626 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2015-04-15T16:11:24.778Z,1429114284.778 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2015-04-15T16:11:24.962Z,1429114284.962 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2015-04-15T16:11:25.078Z,1429114285.078 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2015-04-15T16:11:25.183Z,1429114285.183 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2015-04-15T16:11:25.277Z,1429114285.277 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2015-04-15T16:11:25.387Z,1429114285.387 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2015-04-15T16:11:25.525Z,1429114285.525 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2015-04-15T16:11:25.803Z,1429114285.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-04-15T16:11:25.804Z,1429114285.804 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2015-04-15T16:11:25.808Z,1429114285.808 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-04-15T16:11:25.894Z,1429114285.894 [VerticalControl](DEBUG): Construct VerticalControl.
2015-04-15T16:11:26.037Z,1429114286.037 [VerticalControl] Loaded
2015-04-15T16:11:26.037Z,1429114286.037 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-04-15T16:11:26.038Z,1429114286.038 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-04-15T16:11:26.129Z,1429114286.129 [HorizontalControl] Loaded
2015-04-15T16:11:26.129Z,1429114286.129 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-04-15T16:11:26.130Z,1429114286.130 [SpeedControl](DEBUG): Construct SpeedControl.
2015-04-15T16:11:26.136Z,1429114286.136 [SpeedControl] Loaded
2015-04-15T16:11:26.137Z,1429114286.137 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-04-15T16:11:26.137Z,1429114286.137 [LoopControl](DEBUG): Construct LoopControl.
2015-04-15T16:11:26.138Z,1429114286.138 [LoopControl] Loaded
2015-04-15T16:11:26.138Z,1429114286.138 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-04-15T16:11:26.139Z,1429114286.139 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-04-15T16:11:26.139Z,1429114286.139 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-04-15T16:11:26.324Z,1429114286.324 [SBIT](DEBUG): Construct Startup Built In Test.
2015-04-15T16:11:26.336Z,1429114286.336 [SBIT] Loaded
2015-04-15T16:11:26.337Z,1429114286.337 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-04-15T16:11:26.337Z,1429114286.337 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-04-15T16:11:26.373Z,1429114286.373 [IBIT] Loaded
2015-04-15T16:11:26.373Z,1429114286.373 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-04-15T16:11:26.376Z,1429114286.376 [CBIT](DEBUG): Construct Continuous Built In Test.
2015-04-15T16:11:26.544Z,1429114286.544 [CBIT] Loaded
2015-04-15T16:11:26.544Z,1429114286.544 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-04-15T16:11:26.544Z,1429114286.544 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-04-15T16:11:26.545Z,1429114286.545 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-04-15T16:11:26.579Z,1429114286.579 [DepthRateCalculator] Loaded
2015-04-15T16:11:26.580Z,1429114286.580 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-04-15T16:11:26.586Z,1429114286.586 [PitchRateCalculator] Loaded
2015-04-15T16:11:26.586Z,1429114286.586 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-04-15T16:11:26.603Z,1429114286.603 [SpeedCalculator] Loaded
2015-04-15T16:11:26.604Z,1429114286.604 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-04-15T16:11:26.625Z,1429114286.625 [TempGradientCalculator] Loaded
2015-04-15T16:11:26.626Z,1429114286.626 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-04-15T16:11:26.632Z,1429114286.632 [YawRateCalculator] Loaded
2015-04-15T16:11:26.632Z,1429114286.632 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-04-15T16:11:26.632Z,1429114286.632 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-04-15T16:11:26.633Z,1429114286.633 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-04-15T16:11:26.734Z,1429114286.734 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-04-15T16:11:26.734Z,1429114286.734 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-04-15T16:11:27.067Z,1429114287.067 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-04-15T16:11:27.067Z,1429114287.067 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-04-15T16:11:27.193Z,1429114287.193 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-04-15T16:11:27.193Z,1429114287.193 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-04-15T16:11:27.247Z,1429114287.247 [DeadReckonUsingSpeedCalculator] Loaded
2015-04-15T16:11:27.248Z,1429114287.248 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2015-04-15T16:11:27.266Z,1429114287.266 [NavChart] Loaded
2015-04-15T16:11:27.266Z,1429114287.266 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-04-15T16:11:27.272Z,1429114287.272 [UniversalFixResidualReporter] Loaded
2015-04-15T16:11:27.272Z,1429114287.272 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-04-15T16:11:27.276Z,1429114287.276 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-04-15T16:11:27.277Z,1429114287.277 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-04-15T16:11:27.290Z,1429114287.290 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-04-15T16:11:27.290Z,1429114287.290 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-04-15T16:11:27.586Z,1429114287.586 [Aanderaa_O2] Loaded
2015-04-15T16:11:27.587Z,1429114287.587 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2015-04-15T16:11:27.680Z,1429114287.680 [CTD_NeilBrown] Loaded
2015-04-15T16:11:27.680Z,1429114287.680 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2015-04-15T16:11:27.685Z,1429114287.685 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 405764E0
2015-04-15T16:11:27.685Z,1429114287.685 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 856
2015-04-15T16:11:27.699Z,1429114287.699 [ISUS] Loaded
2015-04-15T16:11:27.700Z,1429114287.700 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2015-04-15T16:11:27.720Z,1429114287.720 [PAR_Licor] Loaded
2015-04-15T16:11:27.720Z,1429114287.720 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2015-04-15T16:11:27.778Z,1429114287.778 [WetLabsBB2FL] Loaded
2015-04-15T16:11:27.779Z,1429114287.779 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2015-04-15T16:11:27.781Z,1429114287.781 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 405A64E0
2015-04-15T16:11:27.782Z,1429114287.782 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 857
2015-04-15T16:11:27.782Z,1429114287.782 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-04-15T16:11:27.783Z,1429114287.783 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-04-15T16:11:28.592Z,1429114288.592 [AHRS_sp3003D] Loaded
2015-04-15T16:11:28.593Z,1429114288.593 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2015-04-15T16:11:28.772Z,1429114288.772 [DataOverHttps] Loaded
2015-04-15T16:11:28.773Z,1429114288.773 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-04-15T16:11:28.792Z,1429114288.792 [Depth_Keller] Loaded
2015-04-15T16:11:28.792Z,1429114288.792 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-04-15T16:11:28.798Z,1429114288.798 [DropWeight] Loaded
2015-04-15T16:11:28.798Z,1429114288.798 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2015-04-15T16:11:28.963Z,1429114288.963 [DVL_micro] Loaded
2015-04-15T16:11:28.963Z,1429114288.963 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2015-04-15T16:11:29.081Z,1429114289.081 [NAL9602] Loaded
2015-04-15T16:11:29.081Z,1429114289.081 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-04-15T16:11:29.132Z,1429114289.132 [Onboard] Loaded
2015-04-15T16:11:29.132Z,1429114289.132 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-04-15T16:11:29.140Z,1429114289.140 [Radio_Surface] Loaded
2015-04-15T16:11:29.140Z,1429114289.140 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-04-15T16:11:29.143Z,1429114289.143 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 407F64E0
2015-04-15T16:11:29.144Z,1429114289.144 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 858
2015-04-15T16:11:31.422Z,1429114291.422 [BPC1] Loaded
2015-04-15T16:11:31.422Z,1429114291.422 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-04-15T16:11:31.422Z,1429114291.422 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-04-15T16:11:31.423Z,1429114291.423 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-04-15T16:11:31.577Z,1429114291.577 [BuoyancyServo] Loaded
2015-04-15T16:11:31.577Z,1429114291.577 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-04-15T16:11:31.591Z,1429114291.591 [ElevatorServo] Loaded
2015-04-15T16:11:31.591Z,1429114291.591 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-04-15T16:11:31.608Z,1429114291.608 [MassServo] Loaded
2015-04-15T16:11:31.608Z,1429114291.608 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2015-04-15T16:11:31.621Z,1429114291.621 [RudderServo] Loaded
2015-04-15T16:11:31.622Z,1429114291.622 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-04-15T16:11:31.634Z,1429114291.634 [ThrusterServo] Loaded
2015-04-15T16:11:31.634Z,1429114291.634 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-04-15T16:11:31.635Z,1429114291.635 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-04-15T16:11:31.636Z,1429114291.636 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-04-15T16:11:31.803Z,1429114291.803 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-04-15T16:11:31.804Z,1429114291.804 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-04-15T16:11:31.849Z,1429114291.849 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-04-15T16:11:31.851Z,1429114291.851 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-04-15T16:11:31.852Z,1429114291.852 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-04-15T16:11:31.859Z,1429114291.859 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-04-15T16:11:31.863Z,1429114291.863 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408A74E0
2015-04-15T16:11:31.864Z,1429114291.864 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 859
2015-04-15T16:11:31.868Z,1429114291.868 [Supervisor](INFO): Main Thread ID is 763
2015-04-15T16:11:31.869Z,1429114291.869 [Supervisor](DEBUG): Running supervisor.
2015-04-15T16:11:31.869Z,1429114291.869 [CommandLine ThreadHandler](INFO): Handler Thread ID is 860
2015-04-15T16:11:31.876Z,1429114291.876 [controlThread ThreadHandler](INFO): Handler Thread ID is 861
2015-04-15T16:11:31.876Z,1429114291.876 [controlThread](DEBUG): Initializing ControlThread
2015-04-15T16:11:31.877Z,1429114291.877 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-04-15T16:11:31.879Z,1429114291.879 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-04-15T16:11:31.880Z,1429114291.880 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-04-15T16:11:31.880Z,1429114291.880 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-04-15T16:11:31.881Z,1429114291.881 [SBIT](INFO): Initialize SBIT Component.
2015-04-15T16:11:31.881Z,1429114291.881 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12068
2015-04-15T16:11:31.881Z,1429114291.881 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-04-15T16:11:31.882Z,1429114291.882 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-04-15T16:11:31.882Z,1429114291.882 [IBIT](INFO): Initialize IBIT Component.
2015-04-15T16:11:31.883Z,1429114291.883 [CBIT](DEBUG): Initialize CBIT Component.
2015-04-15T16:11:31.883Z,1429114291.883 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2015-04-15T16:11:31.883Z,1429114291.883 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-04-15T16:11:31.888Z,1429114291.888 [logger ThreadHandler](INFO): Handler Thread ID is 862
2015-04-15T16:11:31.908Z,1429114291.908 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-04-15T16:11:31.908Z,1429114291.908 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-04-15T16:11:31.908Z,1429114291.908 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-04-15T16:11:31.909Z,1429114291.909 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-04-15T16:11:31.909Z,1429114291.909 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-04-15T16:11:31.910Z,1429114291.910 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-04-15T16:11:31.910Z,1429114291.910 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-04-15T16:11:31.911Z,1429114291.911 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-04-15T16:11:31.911Z,1429114291.911 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-04-15T16:11:31.928Z,1429114291.928 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-04-15T16:11:31.948Z,1429114291.948 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 863
2015-04-15T16:11:31.949Z,1429114291.949 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2015-04-15T16:11:31.956Z,1429114291.956 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 865
2015-04-15T16:11:31.957Z,1429114291.957 [WetLabsBB2FL](INFO): Powering down
2015-04-15T16:11:31.976Z,1429114291.976 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2015-04-15T16:11:32.004Z,1429114292.004 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 866
2015-04-15T16:11:32.010Z,1429114292.010 [Radio_Surface](INFO): Powering up
2015-04-15T16:11:32.020Z,1429114292.020 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-04-15T16:11:32.025Z,1429114292.025 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 867
2015-04-15T16:11:32.042Z,1429114292.042 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-04-15T16:11:32.044Z,1429114292.044 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-04-15T16:11:32.044Z,1429114292.044 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-04-15T16:11:32.045Z,1429114292.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-04-15T16:11:32.045Z,1429114292.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-04-15T16:11:32.045Z,1429114292.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-04-15T16:11:32.045Z,1429114292.045 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-04-15T16:11:32.046Z,1429114292.046 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-04-15T16:11:32.046Z,1429114292.046 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-04-15T16:11:32.053Z,1429114292.053 [MissionManager](DEBUG):
2015-04-15T16:11:32.068Z,1429114292.068 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-04-15T16:11:32.120Z,1429114292.120 [CTD_NeilBrown](DEBUG): CTD uart timeout: serial timeout
2015-04-15T16:11:32.120Z,1429114292.120 [CTD_NeilBrown](ERROR): Could not get real or simulated CTD data. startTime.elapsed() = 0.143524
2015-04-15T16:11:32.189Z,1429114292.189 [MissionManager](INFO): DefineArg Default.TimeMissionWasStarted = 0.000000 h
2015-04-15T16:11:32.209Z,1429114292.209 [MissionManager](INFO): DefineArg Default.ElapsedSinceMissionWasStarted = 0.000000 h
2015-04-15T16:11:32.213Z,1429114292.213 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2015-04-15T16:11:32.258Z,1429114292.258 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-04-15T16:11:32.280Z,1429114292.280 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-04-15T16:11:32.309Z,1429114292.309 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-04-15T16:11:32.315Z,1429114292.315 [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-15T16:11:32.329Z,1429114292.329 [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-15T16:11:32.597Z,1429114292.597 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2015-04-15T16:11:33.016Z,1429114293.016 [DVL_micro](INFO): Initializing
2015-04-15T16:11:33.264Z,1429114293.264 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:11:33.402Z,1429114293.402 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-04-15T16:11:33.410Z,1429114293.410 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-04-15T16:11:33.432Z,1429114293.432 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-04-15T16:11:33.438Z,1429114293.438 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-04-15T16:11:33.448Z,1429114293.448 [MassServo](DEBUG): Initializing EZServoServo.
2015-04-15T16:11:33.454Z,1429114293.454 [MassServo](DEBUG): Initializing MassServo.
2015-04-15T16:11:33.476Z,1429114293.476 [RudderServo](DEBUG): Initializing EZServoServo.
2015-04-15T16:11:33.486Z,1429114293.486 [RudderServo](DEBUG): Initializing RudderServo.
2015-04-15T16:11:33.504Z,1429114293.504 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-04-15T16:11:33.510Z,1429114293.510 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-04-15T16:11:33.847Z,1429114293.847 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:11:34.318Z,1429114294.318 [NAL9602](INFO): Powering up NAL9602
2015-04-15T16:11:34.355Z,1429114294.355 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:11:35.029Z,1429114295.029 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:11:35.445Z,1429114295.445 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:11:35.858Z,1429114295.858 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:11:42.734Z,1429114302.734 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:11:42.734Z,1429114302.734 [Aanderaa_O2] Communications Fault, FailCount= 1
2015-04-15T16:11:42.734Z,1429114302.734 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:11:43.157Z,1429114303.157 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:11:43.281Z,1429114303.281 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:11:44.180Z,1429114304.180 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-15T16:11:44.180Z,1429114304.180 [DVL_micro] Communications Fault, FailCount= 1
2015-04-15T16:11:44.181Z,1429114304.181 [DVL_micro](ERROR): Communications Fault
2015-04-15T16:11:44.226Z,1429114304.226 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-15T16:11:44.672Z,1429114304.672 [DVL_micro](INFO): uninitialize:Powering down
2015-04-15T16:11:44.734Z,1429114304.734 [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,FFFD%32
$B13,0A,0000%31
$B14,0A,FFFD%34
$B15,0A,0000%37
$B16,0A,0000%34
$B17,0A,0000%35
$B18,0A,FF4B%4C
$S,01,40FD,02,00,04,5E%22
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,02A8,03,0001,08,0B8D,09,3EA8,0A,FFFB,0B,0004%4A
$B11,0C,0001,0D,0063,0E,0056,0F,16A2,10,190C,11,FFFF,12,FFFF%4C
$B11,13,2436,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%38
$B11,1A,0031,1B,458C,1C,00C9%31
$B12,02,000A,01,02A8,03,0001,08,0B8E,09,3EA3,0A,FFFC,0B,0004%42
$B12,0C,0001,0D,0063,0E,0055,0F,1691,10,191E,11,FFFF,12,FFFF%30
$B12,13,2643,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%3B
$B12,1A,0031,1B,458C,1C,0103%4A
$B13,02,000A,01,02A8,03,0001,08,0B96,09,3E93,0A,0000,0B,0004%4C
$B13,0C,0001,0D,005B,0E,0057,0F,16FC,10,196F,11,FFFF,12,FFFF%48
$B13,13,24BD,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%39
$B13,1A,0031,1B,458F,1C,0152%4A
$B14,02,000A,01,02A8,03,0001,08,0B90,09,3E91,0A,0000,0B,0004%4F
$B14,0C,0001,0D,005A,0E,0054,0F,164D,10,18E1,11,FFFF,12,FFFF%3F
$B14,13,26AC,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%38
$B14,1A,0031,1B,458C,1C,014A%3A
$B15,02,000A,01,02A8,03,0001,08,0B91,09,3E89,0A,0000,0B,0004%46
$B15,0C,0001,0D,005A,0E,0056,0F,16B2,10,1941,11,FFFF,12,FFFF%4C
$B15,13,2661,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%3C
$B15,1A,0031,1B,458C,1C,0114%4B
$B16,02,000A,01,02A8,03,0001,08,0B8F,09,3E9A,0A,0000,0B,0003%4D
$B16,0C,0001,0D,005A,0E,0056,0F,16AA,10,1960,11,FFFF,12,FFFF%3C
$B16,13,3638,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%32
$B16,1A,0031,1B,458F,1C,015E%38
$B17,02,000A,01,02A8,03,0001,08,0B8D,09,3EAE,0A,0000,0B,0004%35
$B17,0C,0001,0D,0063,0E,0056,0F,169E,10,194C,11,FFFF,12,FFFF%41
$B17,13,3598,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%3A
$B17,1A,0031,1B,
2015-04-15T16:11:44.735Z,1429114304.735 [BPC1](ERROR): Failed to parse bank B battery data
2015-04-15T16:11:44.735Z,1429114304.735 [BPC1] Data Fault, FailCount= 1
2015-04-15T16:11:44.735Z,1429114304.735 [BPC1](ERROR): Data Fault
2015-04-15T16:11:44.797Z,1429114304.797 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-15T16:11:44.797Z,1429114304.797 [Aanderaa_O2] No Fault, FailCount= 1
2015-04-15T16:11:44.798Z,1429114304.798 [CBIT](ERROR): Data Fault in component: BPC1
2015-04-15T16:11:45.180Z,1429114305.180 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-15T16:11:45.647Z,1429114305.647 [NAL9602](INFO): NAL9602 initialized
2015-04-15T16:11:45.703Z,1429114305.703 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-04-15T16:11:45.703Z,1429114305.703 [DVL_micro] No Fault, FailCount= 1
2015-04-15T16:11:46.090Z,1429114306.090 [DVL_micro](INFO): Initializing
2015-04-15T16:11:46.235Z,1429114306.235 [CBIT](INFO): Clearing failed state for component BPC1
2015-04-15T16:11:46.235Z,1429114306.235 [BPC1] No Fault, FailCount= 1
2015-04-15T16:11:47.799Z,1429114307.799 [SBIT](IMPORTANT): Beginning Startup BIT
2015-04-15T16:11:47.806Z,1429114307.806 [CBIT](IMPORTANT): Beginning GF scan
2015-04-15T16:11:55.102Z,1429114315.102 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:11:55.102Z,1429114315.102 [Aanderaa_O2] Communications Fault, FailCount= 2
2015-04-15T16:11:55.102Z,1429114315.102 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:11:55.620Z,1429114315.620 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:11:55.777Z,1429114315.777 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:11:57.132Z,1429114317.132 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-15T16:11:57.133Z,1429114317.133 [DVL_micro] Communications Fault, FailCount= 2
2015-04-15T16:11:57.133Z,1429114317.133 [DVL_micro](ERROR): Communications Fault
2015-04-15T16:11:57.299Z,1429114317.299 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-15T16:11:57.299Z,1429114317.299 [Aanderaa_O2] No Fault, FailCount= 2
2015-04-15T16:11:57.299Z,1429114317.299 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-15T16:11:57.736Z,1429114317.736 [DVL_micro](INFO): uninitialize:Powering down
2015-04-15T16:11:58.270Z,1429114318.270 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-15T16:11:58.950Z,1429114318.950 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-04-15T16:11:58.950Z,1429114318.950 [DVL_micro] No Fault, FailCount= 2
2015-04-15T16:11:59.303Z,1429114319.303 [DVL_micro](INFO): Initializing
2015-04-15T16:12:01.180Z,1429114321.180 [SBIT](FAULT): Mass: EXPECTED:0.005000 ACTUAL:0.004814
2015-04-15T16:12:07.555Z,1429114327.555 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:12:07.555Z,1429114327.555 [Aanderaa_O2] Communications Fault, FailCount= 3
2015-04-15T16:12:07.555Z,1429114327.555 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:12:08.087Z,1429114328.087 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:12:08.087Z,1429114328.087 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2015-04-15T16:12:08.212Z,1429114328.212 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:12:10.297Z,1429114330.297 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-15T16:12:10.297Z,1429114330.297 [DVL_micro] Communications Fault, FailCount= 3
2015-04-15T16:12:10.297Z,1429114330.297 [DVL_micro](ERROR): Communications Fault
2015-04-15T16:12:10.420Z,1429114330.420 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-15T16:12:10.840Z,1429114330.840 [DVL_micro](INFO): uninitialize:Powering down
2015-04-15T16:12:11.314Z,1429114331.314 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-15T16:12:11.892Z,1429114331.892 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-04-15T16:12:11.892Z,1429114331.892 [DVL_micro] No Fault, FailCount= 3
2015-04-15T16:12:12.274Z,1429114332.274 [DVL_micro](INFO): Initializing
2015-04-15T16:12:14.861Z,1429114334.861 [CBIT](IMPORTANT): No ground fault detected
2015-04-15T16:12:22.949Z,1429114342.949 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-15T16:12:22.949Z,1429114342.949 [DVL_micro] Communications Fault, FailCount= 4
2015-04-15T16:12:22.949Z,1429114342.949 [DVL_micro](ERROR): Communications Fault
2015-04-15T16:12:23.035Z,1429114343.035 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-15T16:12:23.476Z,1429114343.476 [DVL_micro](INFO): uninitialize:Powering down
2015-04-15T16:12:23.910Z,1429114343.910 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-15T16:12:24.387Z,1429114344.387 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-04-15T16:12:24.387Z,1429114344.387 [DVL_micro] No Fault, FailCount= 4
2015-04-15T16:12:24.826Z,1429114344.826 [DVL_micro](INFO): Initializing
2015-04-15T16:12:35.592Z,1429114355.592 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-04-15T16:12:35.592Z,1429114355.592 [DVL_micro] Communications Fault, FailCount= 5
2015-04-15T16:12:35.592Z,1429114355.592 [DVL_micro](ERROR): Communications Fault
2015-04-15T16:12:35.711Z,1429114355.711 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-04-15T16:12:35.711Z,1429114355.711 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2015-04-15T16:12:36.131Z,1429114356.131 [DVL_micro](INFO): uninitialize:Powering down
2015-04-15T16:12:36.219Z,1429114356.219 [CommandLine](FAULT): Scheduling is paused
2015-04-15T16:12:36.550Z,1429114356.550 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-04-15T16:12:42.096Z,1429114362.096 [SBIT](CRITICAL): SBIT FAILED
2015-04-15T16:12:42.525Z,1429114362.525 [MissionManager](IMPORTANT): Started mission Startup
2015-04-15T16:12:42.525Z,1429114362.525 [Startup] Running Loop=1
2015-04-15T16:12:42.526Z,1429114362.526 [Startup](INFO): Aggregate::initialize Startup
2015-04-15T16:12:42.526Z,1429114362.526 [Startup:A.GoToSurface] Running Loop=1
2015-04-15T16:12:42.526Z,1429114362.526 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-04-15T16:12:42.526Z,1429114362.526 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-04-15T16:12:42.527Z,1429114362.527 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-04-15T16:12:42.527Z,1429114362.527 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-04-15T16:12:42.533Z,1429114362.533 [Startup:StartupSatComms] Running Loop=1
2015-04-15T16:12:42.533Z,1429114362.533 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2015-04-15T16:12:42.533Z,1429114362.533 [Startup:StartupSatComms:A] Running Loop=1
2015-04-15T16:12:42.949Z,1429114362.949 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-04-15T16:13:42.880Z,1429114422.880 [Startup:StartupSatComms:A](INFO): Timed out from 2015-04-15T16:12:42.5Z
2015-04-15T16:13:42.880Z,1429114422.880 [Startup:StartupSatComms:A] Stopped
2015-04-15T16:13:42.880Z,1429114422.880 [Startup:StartupSatComms:B] Running Loop=1
2015-04-15T16:13:43.356Z,1429114423.356 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-04-15T16:14:01.675Z,1429114441.675 [BPC1](ERROR): Failed to receive battery data
2015-04-15T16:14:01.675Z,1429114441.675 [BPC1] Communications Fault, FailCount= 1
2015-04-15T16:14:01.675Z,1429114441.675 [BPC1](ERROR): Communications Fault
2015-04-15T16:14:01.726Z,1429114441.726 [CBIT](ERROR): Communications Fault in component: BPC1
2015-04-15T16:14:03.006Z,1429114443.006 [CBIT](INFO): Clearing failed state for component BPC1
2015-04-15T16:14:03.006Z,1429114443.006 [BPC1] No Fault, FailCount= 1
2015-04-15T16:14:32.137Z,1429114472.137 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-15T16:14:32.137Z,1429114472.137 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2015-04-15T16:14:32.137Z,1429114472.137 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-04-15T16:14:32.139Z,1429114472.139 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-15T16:14:32.139Z,1429114472.139 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2015-04-15T16:14:32.139Z,1429114472.139 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2015-04-15T16:14:32.183Z,1429114472.183 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-04-15T16:14:32.183Z,1429114472.183 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2015-04-15T16:14:32.584Z,1429114472.584 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-04-15T16:14:32.584Z,1429114472.584 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2015-04-15T16:14:32.584Z,1429114472.584 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2015-04-15T16:14:32.584Z,1429114472.584 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2015-04-15T16:14:32.974Z,1429114472.974 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-04-15T16:14:32.974Z,1429114472.974 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-04-15T16:14:33.397Z,1429114473.397 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:14:33.822Z,1429114473.822 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:14:34.248Z,1429114474.248 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:14:34.679Z,1429114474.679 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:14:35.085Z,1429114475.085 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:14:35.496Z,1429114475.496 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:14:37.972Z,1429114477.972 [CBIT](INFO): Clearing failed count for component Aanderaa_O2
2015-04-15T16:14:37.973Z,1429114477.973 [Aanderaa_O2] No Fault, FailCount= 3
2015-04-15T16:14:43.105Z,1429114483.105 [Startup:StartupSatComms:B](INFO): Timed out from 2015-04-15T16:13:42.9Z
2015-04-15T16:14:43.105Z,1429114483.105 [Startup:StartupSatComms:B] Stopped
2015-04-15T16:14:43.105Z,1429114483.105 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2015-04-15T16:14:43.105Z,1429114483.105 [Startup:StartupSatComms] Stopped
2015-04-15T16:14:43.105Z,1429114483.105 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2015-04-15T16:14:43.106Z,1429114483.106 [Startup](INFO): Completed Startup
2015-04-15T16:14:43.106Z,1429114483.106 [Startup] Stopped
2015-04-15T16:14:43.106Z,1429114483.106 [Startup](INFO): Aggregate::uninitialize Startup
2015-04-15T16:14:43.106Z,1429114483.106 [Startup:A.GoToSurface] Stopped
2015-04-15T16:14:43.106Z,1429114483.106 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-04-15T16:14:43.536Z,1429114483.536 [MissionManager](IMPORTANT): Started mission Default
2015-04-15T16:14:43.536Z,1429114483.536 [Default] Running Loop=1
2015-04-15T16:14:43.536Z,1429114483.536 [Default](INFO): Aggregate::initialize Default
2015-04-15T16:14:43.536Z,1429114483.536 [Default:B.GoToSurface] Running Loop=1
2015-04-15T16:14:43.536Z,1429114483.536 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2015-04-15T16:14:43.537Z,1429114483.537 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2015-04-15T16:14:43.537Z,1429114483.537 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2015-04-15T16:14:43.537Z,1429114483.537 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2015-04-15T16:14:43.537Z,1429114483.537 [Default:StartClock] Running Loop=1
2015-04-15T16:14:43.537Z,1429114483.537 [Default:StartClock](INFO): Aggregate::initialize Default:StartClock
2015-04-15T16:14:43.538Z,1429114483.538 [Default:StartClock:A] Running Loop=1
2015-04-15T16:14:43.538Z,1429114483.538 [Default:CheckIn] Running Loop=1
2015-04-15T16:14:43.538Z,1429114483.538 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn
2015-04-15T16:14:43.538Z,1429114483.538 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-04-15T16:14:43.538Z,1429114483.538 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize.
2015-04-15T16:14:43.539Z,1429114483.539 [Default:CheckIn:Read_GPS] Running Loop=1
2015-04-15T16:14:43.539Z,1429114483.539 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2015-04-15T16:14:43.541Z,1429114483.541 [Default:CheckIn:A.SetSpeed] Running Loop=1
2015-04-15T16:14:43.554Z,1429114483.554 [Default:StartClock:A] Stopped
2015-04-15T16:14:43.554Z,1429114483.554 [Default:StartClock](INFO): Completed Default:StartClock
2015-04-15T16:14:43.554Z,1429114483.554 [Default:StartClock] Stopped
2015-04-15T16:14:43.554Z,1429114483.554 [Default:StartClock](INFO): Aggregate::uninitialize Default:StartClock
2015-04-15T16:14:43.968Z,1429114483.968 [Default:WaitAtTheSurface] Running Loop=1
2015-04-15T16:14:43.969Z,1429114483.969 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2015-04-15T16:14:43.969Z,1429114483.969 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-04-15T16:14:43.969Z,1429114483.969 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize.
2015-04-15T16:14:44.394Z,1429114484.394 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1
2015-04-15T16:14:48.156Z,1429114488.156 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:14:48.156Z,1429114488.156 [Aanderaa_O2] Communications Fault, FailCount= 1
2015-04-15T16:14:48.156Z,1429114488.156 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:14:48.557Z,1429114488.557 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:14:48.681Z,1429114488.681 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:14:49.946Z,1429114489.946 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-15T16:14:49.946Z,1429114489.946 [Aanderaa_O2] No Fault, FailCount= 1
2015-04-15T16:15:00.108Z,1429114500.108 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:15:00.109Z,1429114500.109 [Aanderaa_O2] Communications Fault, FailCount= 2
2015-04-15T16:15:00.109Z,1429114500.109 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:15:00.504Z,1429114500.504 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:15:00.627Z,1429114500.627 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:15:01.854Z,1429114501.854 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-15T16:15:01.854Z,1429114501.854 [Aanderaa_O2] No Fault, FailCount= 2
2015-04-15T16:15:09.764Z,1429114509.764 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003706
2015-04-15T16:15:11.916Z,1429114511.916 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:15:11.916Z,1429114511.916 [Aanderaa_O2] Communications Fault, FailCount= 3
2015-04-15T16:15:11.916Z,1429114511.916 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:15:12.311Z,1429114512.311 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:15:12.312Z,1429114512.312 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2015-04-15T16:15:12.434Z,1429114512.434 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:16:27.368Z,1429114587.368 [BPC1](ERROR): Failed to parse message.
2015-04-15T16:16:27.368Z,1429114587.368 [BPC1](ERROR): Failed to parse bank A battery data
2015-04-15T16:16:27.369Z,1429114587.369 [BPC1] Data Fault, FailCount= 1
2015-04-15T16:16:27.369Z,1429114587.369 [BPC1](ERROR): Data Fault
2015-04-15T16:16:27.388Z,1429114587.388 [CBIT](ERROR): Data Fault in component: BPC1
2015-04-15T16:16:28.633Z,1429114588.633 [CBIT](INFO): Clearing failed state for component BPC1
2015-04-15T16:16:28.633Z,1429114588.633 [BPC1] No Fault, FailCount= 1
2015-04-15T16:16:32.483Z,1429114592.483 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-04-15T16:16:32.483Z,1429114592.483 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-15T16:16:32.483Z,1429114592.483 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-04-15T16:16:32.486Z,1429114592.486 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-04-15T16:16:32.486Z,1429114592.486 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-04-15T16:16:32.901Z,1429114592.901 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 1.815246 min
2015-04-15T16:16:32.903Z,1429114592.903 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-04-15T16:16:32.903Z,1429114592.903 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-15T16:16:32.904Z,1429114592.904 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-04-15T16:16:32.904Z,1429114592.904 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-15T16:16:49.327Z,1429114609.327 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2015-04-15T16:17:33.240Z,1429114653.240 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-15T16:17:33.240Z,1429114653.240 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2015-04-15T16:17:33.240Z,1429114653.240 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-04-15T16:17:33.242Z,1429114653.242 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-15T16:17:33.242Z,1429114653.242 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2015-04-15T16:17:33.242Z,1429114653.242 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2015-04-15T16:17:33.302Z,1429114653.302 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-04-15T16:17:33.302Z,1429114653.302 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2015-04-15T16:17:33.679Z,1429114653.679 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-04-15T16:17:33.679Z,1429114653.679 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2015-04-15T16:17:33.679Z,1429114653.679 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2015-04-15T16:17:33.679Z,1429114653.679 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2015-04-15T16:17:34.066Z,1429114654.066 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-04-15T16:17:34.066Z,1429114654.066 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-04-15T16:17:34.474Z,1429114654.474 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:17:34.897Z,1429114654.897 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:17:35.335Z,1429114655.335 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:17:35.769Z,1429114655.769 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:17:36.184Z,1429114656.184 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:17:36.590Z,1429114656.590 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:17:42.098Z,1429114662.098 [CBIT](INFO): Clearing failed count for component Aanderaa_O2
2015-04-15T16:17:42.098Z,1429114662.098 [Aanderaa_O2] No Fault, FailCount= 3
2015-04-15T16:17:52.289Z,1429114672.289 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:17:52.289Z,1429114672.289 [Aanderaa_O2] Communications Fault, FailCount= 1
2015-04-15T16:17:52.290Z,1429114672.290 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:17:52.687Z,1429114672.687 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:17:52.811Z,1429114672.811 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:17:54.043Z,1429114674.043 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-15T16:17:54.043Z,1429114674.043 [Aanderaa_O2] No Fault, FailCount= 1
2015-04-15T16:18:04.190Z,1429114684.190 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:18:04.190Z,1429114684.190 [Aanderaa_O2] Communications Fault, FailCount= 2
2015-04-15T16:18:04.190Z,1429114684.190 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:18:04.609Z,1429114684.609 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:18:04.733Z,1429114684.733 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:18:05.950Z,1429114685.950 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-15T16:18:05.950Z,1429114685.950 [Aanderaa_O2] No Fault, FailCount= 2
2015-04-15T16:18:16.114Z,1429114696.114 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:18:16.115Z,1429114696.115 [Aanderaa_O2] Communications Fault, FailCount= 3
2015-04-15T16:18:16.115Z,1429114696.115 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:18:16.557Z,1429114696.557 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:18:16.557Z,1429114696.557 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2015-04-15T16:18:16.679Z,1429114696.679 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:19:17.257Z,1429114757.257 [BPC1](DEBUG): Received data from all battery sticks
2015-04-15T16:19:28.375Z,1429114768.375 [BPC1](ERROR): A bank expecting battery number:1 and read number: uart read:X
$S,01,54C0,02,00,04,5E%56
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,0A,FFFB%37
$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,FF94%37
$S,01,5A66,02,00,04,5E%50
$C1,01,FF,02,00,03,FF,04,00,05,00,06,00,07,00%72
$B11,02,000A,01,02A8,03,0001,08,0B9F,09,3EA0,0A,FFFB,0B,FFFF%45
$B11,0C,0001,0D,0063,0E,0056,0F,1698,10,18E3,11,FFFF,12,FFFF%3A
$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,0B90,09,3E9C,0A,FFFC,0B,FFFF%3A
$B12,0C,0001,0D,0063,0E,0056,0F,16D3,10,194F,11,FFFF,12,FFFF%4A
$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,0B90,09,3E8D,0A,0000,0B,0002%3A
$B13,0C,0001,0D,005A,0E,0055,0F,1661,10,18F7,11,FFFF,12,FFFF%4B
$B13,13,4D94,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%44
$B13,1A,0031,1B,458B,1C,0086%46
$B14,02,000A,01,02A8,03,0001,08,0B90,09,3E89,0A,FFFD,0B,FFFF%40
$B14,0C,0001,0D,0059,0E,0053,0F,15F8,10,18EC,11,FFFF,12,FFFF%3F
$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,0B91,09,3E88,0A,0000,0B,0002%41
$B15,0C,0001,0D,005B,0E,0058,0F,174F,10,19A6,11,FFFF,12,FFFF%30
$B15,13,4632,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%3C
$B15,1A,0031,1B,458C,1C,00CB%4E
$B16,02,000A,01,02A8,03,0001,08,0B8D,09,3E9A,0A,0000,0B,0002%4E
$B16,0C,0001,0D,005A,0E,0055,0F,1689,10,1942,11,FFFF,12,FFFF%3E
$B16,13,51AE,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,0B92,09,3EAD,0A,0000,0B,0002%45
$B17,0C,0001,0D,0063,0E,0054,0F,1641,10,18F1,11,FFFF,12,FFFF%3B
$B17,13,A140,14,0BB8,15,41A0,16,00C0,17,0003,18,1A90,19,3840%49
$B17,1A,0031,1B,458B,1C,00A1%3C
$B18,02,000A,01,02A8,03,0001,08,0B8B,09,3E84,0A,FF9D,0B,FF96%42
$B18,0C,0001,0D,005D,0E,0057,0F,16F0,10,1938,11,0DE7,12,0CFC%3D
$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-15T16:19:28.375Z,1429114768.375 [BPC1](ERROR): Failed to parse bank A battery data
2015-04-15T16:19:28.375Z,1429114768.375 [BPC1] Data Fault, FailCount= 1
2015-04-15T16:19:28.375Z,1429114768.375 [BPC1](ERROR): Data Fault
2015-04-15T16:19:28.395Z,1429114768.395 [CBIT](ERROR): Data Fault in component: BPC1
2015-04-15T16:19:29.677Z,1429114769.677 [CBIT](INFO): Clearing failed state for component BPC1
2015-04-15T16:19:29.677Z,1429114769.677 [BPC1] No Fault, FailCount= 1
2015-04-15T16:19:43.732Z,1429114783.732 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-04-15T16:14:43.5Z
2015-04-15T16:19:43.732Z,1429114783.732 [Default:CheckIn:Read_GPS] Stopped
2015-04-15T16:19:43.732Z,1429114783.732 [Default:CheckIn:Read_Iridium] Running Loop=1
2015-04-15T16:19:44.178Z,1429114784.178 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2015-04-15T16:19:49.040Z,1429114789.040 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20150411T193644/Courier0032.lzma
2015-04-15T16:19:50.332Z,1429114790.332 [DataOverHttps](INFO): Moved sent file to Logs/20150411T193644/Courier0032.lzma.bak
2015-04-15T16:19:50.332Z,1429114790.332 [DataOverHttps](INFO): SBD MOMSN=3143987
2015-04-15T16:20:05.324Z,1429114805.324 [Depth_Keller](ERROR): Pressure reading out of range: 1830.495972 decibar
2015-04-15T16:20:11.304Z,1429114811.304 [Depth_Keller](ERROR): Pressure reading out of range: 1830.474121 decibar
2015-04-15T16:20:28.750Z,1429114828.750 [DataOverHttps](INFO): Sending 124 bytes from file Logs/20150415T161118/Courier0000.lzma
2015-04-15T16:20:29.596Z,1429114829.596 [DataOverHttps](INFO): Moved sent file to Logs/20150415T161118/Courier0000.lzma.bak
2015-04-15T16:20:29.597Z,1429114829.597 [DataOverHttps](INFO): SBD MOMSN=3144040
2015-04-15T16:20:34.254Z,1429114834.254 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-15T16:20:34.254Z,1429114834.254 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2015-04-15T16:20:34.254Z,1429114834.254 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2015-04-15T16:20:34.256Z,1429114834.256 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2015-04-15T16:20:34.256Z,1429114834.256 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2015-04-15T16:20:34.256Z,1429114834.256 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2015-04-15T16:20:34.269Z,1429114834.269 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2015-04-15T16:20:34.269Z,1429114834.269 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2015-04-15T16:20:34.761Z,1429114834.761 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2015-04-15T16:20:34.761Z,1429114834.761 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2015-04-15T16:20:34.762Z,1429114834.762 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2015-04-15T16:20:34.762Z,1429114834.762 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2015-04-15T16:20:35.175Z,1429114835.175 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-04-15T16:20:35.175Z,1429114835.175 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-04-15T16:20:35.583Z,1429114835.583 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 0 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:20:36.008Z,1429114836.008 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 1 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:20:39.265Z,1429114839.265 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 2 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:20:39.674Z,1429114839.674 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 3 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:20:40.120Z,1429114840.120 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 4 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:20:40.600Z,1429114840.600 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 5 cycles since last successful read, accepting data for 5 cycles.
2015-04-15T16:20:44.685Z,1429114844.685 [Depth_Keller](ERROR): Pressure reading out of range: 1354.932739 decibar
2015-04-15T16:20:46.130Z,1429114846.130 [CBIT](INFO): Clearing failed count for component Aanderaa_O2
2015-04-15T16:20:46.130Z,1429114846.130 [Aanderaa_O2] No Fault, FailCount= 3
2015-04-15T16:20:56.140Z,1429114856.140 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:20:56.140Z,1429114856.140 [Aanderaa_O2] Communications Fault, FailCount= 1
2015-04-15T16:20:56.141Z,1429114856.141 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:20:56.572Z,1429114856.572 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:20:56.692Z,1429114856.692 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:20:57.988Z,1429114857.988 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-15T16:20:57.988Z,1429114857.988 [Aanderaa_O2] No Fault, FailCount= 1
2015-04-15T16:21:07.366Z,1429114867.366 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20150415T161118/Courier0004.lzma
2015-04-15T16:21:08.216Z,1429114868.216 [DataOverHttps](INFO): Moved sent file to Logs/20150415T161118/Courier0004.lzma.bak
2015-04-15T16:21:08.217Z,1429114868.217 [DataOverHttps](INFO): SBD MOMSN=3144048
2015-04-15T16:21:08.311Z,1429114868.311 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:21:08.311Z,1429114868.311 [Aanderaa_O2] Communications Fault, FailCount= 2
2015-04-15T16:21:08.311Z,1429114868.311 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:21:08.925Z,1429114868.925 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:21:09.050Z,1429114869.050 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:21:13.147Z,1429114873.147 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-04-15T16:21:13.147Z,1429114873.147 [Aanderaa_O2] No Fault, FailCount= 2
2015-04-15T16:21:23.770Z,1429114883.770 [Aanderaa_O2](FAULT): Timed out starting
2015-04-15T16:21:23.770Z,1429114883.770 [Aanderaa_O2] Communications Fault, FailCount= 3
2015-04-15T16:21:23.771Z,1429114883.771 [Aanderaa_O2](ERROR): Communications Fault
2015-04-15T16:21:24.193Z,1429114884.193 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-04-15T16:21:24.193Z,1429114884.193 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2015-04-15T16:21:24.342Z,1429114884.342 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:21:34.802Z,1429114894.802 [Default:UpdateAndReportMinutesSinceMissionStarted] Running Loop=1
2015-04-15T16:21:34.802Z,1429114894.802 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::initialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-15T16:21:34.818Z,1429114894.818 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Running Loop=1
2015-04-15T16:21:34.819Z,1429114894.819 [Default:UpdateAndReportMinutesSinceMissionStarted:A] Stopped
2015-04-15T16:21:34.819Z,1429114894.819 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Running Loop=1
2015-04-15T16:21:35.222Z,1429114895.222 [Default:UpdateAndReportMinutesSinceMissionStarted:B](IMPORTANT): Default mission has been running for 6.806643 min
2015-04-15T16:21:35.222Z,1429114895.222 [Default:UpdateAndReportMinutesSinceMissionStarted:B] Stopped
2015-04-15T16:21:35.222Z,1429114895.222 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Completed Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-15T16:21:35.223Z,1429114895.223 [Default:UpdateAndReportMinutesSinceMissionStarted] Stopped
2015-04-15T16:21:35.223Z,1429114895.223 [Default:UpdateAndReportMinutesSinceMissionStarted](INFO): Aggregate::uninitialize Default:UpdateAndReportMinutesSinceMissionStarted
2015-04-15T16:21:41.383Z,1429114901.383 [DataOverHttps](IMPORTANT): SBD MTMSN=20150415T161939
2015-04-15T16:21:45.949Z,1429114905.949 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20150411T193644/Express0033.lzma
2015-04-15T16:21:45.961Z,1429114905.961 [DataOverHttps](INFO): Received command:restart app
2015-04-15T16:21:46.001Z,1429114906.001 [CommandLine](IMPORTANT): got command restart application
2015-04-15T16:21:47.008Z,1429114907.008 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-15T16:21:47.008Z,1429114907.008 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.036Z,1429114907.036 [DataOverHttps](INFO): Moved sent file to Logs/20150411T193644/Express0033.lzma.bak
2015-04-15T16:21:47.037Z,1429114907.037 [DataOverHttps](INFO): SBD MOMSN=3144054
2015-04-15T16:21:47.042Z,1429114907.042 [NAL9602](FAULT): GPS failed to acquire within timeout.
2015-04-15T16:21:47.042Z,1429114907.042 [NAL9602] Data Fault, FailCount= 1
2015-04-15T16:21:47.043Z,1429114907.043 [NAL9602](ERROR): Data Fault
2015-04-15T16:21:47.087Z,1429114907.087 [CBIT](ERROR): Data Fault in component: NAL9602
2015-04-15T16:21:47.109Z,1429114907.109 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2015-04-15T16:21:47.109Z,1429114907.109 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.110Z,1429114907.110 [CommandLine](INFO): Join timeout helper Thread ID is 946
2015-04-15T16:21:47.121Z,1429114907.121 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-04-15T16:21:47.122Z,1429114907.122 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.122Z,1429114907.122 [NavChartDb](INFO): Join timeout helper Thread ID is 947
2015-04-15T16:21:47.250Z,1429114907.250 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-15T16:21:47.250Z,1429114907.250 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.254Z,1429114907.254 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-04-15T16:21:47.254Z,1429114907.254 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.254Z,1429114907.254 [Radio_Surface](INFO): Join timeout helper Thread ID is 948
2015-04-15T16:21:47.506Z,1429114907.506 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-15T16:21:47.507Z,1429114907.507 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.514Z,1429114907.514 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2015-04-15T16:21:47.514Z,1429114907.514 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.515Z,1429114907.515 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 949
2015-04-15T16:21:47.525Z,1429114907.525 [NAL9602](INFO): Powering down
2015-04-15T16:21:47.714Z,1429114907.714 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-15T16:21:47.715Z,1429114907.715 [WetLabsBB2FL](INFO): Powering down
2015-04-15T16:21:47.715Z,1429114907.715 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.718Z,1429114907.718 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2015-04-15T16:21:47.718Z,1429114907.718 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.719Z,1429114907.719 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 950
2015-04-15T16:21:47.759Z,1429114907.759 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-15T16:21:47.759Z,1429114907.759 [CTD_NeilBrown](INFO): Powering down
2015-04-15T16:21:47.760Z,1429114907.760 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.761Z,1429114907.761 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-04-15T16:21:47.762Z,1429114907.762 [logger ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.762Z,1429114907.762 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-15T16:21:47.763Z,1429114907.763 [logger ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.763Z,1429114907.763 [logger](INFO): Join timeout helper Thread ID is 951
2015-04-15T16:21:47.764Z,1429114907.764 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-04-15T16:21:47.764Z,1429114907.764 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.764Z,1429114907.764 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-04-15T16:21:47.765Z,1429114907.765 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:47.765Z,1429114907.765 [controlThread](INFO): Join timeout helper Thread ID is 952
2015-04-15T16:21:48.016Z,1429114908.016 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-04-15T16:21:48.017Z,1429114908.017 [controlThread](DEBUG): Uninitializing ControlThread
2015-04-15T16:21:48.017Z,1429114908.017 [Aanderaa_O2](INFO): Powering down
2015-04-15T16:21:48.019Z,1429114908.019 [AHRS_sp3003D](INFO): Powering down
2015-04-15T16:21:48.109Z,1429114908.109 [DVL_micro](INFO): uninitialize:Powering down
2015-04-15T16:21:48.109Z,1429114908.109 [NAL9602](INFO): Powering down
2015-04-15T16:21:48.111Z,1429114908.111 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-04-15T16:21:48.113Z,1429114908.113 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-04-15T16:21:48.113Z,1429114908.113 [Default] Stopped
2015-04-15T16:21:48.113Z,1429114908.113 [Default](INFO): Aggregate::uninitialize Default
2015-04-15T16:21:48.113Z,1429114908.113 [Default:B.GoToSurface] Stopped
2015-04-15T16:21:48.113Z,1429114908.113 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2015-04-15T16:21:48.114Z,1429114908.114 [Default:CheckIn] Stopped
2015-04-15T16:21:48.114Z,1429114908.114 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn
2015-04-15T16:21:48.114Z,1429114908.114 [Default:CheckIn:A.SetSpeed] Stopped
2015-04-15T16:21:48.114Z,1429114908.114 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize.
2015-04-15T16:21:48.114Z,1429114908.114 [Default:CheckIn:Read_Iridium] Stopped
2015-04-15T16:21:48.114Z,1429114908.114 [Default:WaitAtTheSurface] Stopped
2015-04-15T16:21:48.114Z,1429114908.114 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2015-04-15T16:21:48.114Z,1429114908.114 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped
2015-04-15T16:21:48.114Z,1429114908.114 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2015-04-15T16:21:48.118Z,1429114908.118 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-04-15T16:21:48.118Z,1429114908.118 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-04-15T16:21:48.118Z,1429114908.118 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-04-15T16:21:48.119Z,1429114908.119 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-04-15T16:21:48.119Z,1429114908.119 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-04-15T16:21:48.120Z,1429114908.120 [BuoyancyServo](INFO): Powering down
2015-04-15T16:21:48.131Z,1429114908.131 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-04-15T16:21:48.131Z,1429114908.131 [ElevatorServo](INFO): Powering down
2015-04-15T16:21:48.132Z,1429114908.132 [MassServo](DEBUG): Uninitialize Mass Servo.
2015-04-15T16:21:48.132Z,1429114908.132 [MassServo](INFO): Powering down
2015-04-15T16:21:48.133Z,1429114908.133 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-04-15T16:21:48.133Z,1429114908.133 [RudderServo](INFO): Powering down
2015-04-15T16:21:48.134Z,1429114908.134 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-04-15T16:21:48.134Z,1429114908.134 [ThrusterServo](INFO): Powering down
2015-04-15T16:21:48.135Z,1429114908.135 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-04-15T16:21:48.135Z,1429114908.135 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-04-15T16:21:48.136Z,1429114908.136 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-04-15T16:21:48.168Z,1429114908.168 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:48.225Z,1429114908.225 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:48.230Z,1429114908.230 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:48.290Z,1429114908.290 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:48.337Z,1429114908.337 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-04-15T16:21:48.387Z,1429114908.387 [logger ThreadHandler](INFO): Thread cancelled.