2015-04-21T21:13:46.568Z,1429650826.568 [Supervisor](DEBUG): Initializing supervisor. 2015-04-21T21:13:46.572Z,1429650826.572 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2015-04-21T21:13:46.572Z,1429650826.572 [SyncHandler](INFO): Protected caller Thread ID is 768 2015-04-21T21:13:46.573Z,1429650826.573 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2015-04-21T21:13:46.575Z,1429650826.575 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2015-04-21T21:13:46.575Z,1429650826.575 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 769 2015-04-21T21:13:46.578Z,1429650826.578 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2015-04-21T21:13:46.590Z,1429650826.590 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2015-04-21T21:13:46.595Z,1429650826.595 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2015-04-21T21:13:46.595Z,1429650826.595 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 770 2015-04-21T21:13:46.596Z,1429650826.596 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2015-04-21T21:13:46.599Z,1429650826.599 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2015-04-21T21:13:46.599Z,1429650826.599 [logger ThreadHandler](INFO): Protected caller Thread ID is 771 2015-04-21T21:13:46.602Z,1429650826.602 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2015-04-21T21:13:46.602Z,1429650826.602 [Supervisor](INFO): Looking for Config files in directory: Config/ 2015-04-21T21:13:46.606Z,1429650826.606 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2015-04-21T21:13:46.981Z,1429650826.981 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2015-04-21T21:13:46.982Z,1429650826.982 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2015-04-21T21:13:47.173Z,1429650827.173 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2015-04-21T21:13:47.175Z,1429650827.175 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2015-04-21T21:13:47.302Z,1429650827.302 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2015-04-21T21:13:47.302Z,1429650827.302 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2015-04-21T21:13:47.441Z,1429650827.441 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2015-04-21T21:13:47.442Z,1429650827.442 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2015-04-21T21:13:47.538Z,1429650827.538 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2015-04-21T21:13:47.719Z,1429650827.719 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2015-04-21T21:13:47.720Z,1429650827.720 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2015-04-21T21:13:47.816Z,1429650827.816 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2015-04-21T21:13:47.817Z,1429650827.817 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2015-04-21T21:13:48.065Z,1429650828.065 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2015-04-21T21:13:48.066Z,1429650828.066 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2015-04-21T21:13:48.467Z,1429650828.467 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2015-04-21T21:13:48.468Z,1429650828.468 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2015-04-21T21:13:48.802Z,1429650828.802 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2015-04-21T21:13:48.804Z,1429650828.804 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2015-04-21T21:13:49.374Z,1429650829.374 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2015-04-21T21:13:49.375Z,1429650829.375 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2015-04-21T21:13:49.581Z,1429650829.581 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2015-04-21T21:13:49.581Z,1429650829.581 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2015-04-21T21:13:49.691Z,1429650829.691 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2015-04-21T21:13:49.692Z,1429650829.692 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2015-04-21T21:13:50.173Z,1429650830.173 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2015-04-21T21:13:50.174Z,1429650830.174 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2015-04-21T21:13:51.526Z,1429650831.526 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2015-04-21T21:13:51.528Z,1429650831.528 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2015-04-21T21:13:51.531Z,1429650831.531 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2015-04-21T21:13:51.650Z,1429650831.650 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2015-04-21T21:13:51.785Z,1429650831.785 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2015-04-21T21:13:51.897Z,1429650831.897 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg 2015-04-21T21:13:52.020Z,1429650832.020 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2015-04-21T21:13:52.125Z,1429650832.125 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2015-04-21T21:13:52.269Z,1429650832.269 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2015-04-21T21:13:52.437Z,1429650832.437 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2015-04-21T21:13:52.550Z,1429650832.550 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2015-04-21T21:13:52.650Z,1429650832.650 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2015-04-21T21:13:52.740Z,1429650832.740 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2015-04-21T21:13:52.850Z,1429650832.850 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2015-04-21T21:13:52.979Z,1429650832.979 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2015-04-21T21:13:53.247Z,1429650833.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2015-04-21T21:13:53.247Z,1429650833.247 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2015-04-21T21:13:53.253Z,1429650833.253 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2015-04-21T21:13:53.330Z,1429650833.330 [VerticalControl](DEBUG): Construct VerticalControl. 2015-04-21T21:13:53.465Z,1429650833.465 [VerticalControl] Loaded 2015-04-21T21:13:53.465Z,1429650833.465 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2015-04-21T21:13:53.466Z,1429650833.466 [HorizontalControl](DEBUG): Construct HorizontalControl. 2015-04-21T21:13:53.550Z,1429650833.550 [HorizontalControl] Loaded 2015-04-21T21:13:53.550Z,1429650833.550 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2015-04-21T21:13:53.551Z,1429650833.551 [SpeedControl](DEBUG): Construct SpeedControl. 2015-04-21T21:13:53.557Z,1429650833.557 [SpeedControl] Loaded 2015-04-21T21:13:53.557Z,1429650833.557 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2015-04-21T21:13:53.558Z,1429650833.558 [LoopControl](DEBUG): Construct LoopControl. 2015-04-21T21:13:53.558Z,1429650833.558 [LoopControl] Loaded 2015-04-21T21:13:53.559Z,1429650833.559 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2015-04-21T21:13:53.559Z,1429650833.559 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2015-04-21T21:13:53.560Z,1429650833.560 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2015-04-21T21:13:53.725Z,1429650833.725 [SBIT](DEBUG): Construct Startup Built In Test. 2015-04-21T21:13:53.741Z,1429650833.741 [SBIT] Loaded 2015-04-21T21:13:53.741Z,1429650833.741 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2015-04-21T21:13:53.742Z,1429650833.742 [IBIT](DEBUG): Construct Initiated Built In Test. 2015-04-21T21:13:53.776Z,1429650833.776 [IBIT] Loaded 2015-04-21T21:13:53.777Z,1429650833.777 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2015-04-21T21:13:53.779Z,1429650833.779 [CBIT](DEBUG): Construct Continuous Built In Test. 2015-04-21T21:13:53.937Z,1429650833.937 [CBIT] Loaded 2015-04-21T21:13:53.937Z,1429650833.937 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2015-04-21T21:13:53.937Z,1429650833.937 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2015-04-21T21:13:53.938Z,1429650833.938 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2015-04-21T21:13:53.971Z,1429650833.971 [DepthRateCalculator] Loaded 2015-04-21T21:13:53.971Z,1429650833.971 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2015-04-21T21:13:53.977Z,1429650833.977 [PitchRateCalculator] Loaded 2015-04-21T21:13:53.977Z,1429650833.977 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2015-04-21T21:13:53.993Z,1429650833.993 [SpeedCalculator] Loaded 2015-04-21T21:13:53.993Z,1429650833.993 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2015-04-21T21:13:54.011Z,1429650834.011 [TempGradientCalculator] Loaded 2015-04-21T21:13:54.011Z,1429650834.011 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2015-04-21T21:13:54.016Z,1429650834.016 [YawRateCalculator] Loaded 2015-04-21T21:13:54.017Z,1429650834.017 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2015-04-21T21:13:54.017Z,1429650834.017 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2015-04-21T21:13:54.018Z,1429650834.018 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2015-04-21T21:13:58.644Z,1429650838.644 [HFRadarCompactModelForecaster] Loaded 2015-04-21T21:13:58.644Z,1429650838.644 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread. 2015-04-21T21:13:59.745Z,1429650839.745 [HFRCMSpaceInterpolator] Loaded 2015-04-21T21:13:59.745Z,1429650839.745 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread. 2015-04-21T21:14:00.981Z,1429650840.981 [HFRCMReconstructedInterpolator] Loaded 2015-04-21T21:14:00.982Z,1429650840.982 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread. 2015-04-21T21:14:00.998Z,1429650840.998 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded 2015-04-21T21:14:00.998Z,1429650840.998 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread. 2015-04-21T21:14:01.026Z,1429650841.026 [HFRCMVirtualSurfaceDrifter] Loaded 2015-04-21T21:14:01.026Z,1429650841.026 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread. 2015-04-21T21:14:01.027Z,1429650841.027 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2015-04-21T21:14:01.028Z,1429650841.028 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2015-04-21T21:14:01.333Z,1429650841.333 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2015-04-21T21:14:01.338Z,1429650841.338 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2015-04-21T21:14:01.455Z,1429650841.455 [DeadReckonUsingMultipleVelocitySources] Loaded 2015-04-21T21:14:01.456Z,1429650841.456 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2015-04-21T21:14:01.507Z,1429650841.507 [DeadReckonUsingSpeedCalculator] Loaded 2015-04-21T21:14:01.507Z,1429650841.507 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2015-04-21T21:14:01.529Z,1429650841.529 [NavChart] Loaded 2015-04-21T21:14:01.529Z,1429650841.529 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2015-04-21T21:14:01.534Z,1429650841.534 [UniversalFixResidualReporter] Loaded 2015-04-21T21:14:01.534Z,1429650841.534 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2015-04-21T21:14:01.535Z,1429650841.535 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2015-04-21T21:14:01.535Z,1429650841.535 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2015-04-21T21:14:01.544Z,1429650841.544 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2015-04-21T21:14:01.545Z,1429650841.545 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2015-04-21T21:14:01.763Z,1429650841.763 [Aanderaa_O2] Loaded 2015-04-21T21:14:01.764Z,1429650841.764 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2015-04-21T21:14:01.851Z,1429650841.851 [CTD_NeilBrown] Loaded 2015-04-21T21:14:01.852Z,1429650841.852 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2015-04-21T21:14:01.855Z,1429650841.855 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406E94E0 2015-04-21T21:14:01.855Z,1429650841.855 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 856 2015-04-21T21:14:01.868Z,1429650841.868 [ISUS] Loaded 2015-04-21T21:14:01.869Z,1429650841.869 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2015-04-21T21:14:01.888Z,1429650841.888 [PAR_Licor] Loaded 2015-04-21T21:14:01.888Z,1429650841.888 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2015-04-21T21:14:01.941Z,1429650841.941 [WetLabsBB2FL] Loaded 2015-04-21T21:14:01.942Z,1429650841.942 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2015-04-21T21:14:01.947Z,1429650841.947 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407194E0 2015-04-21T21:14:01.947Z,1429650841.947 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 857 2015-04-21T21:14:01.948Z,1429650841.948 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2015-04-21T21:14:01.949Z,1429650841.949 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2015-04-21T21:14:02.681Z,1429650842.681 [AHRS_sp3003D] Loaded 2015-04-21T21:14:02.681Z,1429650842.681 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2015-04-21T21:14:02.867Z,1429650842.867 [DataOverHttps] Loaded 2015-04-21T21:14:02.867Z,1429650842.867 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2015-04-21T21:14:02.881Z,1429650842.881 [Depth_Keller] Loaded 2015-04-21T21:14:02.881Z,1429650842.881 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2015-04-21T21:14:02.886Z,1429650842.886 [DropWeight] Loaded 2015-04-21T21:14:02.887Z,1429650842.887 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2015-04-21T21:14:03.044Z,1429650843.044 [DVL_micro] Loaded 2015-04-21T21:14:03.045Z,1429650843.045 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2015-04-21T21:14:03.156Z,1429650843.156 [NAL9602] Loaded 2015-04-21T21:14:03.156Z,1429650843.156 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2015-04-21T21:14:03.205Z,1429650843.205 [Onboard] Loaded 2015-04-21T21:14:03.205Z,1429650843.205 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2015-04-21T21:14:03.212Z,1429650843.212 [Radio_Surface] Loaded 2015-04-21T21:14:03.212Z,1429650843.212 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2015-04-21T21:14:03.217Z,1429650843.217 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4095C4E0 2015-04-21T21:14:03.217Z,1429650843.217 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 858 2015-04-21T21:14:03.375Z,1429650843.375 [DAT] Loaded 2015-04-21T21:14:03.375Z,1429650843.375 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2015-04-21T21:14:05.588Z,1429650845.588 [BPC1] Loaded 2015-04-21T21:14:05.588Z,1429650845.588 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2015-04-21T21:14:05.588Z,1429650845.588 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2015-04-21T21:14:05.589Z,1429650845.589 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2015-04-21T21:14:05.728Z,1429650845.728 [BuoyancyServo] Loaded 2015-04-21T21:14:05.729Z,1429650845.729 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2015-04-21T21:14:05.746Z,1429650845.746 [ElevatorServo] Loaded 2015-04-21T21:14:05.746Z,1429650845.746 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2015-04-21T21:14:05.758Z,1429650845.758 [RudderServo] Loaded 2015-04-21T21:14:05.758Z,1429650845.758 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2015-04-21T21:14:05.770Z,1429650845.770 [ThrusterServo] Loaded 2015-04-21T21:14:05.771Z,1429650845.771 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2015-04-21T21:14:05.771Z,1429650845.771 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2015-04-21T21:14:05.772Z,1429650845.772 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2015-04-21T21:14:05.923Z,1429650845.923 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2015-04-21T21:14:05.924Z,1429650845.924 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2015-04-21T21:14:05.968Z,1429650845.968 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2015-04-21T21:14:05.972Z,1429650845.972 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2015-04-21T21:14:05.973Z,1429650845.973 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2015-04-21T21:14:05.980Z,1429650845.980 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2015-04-21T21:14:05.981Z,1429650845.981 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A0D4E0 2015-04-21T21:14:05.981Z,1429650845.981 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 860 2015-04-21T21:14:05.986Z,1429650845.986 [Supervisor](INFO): Main Thread ID is 764 2015-04-21T21:14:05.986Z,1429650845.986 [Supervisor](DEBUG): Running supervisor. 2015-04-21T21:14:05.987Z,1429650845.987 [CommandLine ThreadHandler](INFO): Handler Thread ID is 861 2015-04-21T21:14:05.994Z,1429650845.994 [controlThread ThreadHandler](INFO): Handler Thread ID is 862 2015-04-21T21:14:05.994Z,1429650845.994 [controlThread](DEBUG): Initializing ControlThread 2015-04-21T21:14:05.995Z,1429650845.995 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2015-04-21T21:14:05.997Z,1429650845.997 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2015-04-21T21:14:05.997Z,1429650845.997 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2015-04-21T21:14:05.998Z,1429650845.998 [LoopControl](DEBUG): Initialize LoopControlComponent. 2015-04-21T21:14:05.998Z,1429650845.998 [SBIT](INFO): Initialize SBIT Component. 2015-04-21T21:14:05.999Z,1429650845.999 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12129 2015-04-21T21:14:05.999Z,1429650845.999 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2015-04-21T21:14:05.999Z,1429650845.999 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2015-04-21T21:14:05.000Z,1429650846.000 [IBIT](INFO): Initialize IBIT Component. 2015-04-21T21:14:06.001Z,1429650846.001 [CBIT](DEBUG): Initialize CBIT Component. 2015-04-21T21:14:06.001Z,1429650846.001 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2015-04-21T21:14:06.001Z,1429650846.001 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2015-04-21T21:14:06.006Z,1429650846.006 [logger ThreadHandler](INFO): Handler Thread ID is 863 2015-04-21T21:14:06.025Z,1429650846.025 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-04-21T21:14:06.026Z,1429650846.026 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2015-04-21T21:14:06.026Z,1429650846.026 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2015-04-21T21:14:06.026Z,1429650846.026 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2015-04-21T21:14:06.027Z,1429650846.027 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2015-04-21T21:14:06.042Z,1429650846.042 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 864 2015-04-21T21:14:06.043Z,1429650846.043 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2015-04-21T21:14:06.045Z,1429650846.045 [HFRadarCompactModelForecaster](DEBUG): Found new ECs! 2015-04-21T21:14:06.045Z,1429650846.045 [HFRadarCompactModelForecaster](ERROR): Most recent ECs are more than six hours old. 2015-04-21T21:14:06.047Z,1429650846.047 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2015-04-21T21:14:06.067Z,1429650846.067 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 866 2015-04-21T21:14:06.069Z,1429650846.069 [WetLabsBB2FL](INFO): Powering down 2015-04-21T21:14:06.103Z,1429650846.103 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 867 2015-04-21T21:14:06.120Z,1429650846.120 [Radio_Surface](INFO): Powering up 2015-04-21T21:14:06.128Z,1429650846.128 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 868 2015-04-21T21:14:06.139Z,1429650846.139 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2015-04-21T21:14:06.140Z,1429650846.140 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2015-04-21T21:14:06.140Z,1429650846.140 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2015-04-21T21:14:06.141Z,1429650846.141 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2015-04-21T21:14:06.141Z,1429650846.141 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2015-04-21T21:14:06.141Z,1429650846.141 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2015-04-21T21:14:06.142Z,1429650846.142 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2015-04-21T21:14:06.142Z,1429650846.142 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2015-04-21T21:14:06.142Z,1429650846.142 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2015-04-21T21:14:06.181Z,1429650846.181 [CTD_NeilBrown](DEBUG): CTD uart timeout: serial timeout 2015-04-21T21:14:06.182Z,1429650846.182 [CTD_NeilBrown](ERROR): Could not get real or simulated CTD data. startTime.elapsed() = 0.134212 2015-04-21T21:14:15.070Z,1429650855.070 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201504131600 published 2015-04-21T21:14:15.081Z,1429650855.081 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 1. 2015-04-21T21:14:15.092Z,1429650855.092 [HFRCMSpaceInterpolator](INFO): gridIdxRev_: 541 by 1, [25.000000, 718.000000] 2015-04-21T21:14:15.092Z,1429650855.092 [HFRCMSpaceInterpolator](INFO): gridIdx_: 25 by 29, [nan, nan] 2015-04-21T21:14:15.093Z,1429650855.093 [HFRCMSpaceInterpolator](INFO): longitude grid: 25 by 29, [-122.743156, -121.797913] 2015-04-21T21:14:15.094Z,1429650855.094 [HFRCMSpaceInterpolator](INFO): latitude grid: 25 by 29, [36.341251, 36.990059] 2015-04-21T21:14:15.103Z,1429650855.103 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s. 2015-04-21T21:14:15.105Z,1429650855.105 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component. 2015-04-21T21:14:15.105Z,1429650855.105 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component. 2015-04-21T21:14:15.106Z,1429650855.106 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-04-21T21:14:15.106Z,1429650855.106 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-04-21T21:14:15.106Z,1429650855.106 [NavChart](DEBUG): Initialize NavChart Navigation. 2015-04-21T21:14:15.107Z,1429650855.107 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2015-04-21T21:14:15.140Z,1429650855.140 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2015-04-21T21:14:15.177Z,1429650855.177 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-04-21T21:14:15.202Z,1429650855.202 [MissionManager](DEBUG): 2015-04-21T21:14:15.203Z,1429650855.203 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2015-04-21T21:14:15.305Z,1429650855.305 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2015-04-21T21:14:15.306Z,1429650855.306 [Default:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-04-21T21:14:15.331Z,1429650855.331 [Default:CheckIn:A.SetSpeed](DEBUG): Construct. 2015-04-21T21:14:15.380Z,1429650855.380 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2015-04-21T21:14:15.384Z,1429650855.384 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct. 2015-04-21T21:14:15.407Z,1429650855.407 [MissionManager](DEBUG): 0 5.0 1.0 400