2015-04-21T20:44:38.861Z,1429649078.861 [Supervisor](DEBUG): Initializing supervisor. 2015-04-21T20:44:38.864Z,1429649078.864 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2015-04-21T20:44:38.864Z,1429649078.864 [SyncHandler](INFO): Protected caller Thread ID is 768 2015-04-21T20:44:38.865Z,1429649078.865 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2015-04-21T20:44:38.866Z,1429649078.866 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2015-04-21T20:44:38.867Z,1429649078.867 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 769 2015-04-21T20:44:38.870Z,1429649078.870 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2015-04-21T20:44:38.882Z,1429649078.882 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2015-04-21T20:44:38.886Z,1429649078.886 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2015-04-21T20:44:38.887Z,1429649078.887 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 770 2015-04-21T20:44:38.888Z,1429649078.888 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2015-04-21T20:44:38.890Z,1429649078.890 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2015-04-21T20:44:38.891Z,1429649078.891 [logger ThreadHandler](INFO): Protected caller Thread ID is 771 2015-04-21T20:44:38.893Z,1429649078.893 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2015-04-21T20:44:38.893Z,1429649078.893 [Supervisor](INFO): Looking for Config files in directory: Config/ 2015-04-21T20:44:38.898Z,1429649078.898 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2015-04-21T20:44:39.330Z,1429649079.330 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2015-04-21T20:44:39.333Z,1429649079.333 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2015-04-21T20:44:39.540Z,1429649079.540 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2015-04-21T20:44:39.541Z,1429649079.541 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2015-04-21T20:44:39.670Z,1429649079.670 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2015-04-21T20:44:39.670Z,1429649079.670 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2015-04-21T20:44:39.821Z,1429649079.821 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2015-04-21T20:44:39.822Z,1429649079.822 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2015-04-21T20:44:39.916Z,1429649079.916 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2015-04-21T20:44:40.113Z,1429649080.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2015-04-21T20:44:40.114Z,1429649080.114 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2015-04-21T20:44:40.208Z,1429649080.208 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2015-04-21T20:44:40.208Z,1429649080.208 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2015-04-21T20:44:40.482Z,1429649080.482 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2015-04-21T20:44:40.483Z,1429649080.483 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2015-04-21T20:44:40.944Z,1429649080.944 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2015-04-21T20:44:40.946Z,1429649080.946 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2015-04-21T20:44:41.340Z,1429649081.340 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2015-04-21T20:44:41.340Z,1429649081.340 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2015-04-21T20:44:41.973Z,1429649081.973 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2015-04-21T20:44:41.974Z,1429649081.974 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2015-04-21T20:44:42.208Z,1429649082.208 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2015-04-21T20:44:42.208Z,1429649082.208 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2015-04-21T20:44:42.361Z,1429649082.361 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2015-04-21T20:44:42.361Z,1429649082.361 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2015-04-21T20:44:42.902Z,1429649082.902 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2015-04-21T20:44:42.903Z,1429649082.903 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2015-04-21T20:44:43.038Z,1429649083.038 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2015-04-21T20:44:43.040Z,1429649083.040 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2015-04-21T20:44:43.043Z,1429649083.043 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2015-04-21T20:44:43.166Z,1429649083.166 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2015-04-21T20:44:43.373Z,1429649083.373 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2015-04-21T20:44:43.491Z,1429649083.491 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg 2015-04-21T20:44:43.623Z,1429649083.623 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2015-04-21T20:44:43.735Z,1429649083.735 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2015-04-21T20:44:43.892Z,1429649083.892 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2015-04-21T20:44:44.080Z,1429649084.080 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2015-04-21T20:44:44.196Z,1429649084.196 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2015-04-21T20:44:44.300Z,1429649084.300 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2015-04-21T20:44:44.395Z,1429649084.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2015-04-21T20:44:44.509Z,1429649084.509 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2015-04-21T20:44:44.649Z,1429649084.649 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2015-04-21T20:44:44.933Z,1429649084.933 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2015-04-21T20:44:44.933Z,1429649084.933 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2015-04-21T20:44:44.938Z,1429649084.938 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2015-04-21T20:44:45.017Z,1429649085.017 [VerticalControl](DEBUG): Construct VerticalControl. 2015-04-21T20:44:45.159Z,1429649085.159 [VerticalControl] Loaded 2015-04-21T20:44:45.160Z,1429649085.160 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2015-04-21T20:44:45.160Z,1429649085.160 [HorizontalControl](DEBUG): Construct HorizontalControl. 2015-04-21T20:44:45.251Z,1429649085.251 [HorizontalControl] Loaded 2015-04-21T20:44:45.251Z,1429649085.251 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2015-04-21T20:44:45.252Z,1429649085.252 [SpeedControl](DEBUG): Construct SpeedControl. 2015-04-21T20:44:45.259Z,1429649085.259 [SpeedControl] Loaded 2015-04-21T20:44:45.259Z,1429649085.259 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2015-04-21T20:44:45.260Z,1429649085.260 [LoopControl](DEBUG): Construct LoopControl. 2015-04-21T20:44:45.260Z,1429649085.260 [LoopControl] Loaded 2015-04-21T20:44:45.261Z,1429649085.261 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2015-04-21T20:44:45.261Z,1429649085.261 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2015-04-21T20:44:45.263Z,1429649085.263 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2015-04-21T20:44:45.438Z,1429649085.438 [SBIT](DEBUG): Construct Startup Built In Test. 2015-04-21T20:44:45.450Z,1429649085.450 [SBIT] Loaded 2015-04-21T20:44:45.450Z,1429649085.450 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2015-04-21T20:44:45.451Z,1429649085.451 [IBIT](DEBUG): Construct Initiated Built In Test. 2015-04-21T20:44:45.487Z,1429649085.487 [IBIT] Loaded 2015-04-21T20:44:45.487Z,1429649085.487 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2015-04-21T20:44:45.489Z,1429649085.489 [CBIT](DEBUG): Construct Continuous Built In Test. 2015-04-21T20:44:45.648Z,1429649085.648 [CBIT] Loaded 2015-04-21T20:44:45.653Z,1429649085.653 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2015-04-21T20:44:45.653Z,1429649085.653 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2015-04-21T20:44:45.654Z,1429649085.654 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2015-04-21T20:44:45.688Z,1429649085.688 [DepthRateCalculator] Loaded 2015-04-21T20:44:45.688Z,1429649085.688 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2015-04-21T20:44:45.699Z,1429649085.699 [PitchRateCalculator] Loaded 2015-04-21T20:44:45.699Z,1429649085.699 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2015-04-21T20:44:45.712Z,1429649085.712 [SpeedCalculator] Loaded 2015-04-21T20:44:45.712Z,1429649085.712 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2015-04-21T20:44:45.731Z,1429649085.731 [TempGradientCalculator] Loaded 2015-04-21T20:44:45.731Z,1429649085.731 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2015-04-21T20:44:45.741Z,1429649085.741 [YawRateCalculator] Loaded 2015-04-21T20:44:45.741Z,1429649085.741 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2015-04-21T20:44:45.742Z,1429649085.742 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2015-04-21T20:44:45.743Z,1429649085.743 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2015-04-21T20:44:51.876Z,1429649091.876 [HFRadarCompactModelForecaster] Loaded 2015-04-21T20:44:51.876Z,1429649091.876 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread. 2015-04-21T20:44:53.232Z,1429649093.232 [HFRCMSpaceInterpolator] Loaded 2015-04-21T20:44:53.232Z,1429649093.232 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread. 2015-04-21T20:44:54.735Z,1429649094.735 [HFRCMReconstructedInterpolator] Loaded 2015-04-21T20:44:54.736Z,1429649094.736 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread. 2015-04-21T20:44:54.748Z,1429649094.748 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded 2015-04-21T20:44:54.749Z,1429649094.749 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread. 2015-04-21T20:44:54.798Z,1429649094.798 [HFRCMVirtualSurfaceDrifter] Loaded 2015-04-21T20:44:54.799Z,1429649094.799 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread. 2015-04-21T20:44:54.799Z,1429649094.799 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2015-04-21T20:44:54.800Z,1429649094.800 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2015-04-21T20:44:55.137Z,1429649095.137 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2015-04-21T20:44:55.138Z,1429649095.138 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2015-04-21T20:44:55.255Z,1429649095.255 [DeadReckonUsingMultipleVelocitySources] Loaded 2015-04-21T20:44:55.256Z,1429649095.256 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2015-04-21T20:44:55.309Z,1429649095.309 [DeadReckonUsingSpeedCalculator] Loaded 2015-04-21T20:44:55.309Z,1429649095.309 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2015-04-21T20:44:55.332Z,1429649095.332 [NavChart] Loaded 2015-04-21T20:44:55.332Z,1429649095.332 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2015-04-21T20:44:55.337Z,1429649095.337 [UniversalFixResidualReporter] Loaded 2015-04-21T20:44:55.337Z,1429649095.337 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2015-04-21T20:44:55.338Z,1429649095.338 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2015-04-21T20:44:55.338Z,1429649095.338 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2015-04-21T20:44:55.347Z,1429649095.347 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2015-04-21T20:44:55.348Z,1429649095.348 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2015-04-21T20:44:55.570Z,1429649095.570 [Aanderaa_O2] Loaded 2015-04-21T20:44:55.570Z,1429649095.570 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2015-04-21T20:44:55.661Z,1429649095.661 [CTD_NeilBrown] Loaded 2015-04-21T20:44:55.661Z,1429649095.661 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2015-04-21T20:44:55.664Z,1429649095.664 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406E94E0 2015-04-21T20:44:55.665Z,1429649095.665 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 858 2015-04-21T20:44:55.679Z,1429649095.679 [ISUS] Loaded 2015-04-21T20:44:55.679Z,1429649095.679 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2015-04-21T20:44:55.699Z,1429649095.699 [PAR_Licor] Loaded 2015-04-21T20:44:55.699Z,1429649095.699 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2015-04-21T20:44:55.754Z,1429649095.754 [WetLabsBB2FL] Loaded 2015-04-21T20:44:55.755Z,1429649095.755 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2015-04-21T20:44:55.757Z,1429649095.757 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407194E0 2015-04-21T20:44:55.757Z,1429649095.757 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 859 2015-04-21T20:44:55.758Z,1429649095.758 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2015-04-21T20:44:55.758Z,1429649095.758 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2015-04-21T20:44:56.497Z,1429649096.497 [AHRS_sp3003D] Loaded 2015-04-21T20:44:56.497Z,1429649096.497 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2015-04-21T20:44:56.679Z,1429649096.679 [DataOverHttps] Loaded 2015-04-21T20:44:56.679Z,1429649096.679 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2015-04-21T20:44:56.694Z,1429649096.694 [Depth_Keller] Loaded 2015-04-21T20:44:56.694Z,1429649096.694 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2015-04-21T20:44:56.699Z,1429649096.699 [DropWeight] Loaded 2015-04-21T20:44:56.700Z,1429649096.700 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2015-04-21T20:44:56.863Z,1429649096.863 [DVL_micro] Loaded 2015-04-21T20:44:56.863Z,1429649096.863 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2015-04-21T20:44:56.979Z,1429649096.979 [NAL9602] Loaded 2015-04-21T20:44:56.980Z,1429649096.980 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2015-04-21T20:44:57.030Z,1429649097.030 [Onboard] Loaded 2015-04-21T20:44:57.030Z,1429649097.030 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2015-04-21T20:44:57.038Z,1429649097.038 [Radio_Surface] Loaded 2015-04-21T20:44:57.038Z,1429649097.038 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2015-04-21T20:44:57.042Z,1429649097.042 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4095C4E0 2015-04-21T20:44:57.043Z,1429649097.043 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 860 2015-04-21T20:44:57.206Z,1429649097.206 [DAT] Loaded 2015-04-21T20:44:57.206Z,1429649097.206 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2015-04-21T20:44:59.439Z,1429649099.439 [BPC1] Loaded 2015-04-21T20:44:59.439Z,1429649099.439 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2015-04-21T20:44:59.439Z,1429649099.439 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2015-04-21T20:44:59.440Z,1429649099.440 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2015-04-21T20:44:59.587Z,1429649099.587 [BuoyancyServo] Loaded 2015-04-21T20:44:59.587Z,1429649099.587 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2015-04-21T20:44:59.600Z,1429649099.600 [ElevatorServo] Loaded 2015-04-21T20:44:59.601Z,1429649099.601 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2015-04-21T20:44:59.613Z,1429649099.613 [RudderServo] Loaded 2015-04-21T20:44:59.614Z,1429649099.614 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2015-04-21T20:44:59.626Z,1429649099.626 [ThrusterServo] Loaded 2015-04-21T20:44:59.630Z,1429649099.630 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2015-04-21T20:44:59.631Z,1429649099.631 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2015-04-21T20:44:59.632Z,1429649099.632 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2015-04-21T20:44:59.789Z,1429649099.789 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2015-04-21T20:44:59.790Z,1429649099.790 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2015-04-21T20:44:59.834Z,1429649099.834 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2015-04-21T20:44:59.838Z,1429649099.838 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2015-04-21T20:44:59.839Z,1429649099.839 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2015-04-21T20:44:59.846Z,1429649099.846 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2015-04-21T20:44:59.851Z,1429649099.851 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A0D4E0 2015-04-21T20:44:59.851Z,1429649099.851 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 861 2015-04-21T20:44:59.856Z,1429649099.856 [Supervisor](INFO): Main Thread ID is 764 2015-04-21T20:44:59.856Z,1429649099.856 [Supervisor](DEBUG): Running supervisor. 2015-04-21T20:44:59.857Z,1429649099.857 [CommandLine ThreadHandler](INFO): Handler Thread ID is 862 2015-04-21T20:44:59.863Z,1429649099.863 [controlThread ThreadHandler](INFO): Handler Thread ID is 863 2015-04-21T20:44:59.864Z,1429649099.864 [controlThread](DEBUG): Initializing ControlThread 2015-04-21T20:44:59.865Z,1429649099.865 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2015-04-21T20:44:59.866Z,1429649099.866 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2015-04-21T20:44:59.867Z,1429649099.867 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2015-04-21T20:44:59.868Z,1429649099.868 [LoopControl](DEBUG): Initialize LoopControlComponent. 2015-04-21T20:44:59.868Z,1429649099.868 [SBIT](INFO): Initialize SBIT Component. 2015-04-21T20:44:59.868Z,1429649099.868 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12129 2015-04-21T20:44:59.869Z,1429649099.869 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2015-04-21T20:44:59.869Z,1429649099.869 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2015-04-21T20:44:59.870Z,1429649099.870 [IBIT](INFO): Initialize IBIT Component. 2015-04-21T20:44:59.871Z,1429649099.871 [CBIT](DEBUG): Initialize CBIT Component. 2015-04-21T20:44:59.871Z,1429649099.871 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2015-04-21T20:44:59.871Z,1429649099.871 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2015-04-21T20:44:59.875Z,1429649099.875 [logger ThreadHandler](INFO): Handler Thread ID is 864 2015-04-21T20:44:59.895Z,1429649099.895 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-04-21T20:44:59.895Z,1429649099.895 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2015-04-21T20:44:59.896Z,1429649099.896 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2015-04-21T20:44:59.896Z,1429649099.896 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2015-04-21T20:44:59.897Z,1429649099.897 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2015-04-21T20:44:59.912Z,1429649099.912 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 865 2015-04-21T20:44:59.913Z,1429649099.913 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2015-04-21T20:44:59.915Z,1429649099.915 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2015-04-21T20:44:59.919Z,1429649099.919 [HFRadarCompactModelForecaster](DEBUG): Found new ECs! 2015-04-21T20:44:59.920Z,1429649099.920 [HFRadarCompactModelForecaster](ERROR): Most recent ECs are more than six hours old. 2015-04-21T20:44:59.932Z,1429649099.932 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 867 2015-04-21T20:44:59.933Z,1429649099.933 [WetLabsBB2FL](INFO): Powering down 2015-04-21T20:44:59.962Z,1429649099.962 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 868 2015-04-21T20:44:59.986Z,1429649099.986 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 869 2015-04-21T20:44:59.992Z,1429649099.992 [Radio_Surface](INFO): Powering up 2015-04-21T20:44:59.994Z,1429649099.994 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2015-04-21T20:44:59.995Z,1429649099.995 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2015-04-21T20:44:59.995Z,1429649099.995 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2015-04-21T20:44:59.996Z,1429649099.996 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2015-04-21T20:44:59.996Z,1429649099.996 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2015-04-21T20:44:59.996Z,1429649099.996 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2015-04-21T20:44:59.996Z,1429649099.996 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2015-04-21T20:44:59.997Z,1429649099.997 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2015-04-21T20:44:59.997Z,1429649099.997 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2015-04-21T20:45:00.063Z,1429649100.063 [CTD_NeilBrown](DEBUG): CTD uart timeout: serial timeout 2015-04-21T20:45:00.064Z,1429649100.064 [CTD_NeilBrown](ERROR): Could not get real or simulated CTD data. startTime.elapsed() = 0.147929 2015-04-21T20:45:09.086Z,1429649109.086 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201504131600 published 2015-04-21T20:45:09.094Z,1429649109.094 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 1. 2015-04-21T20:45:09.096Z,1429649109.096 [HFRCMSpaceInterpolator](INFO): gridIdxRev_: 541 by 1, [25.000000, 718.000000] 2015-04-21T20:45:09.096Z,1429649109.096 [HFRCMSpaceInterpolator](INFO): gridIdx_: 25 by 29, [nan, nan] 2015-04-21T20:45:09.097Z,1429649109.097 [HFRCMSpaceInterpolator](INFO): longitude grid: 25 by 29, [-122.743156, -121.797913] 2015-04-21T20:45:09.098Z,1429649109.098 [HFRCMSpaceInterpolator](INFO): latitude grid: 25 by 29, [36.341251, 36.990059] 2015-04-21T20:45:09.110Z,1429649109.110 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s. 2015-04-21T20:45:09.112Z,1429649109.112 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component. 2015-04-21T20:45:09.112Z,1429649109.112 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component. 2015-04-21T20:45:09.112Z,1429649109.112 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-04-21T20:45:09.113Z,1429649109.113 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-04-21T20:45:09.121Z,1429649109.121 [NavChart](DEBUG): Initialize NavChart Navigation. 2015-04-21T20:45:09.122Z,1429649109.122 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2015-04-21T20:45:09.132Z,1429649109.132 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2015-04-21T20:45:09.190Z,1429649109.190 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-04-21T20:45:09.219Z,1429649109.219 [MissionManager](DEBUG): 2015-04-21T20:45:09.220Z,1429649109.220 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2015-04-21T20:45:09.315Z,1429649109.315 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2015-04-21T20:45:09.316Z,1429649109.316 [Default:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-04-21T20:45:09.353Z,1429649109.353 [Default:CheckIn:A.SetSpeed](DEBUG): Construct. 2015-04-21T20:45:09.390Z,1429649109.390 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2015-04-21T20:45:09.393Z,1429649109.393 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct. 2015-04-21T20:45:09.420Z,1429649109.420 [MissionManager](DEBUG): 0 5.0 1.0 400