2013-05-21T18:47:03.271Z,1369162023.271 [Supervisor](DEBUG): Initializing supervisor.
2013-05-21T18:47:03.277Z,1369162023.277 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-05-21T18:47:03.278Z,1369162023.278 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-05-21T18:47:03.281Z,1369162023.281 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-05-21T18:47:03.285Z,1369162023.285 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-05-21T18:47:03.295Z,1369162023.295 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-05-21T18:47:03.297Z,1369162023.297 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-05-21T18:47:03.298Z,1369162023.298 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-05-21T18:47:03.301Z,1369162023.301 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-05-21T18:47:03.302Z,1369162023.302 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-05-21T18:47:03.306Z,1369162023.306 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-05-21T18:47:03.622Z,1369162023.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-05-21T18:47:03.623Z,1369162023.623 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-05-21T18:47:03.840Z,1369162023.840 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-05-21T18:47:03.841Z,1369162023.841 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-05-21T18:47:03.937Z,1369162023.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-05-21T18:47:03.939Z,1369162023.939 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-05-21T18:47:04.166Z,1369162024.166 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-05-21T18:47:04.167Z,1369162024.167 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-05-21T18:47:04.322Z,1369162024.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-05-21T18:47:04.324Z,1369162024.324 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-05-21T18:47:04.593Z,1369162024.593 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-05-21T18:47:04.593Z,1369162024.593 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-05-21T18:47:04.784Z,1369162024.784 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-05-21T18:47:04.787Z,1369162024.787 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-05-21T18:47:05.076Z,1369162025.076 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-05-21T18:47:05.079Z,1369162025.079 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-05-21T18:47:05.189Z,1369162025.188 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-05-21T18:47:05.189Z,1369162025.189 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-05-21T18:47:05.653Z,1369162025.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-05-21T18:47:05.654Z,1369162025.654 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-05-21T18:47:05.894Z,1369162025.894 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-05-21T18:47:05.895Z,1369162025.895 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-05-21T18:47:05.994Z,1369162025.994 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-05-21T18:47:05.998Z,1369162025.998 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-05-21T18:47:06.116Z,1369162026.116 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-05-21T18:47:06.263Z,1369162026.263 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-05-21T18:47:06.361Z,1369162026.361 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-05-21T18:47:06.478Z,1369162026.478 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-05-21T18:47:06.591Z,1369162026.591 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-05-21T18:47:06.730Z,1369162026.730 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-05-21T18:47:06.839Z,1369162026.839 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-05-21T18:47:06.937Z,1369162026.937 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2013-05-21T18:47:06.964Z,1369162026.964 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-05-21T18:47:07.168Z,1369162027.168 [InternalSim] Loaded
2013-05-21T18:47:07.168Z,1369162027.168 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-05-21T18:47:07.169Z,1369162027.169 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-05-21T18:47:07.169Z,1369162027.170 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-05-21T18:47:07.255Z,1369162027.255 [SBIT](DEBUG): Construct Startup Built In Test.
2013-05-21T18:47:07.288Z,1369162027.288 [SBIT] Loaded
2013-05-21T18:47:07.289Z,1369162027.289 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-05-21T18:47:07.290Z,1369162027.290 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-05-21T18:47:07.323Z,1369162027.323 [IBIT] Loaded
2013-05-21T18:47:07.323Z,1369162027.323 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-05-21T18:47:07.327Z,1369162027.327 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-05-21T18:47:07.461Z,1369162027.461 [CBIT] Loaded
2013-05-21T18:47:07.465Z,1369162027.465 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-05-21T18:47:07.465Z,1369162027.466 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-05-21T18:47:07.466Z,1369162027.466 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-05-21T18:47:07.647Z,1369162027.647 [BuoyancyServo] Loaded
2013-05-21T18:47:07.647Z,1369162027.647 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-05-21T18:47:07.660Z,1369162027.659 [ElevatorServo] Loaded
2013-05-21T18:47:07.660Z,1369162027.660 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-05-21T18:47:07.676Z,1369162027.676 [MassServo] Loaded
2013-05-21T18:47:07.676Z,1369162027.676 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-05-21T18:47:07.688Z,1369162027.688 [RudderServo] Loaded
2013-05-21T18:47:07.689Z,1369162027.689 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-05-21T18:47:07.701Z,1369162027.701 [ThrusterServo] Loaded
2013-05-21T18:47:07.701Z,1369162027.701 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-05-21T18:47:07.701Z,1369162027.701 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-05-21T18:47:07.702Z,1369162027.702 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-05-21T18:47:07.738Z,1369162027.738 [DepthRateCalculator] Loaded
2013-05-21T18:47:07.739Z,1369162027.739 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-05-21T18:47:11.105Z,1369162031.105 [HFRadarModelCalc] Loaded
2013-05-21T18:47:11.105Z,1369162031.105 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-05-21T18:47:11.121Z,1369162031.121 [NavChart] Loaded
2013-05-21T18:47:11.122Z,1369162031.122 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-05-21T18:47:11.127Z,1369162031.128 [PitchRateCalculator] Loaded
2013-05-21T18:47:11.128Z,1369162031.128 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-05-21T18:47:11.143Z,1369162031.143 [SpeedCalculator] Loaded
2013-05-21T18:47:11.143Z,1369162031.143 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-05-21T18:47:11.159Z,1369162031.159 [TempGradientCalculator] Loaded
2013-05-21T18:47:11.160Z,1369162031.159 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-05-21T18:47:11.166Z,1369162031.165 [YawRateCalculator] Loaded
2013-05-21T18:47:11.166Z,1369162031.166 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-05-21T18:47:11.217Z,1369162031.217 [Navigation] Loaded
2013-05-21T18:47:11.217Z,1369162031.217 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-05-21T18:47:11.218Z,1369162031.218 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-05-21T18:47:11.219Z,1369162031.218 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-05-21T18:47:11.498Z,1369162031.499 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-05-21T18:47:11.499Z,1369162031.499 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-05-21T18:47:11.541Z,1369162031.542 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-05-21T18:47:11.542Z,1369162031.542 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-05-21T18:47:11.607Z,1369162031.607 [VerticalControl](DEBUG): Construct VerticalControl.
2013-05-21T18:47:11.715Z,1369162031.715 [VerticalControl] Loaded
2013-05-21T18:47:11.715Z,1369162031.715 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-05-21T18:47:11.716Z,1369162031.716 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-05-21T18:47:11.777Z,1369162031.777 [HorizontalControl] Loaded
2013-05-21T18:47:11.777Z,1369162031.777 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-05-21T18:47:11.778Z,1369162031.778 [SpeedControl](DEBUG): Construct SpeedControl.
2013-05-21T18:47:11.780Z,1369162031.780 [SpeedControl] Loaded
2013-05-21T18:47:11.780Z,1369162031.780 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-05-21T18:47:11.781Z,1369162031.781 [LoopControl](DEBUG): Construct LoopControl.
2013-05-21T18:47:11.781Z,1369162031.782 [LoopControl] Loaded
2013-05-21T18:47:11.782Z,1369162031.782 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-05-21T18:47:11.782Z,1369162031.782 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-05-21T18:47:11.783Z,1369162031.783 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-05-21T18:47:11.791Z,1369162031.791 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-05-21T18:47:11.796Z,1369162031.796 [AsyncPiEstimator] Loaded
2013-05-21T18:47:11.797Z,1369162031.797 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-05-21T18:47:11.801Z,1369162031.801 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0
2013-05-21T18:47:11.802Z,1369162031.802 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-05-21T18:47:11.803Z,1369162031.803 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-05-21T18:47:11.990Z,1369162031.990 [AHRS_sp3003D] Loaded
2013-05-21T18:47:11.990Z,1369162031.990 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-05-21T18:47:12.280Z,1369162032.280 [Batt_Ocean_Server] Loaded
2013-05-21T18:47:12.281Z,1369162032.281 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-05-21T18:47:12.295Z,1369162032.295 [Depth_Keller] Loaded
2013-05-21T18:47:12.295Z,1369162032.295 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-05-21T18:47:12.492Z,1369162032.492 [DVL_micro] Loaded
2013-05-21T18:47:12.493Z,1369162032.493 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-05-21T18:47:12.497Z,1369162032.497 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406B64E0
2013-05-21T18:47:12.590Z,1369162032.590 [NAL9602] Loaded
2013-05-21T18:47:12.590Z,1369162032.590 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-05-21T18:47:12.649Z,1369162032.649 [Onboard] Loaded
2013-05-21T18:47:12.650Z,1369162032.650 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-05-21T18:47:12.656Z,1369162032.657 [Radio_Freewave] Loaded
2013-05-21T18:47:12.657Z,1369162032.657 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-05-21T18:47:12.832Z,1369162032.832 [DAT] Loaded
2013-05-21T18:47:12.833Z,1369162032.833 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2013-05-21T18:47:12.833Z,1369162032.833 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-05-21T18:47:12.834Z,1369162032.834 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-05-21T18:47:12.938Z,1369162032.938 [CTD_NeilBrown] Loaded
2013-05-21T18:47:12.938Z,1369162032.938 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-05-21T18:47:12.941Z,1369162032.941 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407084E0
2013-05-21T18:47:12.974Z,1369162032.974 [WetLabsBB2FL] Loaded
2013-05-21T18:47:12.974Z,1369162032.974 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-05-21T18:47:12.977Z,1369162032.977 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407384E0
2013-05-21T18:47:12.978Z,1369162032.978 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-05-21T18:47:12.980Z,1369162032.980 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-05-21T18:47:12.981Z,1369162032.981 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-05-21T18:47:12.991Z,1369162032.991 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-05-21T18:47:12.993Z,1369162032.993 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407684E0
2013-05-21T18:47:12.998Z,1369162032.998 [Supervisor](DEBUG): Running supervisor.
2013-05-21T18:47:12.999Z,1369162032.999 [CommandLine](INFO): Thread ID is 750
2013-05-21T18:47:13.002Z,1369162033.002 [controlThread](INFO): Thread ID is 749
2013-05-21T18:47:13.002Z,1369162033.002 [controlThread](DEBUG): Initializing ControlThread
2013-05-21T18:47:13.002Z,1369162033.003 [CycleStarter](INFO): Thread ID is 748
2013-05-21T18:47:13.003Z,1369162033.003 [InternalSim](DEBUG): InternalSim initializing...
2013-05-21T18:47:13.117Z,1369162033.117 [logger](INFO): Thread ID is 751
2013-05-21T18:47:13.216Z,1369162033.216 [AsyncPiEstimator](INFO): Thread ID is 812
2013-05-21T18:47:13.216Z,1369162033.216 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-05-21T18:47:13.338Z,1369162033.338 [DVL_micro](INFO): Thread ID is 813
2013-05-21T18:47:13.377Z,1369162033.377 [CTD_NeilBrown](INFO): Thread ID is 814
2013-05-21T18:47:13.377Z,1369162033.377 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-05-21T18:47:13.384Z,1369162033.384 [SBIT](INFO): Initialize SBIT Component.
2013-05-21T18:47:13.384Z,1369162033.384 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:10367
2013-05-21T18:47:13.385Z,1369162033.385 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-05-21T18:47:13.390Z,1369162033.390 [WetLabsBB2FL](INFO): Thread ID is 815
2013-05-21T18:47:13.390Z,1369162033.390 [WetLabsBB2FL](INFO): Powering down
2013-05-21T18:47:13.410Z,1369162033.410 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-05-21T18:47:13.418Z,1369162033.418 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-05-21T18:47:13.418Z,1369162033.418 [IBIT](INFO): Initialize IBIT Component.
2013-05-21T18:47:13.419Z,1369162033.419 [CBIT](DEBUG): Initialize CBIT Component.
2013-05-21T18:47:13.419Z,1369162033.419 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2013-05-21T18:47:13.420Z,1369162033.420 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-05-21T18:47:13.421Z,1369162033.421 [NavChartDb](INFO): Thread ID is 816
2013-05-21T18:47:13.443Z,1369162033.443 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-05-21T18:47:13.443Z,1369162033.443 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-05-21T18:47:13.444Z,1369162033.444 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-05-21T18:47:13.444Z,1369162033.444 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-05-21T18:47:13.444Z,1369162033.444 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-05-21T18:47:13.445Z,1369162033.445 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-05-21T18:47:13.447Z,1369162033.447 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-05-21T18:47:13.447Z,1369162033.447 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-05-21T18:47:13.447Z,1369162033.447 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-05-21T18:47:13.448Z,1369162033.448 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-05-21T18:47:13.448Z,1369162033.448 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-05-21T18:47:13.445Z,1369162033.445 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-05-21T18:47:13.449Z,1369162033.449 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-05-21T18:47:13.450Z,1369162033.450 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-05-21T18:47:13.452Z,1369162033.452 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-05-21T18:47:13.468Z,1369162033.468 [DVL_micro](INFO): Initializing
2013-05-21T18:47:13.468Z,1369162033.468 [DVL_micro](INFO): start:Powering up
2013-05-21T18:47:13.453Z,1369162033.453 [Navigation](DEBUG): Initializing Navigation.
2013-05-21T18:47:13.470Z,1369162033.470 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-05-21T18:47:13.472Z,1369162033.472 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-05-21T18:47:13.472Z,1369162033.472 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-05-21T18:47:13.469Z,1369162033.469 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-21T18:47:13.478Z,1369162033.478 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-05-21T18:47:13.478Z,1369162033.478 [DVL_micro](INFO): Cycling power to configure device.
2013-05-21T18:47:14.870Z,1369162034.870 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout
2013-05-21T18:47:14.870Z,1369162034.870 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing
2013-05-21T18:47:14.870Z,1369162034.870 [Batt_Ocean_Server] Communications Fault, FailCount= 1
2013-05-21T18:47:14.870Z,1369162034.870 [Batt_Ocean_Server](ERROR): Communications Fault
2013-05-21T18:47:14.875Z,1369162034.875 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-05-21T18:47:14.906Z,1369162034.906 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-21T18:47:14.924Z,1369162034.924 [MissionManager](DEBUG):
2013-05-21T18:47:14.945Z,1369162034.945 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-05-21T18:47:15.020Z,1369162035.020 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-05-21T18:47:15.042Z,1369162035.042 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-05-21T18:47:15.045Z,1369162035.045 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-21T18:47:15.069Z,1369162035.069 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-05-21T18:47:15.072Z,1369162035.072 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-21T18:47:15.100Z,1369162035.100 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-05-21T18:47:15.113Z,1369162035.113 [Default:D.SetSpeed](DEBUG): Construct.
2013-05-21T18:47:15.116Z,1369162035.116 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-21T18:47:15.153Z,1369162035.152 [Default:F.Wait](DEBUG): Construct Wait.
2013-05-21T18:47:15.156Z,1369162035.156 [MissionManager](DEBUG):
400
400
Burn 300
Dropped drop weight due to communications timeout
5.0
1.0
5
2013-05-21T18:47:15.161Z,1369162035.161 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,NAL9602,Onboard,Radio_Freewave,DAT,Depth_Keller,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,
2013-05-21T18:47:15.206Z,1369162035.205 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-05-21T18:47:15.421Z,1369162035.421 [Radio_Freewave](INFO): Powering up
2013-05-21T18:47:15.446Z,1369162035.446 [DAT](INFO): Powering up
2013-05-21T18:47:15.447Z,1369162035.447 [DAT](DEBUG): Initializing DAT.
2013-05-21T18:47:15.510Z,1369162035.510 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-21T18:47:15.510Z,1369162035.510 [DVL_micro](INFO): Querying output modes
2013-05-21T18:47:15.510Z,1369162035.510 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606
2013-05-21T18:47:15.521Z,1369162035.521 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2013-05-21T18:47:15.522Z,1369162035.522 [DVL_micro](INFO): NQ1 output enabled
2013-05-21T18:47:15.522Z,1369162035.522 [DVL_micro](INFO): RSSI output enabled
2013-05-21T18:47:15.522Z,1369162035.522 [DVL_micro](INFO): ADCP output enabled
2013-05-21T18:47:15.522Z,1369162035.522 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525
2013-05-21T18:47:15.545Z,1369162035.545 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON
2013-05-21T18:47:15.551Z,1369162035.551 [DVL_micro](INFO): pause:Powering down
2013-05-21T18:47:15.665Z,1369162035.665 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-05-21T18:47:15.677Z,1369162035.677 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-05-21T18:47:15.696Z,1369162035.696 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-05-21T18:47:15.701Z,1369162035.701 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-05-21T18:47:15.708Z,1369162035.708 [MassServo](DEBUG): Initializing EZServoServo.
2013-05-21T18:47:15.714Z,1369162035.714 [MassServo](DEBUG): Initializing MassServo.
2013-05-21T18:47:15.719Z,1369162035.719 [RudderServo](DEBUG): Initializing EZServoServo.
2013-05-21T18:47:15.750Z,1369162035.750 [RudderServo](DEBUG): Initializing RudderServo.
2013-05-21T18:47:15.756Z,1369162035.756 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-05-21T18:47:15.762Z,1369162035.761 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-05-21T18:47:15.794Z,1369162035.793 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server
2013-05-21T18:47:15.794Z,1369162035.794 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server
2013-05-21T18:47:15.794Z,1369162035.794 [Batt_Ocean_Server] No Fault, FailCount= 1
2013-05-21T18:47:17.595Z,1369162037.595 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-05-21T18:47:17.647Z,1369162037.648 [NAL9602](INFO): Powering up NAL9602
2013-05-21T18:47:28.586Z,1369162048.586 [NAL9602](INFO): NAL9602 initialized
2013-05-21T18:47:28.971Z,1369162048.971 [SBIT](IMPORTANT): Beginning Startup BIT
2013-05-21T18:47:28.979Z,1369162048.979 [CBIT](IMPORTANT): Beginning GF scan
2013-05-21T18:47:35.423Z,1369162055.423 [DAT](INFO): Powering down
2013-05-21T18:47:55.852Z,1369162075.852 [CBIT](IMPORTANT): No ground fault detected
2013-05-21T18:48:22.332Z,1369162102.332 [SBIT](IMPORTANT): SBIT PASSED
2013-05-21T18:48:22.735Z,1369162102.735 [MissionManager](IMPORTANT): Started mission Startup
2013-05-21T18:48:22.735Z,1369162102.735 [Startup] Running Loop=1
2013-05-21T18:48:22.735Z,1369162102.735 [Startup](INFO): Aggregate::initialize Startup
2013-05-21T18:48:22.735Z,1369162102.736 [Startup:A.GoToSurface] Running Loop=1
2013-05-21T18:48:22.736Z,1369162102.736 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-21T18:48:22.762Z,1369162102.762 [Startup:StartupSatComms] Running Loop=1
2013-05-21T18:48:22.762Z,1369162102.763 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2013-05-21T18:48:22.763Z,1369162102.763 [Startup:StartupSatComms:A] Running Loop=1
2013-05-21T18:48:23.132Z,1369162103.132 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-05-21T18:49:23.131Z,1369162163.131 [Startup:StartupSatComms:A](INFO): Timed out from 2013-05-21T18:48:22.8Z
2013-05-21T18:49:23.131Z,1369162163.131 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2013-05-21T18:49:23.132Z,1369162163.132 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2013-05-21T18:49:23.132Z,1369162163.132 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2013-05-21T18:49:23.132Z,1369162163.132 [Startup:StartupSatComms:A] Stopped
2013-05-21T18:49:23.132Z,1369162163.132 [Startup:StartupSatComms:B] Running Loop=1
2013-05-21T18:49:23.530Z,1369162163.530 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-05-21T18:49:26.647Z,1369162166.647 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:49:30.956Z,1369162170.956 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:49:34.935Z,1369162174.935 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:49:39.247Z,1369162179.247 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:49:43.918Z,1369162183.918 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:49:48.631Z,1369162188.631 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:49:52.975Z,1369162192.975 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:49:57.685Z,1369162197.685 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:02.063Z,1369162202.063 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:10.379Z,1369162210.379 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:19.079Z,1369162219.079 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:23.459Z,1369162223.459 [Startup:StartupSatComms:B](INFO): Timed out from 2013-05-21T18:49:23.1Z
2013-05-21T18:50:23.460Z,1369162223.460 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2013-05-21T18:50:23.460Z,1369162223.460 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2013-05-21T18:50:23.460Z,1369162223.460 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2013-05-21T18:50:23.460Z,1369162223.460 [Startup:StartupSatComms:B] Stopped
2013-05-21T18:50:23.460Z,1369162223.460 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2013-05-21T18:50:23.460Z,1369162223.460 [Startup:StartupSatComms] Stopped
2013-05-21T18:50:23.460Z,1369162223.460 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2013-05-21T18:50:23.461Z,1369162223.461 [Startup](INFO): Completed Startup
2013-05-21T18:50:23.461Z,1369162223.461 [Startup] Stopped
2013-05-21T18:50:23.462Z,1369162223.462 [Startup](INFO): Aggregate::uninitialize Startup
2013-05-21T18:50:23.462Z,1369162223.462 [Startup:A.GoToSurface] Stopped
2013-05-21T18:50:23.462Z,1369162223.462 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-21T18:50:23.855Z,1369162223.855 [MissionManager](IMPORTANT): Started mission Default
2013-05-21T18:50:23.855Z,1369162223.855 [Default] Running Loop=1
2013-05-21T18:50:23.855Z,1369162223.855 [Default](INFO): Aggregate::initialize Default
2013-05-21T18:50:23.856Z,1369162223.856 [Default:D.SetSpeed] Running Loop=1
2013-05-21T18:50:23.856Z,1369162223.856 [Default:D.SetSpeed](DEBUG): Initialize.
2013-05-21T18:50:23.856Z,1369162223.856 [Default:E.GoToSurface] Running Loop=1
2013-05-21T18:50:23.856Z,1369162223.856 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-21T18:50:23.856Z,1369162223.856 [Default:Iridium] Running Loop=1
2013-05-21T18:50:23.856Z,1369162223.856 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2013-05-21T18:50:23.856Z,1369162223.856 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-21T18:50:23.856Z,1369162223.856 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2013-05-21T18:50:23.857Z,1369162223.857 [Default:Iridium:B.GoToSurface] Running Loop=1
2013-05-21T18:50:23.857Z,1369162223.857 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-21T18:50:23.857Z,1369162223.857 [Default:E.GoToSurface] Running Loop=1
2013-05-21T18:50:23.863Z,1369162223.863 [Default:D.SetSpeed] Running Loop=1
2013-05-21T18:50:23.868Z,1369162223.868 [Default:CallIridium] Running Loop=1
2013-05-21T18:50:23.868Z,1369162223.868 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2013-05-21T18:50:23.868Z,1369162223.868 [Default:CallIridium:A] Running Loop=1
2013-05-21T18:50:23.870Z,1369162223.870 [Default:CallIridium:A] Stopped
2013-05-21T18:50:23.871Z,1369162223.871 [Default:CallIridium:B] Running Loop=1
2013-05-21T18:50:23.871Z,1369162223.871 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2013-05-21T18:50:23.876Z,1369162223.876 [Default:Iridium:B.GoToSurface] Stopped
2013-05-21T18:50:23.876Z,1369162223.876 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-21T18:50:23.876Z,1369162223.876 [Default:Iridium:Read_Iridium] Running Loop=1
2013-05-21T18:50:23.876Z,1369162223.876 [Default:Iridium:A.SetSpeed] Running Loop=1
2013-05-21T18:50:23.882Z,1369162223.882 [Default:GPS] Running Loop=1
2013-05-21T18:50:23.882Z,1369162223.882 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2013-05-21T18:50:23.882Z,1369162223.882 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-21T18:50:23.882Z,1369162223.882 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2013-05-21T18:50:23.883Z,1369162223.883 [Default:GPS:B.GoToSurface] Running Loop=1
2013-05-21T18:50:23.883Z,1369162223.883 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-21T18:50:23.891Z,1369162223.891 [Default:GPS:B.GoToSurface] Stopped
2013-05-21T18:50:23.891Z,1369162223.891 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-21T18:50:23.891Z,1369162223.891 [Default:GPS:Read_GPS] Running Loop=1
2013-05-21T18:50:23.891Z,1369162223.891 [Default:GPS:A.SetSpeed] Running Loop=1
2013-05-21T18:50:24.261Z,1369162224.261 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2013-05-21T18:50:24.264Z,1369162224.264 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2013-05-21T18:50:27.366Z,1369162227.365 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:31.783Z,1369162231.783 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:36.119Z,1369162236.119 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:40.771Z,1369162240.771 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:45.150Z,1369162245.151 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:49.801Z,1369162249.801 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:54.559Z,1369162254.559 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:50:58.863Z,1369162258.862 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:03.561Z,1369162263.560 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:07.923Z,1369162267.923 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:12.607Z,1369162272.607 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:16.983Z,1369162276.983 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:21.719Z,1369162281.719 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:25.979Z,1369162285.979 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:30.691Z,1369162290.691 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:35.041Z,1369162295.041 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:39.353Z,1369162299.353 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:43.683Z,1369162303.682 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:47.691Z,1369162307.691 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:51.923Z,1369162311.923 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:51:56.631Z,1369162316.631 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:00.994Z,1369162320.994 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:05.665Z,1369162325.665 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:10.045Z,1369162330.046 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:14.471Z,1369162334.471 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:18.847Z,1369162338.847 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:23.711Z,1369162343.711 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:27.723Z,1369162347.723 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:31.635Z,1369162351.635 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:36.036Z,1369162356.036 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:40.368Z,1369162360.368 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:44.650Z,1369162364.651 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:48.615Z,1369162368.615 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:52.879Z,1369162372.879 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:52:57.593Z,1369162377.593 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:53:01.907Z,1369162381.907 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:53:06.231Z,1369162386.231 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:53:10.586Z,1369162390.586 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:53:14.953Z,1369162394.953 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:53:19.764Z,1369162399.764 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:53:24.507Z,1369162404.507 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:53:28.771Z,1369162408.771 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:53:33.521Z,1369162413.522 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:53:37.841Z,1369162417.841 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0
2013-05-21T18:53:42.155Z,1369162422.155 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0