2012-10-16T21:43:03.244Z,1350423783.244 [Supervisor](DEBUG): Initializing supervisor.
2012-10-16T21:43:03.250Z,1350423783.250 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2012-10-16T21:43:03.251Z,1350423783.251 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2012-10-16T21:43:03.254Z,1350423783.254 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2012-10-16T21:43:03.258Z,1350423783.258 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2012-10-16T21:43:03.269Z,1350423783.269 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2012-10-16T21:43:03.270Z,1350423783.270 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2012-10-16T21:43:03.271Z,1350423783.271 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread.
2012-10-16T21:43:03.272Z,1350423783.272 [Supervisor](INFO): Looking for Config files in directory: Config/
2012-10-16T21:43:03.275Z,1350423783.275 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2012-10-16T21:43:03.582Z,1350423783.582 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2012-10-16T21:43:03.584Z,1350423783.584 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2012-10-16T21:43:03.787Z,1350423783.787 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2012-10-16T21:43:03.788Z,1350423783.788 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2012-10-16T21:43:03.882Z,1350423783.882 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2012-10-16T21:43:03.884Z,1350423783.884 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2012-10-16T21:43:04.111Z,1350423784.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2012-10-16T21:43:04.112Z,1350423784.112 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2012-10-16T21:43:04.262Z,1350423784.262 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2012-10-16T21:43:04.264Z,1350423784.264 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2012-10-16T21:43:04.519Z,1350423784.519 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2012-10-16T21:43:04.520Z,1350423784.520 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2012-10-16T21:43:04.707Z,1350423784.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2012-10-16T21:43:04.709Z,1350423784.709 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2012-10-16T21:43:04.984Z,1350423784.984 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2012-10-16T21:43:04.986Z,1350423784.986 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2012-10-16T21:43:05.099Z,1350423785.099 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2012-10-16T21:43:05.100Z,1350423785.100 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2012-10-16T21:43:05.540Z,1350423785.540 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2012-10-16T21:43:05.540Z,1350423785.540 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2012-10-16T21:43:05.682Z,1350423785.682 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2012-10-16T21:43:05.683Z,1350423785.683 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2012-10-16T21:43:05.812Z,1350423785.812 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2012-10-16T21:43:05.817Z,1350423785.817 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2012-10-16T21:43:05.930Z,1350423785.930 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2012-10-16T21:43:06.076Z,1350423786.076 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2012-10-16T21:43:06.170Z,1350423786.170 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2012-10-16T21:43:06.283Z,1350423786.283 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2012-10-16T21:43:06.396Z,1350423786.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2012-10-16T21:43:06.528Z,1350423786.528 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2012-10-16T21:43:06.630Z,1350423786.630 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2012-10-16T21:43:06.726Z,1350423786.726 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2012-10-16T21:43:06.757Z,1350423786.757 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2012-10-16T21:43:06.950Z,1350423786.950 [InternalSim] Loaded
2012-10-16T21:43:06.950Z,1350423786.950 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2012-10-16T21:43:06.951Z,1350423786.951 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2012-10-16T21:43:06.951Z,1350423786.951 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2012-10-16T21:43:07.038Z,1350423787.038 [SBIT](DEBUG): Construct Startup Built In Test.
2012-10-16T21:43:07.052Z,1350423787.052 [SBIT] Loaded
2012-10-16T21:43:07.052Z,1350423787.053 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2012-10-16T21:43:07.053Z,1350423787.053 [IBIT](DEBUG): Construct Initiated Built In Test.
2012-10-16T21:43:07.087Z,1350423787.087 [IBIT] Loaded
2012-10-16T21:43:07.087Z,1350423787.088 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2012-10-16T21:43:07.091Z,1350423787.091 [CBIT](DEBUG): Construct CBIT Built In Test.
2012-10-16T21:43:07.225Z,1350423787.224 [CBIT] Loaded
2012-10-16T21:43:07.225Z,1350423787.225 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2012-10-16T21:43:07.225Z,1350423787.225 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2012-10-16T21:43:07.226Z,1350423787.226 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2012-10-16T21:43:07.397Z,1350423787.397 [BuoyancyServo] Loaded
2012-10-16T21:43:07.397Z,1350423787.397 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2012-10-16T21:43:07.407Z,1350423787.407 [ElevatorServo] Loaded
2012-10-16T21:43:07.407Z,1350423787.408 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2012-10-16T21:43:07.420Z,1350423787.420 [RudderServo] Loaded
2012-10-16T21:43:07.421Z,1350423787.421 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2012-10-16T21:43:07.437Z,1350423787.437 [ThrusterServo] Loaded
2012-10-16T21:43:07.437Z,1350423787.437 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2012-10-16T21:43:07.437Z,1350423787.437 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2012-10-16T21:43:07.438Z,1350423787.438 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2012-10-16T21:43:07.471Z,1350423787.471 [DepthRateCalculator] Loaded
2012-10-16T21:43:07.471Z,1350423787.471 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2012-10-16T21:43:11.801Z,1350423791.801 [HFRadarModelCalc] Loaded
2012-10-16T21:43:11.801Z,1350423791.801 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2012-10-16T21:43:11.818Z,1350423791.818 [NavChart] Loaded
2012-10-16T21:43:11.818Z,1350423791.818 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2012-10-16T21:43:11.824Z,1350423791.824 [PitchRateCalculator] Loaded
2012-10-16T21:43:11.825Z,1350423791.825 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2012-10-16T21:43:11.831Z,1350423791.831 [SpeedCalculator] Loaded
2012-10-16T21:43:11.831Z,1350423791.831 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2012-10-16T21:43:11.850Z,1350423791.850 [TempGradientCalculator] Loaded
2012-10-16T21:43:11.851Z,1350423791.851 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2012-10-16T21:43:11.857Z,1350423791.856 [YawRateCalculator] Loaded
2012-10-16T21:43:11.857Z,1350423791.857 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2012-10-16T21:43:11.877Z,1350423791.877 [Navigation] Loaded
2012-10-16T21:43:11.877Z,1350423791.877 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2012-10-16T21:43:11.878Z,1350423791.878 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2012-10-16T21:43:11.879Z,1350423791.879 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2012-10-16T21:43:12.164Z,1350423792.164 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2012-10-16T21:43:12.165Z,1350423792.165 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2012-10-16T21:43:12.208Z,1350423792.208 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2012-10-16T21:43:12.209Z,1350423792.209 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2012-10-16T21:43:12.273Z,1350423792.273 [VerticalControl](DEBUG): Construct VerticalControl.
2012-10-16T21:43:12.325Z,1350423792.325 [VerticalControl] Loaded
2012-10-16T21:43:12.325Z,1350423792.325 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2012-10-16T21:43:12.326Z,1350423792.326 [HorizontalControl](DEBUG): Construct HorizontalControl.
2012-10-16T21:43:12.352Z,1350423792.352 [HorizontalControl] Loaded
2012-10-16T21:43:12.352Z,1350423792.352 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2012-10-16T21:43:12.353Z,1350423792.353 [SpeedControl](DEBUG): Construct SpeedControl.
2012-10-16T21:43:12.355Z,1350423792.355 [SpeedControl] Loaded
2012-10-16T21:43:12.355Z,1350423792.355 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2012-10-16T21:43:12.356Z,1350423792.356 [LoopControl](DEBUG): Construct LoopControl.
2012-10-16T21:43:12.357Z,1350423792.357 [LoopControl] Loaded
2012-10-16T21:43:12.357Z,1350423792.357 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2012-10-16T21:43:12.357Z,1350423792.358 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2012-10-16T21:43:12.358Z,1350423792.358 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2012-10-16T21:43:12.366Z,1350423792.366 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2012-10-16T21:43:12.371Z,1350423792.371 [AsyncPiEstimator] Loaded
2012-10-16T21:43:12.371Z,1350423792.372 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2012-10-16T21:43:12.374Z,1350423792.374 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406724E0
2012-10-16T21:43:12.375Z,1350423792.375 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2012-10-16T21:43:12.376Z,1350423792.376 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2012-10-16T21:43:12.562Z,1350423792.562 [AHRS_sp3003D] Loaded
2012-10-16T21:43:12.563Z,1350423792.563 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2012-10-16T21:43:12.860Z,1350423792.860 [Batt_Ocean_Server] Loaded
2012-10-16T21:43:12.860Z,1350423792.860 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2012-10-16T21:43:12.877Z,1350423792.877 [Depth_Keller] Loaded
2012-10-16T21:43:12.877Z,1350423792.877 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2012-10-16T21:43:12.883Z,1350423792.883 [DropWeight] Loaded
2012-10-16T21:43:12.883Z,1350423792.883 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2012-10-16T21:43:13.020Z,1350423793.020 [DVL_micro] Loaded
2012-10-16T21:43:13.020Z,1350423793.020 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2012-10-16T21:43:13.022Z,1350423793.022 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406F34E0
2012-10-16T21:43:13.118Z,1350423793.118 [NAL9602] Loaded
2012-10-16T21:43:13.118Z,1350423793.118 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2012-10-16T21:43:13.174Z,1350423793.174 [Onboard] Loaded
2012-10-16T21:43:13.178Z,1350423793.178 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2012-10-16T21:43:13.185Z,1350423793.185 [Radio_Freewave] Loaded
2012-10-16T21:43:13.186Z,1350423793.186 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2012-10-16T21:43:13.187Z,1350423793.187 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2012-10-16T21:43:13.187Z,1350423793.187 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2012-10-16T21:43:13.290Z,1350423793.290 [CTD_NeilBrown] Loaded
2012-10-16T21:43:13.291Z,1350423793.291 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2012-10-16T21:43:13.295Z,1350423793.295 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4074B4E0
2012-10-16T21:43:13.305Z,1350423793.305 [PAR_Licor] Loaded
2012-10-16T21:43:13.305Z,1350423793.305 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2012-10-16T21:43:13.327Z,1350423793.327 [Turbulence_NPS] Loaded
2012-10-16T21:43:13.327Z,1350423793.327 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread.
2012-10-16T21:43:13.330Z,1350423793.330 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 4077B4E0
2012-10-16T21:43:13.365Z,1350423793.365 [WetLabsBB2FL] Loaded
2012-10-16T21:43:13.366Z,1350423793.366 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2012-10-16T21:43:13.370Z,1350423793.370 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AB4E0
2012-10-16T21:43:13.371Z,1350423793.371 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2012-10-16T21:43:13.373Z,1350423793.374 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2012-10-16T21:43:13.374Z,1350423793.374 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2012-10-16T21:43:13.385Z,1350423793.385 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2012-10-16T21:43:13.387Z,1350423793.387 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DB4E0
2012-10-16T21:43:13.391Z,1350423793.391 [Supervisor](DEBUG): Running supervisor.
2012-10-16T21:43:13.392Z,1350423793.392 [CommandLine](INFO): Thread ID is 749
2012-10-16T21:43:13.395Z,1350423793.395 [controlThread](INFO): Thread ID is 748
2012-10-16T21:43:13.395Z,1350423793.395 [controlThread](DEBUG): Initializing ControlThread
2012-10-16T21:43:13.396Z,1350423793.396 [CycleStarter](INFO): Thread ID is 747
2012-10-16T21:43:13.396Z,1350423793.397 [InternalSim](DEBUG): InternalSim initializing...
2012-10-16T21:43:13.503Z,1350423793.503 [AsyncPiEstimator](INFO): Thread ID is 810
2012-10-16T21:43:13.503Z,1350423793.503 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2012-10-16T21:43:13.576Z,1350423793.576 [DVL_micro](INFO): Thread ID is 811
2012-10-16T21:43:13.659Z,1350423793.659 [CTD_NeilBrown](INFO): Thread ID is 812
2012-10-16T21:43:13.660Z,1350423793.660 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2012-10-16T21:43:13.663Z,1350423793.663 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2012-10-16T21:43:13.703Z,1350423793.703 [Turbulence_NPS](INFO): Thread ID is 813
2012-10-16T21:43:13.703Z,1350423793.703 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS.
2012-10-16T21:43:13.704Z,1350423793.704 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1
2012-10-16T21:43:13.711Z,1350423793.711 [WetLabsBB2FL](INFO): Thread ID is 814
2012-10-16T21:43:13.712Z,1350423793.712 [WetLabsBB2FL](INFO): Powering down
2012-10-16T21:43:13.730Z,1350423793.730 [SBIT](INFO): Initialize SBIT Component.
2012-10-16T21:43:13.736Z,1350423793.736 [DVL_micro](INFO): Initializing
2012-10-16T21:43:13.737Z,1350423793.737 [DVL_micro](INFO): start:Powering up
2012-10-16T21:43:13.737Z,1350423793.737 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-16T21:43:13.738Z,1350423793.738 [DVL_micro](INFO): Cycling power to configure device.
2012-10-16T21:43:13.743Z,1350423793.743 [SBIT](IMPORTANT): Tethys CM Info:
$Rev: 9967
2012-10-16T21:43:13.743Z,1350423793.743 [IBIT](INFO): Initialize IBIT Component.
2012-10-16T21:43:13.744Z,1350423793.744 [CBIT](DEBUG): Initialize CBIT Component.
2012-10-16T21:43:13.744Z,1350423793.744 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2012-10-16T21:43:13.745Z,1350423793.745 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2012-10-16T21:43:13.746Z,1350423793.746 [NavChartDb](INFO): Thread ID is 815
2012-10-16T21:43:13.812Z,1350423793.812 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-10-16T21:43:13.812Z,1350423793.812 [NavChart](DEBUG): Initialize NavChart Derivation.
2012-10-16T21:43:13.813Z,1350423793.813 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2012-10-16T21:43:13.813Z,1350423793.813 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2012-10-16T21:43:13.813Z,1350423793.813 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2012-10-16T21:43:13.815Z,1350423793.815 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2012-10-16T21:43:13.815Z,1350423793.815 [Navigation](DEBUG): Initializing Navigation.
2012-10-16T21:43:13.816Z,1350423793.816 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2012-10-16T21:43:13.817Z,1350423793.817 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2012-10-16T21:43:13.818Z,1350423793.818 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2012-10-16T21:43:13.823Z,1350423793.823 [LoopControl](DEBUG): Initialize LoopControlComponent.
2012-10-16T21:43:13.847Z,1350423793.847 [Turbulence_NPS](INFO): Pause powering down
2012-10-16T21:43:13.873Z,1350423793.873 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2012-10-16T21:43:13.874Z,1350423793.874 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2012-10-16T21:43:14.007Z,1350423794.007 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2012-10-16T21:43:14.007Z,1350423794.007 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2012-10-16T21:43:14.007Z,1350423794.007 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2012-10-16T21:43:15.059Z,1350423795.059 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout
2012-10-16T21:43:15.059Z,1350423795.059 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing
2012-10-16T21:43:15.059Z,1350423795.059 [Batt_Ocean_Server] Communications Fault, FailCount= 1
2012-10-16T21:43:15.059Z,1350423795.059 [Batt_Ocean_Server](ERROR): Communications Fault
2012-10-16T21:43:15.064Z,1350423795.064 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2012-10-16T21:43:15.213Z,1350423795.213 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-16T21:43:15.223Z,1350423795.224 [MissionManager](DEBUG):
2012-10-16T21:43:15.224Z,1350423795.224 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2012-10-16T21:43:15.306Z,1350423795.306 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2012-10-16T21:43:15.308Z,1350423795.308 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2012-10-16T21:43:15.311Z,1350423795.311 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-16T21:43:15.319Z,1350423795.319 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2012-10-16T21:43:15.322Z,1350423795.322 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-16T21:43:15.333Z,1350423795.333 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2012-10-16T21:43:15.341Z,1350423795.341 [Default:D.SetSpeed](DEBUG): Construct.
2012-10-16T21:43:15.344Z,1350423795.344 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2012-10-16T21:43:15.353Z,1350423795.353 [Default:F.Wait](DEBUG): Construct Wait.
2012-10-16T21:43:15.357Z,1350423795.357 [MissionManager](DEBUG):
400
400
Burn 300
Dropped drop weight due to communications timeout
5.0
1.0
5
2012-10-16T21:43:15.361Z,1350423795.361 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,logger,
2012-10-16T21:43:15.381Z,1350423795.381 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2012-10-16T21:43:15.569Z,1350423795.569 [Radio_Freewave](INFO): Powering up
2012-10-16T21:43:15.679Z,1350423795.679 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2012-10-16T21:43:15.683Z,1350423795.683 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2012-10-16T21:43:15.689Z,1350423795.689 [ElevatorServo](DEBUG): Initializing EZServoServo.
2012-10-16T21:43:15.690Z,1350423795.690 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2012-10-16T21:43:15.696Z,1350423795.696 [RudderServo](DEBUG): Initializing EZServoServo.
2012-10-16T21:43:15.699Z,1350423795.699 [RudderServo](DEBUG): Initializing RudderServo.
2012-10-16T21:43:15.704Z,1350423795.704 [ThrusterServo](DEBUG): Initializing EZServoServo.
2012-10-16T21:43:15.705Z,1350423795.705 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2012-10-16T21:43:15.724Z,1350423795.724 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server
2012-10-16T21:43:15.725Z,1350423795.724 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server
2012-10-16T21:43:15.725Z,1350423795.725 [Batt_Ocean_Server] No Fault, FailCount= 1
2012-10-16T21:43:15.775Z,1350423795.775 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2012-10-16T21:43:15.775Z,1350423795.775 [DVL_micro](INFO): Querying output modes
2012-10-16T21:43:15.775Z,1350423795.776 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606
2012-10-16T21:43:15.779Z,1350423795.779 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2012-10-16T21:43:15.779Z,1350423795.779 [DVL_micro](INFO): NQ1 output enabled
2012-10-16T21:43:15.779Z,1350423795.779 [DVL_micro](INFO): RSSI output enabled
2012-10-16T21:43:15.779Z,1350423795.779 [DVL_micro](INFO): ADCP output enabled
2012-10-16T21:43:15.779Z,1350423795.779 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525
2012-10-16T21:43:15.787Z,1350423795.787 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON
2012-10-16T21:43:15.792Z,1350423795.792 [DVL_micro](INFO): pause:Powering down
2012-10-16T21:43:20.117Z,1350423800.117 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2012-10-16T21:43:20.258Z,1350423800.258 [NAL9602](INFO): Powering up NAL9602
2012-10-16T21:43:29.483Z,1350423809.483 [SBIT](IMPORTANT): Beginning Startup BIT
2012-10-16T21:43:29.485Z,1350423809.485 [CBIT](IMPORTANT): Beginning GF scan
2012-10-16T21:43:31.243Z,1350423811.243 [NAL9602](INFO): NAL9602 initialized
2012-10-16T21:43:58.076Z,1350423838.076 [CBIT](IMPORTANT): No ground fault detected
2012-10-16T21:44:24.522Z,1350423864.522 [SBIT](IMPORTANT): SBIT PASSED
2012-10-16T21:44:24.914Z,1350423864.914 [MissionManager](IMPORTANT): Started mission Startup
2012-10-16T21:44:24.914Z,1350423864.914 [Startup] Running Loop=1
2012-10-16T21:44:24.914Z,1350423864.914 [Startup](INFO): Aggregate::initialize Startup
2012-10-16T21:44:24.914Z,1350423864.914 [Startup:A.GoToSurface] Running Loop=1
2012-10-16T21:44:24.914Z,1350423864.914 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-16T21:44:24.921Z,1350423864.921 [Startup:StartupSatComms] Running Loop=1
2012-10-16T21:44:24.921Z,1350423864.921 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2012-10-16T21:44:24.921Z,1350423864.921 [Startup:StartupSatComms:A] Running Loop=1
2012-10-16T21:44:25.314Z,1350423865.314 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-10-16T21:45:25.320Z,1350423925.320 [Startup:StartupSatComms:A](INFO): Timed out from 2012-10-16T21:44:24.9Z
2012-10-16T21:45:25.320Z,1350423925.320 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1
2012-10-16T21:45:25.320Z,1350423925.320 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout
2012-10-16T21:45:25.320Z,1350423925.320 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout
2012-10-16T21:45:25.321Z,1350423925.321 [Startup:StartupSatComms:A] Stopped
2012-10-16T21:45:25.321Z,1350423925.321 [Startup:StartupSatComms:B] Running Loop=1
2012-10-16T21:45:25.714Z,1350423925.714 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-10-16T21:46:25.422Z,1350423985.422 [Startup:StartupSatComms:B](INFO): Timed out from 2012-10-16T21:45:25.3Z
2012-10-16T21:46:25.422Z,1350423985.422 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1
2012-10-16T21:46:25.423Z,1350423985.422 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout
2012-10-16T21:46:25.423Z,1350423985.423 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout
2012-10-16T21:46:25.423Z,1350423985.423 [Startup:StartupSatComms:B] Stopped
2012-10-16T21:46:25.423Z,1350423985.423 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2012-10-16T21:46:25.423Z,1350423985.423 [Startup:StartupSatComms] Stopped
2012-10-16T21:46:25.423Z,1350423985.423 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2012-10-16T21:46:25.424Z,1350423985.424 [Startup](INFO): Completed Startup
2012-10-16T21:46:25.424Z,1350423985.424 [Startup] Stopped
2012-10-16T21:46:25.424Z,1350423985.424 [Startup](INFO): Aggregate::uninitialize Startup
2012-10-16T21:46:25.424Z,1350423985.424 [Startup:A.GoToSurface] Stopped
2012-10-16T21:46:25.424Z,1350423985.424 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-16T21:46:25.787Z,1350423985.787 [MissionManager](IMPORTANT): Started mission Default
2012-10-16T21:46:25.787Z,1350423985.787 [Default] Running Loop=1
2012-10-16T21:46:25.787Z,1350423985.787 [Default](INFO): Aggregate::initialize Default
2012-10-16T21:46:25.787Z,1350423985.787 [Default:D.SetSpeed] Running Loop=1
2012-10-16T21:46:25.787Z,1350423985.787 [Default:D.SetSpeed](DEBUG): Initialize.
2012-10-16T21:46:25.787Z,1350423985.787 [Default:E.GoToSurface] Running Loop=1
2012-10-16T21:46:25.787Z,1350423985.787 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-16T21:46:25.788Z,1350423985.788 [Default:Iridium] Running Loop=1
2012-10-16T21:46:25.788Z,1350423985.788 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2012-10-16T21:46:25.788Z,1350423985.788 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-10-16T21:46:25.788Z,1350423985.788 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2012-10-16T21:46:25.788Z,1350423985.788 [Default:Iridium:B.GoToSurface] Running Loop=1
2012-10-16T21:46:25.788Z,1350423985.788 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-16T21:46:25.789Z,1350423985.789 [Default:E.GoToSurface] Running Loop=1
2012-10-16T21:46:25.794Z,1350423985.794 [Default:D.SetSpeed] Running Loop=1
2012-10-16T21:46:25.799Z,1350423985.799 [Default:CallIridium] Running Loop=1
2012-10-16T21:46:25.799Z,1350423985.799 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2012-10-16T21:46:25.799Z,1350423985.799 [Default:CallIridium:A] Running Loop=1
2012-10-16T21:46:25.801Z,1350423985.801 [Default:CallIridium:A] Stopped
2012-10-16T21:46:25.801Z,1350423985.801 [Default:CallIridium:B] Running Loop=1
2012-10-16T21:46:25.801Z,1350423985.801 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2012-10-16T21:46:25.807Z,1350423985.807 [Default:Iridium:B.GoToSurface] Stopped
2012-10-16T21:46:25.807Z,1350423985.807 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-16T21:46:25.807Z,1350423985.807 [Default:Iridium:Read_Iridium] Running Loop=1
2012-10-16T21:46:25.807Z,1350423985.807 [Default:Iridium:A.SetSpeed] Running Loop=1
2012-10-16T21:46:25.812Z,1350423985.812 [Default:GPS] Running Loop=1
2012-10-16T21:46:25.812Z,1350423985.812 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2012-10-16T21:46:25.812Z,1350423985.812 [Default:GPS:A.SetSpeed] Running Loop=1
2012-10-16T21:46:25.812Z,1350423985.812 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2012-10-16T21:46:25.812Z,1350423985.812 [Default:GPS:B.GoToSurface] Running Loop=1
2012-10-16T21:46:25.812Z,1350423985.812 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2012-10-16T21:46:25.817Z,1350423985.818 [Default:GPS:B.GoToSurface] Stopped
2012-10-16T21:46:25.818Z,1350423985.818 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-16T21:46:25.818Z,1350423985.818 [Default:GPS:Read_GPS] Running Loop=1
2012-10-16T21:46:25.818Z,1350423985.818 [Default:GPS:A.SetSpeed] Running Loop=1
2012-10-16T21:46:26.190Z,1350423986.190 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2012-10-16T21:46:26.193Z,1350423986.193 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2012-10-16T21:53:33.913Z,1350424413.913 [NAL9602](FAULT): GPS failed to acquire within timeout.
2012-10-16T21:53:33.913Z,1350424413.913 [NAL9602] Data Fault, FailCount= 1
2012-10-16T21:53:33.913Z,1350424413.913 [NAL9602](ERROR): Data Fault
2012-10-16T21:53:33.936Z,1350424413.936 [CBIT](ERROR): Data Fault in component: NAL9602
2012-10-16T21:53:34.292Z,1350424414.292 [NAL9602](INFO): Powering down
2012-10-16T21:53:34.315Z,1350424414.315 [CBIT](INFO): Clearing failed state for component NAL9602
2012-10-16T21:53:34.315Z,1350424414.316 [NAL9602] No Fault, FailCount= 1
2012-10-16T21:53:39.488Z,1350424419.487 [NAL9602](INFO): Powering up NAL9602
2012-10-16T21:53:50.327Z,1350424430.327 [NAL9602](INFO): NAL9602 initialized
2012-10-16T22:03:51.184Z,1350425031.184 [NAL9602](FAULT): GPS failed to acquire within timeout.
2012-10-16T22:03:51.184Z,1350425031.184 [NAL9602] Data Fault, FailCount= 2
2012-10-16T22:03:51.184Z,1350425031.184 [NAL9602](ERROR): Data Fault
2012-10-16T22:03:51.207Z,1350425031.207 [CBIT](ERROR): Data Fault in component: NAL9602
2012-10-16T22:03:51.208Z,1350425031.208 [CBIT](CRITICAL): Data Fault in component: NAL9602
2012-10-16T22:03:51.600Z,1350425031.601 [NAL9602](INFO): Powering down
2012-10-16T22:04:10.171Z,1350425050.171 [CommandLine](IMPORTANT): got command
2012-10-16T22:04:10.171Z,1350425050.171 [CommandLine](FAULT): Incomplete syntax. Try: help
2012-10-16T22:04:47.155Z,1350425087.155 [CommandLine](IMPORTANT): got command @ ifconfig
2012-10-16T22:05:34.095Z,1350425134.095 [CommandLine](IMPORTANT): got command @ tellum.shore.mbari.org
2012-10-16T22:05:39.607Z,1350425139.607 [CommandLine](IMPORTANT): got command @ tellum.shore.mbari.org
2012-10-16T22:05:51.207Z,1350425151.207 [CBIT](INFO): Clearing failed count for component NAL9602
2012-10-16T22:05:51.207Z,1350425151.207 [NAL9602] No Fault, FailCount= 2
2012-10-16T22:05:51.576Z,1350425151.576 [NAL9602](INFO): Powering up NAL9602
2012-10-16T22:06:01.143Z,1350425161.143 [CommandLine](IMPORTANT): got command quit
2012-10-16T22:06:02.318Z,1350425162.318 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2012-10-16T22:06:02.319Z,1350425162.319 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2012-10-16T22:06:02.399Z,1350425162.399 [NAL9602](INFO): NAL9602 initialized
2012-10-16T22:06:02.498Z,1350425162.498 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2012-10-16T22:06:02.843Z,1350425162.843 [WetLabsBB2FL](INFO): Powering down
2012-10-16T22:06:02.863Z,1350425162.862 [ComponentRegistry](INFO): Shutting down Turbulence_NPS ThreadHandler
2012-10-16T22:06:03.111Z,1350425163.111 [Turbulence_NPS](INFO): Uninitialize Powering down
2012-10-16T22:06:03.131Z,1350425163.131 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2012-10-16T22:06:03.179Z,1350425163.179 [CTD_NeilBrown](INFO): Powering down
2012-10-16T22:06:03.191Z,1350425163.191 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2012-10-16T22:06:03.255Z,1350425163.255 [DVL_micro](INFO): uninitialize:Powering down
2012-10-16T22:06:03.259Z,1350425163.259 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2012-10-16T22:06:03.266Z,1350425163.266 [NAL9602](ERROR): getFix uart error: serial timeout
2012-10-16T22:06:03.503Z,1350425163.503 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2012-10-16T22:06:03.519Z,1350425163.519 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2012-10-16T22:06:03.521Z,1350425163.521 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2012-10-16T22:06:03.622Z,1350425163.622 [controlThread](DEBUG): Uninitializing ControlThread
2012-10-16T22:06:03.623Z,1350425163.623 [AHRS_sp3003D](INFO): Powering down
2012-10-16T22:06:03.711Z,1350425163.711 [NAL9602](INFO): Powering down
2012-10-16T22:06:03.713Z,1350425163.713 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2012-10-16T22:06:03.714Z,1350425163.714 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2012-10-16T22:06:03.715Z,1350425163.715 [Default] Stopped
2012-10-16T22:06:03.715Z,1350425163.715 [Default](INFO): Aggregate::uninitialize Default
2012-10-16T22:06:03.715Z,1350425163.715 [Default:GPS] Stopped
2012-10-16T22:06:03.715Z,1350425163.715 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2012-10-16T22:06:03.715Z,1350425163.715 [Default:GPS:A.SetSpeed] Stopped
2012-10-16T22:06:03.715Z,1350425163.715 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2012-10-16T22:06:03.715Z,1350425163.716 [Default:GPS:Read_GPS] Stopped
2012-10-16T22:06:03.716Z,1350425163.716 [Default:Iridium] Stopped
2012-10-16T22:06:03.716Z,1350425163.716 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2012-10-16T22:06:03.716Z,1350425163.716 [Default:Iridium:A.SetSpeed] Stopped
2012-10-16T22:06:03.716Z,1350425163.716 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2012-10-16T22:06:03.716Z,1350425163.716 [Default:Iridium:Read_Iridium] Stopped
2012-10-16T22:06:03.716Z,1350425163.716 [Default:CallIridium] Stopped
2012-10-16T22:06:03.716Z,1350425163.716 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2012-10-16T22:06:03.716Z,1350425163.716 [Default:CallIridium:B] Stopped
2012-10-16T22:06:03.716Z,1350425163.716 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2012-10-16T22:06:03.716Z,1350425163.716 [Default:D.SetSpeed] Stopped
2012-10-16T22:06:03.716Z,1350425163.716 [Default:D.SetSpeed](DEBUG): Uninitialize.
2012-10-16T22:06:03.716Z,1350425163.716 [Default:E.GoToSurface] Stopped
2012-10-16T22:06:03.716Z,1350425163.717 [Default:E.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2012-10-16T22:06:03.721Z,1350425163.721 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2012-10-16T22:06:03.721Z,1350425163.721 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2012-10-16T22:06:03.721Z,1350425163.721 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2012-10-16T22:06:03.722Z,1350425163.722 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2012-10-16T22:06:03.722Z,1350425163.722 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2012-10-16T22:06:03.722Z,1350425163.722 [BuoyancyServo](INFO): Powering down
2012-10-16T22:06:03.727Z,1350425163.727 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2012-10-16T22:06:03.727Z,1350425163.727 [ElevatorServo](INFO): Powering down
2012-10-16T22:06:03.728Z,1350425163.728 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2012-10-16T22:06:03.728Z,1350425163.728 [RudderServo](INFO): Powering down
2012-10-16T22:06:03.729Z,1350425163.728 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2012-10-16T22:06:03.729Z,1350425163.729 [ThrusterServo](INFO): Powering down
2012-10-16T22:06:03.729Z,1350425163.729 [SBIT](DEBUG): Uninitialize SBIT Component.
2012-10-16T22:06:03.730Z,1350425163.730 [IBIT](DEBUG): Uninitialize IBIT Component.
2012-10-16T22:06:03.730Z,1350425163.730 [CBIT](DEBUG): Uninitialize CBIT Component.