2014-06-03T17:35:03.332Z,1401816903.332 [Supervisor](DEBUG): Initializing supervisor.
2014-06-03T17:35:03.334Z,1401816903.334 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-06-03T17:35:03.335Z,1401816903.335 [SyncHandler](INFO): Protected caller Thread ID is 6462
2014-06-03T17:35:03.335Z,1401816903.335 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-06-03T17:35:03.336Z,1401816903.336 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-06-03T17:35:03.337Z,1401816903.337 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6463
2014-06-03T17:35:03.340Z,1401816903.340 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-06-03T17:35:03.510Z,1401816903.510 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-06-03T17:35:03.511Z,1401816903.511 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-06-03T17:35:03.511Z,1401816903.511 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6464
2014-06-03T17:35:03.512Z,1401816903.512 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-06-03T17:35:03.513Z,1401816903.513 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-06-03T17:35:03.514Z,1401816903.514 [logger ThreadHandler](INFO): Protected caller Thread ID is 6465
2014-06-03T17:35:03.516Z,1401816903.516 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-06-03T17:35:03.517Z,1401816903.517 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-06-03T17:35:03.518Z,1401816903.518 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-06-03T17:35:04.375Z,1401816904.375 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-06-03T17:35:04.376Z,1401816904.376 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-06-03T17:35:04.670Z,1401816904.670 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-06-03T17:35:04.671Z,1401816904.671 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-06-03T17:35:04.760Z,1401816904.760 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-06-03T17:35:04.761Z,1401816904.761 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-06-03T17:35:04.957Z,1401816904.957 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-06-03T17:35:04.957Z,1401816904.957 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-06-03T17:35:05.128Z,1401816905.128 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-06-03T17:35:05.128Z,1401816905.128 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-06-03T17:35:05.445Z,1401816905.445 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-06-03T17:35:05.445Z,1401816905.445 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-06-03T17:35:05.636Z,1401816905.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-06-03T17:35:05.636Z,1401816905.636 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-06-03T17:35:05.988Z,1401816905.988 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-06-03T17:35:05.988Z,1401816905.988 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-06-03T17:35:06.103Z,1401816906.103 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-06-03T17:35:06.104Z,1401816906.104 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-06-03T17:35:06.622Z,1401816906.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-06-03T17:35:06.622Z,1401816906.622 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-06-03T17:35:06.735Z,1401816906.735 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-06-03T17:35:06.736Z,1401816906.736 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-06-03T17:35:06.826Z,1401816906.826 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-06-03T17:35:06.950Z,1401816906.950 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-06-03T17:35:06.951Z,1401816906.951 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-06-03T17:35:07.059Z,1401816907.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-06-03T17:35:07.060Z,1401816907.060 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-06-03T17:35:07.204Z,1401816907.204 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-06-03T17:35:07.206Z,1401816907.206 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-06-03T17:35:07.207Z,1401816907.207 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-06-03T17:35:07.235Z,1401816907.235 [Config/vehicle](ERROR): Could not parse value: Will
2014-06-03T17:35:07.237Z,1401816907.237 [Config/vehicle](ERROR): Could not parse value: a
2014-06-03T17:35:07.240Z,1401816907.240 [Config/vehicle](ERROR): Could not parse value: queue
2014-06-03T17:35:07.242Z,1401816907.242 [Config/vehicle](ERROR): Could not parse value: while
2014-06-03T17:35:07.326Z,1401816907.326 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-06-03T17:35:07.461Z,1401816907.461 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-06-03T17:35:07.561Z,1401816907.561 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-06-03T17:35:07.657Z,1401816907.657 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-06-03T17:35:07.805Z,1401816907.805 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-06-03T17:35:07.926Z,1401816907.926 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-06-03T17:35:08.016Z,1401816908.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-06-03T17:35:08.125Z,1401816908.125 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-06-03T17:35:08.230Z,1401816908.230 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-06-03T17:35:08.331Z,1401816908.331 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-06-03T17:35:08.422Z,1401816908.422 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-06-03T17:35:08.524Z,1401816908.524 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/
2014-06-03T17:35:08.525Z,1401816908.525 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-06-03T17:35:08.526Z,1401816908.526 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-06-03T17:35:08.895Z,1401816908.895 [AHRS_sp3003D] Loaded
2014-06-03T17:35:08.895Z,1401816908.895 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-06-03T17:35:09.214Z,1401816909.214 [Batt_Ocean_Server] Loaded
2014-06-03T17:35:09.214Z,1401816909.214 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-06-03T17:35:09.229Z,1401816909.229 [Depth_Keller] Loaded
2014-06-03T17:35:09.229Z,1401816909.229 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-06-03T17:35:09.234Z,1401816909.234 [DropWeight] Loaded
2014-06-03T17:35:09.235Z,1401816909.235 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-06-03T17:35:09.385Z,1401816909.385 [DVL_micro] Loaded
2014-06-03T17:35:09.385Z,1401816909.385 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-06-03T17:35:09.493Z,1401816909.493 [NAL9602] Loaded
2014-06-03T17:35:09.493Z,1401816909.493 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-06-03T17:35:09.549Z,1401816909.549 [Onboard] Loaded
2014-06-03T17:35:09.549Z,1401816909.549 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-06-03T17:35:09.557Z,1401816909.557 [Radio_Freewave] Loaded
2014-06-03T17:35:09.557Z,1401816909.557 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-06-03T17:35:09.558Z,1401816909.558 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 406104E0
2014-06-03T17:35:09.559Z,1401816909.559 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 6547
2014-06-03T17:35:09.566Z,1401816909.566 [SCPI] Loaded
2014-06-03T17:35:09.566Z,1401816909.566 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-06-03T17:35:09.567Z,1401816909.567 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-06-03T17:35:09.567Z,1401816909.567 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-06-03T17:35:09.747Z,1401816909.747 [InternalSim] Loaded
2014-06-03T17:35:09.748Z,1401816909.748 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-06-03T17:35:09.748Z,1401816909.748 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-06-03T17:35:09.749Z,1401816909.749 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-06-03T17:35:10.017Z,1401816910.017 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-06-03T17:35:10.018Z,1401816910.018 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-06-03T17:35:10.023Z,1401816910.023 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-06-03T17:35:10.024Z,1401816910.024 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-06-03T17:35:10.109Z,1401816910.109 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-06-03T17:35:10.109Z,1401816910.109 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-06-03T17:35:10.157Z,1401816910.157 [DeadReckonWithRespectToWater] Loaded
2014-06-03T17:35:10.157Z,1401816910.157 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-06-03T17:35:10.206Z,1401816910.206 [DeadReckonWithRespectToSeafloor] Loaded
2014-06-03T17:35:10.207Z,1401816910.207 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-06-03T17:35:10.308Z,1401816910.308 [DeadReckonUsingDVLWaterTrack] Loaded
2014-06-03T17:35:10.309Z,1401816910.309 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-06-03T17:35:10.360Z,1401816910.360 [DeadReckonUsingCompactModelForecast] Loaded
2014-06-03T17:35:10.361Z,1401816910.361 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-06-03T17:35:10.400Z,1401816910.400 [NavChart] Loaded
2014-06-03T17:35:10.400Z,1401816910.400 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-06-03T17:35:10.412Z,1401816910.412 [UniversalFixResidualReporter] Loaded
2014-06-03T17:35:10.412Z,1401816910.412 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-06-03T17:35:10.413Z,1401816910.413 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-06-03T17:35:10.413Z,1401816910.413 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-06-03T17:35:10.966Z,1401816910.966 [VerticalControl](DEBUG): Construct VerticalControl.
2014-06-03T17:35:11.083Z,1401816911.083 [VerticalControl] Loaded
2014-06-03T17:35:11.084Z,1401816911.084 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-06-03T17:35:11.084Z,1401816911.084 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-06-03T17:35:11.156Z,1401816911.156 [HorizontalControl] Loaded
2014-06-03T17:35:11.157Z,1401816911.157 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-06-03T17:35:11.157Z,1401816911.157 [SpeedControl](DEBUG): Construct SpeedControl.
2014-06-03T17:35:11.159Z,1401816911.159 [SpeedControl] Loaded
2014-06-03T17:35:11.160Z,1401816911.160 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-06-03T17:35:11.160Z,1401816911.160 [LoopControl](DEBUG): Construct LoopControl.
2014-06-03T17:35:11.161Z,1401816911.161 [LoopControl] Loaded
2014-06-03T17:35:11.161Z,1401816911.161 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-06-03T17:35:11.162Z,1401816911.162 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-06-03T17:35:11.162Z,1401816911.162 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-06-03T17:35:11.182Z,1401816911.182 [DepthRateCalculator] Loaded
2014-06-03T17:35:11.182Z,1401816911.182 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-06-03T17:35:11.188Z,1401816911.188 [PitchRateCalculator] Loaded
2014-06-03T17:35:11.189Z,1401816911.189 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-06-03T17:35:11.196Z,1401816911.196 [SpeedCalculator] Loaded
2014-06-03T17:35:11.196Z,1401816911.196 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-06-03T17:35:11.214Z,1401816911.214 [TempGradientCalculator] Loaded
2014-06-03T17:35:11.215Z,1401816911.215 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-06-03T17:35:11.220Z,1401816911.220 [YawRateCalculator] Loaded
2014-06-03T17:35:11.221Z,1401816911.221 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-06-03T17:35:11.221Z,1401816911.221 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-06-03T17:35:11.222Z,1401816911.222 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-06-03T17:35:11.338Z,1401816911.338 [CTD_NeilBrown] Loaded
2014-06-03T17:35:11.338Z,1401816911.338 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-06-03T17:35:11.339Z,1401816911.339 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4075F4E0
2014-06-03T17:35:11.339Z,1401816911.339 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 6548
2014-06-03T17:35:11.353Z,1401816911.353 [ISUS] Loaded
2014-06-03T17:35:11.354Z,1401816911.354 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-06-03T17:35:11.369Z,1401816911.369 [PAR_Licor] Loaded
2014-06-03T17:35:11.369Z,1401816911.369 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-06-03T17:35:11.406Z,1401816911.406 [WetLabsBB2FL] Loaded
2014-06-03T17:35:11.406Z,1401816911.406 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-06-03T17:35:11.407Z,1401816911.407 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4078F4E0
2014-06-03T17:35:11.408Z,1401816911.408 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 6549
2014-06-03T17:35:11.408Z,1401816911.408 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-06-03T17:35:11.409Z,1401816911.409 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-06-03T17:35:11.514Z,1401816911.514 [SBIT](DEBUG): Construct Startup Built In Test.
2014-06-03T17:35:11.526Z,1401816911.526 [SBIT] Loaded
2014-06-03T17:35:11.527Z,1401816911.527 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-06-03T17:35:11.527Z,1401816911.527 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-06-03T17:35:11.540Z,1401816911.540 [IBIT] Loaded
2014-06-03T17:35:11.541Z,1401816911.541 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-06-03T17:35:11.543Z,1401816911.543 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-06-03T17:35:11.615Z,1401816911.615 [CBIT] Loaded
2014-06-03T17:35:11.616Z,1401816911.616 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-06-03T17:35:11.616Z,1401816911.616 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-06-03T17:35:11.617Z,1401816911.617 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-06-03T17:35:16.544Z,1401816916.544 [HFRadarModelCalc] Loaded
2014-06-03T17:35:16.544Z,1401816916.544 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-06-03T17:35:20.341Z,1401816920.341 [HFRadarCompactModelForecaster] Loaded
2014-06-03T17:35:20.341Z,1401816920.341 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-06-03T17:35:22.118Z,1401816922.118 [HFRCMSpaceInterpolator] Loaded
2014-06-03T17:35:22.118Z,1401816922.118 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-06-03T17:35:22.120Z,1401816922.120 [HFRCMTimeInterpolator] Loaded
2014-06-03T17:35:22.121Z,1401816922.121 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-06-03T17:35:22.133Z,1401816922.133 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-06-03T17:35:22.134Z,1401816922.134 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-06-03T17:35:22.162Z,1401816922.162 [HFRCMVirtualSurfaceDrifter] Loaded
2014-06-03T17:35:22.163Z,1401816922.163 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-06-03T17:35:22.163Z,1401816922.163 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-06-03T17:35:22.164Z,1401816922.164 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-06-03T17:35:22.274Z,1401816922.274 [BuoyancyServo] Loaded
2014-06-03T17:35:22.274Z,1401816922.274 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-06-03T17:35:22.287Z,1401816922.287 [ElevatorServo] Loaded
2014-06-03T17:35:22.287Z,1401816922.287 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-06-03T17:35:22.299Z,1401816922.299 [MassServo] Loaded
2014-06-03T17:35:22.300Z,1401816922.300 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-06-03T17:35:22.312Z,1401816922.312 [RudderServo] Loaded
2014-06-03T17:35:22.312Z,1401816922.312 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-06-03T17:35:22.324Z,1401816922.324 [ThrusterServo] Loaded
2014-06-03T17:35:22.325Z,1401816922.325 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-06-03T17:35:22.325Z,1401816922.325 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-06-03T17:35:22.326Z,1401816922.326 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-06-03T17:35:22.352Z,1401816922.352 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-06-03T17:35:22.354Z,1401816922.354 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-06-03T17:35:22.355Z,1401816922.355 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-06-03T17:35:22.361Z,1401816922.361 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-06-03T17:35:22.362Z,1401816922.362 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A544E0
2014-06-03T17:35:22.363Z,1401816922.363 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6550
2014-06-03T17:35:22.368Z,1401816922.368 [Supervisor](INFO): Main Thread ID is 6461
2014-06-03T17:35:22.368Z,1401816922.368 [Supervisor](DEBUG): Running supervisor.
2014-06-03T17:35:22.369Z,1401816922.369 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6551
2014-06-03T17:35:22.371Z,1401816922.371 [controlThread ThreadHandler](INFO): Handler Thread ID is 6552
2014-06-03T17:35:22.372Z,1401816922.372 [controlThread](DEBUG): Initializing ControlThread
2014-06-03T17:35:22.375Z,1401816922.375 [logger ThreadHandler](INFO): Handler Thread ID is 6553
2014-06-03T17:35:22.394Z,1401816922.394 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 6554
2014-06-03T17:35:22.410Z,1401816922.410 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 6555
2014-06-03T17:35:22.411Z,1401816922.411 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-06-03T17:35:22.414Z,1401816922.414 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-06-03T17:35:22.424Z,1401816922.424 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 6557
2014-06-03T17:35:22.425Z,1401816922.425 [WetLabsBB2FL](INFO): Powering down
2014-06-03T17:35:22.453Z,1401816922.453 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6558
2014-06-03T17:35:22.455Z,1401816922.455 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-06-03T17:35:22.456Z,1401816922.456 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-06-03T17:35:22.456Z,1401816922.456 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-06-03T17:35:22.457Z,1401816922.457 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-06-03T17:35:22.457Z,1401816922.457 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-06-03T17:35:22.457Z,1401816922.457 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-06-03T17:35:22.457Z,1401816922.457 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-06-03T17:35:22.458Z,1401816922.458 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-06-03T17:35:22.458Z,1401816922.458 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-06-03T17:35:23.953Z,1401816923.953 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-06-03T17:35:23.983Z,1401816923.983 [InternalSim](DEBUG): InternalSim initializing...
2014-06-03T17:35:24.100Z,1401816924.100 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-06-03T17:35:24.101Z,1401816924.101 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-06-03T17:35:24.101Z,1401816924.101 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-06-03T17:35:24.101Z,1401816924.101 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-06-03T17:35:24.102Z,1401816924.102 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-06-03T17:35:24.102Z,1401816924.102 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-06-03T17:35:24.103Z,1401816924.103 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-06-03T17:35:24.103Z,1401816924.103 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-06-03T17:35:24.105Z,1401816924.105 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-06-03T17:35:24.105Z,1401816924.105 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-06-03T17:35:24.106Z,1401816924.106 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-06-03T17:35:24.106Z,1401816924.106 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-06-03T17:35:24.107Z,1401816924.107 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-06-03T17:35:24.107Z,1401816924.107 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-06-03T17:35:24.107Z,1401816924.107 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-06-03T17:35:24.108Z,1401816924.108 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-06-03T17:35:24.118Z,1401816924.118 [SBIT](INFO): Initialize SBIT Component.
2014-06-03T17:35:24.118Z,1401816924.118 [SBIT](IMPORTANT): Tethys CM Info:
$Rev:11349
2014-06-03T17:35:24.119Z,1401816924.119 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-06-03T17:35:24.119Z,1401816924.119 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-06-03T17:35:24.120Z,1401816924.120 [IBIT](INFO): Initialize IBIT Component.
2014-06-03T17:35:24.129Z,1401816924.129 [CBIT](DEBUG): Initialize CBIT Component.
2014-06-03T17:35:24.129Z,1401816924.129 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2014-06-03T17:35:24.160Z,1401816924.160 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-06-03T17:35:24.706Z,1401816924.706 [Radio_Freewave](INFO): Powering up
2014-06-03T17:35:25.516Z,1401816925.516 [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:35:33.440Z,1401816933.440 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201406031400: published 50 modes in rows, 61 hours in columns
2014-06-03T17:35:33.459Z,1401816933.459 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0.
2014-06-03T17:35:33.461Z,1401816933.461 [HFRCMSpaceInterpolator](INFO): gridIdxRev_: 541 by 1, [25.000000, 718.000000]
2014-06-03T17:35:33.462Z,1401816933.462 [HFRCMSpaceInterpolator](INFO): gridIdx_: 25 by 29, [nan, nan]
2014-06-03T17:35:33.463Z,1401816933.463 [HFRCMSpaceInterpolator](INFO): longitude grid: 25 by 29, [-122.743156, -121.797913]
2014-06-03T17:35:33.464Z,1401816933.464 [HFRCMSpaceInterpolator](INFO): latitude grid: 25 by 29, [36.341251, 36.990059]
2014-06-03T17:35:33.465Z,1401816933.465 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-06-03T17:35:33.465Z,1401816933.465 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-06-03T17:35:33.466Z,1401816933.466 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-06-03T17:35:33.468Z,1401816933.468 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-06-03T17:35:33.507Z,1401816933.507 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:35:33.517Z,1401816933.517 [MissionManager](DEBUG):
2014-06-03T17:35:33.518Z,1401816933.518 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-06-03T17:35:33.618Z,1401816933.618 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-06-03T17:35:33.636Z,1401816933.636 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-06-03T17:35:33.639Z,1401816933.639 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:35:33.656Z,1401816933.656 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-06-03T17:35:33.683Z,1401816933.683 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:35:33.690Z,1401816933.690 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-06-03T17:35:33.725Z,1401816933.725 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-06-03T17:35:33.739Z,1401816933.739 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-06-03T17:35:33.770Z,1401816933.770 [MissionManager](DEBUG):
400
400
Burn 300
Dropped drop weight due to communications timeout
5.0
1.0
5
2014-06-03T17:35:33.785Z,1401816933.785 [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:35:33.840Z,1401816933.840 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-06-03T17:35:34.597Z,1401816934.597 [DVL_micro](INFO): Initializing
2014-06-03T17:35:34.629Z,1401816934.629 [NAL9602](INFO): Powering up NAL9602
2014-06-03T17:35:34.985Z,1401816934.985 [CommandLine](IMPORTANT): got command quit
2014-06-03T17:35:35.158Z,1401816935.158 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:35:35.166Z,1401816935.166 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-06-03T17:35:35.188Z,1401816935.188 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:35:35.194Z,1401816935.194 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-06-03T17:35:35.222Z,1401816935.222 [MassServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:35:35.230Z,1401816935.230 [MassServo](DEBUG): Initializing MassServo.
2014-06-03T17:35:35.236Z,1401816935.236 [RudderServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:35:35.242Z,1401816935.242 [RudderServo](DEBUG): Initializing RudderServo.
2014-06-03T17:35:35.263Z,1401816935.263 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-06-03T17:35:35.270Z,1401816935.270 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-06-03T17:35:35.314Z,1401816935.314 [CommandLine](FAULT): Scheduling is paused
2014-06-03T17:35:35.990Z,1401816935.990 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:35:35.990Z,1401816935.990 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:36.119Z,1401816936.119 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2014-06-03T17:35:36.119Z,1401816936.119 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:36.120Z,1401816936.120 [CommandLine](INFO): Join timeout helper Thread ID is 6570
2014-06-03T17:35:36.120Z,1401816936.120 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-06-03T17:35:36.120Z,1401816936.120 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:36.121Z,1401816936.121 [NavChartDb](INFO): Join timeout helper Thread ID is 6571
2014-06-03T17:35:38.367Z,1401816938.367 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:35:38.367Z,1401816938.367 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:38.375Z,1401816938.375 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-06-03T17:35:38.375Z,1401816938.375 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:38.375Z,1401816938.375 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6572
2014-06-03T17:35:38.655Z,1401816938.655 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:35:38.655Z,1401816938.655 [WetLabsBB2FL](INFO): Powering down
2014-06-03T17:35:38.656Z,1401816938.656 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:38.663Z,1401816938.663 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-06-03T17:35:38.663Z,1401816938.663 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:38.663Z,1401816938.663 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 6573
2014-06-03T17:35:38.787Z,1401816938.787 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:35:38.787Z,1401816938.787 [CTD_NeilBrown](INFO): Powering down
2014-06-03T17:35:38.788Z,1401816938.788 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:38.803Z,1401816938.803 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-06-03T17:35:38.803Z,1401816938.803 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:38.804Z,1401816938.804 [Radio_Freewave](INFO): Join timeout helper Thread ID is 6574
2014-06-03T17:35:39.168Z,1401816939.168 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:35:39.273Z,1401816939.273 [Radio_Freewave](INFO): Powering down
2014-06-03T17:35:39.677Z,1401816939.677 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:39.694Z,1401816939.694 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-06-03T17:35:39.694Z,1401816939.694 [logger ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:39.694Z,1401816939.694 [logger](INFO): Join timeout helper Thread ID is 6576
2014-06-03T17:35:39.725Z,1401816939.725 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:35:39.725Z,1401816939.725 [logger ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:39.737Z,1401816939.737 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-06-03T17:35:39.738Z,1401816939.738 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:39.738Z,1401816939.738 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-06-03T17:35:39.738Z,1401816939.738 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:39.738Z,1401816939.738 [controlThread](INFO): Join timeout helper Thread ID is 6577
2014-06-03T17:35:39.921Z,1401816939.921 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-06-03T17:35:39.922Z,1401816939.922 [controlThread](DEBUG): Uninitializing ControlThread
2014-06-03T17:35:39.922Z,1401816939.922 [AHRS_sp3003D](INFO): Powering down
2014-06-03T17:35:40.081Z,1401816940.081 [DVL_micro](INFO): uninitialize:Powering down
2014-06-03T17:35:40.093Z,1401816940.093 [NAL9602](INFO): Powering down
2014-06-03T17:35:40.116Z,1401816940.116 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-06-03T17:35:40.119Z,1401816940.119 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-06-03T17:35:40.125Z,1401816940.125 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-06-03T17:35:40.125Z,1401816940.125 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-06-03T17:35:40.125Z,1401816940.125 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-06-03T17:35:40.126Z,1401816940.126 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-06-03T17:35:40.126Z,1401816940.126 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-06-03T17:35:40.126Z,1401816940.126 [BuoyancyServo](INFO): Powering down
2014-06-03T17:35:40.137Z,1401816940.137 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-06-03T17:35:40.138Z,1401816940.138 [ElevatorServo](INFO): Powering down
2014-06-03T17:35:40.157Z,1401816940.157 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-06-03T17:35:40.157Z,1401816940.157 [MassServo](INFO): Powering down
2014-06-03T17:35:40.158Z,1401816940.158 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-06-03T17:35:40.158Z,1401816940.158 [RudderServo](INFO): Powering down
2014-06-03T17:35:40.168Z,1401816940.168 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-06-03T17:35:40.168Z,1401816940.168 [ThrusterServo](INFO): Powering down
2014-06-03T17:35:40.187Z,1401816940.187 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-06-03T17:35:40.187Z,1401816940.187 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-06-03T17:35:40.188Z,1401816940.188 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-06-03T17:35:40.231Z,1401816940.231 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:40.233Z,1401816940.233 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:40.306Z,1401816940.306 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:40.310Z,1401816940.310 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:40.714Z,1401816940.714 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-06-03T17:35:40.748Z,1401816940.748 [logger ThreadHandler](INFO): Thread cancelled.