2013-05-16T22:53:47.180Z,1368744827.180 [Supervisor](DEBUG): Initializing supervisor.
2013-05-16T22:53:47.184Z,1368744827.184 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0
2013-05-16T22:53:47.184Z,1368744827.184 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2013-05-16T22:53:47.185Z,1368744827.185 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0
2013-05-16T22:53:47.189Z,1368744827.189 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2013-05-16T22:53:47.199Z,1368744827.199 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2013-05-16T22:53:47.200Z,1368744827.200 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0
2013-05-16T22:53:47.201Z,1368744827.201 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2013-05-16T22:53:47.202Z,1368744827.202 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0
2013-05-16T22:53:47.203Z,1368744827.203 [Supervisor](INFO): Looking for Config files in directory: Config/
2013-05-16T22:53:47.204Z,1368744827.204 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2013-05-16T22:53:47.488Z,1368744827.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2013-05-16T22:53:47.489Z,1368744827.489 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2013-05-16T22:53:47.679Z,1368744827.679 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2013-05-16T22:53:47.680Z,1368744827.680 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2013-05-16T22:53:47.764Z,1368744827.764 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2013-05-16T22:53:47.764Z,1368744827.764 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2013-05-16T22:53:47.967Z,1368744827.967 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2013-05-16T22:53:47.967Z,1368744827.967 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2013-05-16T22:53:48.105Z,1368744828.105 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2013-05-16T22:53:48.106Z,1368744828.106 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2013-05-16T22:53:48.342Z,1368744828.342 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2013-05-16T22:53:48.342Z,1368744828.342 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2013-05-16T22:53:48.513Z,1368744828.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2013-05-16T22:53:48.513Z,1368744828.513 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2013-05-16T22:53:48.769Z,1368744828.769 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2013-05-16T22:53:48.770Z,1368744828.770 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2013-05-16T22:53:48.868Z,1368744828.868 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2013-05-16T22:53:48.868Z,1368744828.868 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2013-05-16T22:53:49.274Z,1368744829.274 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2013-05-16T22:53:49.275Z,1368744829.275 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2013-05-16T22:53:49.388Z,1368744829.388 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2013-05-16T22:53:49.389Z,1368744829.389 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2013-05-16T22:53:49.474Z,1368744829.474 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2013-05-16T22:53:49.475Z,1368744829.475 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2013-05-16T22:53:49.580Z,1368744829.579 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2013-05-16T22:53:49.751Z,1368744829.751 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2013-05-16T22:53:49.837Z,1368744829.837 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2013-05-16T22:53:49.944Z,1368744829.944 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2013-05-16T22:53:50.046Z,1368744830.046 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2013-05-16T22:53:50.168Z,1368744830.168 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2013-05-16T22:53:50.264Z,1368744830.264 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2013-05-16T22:53:50.352Z,1368744830.352 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/
2013-05-16T22:53:50.352Z,1368744830.352 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2013-05-16T22:53:50.376Z,1368744830.376 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2013-05-16T22:53:50.530Z,1368744830.530 [InternalSim] Loaded
2013-05-16T22:53:50.531Z,1368744830.531 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2013-05-16T22:53:50.531Z,1368744830.531 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2013-05-16T22:53:50.532Z,1368744830.532 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2013-05-16T22:53:50.591Z,1368744830.591 [SBIT](DEBUG): Construct Startup Built In Test.
2013-05-16T22:53:50.620Z,1368744830.620 [SBIT] Loaded
2013-05-16T22:53:50.621Z,1368744830.621 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2013-05-16T22:53:50.622Z,1368744830.622 [IBIT](DEBUG): Construct Initiated Built In Test.
2013-05-16T22:53:50.650Z,1368744830.650 [IBIT] Loaded
2013-05-16T22:53:50.651Z,1368744830.651 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2013-05-16T22:53:50.654Z,1368744830.654 [CBIT](DEBUG): Construct CBIT Built In Test.
2013-05-16T22:53:50.772Z,1368744830.772 [CBIT] Loaded
2013-05-16T22:53:50.773Z,1368744830.773 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2013-05-16T22:53:50.773Z,1368744830.773 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2013-05-16T22:53:50.774Z,1368744830.774 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2013-05-16T22:53:50.927Z,1368744830.927 [BuoyancyServo] Loaded
2013-05-16T22:53:50.927Z,1368744830.927 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2013-05-16T22:53:50.939Z,1368744830.939 [ElevatorServo] Loaded
2013-05-16T22:53:50.940Z,1368744830.940 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2013-05-16T22:53:50.952Z,1368744830.952 [MassServo] Loaded
2013-05-16T22:53:50.952Z,1368744830.952 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2013-05-16T22:53:50.964Z,1368744830.964 [RudderServo] Loaded
2013-05-16T22:53:50.964Z,1368744830.964 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2013-05-16T22:53:50.976Z,1368744830.976 [ThrusterServo] Loaded
2013-05-16T22:53:50.976Z,1368744830.976 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2013-05-16T22:53:50.977Z,1368744830.977 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2013-05-16T22:53:50.977Z,1368744830.977 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2013-05-16T22:53:50.996Z,1368744830.996 [DepthRateCalculator] Loaded
2013-05-16T22:53:50.996Z,1368744830.996 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2013-05-16T22:53:53.928Z,1368744833.928 [HFRadarModelCalc] Loaded
2013-05-16T22:53:53.928Z,1368744833.928 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2013-05-16T22:53:53.945Z,1368744833.945 [NavChart] Loaded
2013-05-16T22:53:53.945Z,1368744833.945 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2013-05-16T22:53:53.951Z,1368744833.951 [PitchRateCalculator] Loaded
2013-05-16T22:53:53.951Z,1368744833.951 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2013-05-16T22:53:53.962Z,1368744833.962 [SpeedCalculator] Loaded
2013-05-16T22:53:53.962Z,1368744833.962 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2013-05-16T22:53:53.978Z,1368744833.978 [TempGradientCalculator] Loaded
2013-05-16T22:53:53.978Z,1368744833.978 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2013-05-16T22:53:53.984Z,1368744833.984 [YawRateCalculator] Loaded
2013-05-16T22:53:53.984Z,1368744833.984 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2013-05-16T22:53:54.030Z,1368744834.030 [Navigation] Loaded
2013-05-16T22:53:54.031Z,1368744834.031 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread.
2013-05-16T22:53:54.031Z,1368744834.031 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2013-05-16T22:53:54.032Z,1368744834.032 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2013-05-16T22:53:54.246Z,1368744834.246 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2013-05-16T22:53:54.246Z,1368744834.246 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2013-05-16T22:53:54.269Z,1368744834.269 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2013-05-16T22:53:54.270Z,1368744834.270 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2013-05-16T22:53:54.312Z,1368744834.312 [VerticalControl](DEBUG): Construct VerticalControl.
2013-05-16T22:53:54.404Z,1368744834.404 [VerticalControl] Loaded
2013-05-16T22:53:54.405Z,1368744834.405 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2013-05-16T22:53:54.406Z,1368744834.406 [HorizontalControl](DEBUG): Construct HorizontalControl.
2013-05-16T22:53:54.462Z,1368744834.462 [HorizontalControl] Loaded
2013-05-16T22:53:54.462Z,1368744834.462 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2013-05-16T22:53:54.463Z,1368744834.463 [SpeedControl](DEBUG): Construct SpeedControl.
2013-05-16T22:53:54.465Z,1368744834.465 [SpeedControl] Loaded
2013-05-16T22:53:54.465Z,1368744834.465 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2013-05-16T22:53:54.466Z,1368744834.466 [LoopControl](DEBUG): Construct LoopControl.
2013-05-16T22:53:54.467Z,1368744834.467 [LoopControl] Loaded
2013-05-16T22:53:54.467Z,1368744834.467 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2013-05-16T22:53:54.468Z,1368744834.467 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2013-05-16T22:53:54.468Z,1368744834.468 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2013-05-16T22:53:54.474Z,1368744834.474 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2013-05-16T22:53:54.479Z,1368744834.479 [AsyncPiEstimator] Loaded
2013-05-16T22:53:54.479Z,1368744834.479 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2013-05-16T22:53:54.481Z,1368744834.480 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4063B4E0
2013-05-16T22:53:54.481Z,1368744834.481 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2013-05-16T22:53:54.482Z,1368744834.482 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2013-05-16T22:53:54.612Z,1368744834.612 [AHRS_sp3003D] Loaded
2013-05-16T22:53:54.612Z,1368744834.612 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2013-05-16T22:53:54.885Z,1368744834.885 [Batt_Ocean_Server] Loaded
2013-05-16T22:53:54.885Z,1368744834.885 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2013-05-16T22:53:54.899Z,1368744834.899 [Depth_Keller] Loaded
2013-05-16T22:53:54.900Z,1368744834.900 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2013-05-16T22:53:54.905Z,1368744834.905 [DropWeight] Loaded
2013-05-16T22:53:54.905Z,1368744834.905 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2013-05-16T22:53:55.076Z,1368744835.076 [DVL_micro] Loaded
2013-05-16T22:53:55.077Z,1368744835.077 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread.
2013-05-16T22:53:55.078Z,1368744835.078 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406BD4E0
2013-05-16T22:53:55.160Z,1368744835.160 [NAL9602] Loaded
2013-05-16T22:53:55.160Z,1368744835.160 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2013-05-16T22:53:55.211Z,1368744835.211 [Onboard] Loaded
2013-05-16T22:53:55.211Z,1368744835.211 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2013-05-16T22:53:55.218Z,1368744835.218 [Radio_Freewave] Loaded
2013-05-16T22:53:55.218Z,1368744835.218 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread.
2013-05-16T22:53:55.219Z,1368744835.219 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2013-05-16T22:53:55.220Z,1368744835.220 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2013-05-16T22:53:55.293Z,1368744835.293 [CTD_NeilBrown] Loaded
2013-05-16T22:53:55.293Z,1368744835.293 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2013-05-16T22:53:55.294Z,1368744835.294 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4070F4E0
2013-05-16T22:53:55.326Z,1368744835.326 [WetLabsBB2FL] Loaded
2013-05-16T22:53:55.326Z,1368744835.326 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2013-05-16T22:53:55.327Z,1368744835.327 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4073F4E0
2013-05-16T22:53:55.328Z,1368744835.328 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2013-05-16T22:53:55.330Z,1368744835.330 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2013-05-16T22:53:55.331Z,1368744835.331 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2013-05-16T22:53:55.342Z,1368744835.342 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2013-05-16T22:53:55.343Z,1368744835.343 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4076F4E0
2013-05-16T22:53:55.347Z,1368744835.348 [Supervisor](DEBUG): Running supervisor.
2013-05-16T22:53:55.349Z,1368744835.349 [CommandLine](INFO): Thread ID is 1086
2013-05-16T22:53:55.351Z,1368744835.351 [controlThread](INFO): Thread ID is 1085
2013-05-16T22:53:55.352Z,1368744835.352 [controlThread](DEBUG): Initializing ControlThread
2013-05-16T22:53:55.352Z,1368744835.352 [CycleStarter](INFO): Thread ID is 1084
2013-05-16T22:53:55.352Z,1368744835.352 [InternalSim](DEBUG):  InternalSim initializing...
2013-05-16T22:53:55.386Z,1368744835.386 [logger](INFO): Thread ID is 1087
2013-05-16T22:53:55.412Z,1368744835.412 [SBIT](INFO): Initialize SBIT Component.
2013-05-16T22:53:55.412Z,1368744835.412 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:10359
2013-05-16T22:53:55.412Z,1368744835.412 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2013-05-16T22:53:55.413Z,1368744835.413 [SBIT](IMPORTANT): Kernel Version:#634 PREEMPT Wed Feb 13 10:21:48 PST 2013
2013-05-16T22:53:55.414Z,1368744835.414 [IBIT](INFO): Initialize IBIT Component.
2013-05-16T22:53:55.414Z,1368744835.414 [CBIT](DEBUG): Initialize CBIT Component.
2013-05-16T22:53:55.415Z,1368744835.415 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2013-05-16T22:53:55.426Z,1368744835.426 [AsyncPiEstimator](INFO): Thread ID is 1148
2013-05-16T22:53:55.426Z,1368744835.426 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2013-05-16T22:53:55.438Z,1368744835.438 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-05-16T22:53:55.439Z,1368744835.439 [NavChart](DEBUG): Initialize NavChart Derivation.
2013-05-16T22:53:55.439Z,1368744835.439 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2013-05-16T22:53:55.440Z,1368744835.440 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2013-05-16T22:53:55.440Z,1368744835.440 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2013-05-16T22:53:55.442Z,1368744835.442 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2013-05-16T22:53:55.442Z,1368744835.442 [Navigation](DEBUG): Initializing Navigation.
2013-05-16T22:53:55.442Z,1368744835.442 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2013-05-16T22:53:55.444Z,1368744835.444 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2013-05-16T22:53:55.445Z,1368744835.445 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2013-05-16T22:53:55.446Z,1368744835.446 [LoopControl](DEBUG): Initialize LoopControlComponent.
2013-05-16T22:53:55.452Z,1368744835.452 [DVL_micro](INFO): Thread ID is 1149
2013-05-16T22:53:55.461Z,1368744835.461 [DVL_micro](INFO): Initializing
2013-05-16T22:53:55.461Z,1368744835.461 [DVL_micro](INFO): start:Powering up
2013-05-16T22:53:55.462Z,1368744835.462 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T22:53:55.463Z,1368744835.463 [DVL_micro](INFO): Cycling power to configure device.
2013-05-16T22:53:55.474Z,1368744835.474 [CTD_NeilBrown](INFO): Thread ID is 1150
2013-05-16T22:53:55.475Z,1368744835.475 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2013-05-16T22:53:55.482Z,1368744835.482 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2013-05-16T22:53:55.498Z,1368744835.498 [WetLabsBB2FL](INFO): Thread ID is 1151
2013-05-16T22:53:55.498Z,1368744835.499 [WetLabsBB2FL](INFO): Powering down
2013-05-16T22:53:55.526Z,1368744835.526 [NavChartDb](INFO): Thread ID is 1152
2013-05-16T22:53:55.528Z,1368744835.528 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2013-05-16T22:53:55.529Z,1368744835.529 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2013-05-16T22:53:55.530Z,1368744835.530 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2013-05-16T22:53:55.530Z,1368744835.530 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2013-05-16T22:53:55.530Z,1368744835.530 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2013-05-16T22:53:55.530Z,1368744835.530 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2013-05-16T22:53:55.530Z,1368744835.530 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2013-05-16T22:53:55.531Z,1368744835.531 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2013-05-16T22:53:55.531Z,1368744835.531 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2013-05-16T22:53:57.028Z,1368744837.028 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2013-05-16T22:53:57.058Z,1368744837.058 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2013-05-16T22:53:57.058Z,1368744837.058 [DropWeight] Hardware Fault, FailCount= 1
2013-05-16T22:53:57.058Z,1368744837.058 [DropWeight](ERROR): Hardware Fault
2013-05-16T22:53:57.060Z,1368744837.060 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2013-05-16T22:53:57.079Z,1368744837.079 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T22:53:57.130Z,1368744837.130 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface RunIn="Progression"/>

    <Aggregate Id="StartupSatComms" >

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

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

    </Aggregate>

</Mission>


2013-05-16T22:53:57.131Z,1368744837.131 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2013-05-16T22:53:57.178Z,1368744837.178 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2013-05-16T22:53:57.180Z,1368744837.180 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2013-05-16T22:53:57.216Z,1368744837.216 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T22:53:57.240Z,1368744837.240 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2013-05-16T22:53:57.243Z,1368744837.243 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T22:53:57.259Z,1368744837.259 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2013-05-16T22:53:57.279Z,1368744837.279 [Default:D.SetSpeed](DEBUG): Construct.
2013-05-16T22:53:57.283Z,1368744837.283 [Default:E.GoToSurface](DEBUG): Construct GoToSurface.
2013-05-16T22:53:57.288Z,1368744837.288 [Default:F.Wait](DEBUG): Construct Wait.
2013-05-16T22:53:57.324Z,1368744837.324 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="NeedGPS"><True/></DefineArg>

    <Aggregate Id="GPS" >

        <When><Arg Name="NeedGPS"/>
        </When>

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Get GPS fix -->

        <ReadDatum Id="Read_GPS"><Universal:latitude_fix/>
        </ReadDatum>

        <Assign><Arg Name="NeedGPS"/><False/></Assign>

    </Aggregate>

    <Aggregate Id="Iridium" >

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface RunIn="Sequence"/>

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="CallIridium" >

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

        <Assign><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

<!-- Wait forever at the surface-->

<!-- Run at low speed -->

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

    <Guidance:GoToSurface RunIn="Parallel"/>

    <Guidance:Wait RunIn="Sequence"></Guidance:Wait>

</Mission>


2013-05-16T22:53:57.328Z,1368744837.328 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,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-16T22:53:57.361Z,1368744837.361 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2013-05-16T22:53:57.530Z,1368744837.530 [DVL_micro](INFO): Opening uart, block timeout 10ths=20
2013-05-16T22:53:57.530Z,1368744837.530 [DVL_micro](INFO): Querying output modes
2013-05-16T22:53:57.530Z,1368744837.530 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606

2013-05-16T22:53:57.541Z,1368744837.541 [DVL_micro](DEBUG): cmdResponse: 01 03 16
2013-05-16T22:53:57.542Z,1368744837.542 [DVL_micro](INFO): NQ1 output enabled
2013-05-16T22:53:57.542Z,1368744837.542 [DVL_micro](INFO): RSSI output enabled
2013-05-16T22:53:57.542Z,1368744837.542 [DVL_micro](INFO): ADCP output enabled
2013-05-16T22:53:57.542Z,1368744837.542 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525

2013-05-16T22:53:57.553Z,1368744837.553 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 
2013-05-16T22:53:57.558Z,1368744837.558 [DVL_micro](INFO): pause:Powering down
2013-05-16T22:53:57.764Z,1368744837.764 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2013-05-16T22:53:57.769Z,1368744837.769 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2013-05-16T22:53:57.776Z,1368744837.776 [ElevatorServo](DEBUG): Initializing EZServoServo.
2013-05-16T22:53:57.781Z,1368744837.781 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2013-05-16T22:53:57.787Z,1368744837.787 [MassServo](DEBUG): Initializing EZServoServo.
2013-05-16T22:53:57.817Z,1368744837.817 [MassServo](DEBUG): Initializing MassServo.
2013-05-16T22:53:57.823Z,1368744837.823 [RudderServo](DEBUG): Initializing EZServoServo.
2013-05-16T22:53:57.830Z,1368744837.829 [RudderServo](DEBUG): Initializing RudderServo.
2013-05-16T22:53:57.844Z,1368744837.844 [ThrusterServo](DEBUG): Initializing EZServoServo.
2013-05-16T22:53:57.854Z,1368744837.853 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2013-05-16T22:53:57.883Z,1368744837.883 [CBIT](ERROR): Hardware Fault in component: DropWeight
2013-05-16T22:53:57.883Z,1368744837.884 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2013-05-16T22:54:00.212Z,1368744840.212 [NAL9602](INFO): Powering up NAL9602
2013-05-16T22:54:10.906Z,1368744850.906 [CommandLine](IMPORTANT): got command show variable azimuth
2013-05-16T22:54:10.909Z,1368744850.909 [CommandLine](INFO): homing_target_azimuth (unknown)
2013-05-16T22:54:10.946Z,1368744850.945 [NAL9602](INFO): NAL9602 initialized
2013-05-16T22:54:11.037Z,1368744851.037 [SBIT](IMPORTANT): Beginning Startup BIT
2013-05-16T22:54:11.040Z,1368744851.040 [CBIT](IMPORTANT): Beginning GF scan
2013-05-16T22:54:25.978Z,1368744865.978 [CommandLine](IMPORTANT): got command report touch homing_target_azimuth
2013-05-16T22:54:25.978Z,1368744865.978 [CommandLine](IMPORTANT): got command report touch homing_target_elevation
2013-05-16T22:54:30.222Z,1368744870.222 [CommandLine](IMPORTANT): got command show variable DAT
2013-05-16T22:54:30.227Z,1368744870.227 [CommandLine](INFO): Config/vehicle.sendDataToShore (bool)
2013-05-16T22:54:30.231Z,1368744870.231 [CommandLine](INFO): Config/vehicle.DAT_card (none)
2013-05-16T22:54:30.231Z,1368744870.231 [CommandLine](INFO): Config/vehicle.DAT_uart (none)
2013-05-16T22:54:30.232Z,1368744870.232 [CommandLine](INFO): Config/vehicle.DAT_baud (bit_per_second)
2013-05-16T22:54:30.236Z,1368744870.237 [CommandLine](INFO): Config/Sensor.DAT_enable (bool)
2013-05-16T22:54:30.237Z,1368744870.237 [CommandLine](INFO): Config/Sensor.DAT_useHardware (bool)
2013-05-16T22:54:30.237Z,1368744870.237 [CommandLine](INFO): Config/Sensor.DAT_remoteAddress (count)
2013-05-16T22:54:30.238Z,1368744870.238 [CommandLine](INFO): Config/Sensor.DAT_rotationOffset (degree)
2013-05-16T22:54:30.287Z,1368744870.286 [CommandLine](INFO): Config/Simulator.oceanModelData (none)
2013-05-16T22:54:30.317Z,1368744870.316 [CommandLine](INFO): Navigation.useHFRadarData (bool)
2013-05-16T22:54:37.858Z,1368744877.858 [CBIT](IMPORTANT): No ground fault detected
2013-05-16T22:55:04.783Z,1368744904.783 [SBIT](IMPORTANT): SBIT PASSED
2013-05-16T22:55:05.061Z,1368744905.061 [CommandLine](IMPORTANT): got command quit
2013-05-16T22:55:05.179Z,1368744905.179 [MissionManager](IMPORTANT): Started mission Startup
2013-05-16T22:55:05.179Z,1368744905.179 [Startup] Running Loop=1
2013-05-16T22:55:05.179Z,1368744905.179 [Startup](INFO): Aggregate::initialize Startup
2013-05-16T22:55:05.179Z,1368744905.179 [Startup:A.GoToSurface] Running Loop=1
2013-05-16T22:55:05.179Z,1368744905.179 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2013-05-16T22:55:06.205Z,1368744906.205 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2013-05-16T22:55:06.205Z,1368744906.205 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2013-05-16T22:55:06.466Z,1368744906.466 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2013-05-16T22:55:06.662Z,1368744906.662 [WetLabsBB2FL](INFO): Powering down
2013-05-16T22:55:06.665Z,1368744906.665 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2013-05-16T22:55:06.826Z,1368744906.826 [CTD_NeilBrown](INFO): Powering down
2013-05-16T22:55:06.845Z,1368744906.845 [ComponentRegistry](INFO): Shutting down DVL_micro ThreadHandler
2013-05-16T22:55:07.097Z,1368744907.098 [DVL_micro](INFO): uninitialize:Powering down
2013-05-16T22:55:07.105Z,1368744907.105 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2013-05-16T22:55:07.429Z,1368744907.429 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2013-05-16T22:55:07.446Z,1368744907.446 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2013-05-16T22:55:07.506Z,1368744907.506 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2013-05-16T22:55:07.507Z,1368744907.507 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2013-05-16T22:55:07.733Z,1368744907.733 [controlThread](DEBUG): Uninitializing ControlThread
2013-05-16T22:55:07.734Z,1368744907.734 [AHRS_sp3003D](INFO): Powering down
2013-05-16T22:55:07.822Z,1368744907.822 [NAL9602](INFO): Powering down
2013-05-16T22:55:07.824Z,1368744907.824 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2013-05-16T22:55:07.824Z,1368744907.824 [NavChart](DEBUG): Uninitialize NavChart Derivation.
2013-05-16T22:55:07.829Z,1368744907.829 [Startup] Stopped
2013-05-16T22:55:07.829Z,1368744907.829 [Startup](INFO): Aggregate::uninitialize Startup
2013-05-16T22:55:07.829Z,1368744907.829 [Startup:A.GoToSurface] Stopped
2013-05-16T22:55:07.829Z,1368744907.829 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2013-05-16T22:55:07.830Z,1368744907.830 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2013-05-16T22:55:07.831Z,1368744907.831 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2013-05-16T22:55:07.831Z,1368744907.831 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2013-05-16T22:55:07.831Z,1368744907.831 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2013-05-16T22:55:07.831Z,1368744907.831 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2013-05-16T22:55:07.832Z,1368744907.832 [BuoyancyServo](INFO): Powering down
2013-05-16T22:55:07.845Z,1368744907.845 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2013-05-16T22:55:07.845Z,1368744907.845 [ElevatorServo](INFO): Powering down
2013-05-16T22:55:07.846Z,1368744907.846 [MassServo](DEBUG): Uninitialize Mass Servo.
2013-05-16T22:55:07.846Z,1368744907.846 [MassServo](INFO): Powering down
2013-05-16T22:55:07.847Z,1368744907.847 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2013-05-16T22:55:07.847Z,1368744907.847 [RudderServo](INFO): Powering down
2013-05-16T22:55:07.848Z,1368744907.848 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2013-05-16T22:55:07.848Z,1368744907.848 [ThrusterServo](INFO): Powering down
2013-05-16T22:55:07.849Z,1368744907.849 [SBIT](DEBUG): Uninitialize SBIT Component.
2013-05-16T22:55:07.850Z,1368744907.850 [IBIT](DEBUG): Uninitialize IBIT Component.
2013-05-16T22:55:07.850Z,1368744907.850 [CBIT](DEBUG): Uninitialize CBIT Component.