2015-06-09T20:40:31.850Z,1433882431.850 [Supervisor](DEBUG): Initializing supervisor.
2015-06-09T20:40:31.852Z,1433882431.852 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2015-06-09T20:40:31.853Z,1433882431.853 [SyncHandler](INFO): Protected caller Thread ID is 8515
2015-06-09T20:40:31.853Z,1433882431.853 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2015-06-09T20:40:31.854Z,1433882431.854 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2015-06-09T20:40:31.855Z,1433882431.855 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8516
2015-06-09T20:40:31.857Z,1433882431.857 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2015-06-09T20:40:31.870Z,1433882431.870 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2015-06-09T20:40:31.871Z,1433882431.871 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2015-06-09T20:40:31.871Z,1433882431.871 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8517
2015-06-09T20:40:31.872Z,1433882431.872 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2015-06-09T20:40:31.873Z,1433882431.873 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2015-06-09T20:40:31.873Z,1433882431.873 [logger ThreadHandler](INFO): Protected caller Thread ID is 8518
2015-06-09T20:40:31.875Z,1433882431.875 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2015-06-09T20:40:31.876Z,1433882431.876 [Supervisor](INFO): Looking for Config files in directory: Config/
2015-06-09T20:40:31.877Z,1433882431.877 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2015-06-09T20:40:32.214Z,1433882432.214 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2015-06-09T20:40:32.215Z,1433882432.215 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2015-06-09T20:40:32.381Z,1433882432.381 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2015-06-09T20:40:32.381Z,1433882432.381 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2015-06-09T20:40:32.488Z,1433882432.488 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2015-06-09T20:40:32.489Z,1433882432.489 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2015-06-09T20:40:32.612Z,1433882432.612 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2015-06-09T20:40:32.612Z,1433882432.612 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2015-06-09T20:40:32.697Z,1433882432.697 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2015-06-09T20:40:32.888Z,1433882432.888 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2015-06-09T20:40:32.889Z,1433882432.889 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2015-06-09T20:40:32.975Z,1433882432.975 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2015-06-09T20:40:32.976Z,1433882432.976 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2015-06-09T20:40:33.197Z,1433882433.197 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2015-06-09T20:40:33.198Z,1433882433.198 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2015-06-09T20:40:33.568Z,1433882433.568 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2015-06-09T20:40:33.569Z,1433882433.569 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2015-06-09T20:40:33.884Z,1433882433.884 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2015-06-09T20:40:33.885Z,1433882433.885 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2015-06-09T20:40:34.381Z,1433882434.381 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2015-06-09T20:40:34.382Z,1433882434.382 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2015-06-09T20:40:34.579Z,1433882434.579 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2015-06-09T20:40:34.580Z,1433882434.580 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2015-06-09T20:40:34.683Z,1433882434.683 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2015-06-09T20:40:34.684Z,1433882434.684 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2015-06-09T20:40:35.198Z,1433882435.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2015-06-09T20:40:35.198Z,1433882435.198 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2015-06-09T20:40:35.310Z,1433882435.310 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2015-06-09T20:40:35.312Z,1433882435.312 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2015-06-09T20:40:35.313Z,1433882435.313 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2015-06-09T20:40:35.553Z,1433882435.553 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2015-06-09T20:40:35.554Z,1433882435.554 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2015-06-09T20:40:35.674Z,1433882435.674 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2015-06-09T20:40:35.784Z,1433882435.784 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2015-06-09T20:40:35.888Z,1433882435.888 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2015-06-09T20:40:36.002Z,1433882436.002 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2015-06-09T20:40:36.097Z,1433882436.097 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2015-06-09T20:40:36.230Z,1433882436.230 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2015-06-09T20:40:36.382Z,1433882436.382 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2015-06-09T20:40:36.472Z,1433882436.472 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2015-06-09T20:40:36.569Z,1433882436.569 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2015-06-09T20:40:36.667Z,1433882436.667 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2015-06-09T20:40:36.783Z,1433882436.783 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2015-06-09T20:40:36.865Z,1433882436.865 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2015-06-09T20:40:36.868Z,1433882436.868 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2015-06-09T20:40:36.916Z,1433882436.916 [VerticalControl](DEBUG): Construct VerticalControl.
2015-06-09T20:40:37.030Z,1433882437.030 [VerticalControl] Loaded
2015-06-09T20:40:37.031Z,1433882437.031 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2015-06-09T20:40:37.031Z,1433882437.031 [HorizontalControl](DEBUG): Construct HorizontalControl.
2015-06-09T20:40:37.103Z,1433882437.103 [HorizontalControl] Loaded
2015-06-09T20:40:37.103Z,1433882437.103 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2015-06-09T20:40:37.104Z,1433882437.104 [SpeedControl](DEBUG): Construct SpeedControl.
2015-06-09T20:40:37.109Z,1433882437.109 [SpeedControl] Loaded
2015-06-09T20:40:37.110Z,1433882437.110 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2015-06-09T20:40:37.110Z,1433882437.110 [LoopControl](DEBUG): Construct LoopControl.
2015-06-09T20:40:37.111Z,1433882437.111 [LoopControl] Loaded
2015-06-09T20:40:37.111Z,1433882437.111 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2015-06-09T20:40:37.111Z,1433882437.111 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2015-06-09T20:40:37.112Z,1433882437.112 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2015-06-09T20:40:37.227Z,1433882437.227 [SBIT](DEBUG): Construct Startup Built In Test.
2015-06-09T20:40:37.238Z,1433882437.238 [SBIT] Loaded
2015-06-09T20:40:37.239Z,1433882437.239 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2015-06-09T20:40:37.239Z,1433882437.239 [IBIT](DEBUG): Construct Initiated Built In Test.
2015-06-09T20:40:37.269Z,1433882437.269 [IBIT] Loaded
2015-06-09T20:40:37.269Z,1433882437.269 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2015-06-09T20:40:37.271Z,1433882437.271 [CBIT](DEBUG): Construct Continuous Built In Test.
2015-06-09T20:40:37.405Z,1433882437.405 [CBIT] Loaded
2015-06-09T20:40:37.405Z,1433882437.405 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2015-06-09T20:40:37.406Z,1433882437.406 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2015-06-09T20:40:37.406Z,1433882437.406 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2015-06-09T20:40:37.424Z,1433882437.424 [DepthRateCalculator] Loaded
2015-06-09T20:40:37.424Z,1433882437.424 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2015-06-09T20:40:37.430Z,1433882437.430 [PitchRateCalculator] Loaded
2015-06-09T20:40:37.430Z,1433882437.430 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2015-06-09T20:40:37.442Z,1433882437.442 [SpeedCalculator] Loaded
2015-06-09T20:40:37.442Z,1433882437.442 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2015-06-09T20:40:37.458Z,1433882437.458 [TempGradientCalculator] Loaded
2015-06-09T20:40:37.458Z,1433882437.458 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2015-06-09T20:40:37.464Z,1433882437.464 [YawRateCalculator] Loaded
2015-06-09T20:40:37.464Z,1433882437.464 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2015-06-09T20:40:37.464Z,1433882437.464 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2015-06-09T20:40:37.465Z,1433882437.465 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2015-06-09T20:40:42.644Z,1433882442.644 [HFRadarCompactModelForecaster] Loaded
2015-06-09T20:40:42.645Z,1433882442.645 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2015-06-09T20:40:43.536Z,1433882443.536 [HFRCMSpaceInterpolator] Loaded
2015-06-09T20:40:43.536Z,1433882443.536 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2015-06-09T20:40:43.538Z,1433882443.538 [HFRCMTimeInterpolator] Loaded
2015-06-09T20:40:43.539Z,1433882443.539 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2015-06-09T20:40:44.443Z,1433882444.443 [HFRCMReconstructedInterpolator] Loaded
2015-06-09T20:40:44.444Z,1433882444.444 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2015-06-09T20:40:44.455Z,1433882444.455 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2015-06-09T20:40:44.455Z,1433882444.455 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2015-06-09T20:40:44.481Z,1433882444.481 [HFRCMVirtualSurfaceDrifter] Loaded
2015-06-09T20:40:44.481Z,1433882444.481 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2015-06-09T20:40:44.482Z,1433882444.482 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2015-06-09T20:40:44.482Z,1433882444.482 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2015-06-09T20:40:44.704Z,1433882444.704 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2015-06-09T20:40:44.704Z,1433882444.704 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2015-06-09T20:40:44.799Z,1433882444.799 [DeadReckonUsingMultipleVelocitySources] Loaded
2015-06-09T20:40:44.800Z,1433882444.800 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2015-06-09T20:40:44.853Z,1433882444.853 [DeadReckonUsingSpeedCalculator] Loaded
2015-06-09T20:40:44.854Z,1433882444.854 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2015-06-09T20:40:44.870Z,1433882444.870 [NavChart] Loaded
2015-06-09T20:40:44.870Z,1433882444.870 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2015-06-09T20:40:44.874Z,1433882444.874 [UniversalFixResidualReporter] Loaded
2015-06-09T20:40:44.875Z,1433882444.875 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2015-06-09T20:40:44.875Z,1433882444.875 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2015-06-09T20:40:44.876Z,1433882444.876 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2015-06-09T20:40:44.882Z,1433882444.882 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2015-06-09T20:40:44.882Z,1433882444.882 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2015-06-09T20:40:45.061Z,1433882445.061 [Aanderaa_O2] Loaded
2015-06-09T20:40:45.061Z,1433882445.061 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2015-06-09T20:40:45.072Z,1433882445.072 [CANONSampler] Loaded
2015-06-09T20:40:45.072Z,1433882445.072 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2015-06-09T20:40:45.147Z,1433882445.147 [CTD_NeilBrown] Loaded
2015-06-09T20:40:45.147Z,1433882445.147 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2015-06-09T20:40:45.150Z,1433882445.150 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406EF4E0
2015-06-09T20:40:45.150Z,1433882445.150 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 8612
2015-06-09T20:40:45.163Z,1433882445.163 [ISUS] Loaded
2015-06-09T20:40:45.163Z,1433882445.163 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2015-06-09T20:40:45.177Z,1433882445.177 [PAR_Licor] Loaded
2015-06-09T20:40:45.178Z,1433882445.178 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2015-06-09T20:40:45.224Z,1433882445.224 [WetLabsBB2FL] Loaded
2015-06-09T20:40:45.224Z,1433882445.224 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2015-06-09T20:40:45.225Z,1433882445.225 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4071F4E0
2015-06-09T20:40:45.226Z,1433882445.226 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8613
2015-06-09T20:40:45.226Z,1433882445.226 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2015-06-09T20:40:45.227Z,1433882445.227 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2015-06-09T20:40:45.494Z,1433882445.494 [AHRS_sp3003D] Loaded
2015-06-09T20:40:45.495Z,1433882445.495 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2015-06-09T20:40:45.568Z,1433882445.568 [DataOverHttps] Loaded
2015-06-09T20:40:45.569Z,1433882445.569 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2015-06-09T20:40:45.582Z,1433882445.582 [Depth_Keller] Loaded
2015-06-09T20:40:45.584Z,1433882445.584 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2015-06-09T20:40:45.597Z,1433882445.597 [DropWeight] Loaded
2015-06-09T20:40:45.598Z,1433882445.598 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2015-06-09T20:40:45.731Z,1433882445.731 [DVL_micro] Loaded
2015-06-09T20:40:45.732Z,1433882445.732 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2015-06-09T20:40:45.825Z,1433882445.825 [NAL9602] Loaded
2015-06-09T20:40:45.825Z,1433882445.825 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2015-06-09T20:40:45.866Z,1433882445.866 [Onboard] Loaded
2015-06-09T20:40:45.866Z,1433882445.866 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2015-06-09T20:40:45.873Z,1433882445.873 [Radio_Surface] Loaded
2015-06-09T20:40:45.873Z,1433882445.873 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2015-06-09T20:40:45.876Z,1433882445.876 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409634E0
2015-06-09T20:40:45.876Z,1433882445.876 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8614
2015-06-09T20:40:46.010Z,1433882446.010 [DAT] Loaded
2015-06-09T20:40:46.011Z,1433882446.011 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2015-06-09T20:40:47.856Z,1433882447.856 [BPC1] Loaded
2015-06-09T20:40:47.856Z,1433882447.856 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2015-06-09T20:40:47.856Z,1433882447.856 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2015-06-09T20:40:47.857Z,1433882447.857 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2015-06-09T20:40:47.957Z,1433882447.957 [BuoyancyServo] Loaded
2015-06-09T20:40:47.958Z,1433882447.958 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2015-06-09T20:40:47.970Z,1433882447.970 [ElevatorServo] Loaded
2015-06-09T20:40:47.970Z,1433882447.970 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2015-06-09T20:40:47.981Z,1433882447.981 [MassServo] Loaded
2015-06-09T20:40:47.982Z,1433882447.982 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2015-06-09T20:40:47.993Z,1433882447.993 [RudderServo] Loaded
2015-06-09T20:40:47.994Z,1433882447.994 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2015-06-09T20:40:48.005Z,1433882448.005 [ThrusterServo] Loaded
2015-06-09T20:40:48.005Z,1433882448.005 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2015-06-09T20:40:48.006Z,1433882448.006 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2015-06-09T20:40:48.006Z,1433882448.006 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2015-06-09T20:40:48.105Z,1433882448.105 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2015-06-09T20:40:48.105Z,1433882448.105 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2015-06-09T20:40:48.129Z,1433882448.129 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2015-06-09T20:40:48.133Z,1433882448.133 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2015-06-09T20:40:48.134Z,1433882448.134 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2015-06-09T20:40:48.140Z,1433882448.140 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2015-06-09T20:40:48.142Z,1433882448.142 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A114E0
2015-06-09T20:40:48.143Z,1433882448.143 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8615
2015-06-09T20:40:48.148Z,1433882448.148 [Supervisor](INFO): Main Thread ID is 8514
2015-06-09T20:40:48.148Z,1433882448.148 [Supervisor](DEBUG): Running supervisor.
2015-06-09T20:40:48.148Z,1433882448.148 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8616
2015-06-09T20:40:48.151Z,1433882448.151 [controlThread ThreadHandler](INFO): Handler Thread ID is 8617
2015-06-09T20:40:48.152Z,1433882448.152 [controlThread](DEBUG): Initializing ControlThread
2015-06-09T20:40:48.153Z,1433882448.153 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2015-06-09T20:40:48.155Z,1433882448.155 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2015-06-09T20:40:48.155Z,1433882448.155 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2015-06-09T20:40:48.156Z,1433882448.156 [LoopControl](DEBUG): Initialize LoopControlComponent.
2015-06-09T20:40:48.156Z,1433882448.156 [SBIT](INFO): Initialize SBIT Component.
2015-06-09T20:40:48.157Z,1433882448.157 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12274
2015-06-09T20:40:48.157Z,1433882448.157 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2015-06-09T20:40:48.157Z,1433882448.157 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2015-06-09T20:40:48.158Z,1433882448.158 [IBIT](INFO): Initialize IBIT Component.
2015-06-09T20:40:48.159Z,1433882448.159 [CBIT](DEBUG): Initialize CBIT Component.
2015-06-09T20:40:48.159Z,1433882448.159 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2015-06-09T20:40:48.160Z,1433882448.160 [logger ThreadHandler](INFO): Handler Thread ID is 8618
2015-06-09T20:40:48.179Z,1433882448.179 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 8619
2015-06-09T20:40:48.179Z,1433882448.179 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2015-06-09T20:40:48.183Z,1433882448.183 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-06-09T20:40:48.183Z,1433882448.183 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2015-06-09T20:40:48.183Z,1433882448.183 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2015-06-09T20:40:48.184Z,1433882448.184 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2015-06-09T20:40:48.184Z,1433882448.184 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2015-06-09T20:40:48.191Z,1433882448.191 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2015-06-09T20:40:48.203Z,1433882448.203 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2015-06-09T20:40:48.212Z,1433882448.212 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8621
2015-06-09T20:40:48.213Z,1433882448.213 [WetLabsBB2FL](INFO): Powering down
2015-06-09T20:40:48.243Z,1433882448.243 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8622
2015-06-09T20:40:48.249Z,1433882448.249 [Radio_Surface](INFO): Powering up
2015-06-09T20:40:48.263Z,1433882448.263 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8623
2015-06-09T20:40:48.266Z,1433882448.266 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2015-06-09T20:40:48.267Z,1433882448.267 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2015-06-09T20:40:48.267Z,1433882448.267 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2015-06-09T20:40:48.267Z,1433882448.267 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2015-06-09T20:40:48.268Z,1433882448.268 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2015-06-09T20:40:48.268Z,1433882448.268 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2015-06-09T20:40:48.268Z,1433882448.268 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2015-06-09T20:40:48.268Z,1433882448.268 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2015-06-09T20:40:48.269Z,1433882448.269 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2015-06-09T20:40:48.641Z,1433882448.641 [CTD_NeilBrown](DEBUG): CTD uart timeout: serial timeout
2015-06-09T20:40:48.642Z,1433882448.642 [CTD_NeilBrown](ERROR): Could not get real or simulated CTD data. startTime.elapsed() = 0.437977
2015-06-09T20:40:57.484Z,1433882457.484 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201506091700 published
2015-06-09T20:40:57.487Z,1433882457.487 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0.
2015-06-09T20:40:57.489Z,1433882457.489 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2015-06-09T20:40:57.490Z,1433882457.490 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2015-06-09T20:40:57.491Z,1433882457.491 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2015-06-09T20:40:57.491Z,1433882457.491 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2015-06-09T20:40:57.492Z,1433882457.492 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2015-06-09T20:40:57.492Z,1433882457.492 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000
2015-06-09T20:40:57.493Z,1433882457.493 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000
2015-06-09T20:40:57.509Z,1433882457.509 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2015-06-09T20:40:57.509Z,1433882457.509 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000
2015-06-09T20:40:57.510Z,1433882457.510 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000
2015-06-09T20:40:57.510Z,1433882457.510 [NavChart](DEBUG): Initialize NavChart Navigation.
2015-06-09T20:40:57.510Z,1433882457.510 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2015-06-09T20:40:57.530Z,1433882457.530 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2015-06-09T20:40:57.556Z,1433882457.556 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-06-09T20:40:57.610Z,1433882457.610 [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>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2015-06-09T20:40:57.610Z,1433882457.610 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2015-06-09T20:40:57.722Z,1433882457.722 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2015-06-09T20:40:57.723Z,1433882457.723 [Default:A.GoToSurface](DEBUG): Construct GoToSurface.
2015-06-09T20:40:57.768Z,1433882457.768 [Default:CheckIn:A.SetSpeed](DEBUG): Construct.
2015-06-09T20:40:57.822Z,1433882457.822 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2015-06-09T20:40:57.825Z,1433882457.825 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct.
2015-06-09T20:40:57.871Z,1433882457.871 [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="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <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>

<!-- Run application at high speed -->

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

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
<!-- NOTE: Original Default.xml didn't have a timeout on the GPS read, so theoretically could have hung indefinitely there... -->
            <Universal:time_fix/>
        </ReadDatum>

<!-- Do data comms -->

        <Aggregate Id="ReportMinutesSinceMissionStarted">

            <When>
                <Elapsed><Universal:mission_started/></Elapsed>
                <Gt><Units:minute/><Value>10</Value></Gt>
                <And><Elapsed><Universal:time_fix/></Elapsed><Lt><Units:millisecond/><Value>500</Value></Lt></And>
            </When>

            <Assign><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

            <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

        </Aggregate>

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

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

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

    </Aggregate>

</Mission>


2015-06-09T20:40:57.877Z,1433882457.877 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,CANONSampler,ISUS,PAR_Licor,AHRS_sp3003D,DataOverHttps,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,HFRCMReconstructedInterpolator,HFRCMSurfaceCurrentAtVehicleLocation,HFRCMVirtualSurfaceDrifter,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2015-06-09T20:40:57.919Z,1433882457.919 [CANONSampler](INFO): Powering down
2015-06-09T20:40:58.194Z,1433882458.194 [PAR_Licor](INFO): A/D timeout, 9 tries over 150 ms

2015-06-09T20:40:58.194Z,1433882458.194 [PAR_Licor] Data Fault, FailCount= 1
2015-06-09T20:40:58.194Z,1433882458.194 [PAR_Licor](ERROR): Data Fault
2015-06-09T20:40:58.200Z,1433882458.200 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2015-06-09T20:40:58.417Z,1433882458.417 [DVL_micro](INFO): Initializing
2015-06-09T20:40:58.447Z,1433882458.447 [NAL9602](INFO): Powering up NAL9602
2015-06-09T20:40:58.507Z,1433882458.507 [DAT](INFO): Powering up
2015-06-09T20:40:58.507Z,1433882458.507 [DAT](DEBUG): Initializing DAT.
2015-06-09T20:41:03.519Z,1433882463.519 [CommandLine](IMPORTANT): got command report mod platform_mass_position
2015-06-09T20:41:08.477Z,1433882468.477 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:08.509Z,1433882468.509 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:08.646Z,1433882468.646 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2015-06-09T20:41:08.659Z,1433882468.659 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2015-06-09T20:41:08.681Z,1433882468.681 [ElevatorServo](DEBUG): Initializing EZServoServo.
2015-06-09T20:41:08.686Z,1433882468.686 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2015-06-09T20:41:08.710Z,1433882468.710 [MassServo](DEBUG): Initializing EZServoServo.
2015-06-09T20:41:08.718Z,1433882468.718 [MassServo](DEBUG): Initializing MassServo.
2015-06-09T20:41:08.740Z,1433882468.740 [RudderServo](DEBUG): Initializing EZServoServo.
2015-06-09T20:41:08.748Z,1433882468.748 [RudderServo](DEBUG): Initializing RudderServo.
2015-06-09T20:41:08.753Z,1433882468.753 [ThrusterServo](DEBUG): Initializing EZServoServo.
2015-06-09T20:41:08.759Z,1433882468.759 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2015-06-09T20:41:08.804Z,1433882468.804 [CBIT](ERROR): Data Fault in component: PAR_Licor
2015-06-09T20:41:08.804Z,1433882468.804 [CBIT](INFO): Clearing failed state for component PAR_Licor
2015-06-09T20:41:08.804Z,1433882468.804 [PAR_Licor] No Fault, FailCount= 1
2015-06-09T20:41:08.830Z,1433882468.830 [Reporter](INFO): platform_mass_position no_value
2015-06-09T20:41:08.915Z,1433882468.915 [Aanderaa_O2](FAULT): Timed out starting
2015-06-09T20:41:08.915Z,1433882468.915 [Aanderaa_O2] Communications Fault, FailCount= 1
2015-06-09T20:41:08.915Z,1433882468.915 [Aanderaa_O2](ERROR): Communications Fault
2015-06-09T20:41:09.259Z,1433882469.259 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2015-06-09T20:41:09.259Z,1433882469.259 [AHRS_sp3003D](FAULT): SP3003D failed to initialize
2015-06-09T20:41:09.260Z,1433882469.260 [AHRS_sp3003D] Hardware Fault, FailCount= 1
2015-06-09T20:41:09.260Z,1433882469.260 [AHRS_sp3003D](ERROR): Hardware Fault
2015-06-09T20:41:09.354Z,1433882469.354 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:09.364Z,1433882469.364 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:09.725Z,1433882469.725 [SBIT](IMPORTANT): Beginning Startup BIT
2015-06-09T20:41:09.727Z,1433882469.727 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-06-09T20:41:09.727Z,1433882469.727 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2015-06-09T20:41:09.728Z,1433882469.728 [CBIT](IMPORTANT): Beginning GF scan
2015-06-09T20:41:09.868Z,1433882469.868 [Aanderaa_O2](INFO): Powering down
2015-06-09T20:41:10.092Z,1433882470.092 [PAR_Licor](INFO): A/D timeout, 9 tries over 139 ms

2015-06-09T20:41:10.093Z,1433882470.093 [PAR_Licor] Data Fault, FailCount= 2
2015-06-09T20:41:10.093Z,1433882470.093 [PAR_Licor](ERROR): Data Fault
2015-06-09T20:41:10.093Z,1433882470.093 [AHRS_sp3003D](INFO): Powering down
2015-06-09T20:41:10.239Z,1433882470.239 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:10.241Z,1433882470.241 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:10.260Z,1433882470.260 [CBIT](ERROR): Data Fault in component: PAR_Licor
2015-06-09T20:41:10.260Z,1433882470.260 [CBIT](INFO): Clearing failed state for component PAR_Licor
2015-06-09T20:41:10.264Z,1433882470.264 [PAR_Licor] No Fault, FailCount= 2
2015-06-09T20:41:10.382Z,1433882470.382 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:10.383Z,1433882470.383 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:10.807Z,1433882470.807 [PAR_Licor](INFO): A/D timeout, 9 tries over 130 ms

2015-06-09T20:41:10.807Z,1433882470.807 [PAR_Licor] Data Fault, FailCount= 3
2015-06-09T20:41:10.807Z,1433882470.807 [PAR_Licor](ERROR): Data Fault
2015-06-09T20:41:10.832Z,1433882470.832 [NAL9602](INFO): NAL9602 initialized
2015-06-09T20:41:10.938Z,1433882470.938 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:10.939Z,1433882470.939 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:10.959Z,1433882470.959 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-06-09T20:41:10.959Z,1433882470.959 [Aanderaa_O2] No Fault, FailCount= 1
2015-06-09T20:41:10.959Z,1433882470.959 [CBIT](ERROR): Data Fault in component: PAR_Licor
2015-06-09T20:41:10.959Z,1433882470.959 [CBIT](CRITICAL): Data Fault in component: PAR_Licor
2015-06-09T20:41:11.116Z,1433882471.116 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:11.117Z,1433882471.117 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:11.292Z,1433882471.292 [CommandLine](FAULT): Scheduling is paused
2015-06-09T20:41:11.545Z,1433882471.545 [DAT](DEBUG): 
2015-06-09T20:41:11.546Z,1433882471.546 [DAT](DEBUG): Teledyne Benthos ATM-900 Series
2015-06-09T20:41:11.547Z,1433882471.547 [DAT](DEBUG): MF Frequency Band
2015-06-09T20:41:11.548Z,1433882471.548 [DAT](DEBUG): Directional Acoustic Transponder version 8.3.1
2015-06-09T20:41:11.558Z,1433882471.558 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:11.571Z,1433882471.571 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:11.617Z,1433882471.617 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2015-06-09T20:41:11.617Z,1433882471.617 [AHRS_sp3003D] No Fault, FailCount= 1
2015-06-09T20:41:11.871Z,1433882471.871 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2015-06-09T20:41:11.967Z,1433882471.967 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:11.969Z,1433882471.969 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:12.311Z,1433882472.311 [DAT](DEBUG): Jun  9 2015 21:40:47 
2015-06-09T20:41:12.345Z,1433882472.345 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:12.346Z,1433882472.346 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:13.125Z,1433882473.125 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2015-06-09T20:41:13.125Z,1433882473.125 [AHRS_sp3003D](FAULT): SP3003D failed to initialize
2015-06-09T20:41:13.125Z,1433882473.125 [AHRS_sp3003D] Hardware Fault, FailCount= 2
2015-06-09T20:41:13.125Z,1433882473.125 [AHRS_sp3003D](ERROR): Hardware Fault
2015-06-09T20:41:13.224Z,1433882473.224 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:13.226Z,1433882473.226 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:13.377Z,1433882473.377 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2015-06-09T20:41:13.408Z,1433882473.408 [AHRS_sp3003D](INFO): Powering down
2015-06-09T20:41:13.533Z,1433882473.533 [DAT](INFO): entering command mode
2015-06-09T20:41:13.578Z,1433882473.578 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:13.579Z,1433882473.579 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:13.817Z,1433882473.817 [DAT](DEBUG): checking for command mode acknowledgment
2015-06-09T20:41:13.817Z,1433882473.817 [DAT](DEBUG): read user prompt 1: user:1>
2015-06-09T20:41:13.818Z,1433882473.818 [DAT](INFO): command mode acknowledged
2015-06-09T20:41:13.847Z,1433882473.847 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:13.848Z,1433882473.848 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:14.221Z,1433882474.221 [DAT](INFO): setting local address to 2
2015-06-09T20:41:14.270Z,1433882474.270 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:14.276Z,1433882474.276 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:14.606Z,1433882474.606 [DAT](DEBUG): checking for local address setting acknowledgment
2015-06-09T20:41:14.607Z,1433882474.607 [DAT](INFO): set local address to 2
2015-06-09T20:41:14.628Z,1433882474.628 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:14.629Z,1433882474.629 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:15.015Z,1433882475.015 [DAT](DEBUG): read user prompt 2: user:2>
2015-06-09T20:41:15.036Z,1433882475.036 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:15.037Z,1433882475.037 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:15.232Z,1433882475.232 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2015-06-09T20:41:15.232Z,1433882475.232 [AHRS_sp3003D] No Fault, FailCount= 2
2015-06-09T20:41:15.385Z,1433882475.385 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2015-06-09T20:41:15.436Z,1433882475.436 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:15.441Z,1433882475.441 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:15.867Z,1433882475.867 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:15.868Z,1433882475.868 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:16.245Z,1433882476.245 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:16.246Z,1433882476.246 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:16.715Z,1433882476.715 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2015-06-09T20:41:16.715Z,1433882476.715 [AHRS_sp3003D](ERROR): readHeadingMagBin got 0x000800
2015-06-09T20:41:16.715Z,1433882476.715 [AHRS_sp3003D](FAULT): SP3003D failed to initialize
2015-06-09T20:41:16.715Z,1433882476.715 [AHRS_sp3003D] Hardware Fault, FailCount= 3
2015-06-09T20:41:16.715Z,1433882476.715 [AHRS_sp3003D](ERROR): Hardware Fault
2015-06-09T20:41:16.807Z,1433882476.807 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:16.819Z,1433882476.819 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:16.871Z,1433882476.871 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2015-06-09T20:41:16.988Z,1433882476.988 [AHRS_sp3003D](INFO): Powering down
2015-06-09T20:41:17.103Z,1433882477.103 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:17.108Z,1433882477.108 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:17.446Z,1433882477.446 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:17.447Z,1433882477.447 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:17.849Z,1433882477.849 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:17.850Z,1433882477.850 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:18.247Z,1433882478.247 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:18.248Z,1433882478.248 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:18.628Z,1433882478.628 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:18.642Z,1433882478.642 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:18.701Z,1433882478.701 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2015-06-09T20:41:18.701Z,1433882478.701 [AHRS_sp3003D] No Fault, FailCount= 3
2015-06-09T20:41:18.987Z,1433882478.987 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2015-06-09T20:41:19.063Z,1433882479.063 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:19.064Z,1433882479.064 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:19.396Z,1433882479.396 [DVL_micro](ERROR): No DVL communication! Re-initializing
2015-06-09T20:41:19.396Z,1433882479.396 [DVL_micro] Communications Fault, FailCount= 1
2015-06-09T20:41:19.396Z,1433882479.396 [DVL_micro](ERROR): Communications Fault
2015-06-09T20:41:19.438Z,1433882479.438 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:19.480Z,1433882479.480 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:19.527Z,1433882479.527 [CBIT](ERROR): Communications Fault in component: DVL_micro
2015-06-09T20:41:19.860Z,1433882479.860 [DVL_micro](INFO): uninitialize:Powering down
2015-06-09T20:41:19.966Z,1433882479.966 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:19.967Z,1433882479.967 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:20.517Z,1433882480.517 [AHRS_sp3003D](ERROR): readHeadingMagBin UART error: serial timeout
2015-06-09T20:41:20.517Z,1433882480.517 [AHRS_sp3003D](FAULT): SP3003D failed to initialize
2015-06-09T20:41:20.517Z,1433882480.517 [AHRS_sp3003D] Hardware Fault, FailCount= 4
2015-06-09T20:41:20.517Z,1433882480.517 [AHRS_sp3003D](ERROR): Hardware Fault
2015-06-09T20:41:20.522Z,1433882480.522 [DVL_micro](DEBUG): LCB error: Software Overcurrent.
2015-06-09T20:41:20.595Z,1433882480.595 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:20.597Z,1433882480.597 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:20.665Z,1433882480.665 [CBIT](ERROR): Hardware Fault in component: AHRS_sp3003D
2015-06-09T20:41:20.699Z,1433882480.699 [AHRS_sp3003D](INFO): Powering down
2015-06-09T20:41:20.822Z,1433882480.822 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:20.823Z,1433882480.823 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:20.869Z,1433882480.869 [CBIT](INFO): Clearing failed state for component DVL_micro
2015-06-09T20:41:20.869Z,1433882480.869 [DVL_micro] No Fault, FailCount= 1
2015-06-09T20:41:20.982Z,1433882480.982 [CommandLine](IMPORTANT): got command quit
2015-06-09T20:41:21.086Z,1433882481.086 [DVL_micro](INFO): Initializing
2015-06-09T20:41:21.136Z,1433882481.136 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:21.137Z,1433882481.137 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:21.473Z,1433882481.473 [Aanderaa_O2](FAULT): Timed out starting
2015-06-09T20:41:21.473Z,1433882481.473 [Aanderaa_O2] Communications Fault, FailCount= 2
2015-06-09T20:41:21.474Z,1433882481.474 [Aanderaa_O2](ERROR): Communications Fault
2015-06-09T20:41:21.573Z,1433882481.573 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:21.582Z,1433882481.582 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:21.630Z,1433882481.630 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2015-06-09T20:41:21.990Z,1433882481.990 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2015-06-09T20:41:21.990Z,1433882481.990 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:21.995Z,1433882481.995 [Aanderaa_O2](INFO): Powering down
2015-06-09T20:41:22.050Z,1433882482.050 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:22.051Z,1433882482.051 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:22.167Z,1433882482.167 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2015-06-09T20:41:22.167Z,1433882482.167 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:22.168Z,1433882482.168 [CommandLine](INFO): Join timeout helper Thread ID is 8638
2015-06-09T20:41:22.191Z,1433882482.191 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2015-06-09T20:41:22.191Z,1433882482.191 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:22.192Z,1433882482.192 [NavChartDb](INFO): Join timeout helper Thread ID is 8639
2015-06-09T20:41:22.303Z,1433882482.303 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:22.308Z,1433882482.308 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:22.379Z,1433882482.379 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D
2015-06-09T20:41:22.380Z,1433882482.380 [AHRS_sp3003D] No Fault, FailCount= 4
2015-06-09T20:41:22.611Z,1433882482.611 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2015-06-09T20:41:22.612Z,1433882482.612 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:22.632Z,1433882482.632 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2015-06-09T20:41:22.632Z,1433882482.632 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:22.632Z,1433882482.632 [Radio_Surface](INFO): Join timeout helper Thread ID is 8640
2015-06-09T20:41:22.672Z,1433882482.672 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2015-06-09T20:41:22.704Z,1433882482.704 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:22.705Z,1433882482.705 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:22.746Z,1433882482.746 [SBIT](ERROR): Could not read massPosReader_.
2015-06-09T20:41:22.748Z,1433882482.748 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2015-06-09T20:41:22.748Z,1433882482.748 [Aanderaa_O2] No Fault, FailCount= 2
2015-06-09T20:41:22.988Z,1433882482.988 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2015-06-09T20:41:22.989Z,1433882482.989 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:23.000Z,1433882483.000 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2015-06-09T20:41:23.000Z,1433882483.000 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:23.001Z,1433882483.001 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8642
2015-06-09T20:41:23.101Z,1433882483.101 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2015-06-09T20:41:23.101Z,1433882483.101 [WetLabsBB2FL](INFO): Powering down
2015-06-09T20:41:23.102Z,1433882483.102 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:23.105Z,1433882483.105 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2015-06-09T20:41:23.105Z,1433882483.105 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:23.105Z,1433882483.105 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 8644
2015-06-09T20:41:23.116Z,1433882483.116 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:23.117Z,1433882483.117 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet.
2015-06-09T20:41:23.357Z,1433882483.357 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2015-06-09T20:41:23.357Z,1433882483.357 [CTD_NeilBrown](INFO): Powering down
2015-06-09T20:41:23.358Z,1433882483.358 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:23.370Z,1433882483.370 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2015-06-09T20:41:23.370Z,1433882483.370 [logger ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:23.370Z,1433882483.370 [logger](INFO): Join timeout helper Thread ID is 8645
2015-06-09T20:41:23.373Z,1433882483.373 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2015-06-09T20:41:23.373Z,1433882483.373 [logger ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:23.390Z,1433882483.390 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2015-06-09T20:41:23.390Z,1433882483.390 [CommandLine ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:23.390Z,1433882483.390 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2015-06-09T20:41:23.390Z,1433882483.390 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:23.390Z,1433882483.390 [controlThread](INFO): Join timeout helper Thread ID is 8646
2015-06-09T20:41:23.469Z,1433882483.469 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2015-06-09T20:41:23.470Z,1433882483.470 [controlThread](DEBUG): Uninitializing ControlThread
2015-06-09T20:41:23.589Z,1433882483.589 [Aanderaa_O2](INFO): Powering down
2015-06-09T20:41:23.592Z,1433882483.592 [AHRS_sp3003D](INFO): Powering down
2015-06-09T20:41:23.750Z,1433882483.750 [DVL_micro](INFO): uninitialize:Powering down
2015-06-09T20:41:23.751Z,1433882483.751 [NAL9602](INFO): Powering down
2015-06-09T20:41:23.752Z,1433882483.752 [DAT](INFO): Powering down
2015-06-09T20:41:23.871Z,1433882483.871 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2015-06-09T20:41:23.873Z,1433882483.873 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2015-06-09T20:41:23.877Z,1433882483.877 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2015-06-09T20:41:23.877Z,1433882483.877 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2015-06-09T20:41:23.878Z,1433882483.878 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2015-06-09T20:41:23.878Z,1433882483.878 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2015-06-09T20:41:23.878Z,1433882483.878 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2015-06-09T20:41:23.878Z,1433882483.878 [BuoyancyServo](INFO): Powering down
2015-06-09T20:41:23.890Z,1433882483.890 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2015-06-09T20:41:23.890Z,1433882483.890 [ElevatorServo](INFO): Powering down
2015-06-09T20:41:23.891Z,1433882483.891 [MassServo](DEBUG): Uninitialize Mass Servo.
2015-06-09T20:41:23.891Z,1433882483.891 [MassServo](INFO): Powering down
2015-06-09T20:41:23.909Z,1433882483.909 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2015-06-09T20:41:23.909Z,1433882483.909 [RudderServo](INFO): Powering down
2015-06-09T20:41:23.910Z,1433882483.910 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2015-06-09T20:41:23.911Z,1433882483.911 [ThrusterServo](INFO): Powering down
2015-06-09T20:41:23.911Z,1433882483.911 [SBIT](DEBUG): Uninitialize SBIT Component.
2015-06-09T20:41:23.912Z,1433882483.912 [IBIT](DEBUG): Uninitialize IBIT Component.
2015-06-09T20:41:23.912Z,1433882483.912 [CBIT](DEBUG): Uninitialize CBIT Component.
2015-06-09T20:41:23.942Z,1433882483.942 [controlThread ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:24.002Z,1433882484.002 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:24.007Z,1433882484.007 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:24.073Z,1433882484.073 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:24.235Z,1433882484.235 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2015-06-09T20:41:24.286Z,1433882484.286 [logger ThreadHandler](INFO): Thread cancelled.