2014-06-03T17:38:31.744Z,1401817111.744 [Supervisor](DEBUG): Initializing supervisor.
2014-06-03T17:38:31.746Z,1401817111.746 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-06-03T17:38:31.747Z,1401817111.747 [SyncHandler](INFO): Protected caller Thread ID is 6712
2014-06-03T17:38:31.747Z,1401817111.747 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-06-03T17:38:31.748Z,1401817111.748 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-06-03T17:38:31.749Z,1401817111.749 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6713
2014-06-03T17:38:31.752Z,1401817111.752 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-06-03T17:38:31.772Z,1401817111.772 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-06-03T17:38:31.773Z,1401817111.773 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-06-03T17:38:31.774Z,1401817111.774 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6714
2014-06-03T17:38:31.775Z,1401817111.775 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-06-03T17:38:31.776Z,1401817111.776 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-06-03T17:38:31.776Z,1401817111.776 [logger ThreadHandler](INFO): Protected caller Thread ID is 6715
2014-06-03T17:38:31.778Z,1401817111.778 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-06-03T17:38:31.779Z,1401817111.779 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-06-03T17:38:31.780Z,1401817111.780 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-06-03T17:38:32.129Z,1401817112.129 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-06-03T17:38:32.130Z,1401817112.130 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-06-03T17:38:32.411Z,1401817112.411 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-06-03T17:38:32.411Z,1401817112.411 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-06-03T17:38:32.500Z,1401817112.500 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-06-03T17:38:32.501Z,1401817112.501 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-06-03T17:38:32.680Z,1401817112.680 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-06-03T17:38:32.680Z,1401817112.680 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-06-03T17:38:32.844Z,1401817112.844 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-06-03T17:38:32.844Z,1401817112.844 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-06-03T17:38:33.145Z,1401817113.145 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-06-03T17:38:33.146Z,1401817113.146 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-06-03T17:38:33.329Z,1401817113.329 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-06-03T17:38:33.330Z,1401817113.330 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-06-03T17:38:33.663Z,1401817113.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-06-03T17:38:33.663Z,1401817113.663 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-06-03T17:38:33.774Z,1401817113.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-06-03T17:38:33.775Z,1401817113.775 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-06-03T17:38:34.270Z,1401817114.270 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-06-03T17:38:34.270Z,1401817114.270 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-06-03T17:38:34.382Z,1401817114.382 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-06-03T17:38:34.382Z,1401817114.382 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-06-03T17:38:34.470Z,1401817114.470 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-06-03T17:38:34.592Z,1401817114.592 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-06-03T17:38:34.593Z,1401817114.593 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-06-03T17:38:34.698Z,1401817114.698 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-06-03T17:38:34.698Z,1401817114.698 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-06-03T17:38:34.838Z,1401817114.838 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-06-03T17:38:34.841Z,1401817114.841 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-06-03T17:38:34.841Z,1401817114.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-06-03T17:38:34.954Z,1401817114.954 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-06-03T17:38:35.084Z,1401817115.084 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-06-03T17:38:35.182Z,1401817115.182 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-06-03T17:38:35.275Z,1401817115.275 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-06-03T17:38:35.419Z,1401817115.419 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-06-03T17:38:35.536Z,1401817115.536 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-06-03T17:38:35.624Z,1401817115.624 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-06-03T17:38:35.732Z,1401817115.732 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-06-03T17:38:35.834Z,1401817115.834 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-06-03T17:38:35.933Z,1401817115.933 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-06-03T17:38:36.022Z,1401817116.022 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-06-03T17:38:36.122Z,1401817116.122 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/
2014-06-03T17:38:36.122Z,1401817116.122 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-06-03T17:38:36.124Z,1401817116.124 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-06-03T17:38:36.474Z,1401817116.474 [AHRS_sp3003D] Loaded
2014-06-03T17:38:36.474Z,1401817116.474 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-06-03T17:38:36.776Z,1401817116.776 [Batt_Ocean_Server] Loaded
2014-06-03T17:38:36.776Z,1401817116.776 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-06-03T17:38:36.790Z,1401817116.790 [Depth_Keller] Loaded
2014-06-03T17:38:36.790Z,1401817116.790 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-06-03T17:38:36.795Z,1401817116.795 [DropWeight] Loaded
2014-06-03T17:38:36.795Z,1401817116.795 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-06-03T17:38:36.955Z,1401817116.955 [DVL_micro] Loaded
2014-06-03T17:38:36.955Z,1401817116.955 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-06-03T17:38:37.057Z,1401817117.057 [NAL9602] Loaded
2014-06-03T17:38:37.057Z,1401817117.057 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-06-03T17:38:37.110Z,1401817117.110 [Onboard] Loaded
2014-06-03T17:38:37.111Z,1401817117.111 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-06-03T17:38:37.118Z,1401817117.118 [Radio_Freewave] Loaded
2014-06-03T17:38:37.118Z,1401817117.118 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-06-03T17:38:37.119Z,1401817117.119 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 406104E0
2014-06-03T17:38:37.120Z,1401817117.120 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 6797
2014-06-03T17:38:37.126Z,1401817117.126 [SCPI] Loaded
2014-06-03T17:38:37.127Z,1401817117.127 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-06-03T17:38:37.127Z,1401817117.127 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-06-03T17:38:37.128Z,1401817117.128 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-06-03T17:38:37.324Z,1401817117.324 [InternalSim] Loaded
2014-06-03T17:38:37.325Z,1401817117.325 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-06-03T17:38:37.325Z,1401817117.325 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-06-03T17:38:37.326Z,1401817117.326 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-06-03T17:38:37.572Z,1401817117.572 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-06-03T17:38:37.573Z,1401817117.573 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-06-03T17:38:37.579Z,1401817117.579 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-06-03T17:38:37.579Z,1401817117.579 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-06-03T17:38:37.660Z,1401817117.660 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-06-03T17:38:37.660Z,1401817117.660 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-06-03T17:38:37.706Z,1401817117.706 [DeadReckonWithRespectToWater] Loaded
2014-06-03T17:38:37.707Z,1401817117.707 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-06-03T17:38:37.753Z,1401817117.753 [DeadReckonWithRespectToSeafloor] Loaded
2014-06-03T17:38:37.754Z,1401817117.754 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-06-03T17:38:37.801Z,1401817117.801 [DeadReckonUsingDVLWaterTrack] Loaded
2014-06-03T17:38:37.802Z,1401817117.802 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-06-03T17:38:37.850Z,1401817117.850 [DeadReckonUsingCompactModelForecast] Loaded
2014-06-03T17:38:37.850Z,1401817117.850 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-06-03T17:38:37.866Z,1401817117.866 [NavChart] Loaded
2014-06-03T17:38:37.867Z,1401817117.867 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-06-03T17:38:37.871Z,1401817117.871 [UniversalFixResidualReporter] Loaded
2014-06-03T17:38:37.871Z,1401817117.871 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-06-03T17:38:37.872Z,1401817117.872 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-06-03T17:38:37.872Z,1401817117.872 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-06-03T17:38:37.922Z,1401817117.922 [VerticalControl](DEBUG): Construct VerticalControl.
2014-06-03T17:38:38.035Z,1401817118.035 [VerticalControl] Loaded
2014-06-03T17:38:38.035Z,1401817118.035 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-06-03T17:38:38.036Z,1401817118.036 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-06-03T17:38:38.122Z,1401817118.122 [HorizontalControl] Loaded
2014-06-03T17:38:38.123Z,1401817118.123 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-06-03T17:38:38.124Z,1401817118.124 [SpeedControl](DEBUG): Construct SpeedControl.
2014-06-03T17:38:38.138Z,1401817118.138 [SpeedControl] Loaded
2014-06-03T17:38:38.138Z,1401817118.138 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-06-03T17:38:38.139Z,1401817118.139 [LoopControl](DEBUG): Construct LoopControl.
2014-06-03T17:38:38.139Z,1401817118.139 [LoopControl] Loaded
2014-06-03T17:38:38.139Z,1401817118.139 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-06-03T17:38:38.140Z,1401817118.140 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-06-03T17:38:38.141Z,1401817118.141 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-06-03T17:38:38.159Z,1401817118.159 [DepthRateCalculator] Loaded
2014-06-03T17:38:38.160Z,1401817118.160 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-06-03T17:38:38.165Z,1401817118.165 [PitchRateCalculator] Loaded
2014-06-03T17:38:38.166Z,1401817118.166 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-06-03T17:38:38.173Z,1401817118.173 [SpeedCalculator] Loaded
2014-06-03T17:38:38.173Z,1401817118.173 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-06-03T17:38:38.190Z,1401817118.190 [TempGradientCalculator] Loaded
2014-06-03T17:38:38.190Z,1401817118.190 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-06-03T17:38:38.195Z,1401817118.195 [YawRateCalculator] Loaded
2014-06-03T17:38:38.196Z,1401817118.196 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-06-03T17:38:38.196Z,1401817118.196 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-06-03T17:38:38.197Z,1401817118.197 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-06-03T17:38:38.305Z,1401817118.305 [CTD_NeilBrown] Loaded
2014-06-03T17:38:38.305Z,1401817118.305 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-06-03T17:38:38.306Z,1401817118.306 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4075F4E0
2014-06-03T17:38:38.307Z,1401817118.307 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 6798
2014-06-03T17:38:38.320Z,1401817118.320 [ISUS] Loaded
2014-06-03T17:38:38.320Z,1401817118.320 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-06-03T17:38:38.335Z,1401817118.335 [PAR_Licor] Loaded
2014-06-03T17:38:38.336Z,1401817118.336 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-06-03T17:38:38.371Z,1401817118.371 [WetLabsBB2FL] Loaded
2014-06-03T17:38:38.372Z,1401817118.372 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-06-03T17:38:38.373Z,1401817118.373 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4078F4E0
2014-06-03T17:38:38.373Z,1401817118.373 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6799
2014-06-03T17:38:38.374Z,1401817118.374 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-06-03T17:38:38.374Z,1401817118.374 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-06-03T17:38:38.472Z,1401817118.472 [SBIT](DEBUG): Construct Startup Built In Test.
2014-06-03T17:38:38.484Z,1401817118.484 [SBIT] Loaded
2014-06-03T17:38:38.484Z,1401817118.484 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-06-03T17:38:38.485Z,1401817118.485 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-06-03T17:38:38.497Z,1401817118.497 [IBIT] Loaded
2014-06-03T17:38:38.498Z,1401817118.498 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-06-03T17:38:38.500Z,1401817118.500 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-06-03T17:38:38.569Z,1401817118.569 [CBIT] Loaded
2014-06-03T17:38:38.569Z,1401817118.569 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-06-03T17:38:38.570Z,1401817118.570 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-06-03T17:38:38.570Z,1401817118.570 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-06-03T17:38:43.515Z,1401817123.515 [HFRadarModelCalc] Loaded
2014-06-03T17:38:43.515Z,1401817123.515 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-06-03T17:38:46.862Z,1401817126.862 [HFRadarCompactModelForecaster] Loaded
2014-06-03T17:38:46.863Z,1401817126.863 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-06-03T17:38:47.742Z,1401817127.742 [HFRCMSpaceInterpolator] Loaded
2014-06-03T17:38:47.742Z,1401817127.742 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-06-03T17:38:47.744Z,1401817127.744 [HFRCMTimeInterpolator] Loaded
2014-06-03T17:38:47.744Z,1401817127.744 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-06-03T17:38:47.756Z,1401817127.756 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-06-03T17:38:47.757Z,1401817127.757 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-06-03T17:38:47.784Z,1401817127.784 [HFRCMVirtualSurfaceDrifter] Loaded
2014-06-03T17:38:47.784Z,1401817127.784 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-06-03T17:38:47.785Z,1401817127.785 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-06-03T17:38:47.785Z,1401817127.785 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-06-03T17:38:47.889Z,1401817127.889 [BuoyancyServo] Loaded
2014-06-03T17:38:47.889Z,1401817127.889 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-06-03T17:38:47.902Z,1401817127.902 [ElevatorServo] Loaded
2014-06-03T17:38:47.902Z,1401817127.902 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-06-03T17:38:47.914Z,1401817127.914 [MassServo] Loaded
2014-06-03T17:38:47.914Z,1401817127.914 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-06-03T17:38:47.926Z,1401817127.926 [RudderServo] Loaded
2014-06-03T17:38:47.927Z,1401817127.927 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-06-03T17:38:47.939Z,1401817127.939 [ThrusterServo] Loaded
2014-06-03T17:38:47.939Z,1401817127.939 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-06-03T17:38:47.939Z,1401817127.939 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-06-03T17:38:47.940Z,1401817127.940 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-06-03T17:38:47.964Z,1401817127.964 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-06-03T17:38:47.966Z,1401817127.966 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-06-03T17:38:47.967Z,1401817127.967 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-06-03T17:38:47.973Z,1401817127.973 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-06-03T17:38:47.974Z,1401817127.974 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A544E0
2014-06-03T17:38:47.975Z,1401817127.975 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6800
2014-06-03T17:38:47.979Z,1401817127.979 [Supervisor](INFO): Main Thread ID is 6711
2014-06-03T17:38:47.979Z,1401817127.979 [Supervisor](DEBUG): Running supervisor.
2014-06-03T17:38:47.980Z,1401817127.980 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6801
2014-06-03T17:38:47.983Z,1401817127.983 [controlThread ThreadHandler](INFO): Handler Thread ID is 6802
2014-06-03T17:38:47.983Z,1401817127.983 [controlThread](DEBUG): Initializing ControlThread
2014-06-03T17:38:47.986Z,1401817127.986 [logger ThreadHandler](INFO): Handler Thread ID is 6803
2014-06-03T17:38:48.005Z,1401817128.005 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 6804
2014-06-03T17:38:48.021Z,1401817128.021 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 6805
2014-06-03T17:38:48.022Z,1401817128.022 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-06-03T17:38:48.025Z,1401817128.025 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-06-03T17:38:48.035Z,1401817128.035 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6807
2014-06-03T17:38:48.036Z,1401817128.036 [WetLabsBB2FL](INFO): Powering down
2014-06-03T17:38:48.064Z,1401817128.064 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6808
2014-06-03T17:38:48.069Z,1401817128.069 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-06-03T17:38:48.074Z,1401817128.074 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-06-03T17:38:48.074Z,1401817128.074 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-06-03T17:38:48.075Z,1401817128.075 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-06-03T17:38:48.075Z,1401817128.075 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-06-03T17:38:48.075Z,1401817128.075 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-06-03T17:38:48.075Z,1401817128.075 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-06-03T17:38:48.076Z,1401817128.076 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-06-03T17:38:48.076Z,1401817128.076 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-06-03T17:38:49.644Z,1401817129.644 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-06-03T17:38:49.674Z,1401817129.674 [InternalSim](DEBUG): InternalSim initializing...
2014-06-03T17:38:49.783Z,1401817129.783 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-06-03T17:38:49.784Z,1401817129.784 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-06-03T17:38:49.784Z,1401817129.784 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-06-03T17:38:49.785Z,1401817129.785 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-06-03T17:38:49.785Z,1401817129.785 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-06-03T17:38:49.785Z,1401817129.785 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-06-03T17:38:49.786Z,1401817129.786 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-06-03T17:38:49.786Z,1401817129.786 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-06-03T17:38:49.795Z,1401817129.795 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-06-03T17:38:49.796Z,1401817129.796 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-06-03T17:38:49.797Z,1401817129.797 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-06-03T17:38:49.797Z,1401817129.797 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-06-03T17:38:49.797Z,1401817129.797 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-06-03T17:38:49.798Z,1401817129.798 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-06-03T17:38:49.798Z,1401817129.798 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-06-03T17:38:49.799Z,1401817129.799 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-06-03T17:38:49.800Z,1401817129.800 [SBIT](INFO): Initialize SBIT Component.
2014-06-03T17:38:49.801Z,1401817129.801 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:11349
2014-06-03T17:38:49.801Z,1401817129.801 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-06-03T17:38:49.801Z,1401817129.801 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-06-03T17:38:49.802Z,1401817129.802 [IBIT](INFO): Initialize IBIT Component.
2014-06-03T17:38:49.803Z,1401817129.803 [CBIT](DEBUG): Initialize CBIT Component.
2014-06-03T17:38:49.803Z,1401817129.803 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2014-06-03T17:38:49.838Z,1401817129.838 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-06-03T17:38:50.317Z,1401817130.317 [Radio_Freewave](INFO): Powering up
2014-06-03T17:38:51.127Z,1401817131.127 [Radio_Freewave](IMPORTANT): Starting PPPD with command:/sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0
2014-06-03T17:38:58.780Z,1401817138.780 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201406031400: published 50 modes in rows, 61 hours in columns
2014-06-03T17:38:58.786Z,1401817138.786 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0.
2014-06-03T17:38:58.788Z,1401817138.788 [HFRCMSpaceInterpolator](INFO): gridIdxRev_: 541 by 1, [25.000000, 718.000000]
2014-06-03T17:38:58.788Z,1401817138.788 [HFRCMSpaceInterpolator](INFO): gridIdx_: 25 by 29, [nan, nan]
2014-06-03T17:38:58.789Z,1401817138.789 [HFRCMSpaceInterpolator](INFO): longitude grid: 25 by 29, [-122.743156, -121.797913]
2014-06-03T17:38:58.790Z,1401817138.790 [HFRCMSpaceInterpolator](INFO): latitude grid: 25 by 29, [36.341251, 36.990059]
2014-06-03T17:38:58.805Z,1401817138.805 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-06-03T17:38:58.806Z,1401817138.806 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-06-03T17:38:58.806Z,1401817138.806 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-06-03T17:38:58.808Z,1401817138.808 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-06-03T17:38:58.839Z,1401817138.839 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:38:58.857Z,1401817138.857 [MissionManager](DEBUG):
2014-06-03T17:38:58.882Z,1401817138.882 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-06-03T17:38:58.957Z,1401817138.957 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-06-03T17:38:58.959Z,1401817138.959 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-06-03T17:38:58.979Z,1401817138.979 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:38:58.996Z,1401817138.996 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-06-03T17:38:59.015Z,1401817139.015 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:38:59.038Z,1401817139.038 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-06-03T17:38:59.068Z,1401817139.068 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-06-03T17:38:59.071Z,1401817139.071 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:38:59.091Z,1401817139.091 [MissionManager](DEBUG):
400
400
Burn 300
Dropped drop weight due to communications timeout
5.0
1.0
5
2014-06-03T17:38:59.104Z,1401817139.104 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,SCPI,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarModelCalc,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,HFRCMSurfaceCurrentAtVehicleLocation,HFRCMVirtualSurfaceDrifter,DeadReckonUsingMultipleVelocitySources,DeadReckonWithRespectToWater,DeadReckonWithRespectToSeafloor,DeadReckonUsingDVLWaterTrack,DeadReckonUsingCompactModelForecast,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2014-06-03T17:38:59.174Z,1401817139.174 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-06-03T17:38:59.875Z,1401817139.875 [DVL_micro](INFO): Initializing
2014-06-03T17:38:59.919Z,1401817139.919 [NAL9602](INFO): Powering up NAL9602
2014-06-03T17:39:00.457Z,1401817140.457 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:39:00.464Z,1401817140.464 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-06-03T17:39:00.478Z,1401817140.478 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:39:00.484Z,1401817140.484 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-06-03T17:39:00.503Z,1401817140.503 [MassServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:39:00.508Z,1401817140.508 [MassServo](DEBUG): Initializing MassServo.
2014-06-03T17:39:00.526Z,1401817140.526 [RudderServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:39:00.532Z,1401817140.532 [RudderServo](DEBUG): Initializing RudderServo.
2014-06-03T17:39:00.546Z,1401817140.546 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:39:00.552Z,1401817140.552 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-06-03T17:39:00.597Z,1401817140.597 [CommandLine](FAULT): Scheduling is paused
2014-06-03T17:39:05.986Z,1401817145.986 [SBIT](IMPORTANT): Beginning Startup BIT
2014-06-03T17:39:05.988Z,1401817145.988 [CBIT](IMPORTANT): Beginning GF scan
2014-06-03T17:39:10.913Z,1401817150.913 [NAL9602](INFO): NAL9602 initialized
2014-06-03T17:39:18.748Z,1401817158.748 [CommandLine](IMPORTANT): got command quit
2014-06-03T17:39:19.753Z,1401817159.753 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:39:19.753Z,1401817159.753 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:19.762Z,1401817159.762 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2014-06-03T17:39:19.762Z,1401817159.762 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:19.762Z,1401817159.762 [CommandLine](INFO): Join timeout helper Thread ID is 6821
2014-06-03T17:39:19.772Z,1401817159.772 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-06-03T17:39:19.773Z,1401817159.773 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:19.773Z,1401817159.773 [NavChartDb](INFO): Join timeout helper Thread ID is 6822
2014-06-03T17:39:20.637Z,1401817160.637 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:39:20.637Z,1401817160.637 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:20.655Z,1401817160.655 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-06-03T17:39:20.655Z,1401817160.655 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:20.656Z,1401817160.656 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6826
2014-06-03T17:39:20.860Z,1401817160.860 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:39:20.862Z,1401817160.862 [WetLabsBB2FL](INFO): Powering down
2014-06-03T17:39:20.863Z,1401817160.863 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:20.875Z,1401817160.875 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-06-03T17:39:20.875Z,1401817160.875 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:20.876Z,1401817160.876 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 6827
2014-06-03T17:39:21.272Z,1401817161.272 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:39:21.272Z,1401817161.272 [CTD_NeilBrown](INFO): Powering down
2014-06-03T17:39:21.273Z,1401817161.273 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:21.280Z,1401817161.280 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-06-03T17:39:21.280Z,1401817161.280 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:21.281Z,1401817161.281 [Radio_Freewave](INFO): Join timeout helper Thread ID is 6828
2014-06-03T17:39:21.392Z,1401817161.392 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:39:21.613Z,1401817161.613 [Radio_Freewave](INFO): Powering down
2014-06-03T17:39:22.017Z,1401817162.017 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:22.035Z,1401817162.035 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-06-03T17:39:22.035Z,1401817162.035 [logger ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:22.036Z,1401817162.036 [logger](INFO): Join timeout helper Thread ID is 6831
2014-06-03T17:39:22.036Z,1401817162.036 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:39:22.036Z,1401817162.036 [logger ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:22.038Z,1401817162.038 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-06-03T17:39:22.038Z,1401817162.038 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:22.038Z,1401817162.038 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-06-03T17:39:22.039Z,1401817162.039 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:22.039Z,1401817162.039 [controlThread](INFO): Join timeout helper Thread ID is 6832
2014-06-03T17:39:22.083Z,1401817162.083 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:39:22.083Z,1401817162.083 [controlThread](DEBUG): Uninitializing ControlThread
2014-06-03T17:39:22.084Z,1401817162.084 [AHRS_sp3003D](INFO): Powering down
2014-06-03T17:39:22.242Z,1401817162.242 [DVL_micro](INFO): uninitialize:Powering down
2014-06-03T17:39:22.243Z,1401817162.243 [NAL9602](INFO): Powering down
2014-06-03T17:39:22.246Z,1401817162.246 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-06-03T17:39:22.249Z,1401817162.249 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-06-03T17:39:22.255Z,1401817162.255 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-06-03T17:39:22.256Z,1401817162.256 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-06-03T17:39:22.256Z,1401817162.256 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-06-03T17:39:22.256Z,1401817162.256 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-06-03T17:39:22.257Z,1401817162.257 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-06-03T17:39:22.257Z,1401817162.257 [BuoyancyServo](INFO): Powering down
2014-06-03T17:39:22.270Z,1401817162.270 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-06-03T17:39:22.270Z,1401817162.270 [ElevatorServo](INFO): Powering down
2014-06-03T17:39:22.271Z,1401817162.271 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-06-03T17:39:22.271Z,1401817162.271 [MassServo](INFO): Powering down
2014-06-03T17:39:22.272Z,1401817162.272 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-06-03T17:39:22.272Z,1401817162.272 [RudderServo](INFO): Powering down
2014-06-03T17:39:22.273Z,1401817162.273 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-06-03T17:39:22.273Z,1401817162.273 [ThrusterServo](INFO): Powering down
2014-06-03T17:39:22.274Z,1401817162.274 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-06-03T17:39:22.274Z,1401817162.274 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-06-03T17:39:22.274Z,1401817162.274 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-06-03T17:39:22.307Z,1401817162.307 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:22.323Z,1401817162.323 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:22.396Z,1401817162.396 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:22.399Z,1401817162.399 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:22.802Z,1401817162.802 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:39:22.836Z,1401817162.836 [logger ThreadHandler](INFO): Thread cancelled.