2014-05-13T16:11:03.518Z,1399997463.518 [Supervisor](DEBUG): Initializing supervisor.
2014-05-13T16:11:03.522Z,1399997463.522 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-05-13T16:11:03.522Z,1399997463.522 [SyncHandler](INFO): Protected caller Thread ID is 771
2014-05-13T16:11:03.523Z,1399997463.523 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-05-13T16:11:03.526Z,1399997463.526 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-05-13T16:11:03.526Z,1399997463.526 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 772
2014-05-13T16:11:03.529Z,1399997463.529 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-05-13T16:11:03.541Z,1399997463.541 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-05-13T16:11:03.546Z,1399997463.546 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-05-13T16:11:03.546Z,1399997463.546 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 773
2014-05-13T16:11:03.547Z,1399997463.547 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-05-13T16:11:03.550Z,1399997463.550 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-05-13T16:11:03.550Z,1399997463.550 [logger ThreadHandler](INFO): Protected caller Thread ID is 774
2014-05-13T16:11:03.553Z,1399997463.553 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-05-13T16:11:03.553Z,1399997463.553 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-05-13T16:11:03.558Z,1399997463.558 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-05-13T16:11:03.978Z,1399997463.978 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-05-13T16:11:03.980Z,1399997463.980 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-05-13T16:11:04.300Z,1399997464.300 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-05-13T16:11:04.301Z,1399997464.301 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-05-13T16:11:04.398Z,1399997464.398 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-05-13T16:11:04.399Z,1399997464.399 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-05-13T16:11:04.600Z,1399997464.600 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-05-13T16:11:04.602Z,1399997464.602 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-05-13T16:11:04.787Z,1399997464.787 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-05-13T16:11:04.789Z,1399997464.789 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-05-13T16:11:05.137Z,1399997465.137 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-05-13T16:11:05.138Z,1399997465.138 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-05-13T16:11:05.337Z,1399997465.337 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-05-13T16:11:05.338Z,1399997465.338 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-05-13T16:11:05.734Z,1399997465.734 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-05-13T16:11:05.735Z,1399997465.735 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-05-13T16:11:05.859Z,1399997465.859 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-05-13T16:11:05.861Z,1399997465.861 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-05-13T16:11:06.424Z,1399997466.424 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-05-13T16:11:06.426Z,1399997466.426 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-05-13T16:11:06.555Z,1399997466.555 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-05-13T16:11:06.588Z,1399997466.588 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-05-13T16:11:06.704Z,1399997466.704 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-05-13T16:11:06.828Z,1399997466.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-05-13T16:11:06.829Z,1399997466.829 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-05-13T16:11:06.944Z,1399997466.944 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-05-13T16:11:06.946Z,1399997466.946 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-05-13T16:11:07.104Z,1399997467.104 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-05-13T16:11:07.106Z,1399997467.106 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-05-13T16:11:07.110Z,1399997467.110 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-05-13T16:11:07.229Z,1399997467.229 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-05-13T16:11:07.377Z,1399997467.377 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-05-13T16:11:07.489Z,1399997467.489 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-05-13T16:11:07.593Z,1399997467.593 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-05-13T16:11:07.761Z,1399997467.761 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-05-13T16:11:07.898Z,1399997467.898 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-05-13T16:11:07.996Z,1399997467.996 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-05-13T16:11:08.116Z,1399997468.116 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-05-13T16:11:08.230Z,1399997468.230 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-05-13T16:11:08.338Z,1399997468.338 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-05-13T16:11:08.439Z,1399997468.439 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-05-13T16:11:08.551Z,1399997468.551 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2014-05-13T16:11:08.556Z,1399997468.556 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-05-13T16:11:09.342Z,1399997469.342 [AHRS_sp3003D] Loaded
2014-05-13T16:11:09.342Z,1399997469.342 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-05-13T16:11:09.678Z,1399997469.678 [Batt_Ocean_Server] Loaded
2014-05-13T16:11:09.678Z,1399997469.678 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-05-13T16:11:09.692Z,1399997469.692 [Depth_Keller] Loaded
2014-05-13T16:11:09.692Z,1399997469.692 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-05-13T16:11:09.697Z,1399997469.697 [DropWeight] Loaded
2014-05-13T16:11:09.697Z,1399997469.697 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-05-13T16:11:09.858Z,1399997469.858 [DVL_micro] Loaded
2014-05-13T16:11:09.859Z,1399997469.859 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-05-13T16:11:09.973Z,1399997469.973 [NAL9602] Loaded
2014-05-13T16:11:09.973Z,1399997469.973 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-05-13T16:11:10.030Z,1399997470.030 [Onboard] Loaded
2014-05-13T16:11:10.031Z,1399997470.031 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-05-13T16:11:10.042Z,1399997470.042 [Radio_Freewave] Loaded
2014-05-13T16:11:10.042Z,1399997470.042 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-05-13T16:11:10.048Z,1399997470.048 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 406074E0
2014-05-13T16:11:10.048Z,1399997470.048 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 856
2014-05-13T16:11:10.055Z,1399997470.055 [SCPI] Loaded
2014-05-13T16:11:10.055Z,1399997470.055 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-05-13T16:11:10.056Z,1399997470.056 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-05-13T16:11:10.057Z,1399997470.057 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-05-13T16:11:10.278Z,1399997470.278 [InternalSim] Loaded
2014-05-13T16:11:10.278Z,1399997470.278 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-05-13T16:11:10.279Z,1399997470.279 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-05-13T16:11:10.282Z,1399997470.282 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-05-13T16:11:10.609Z,1399997470.609 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-05-13T16:11:10.609Z,1399997470.609 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-05-13T16:11:10.618Z,1399997470.618 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator.
2014-05-13T16:11:10.623Z,1399997470.623 [AsyncPiEstimator] Loaded
2014-05-13T16:11:10.624Z,1399997470.624 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread.
2014-05-13T16:11:10.629Z,1399997470.629 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406E44E0
2014-05-13T16:11:10.629Z,1399997470.629 [AsyncPiEstimator ThreadHandler](INFO): Protected caller Thread ID is 857
2014-05-13T16:11:10.630Z,1399997470.630 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-05-13T16:11:10.632Z,1399997470.632 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-05-13T16:11:10.739Z,1399997470.739 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-05-13T16:11:10.739Z,1399997470.739 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-05-13T16:11:10.794Z,1399997470.794 [DeadReckonWithRespectToWater] Loaded
2014-05-13T16:11:10.795Z,1399997470.795 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-05-13T16:11:10.846Z,1399997470.846 [DeadReckonWithRespectToSeafloor] Loaded
2014-05-13T16:11:10.847Z,1399997470.847 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-05-13T16:11:10.900Z,1399997470.900 [DeadReckonUsingDVLWaterTrack] Loaded
2014-05-13T16:11:10.900Z,1399997470.900 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-05-13T16:11:10.917Z,1399997470.917 [NavChart] Loaded
2014-05-13T16:11:10.917Z,1399997470.917 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-05-13T16:11:10.926Z,1399997470.926 [UniversalFixResidualReporter] Loaded
2014-05-13T16:11:10.926Z,1399997470.926 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-05-13T16:11:10.926Z,1399997470.926 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-05-13T16:11:10.927Z,1399997470.927 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-05-13T16:11:11.006Z,1399997471.006 [VerticalControl](DEBUG): Construct VerticalControl.
2014-05-13T16:11:11.133Z,1399997471.133 [VerticalControl] Loaded
2014-05-13T16:11:11.133Z,1399997471.133 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-05-13T16:11:11.134Z,1399997471.134 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-05-13T16:11:11.216Z,1399997471.216 [HorizontalControl] Loaded
2014-05-13T16:11:11.216Z,1399997471.216 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-05-13T16:11:11.217Z,1399997471.217 [SpeedControl](DEBUG): Construct SpeedControl.
2014-05-13T16:11:11.219Z,1399997471.219 [SpeedControl] Loaded
2014-05-13T16:11:11.219Z,1399997471.219 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-05-13T16:11:11.220Z,1399997471.220 [LoopControl](DEBUG): Construct LoopControl.
2014-05-13T16:11:11.220Z,1399997471.220 [LoopControl] Loaded
2014-05-13T16:11:11.220Z,1399997471.220 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-05-13T16:11:11.221Z,1399997471.221 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-05-13T16:11:11.226Z,1399997471.226 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-05-13T16:11:11.260Z,1399997471.260 [DepthRateCalculator] Loaded
2014-05-13T16:11:11.260Z,1399997471.260 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-05-13T16:11:11.266Z,1399997471.266 [PitchRateCalculator] Loaded
2014-05-13T16:11:11.266Z,1399997471.266 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-05-13T16:11:11.278Z,1399997471.278 [SpeedCalculator] Loaded
2014-05-13T16:11:11.278Z,1399997471.278 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-05-13T16:11:11.295Z,1399997471.295 [TempGradientCalculator] Loaded
2014-05-13T16:11:11.295Z,1399997471.295 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-05-13T16:11:11.305Z,1399997471.305 [YawRateCalculator] Loaded
2014-05-13T16:11:11.305Z,1399997471.305 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-05-13T16:11:11.306Z,1399997471.306 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-05-13T16:11:11.308Z,1399997471.308 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-05-13T16:11:11.450Z,1399997471.450 [CTD_NeilBrown] Loaded
2014-05-13T16:11:11.454Z,1399997471.454 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-05-13T16:11:11.458Z,1399997471.458 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407864E0
2014-05-13T16:11:11.458Z,1399997471.458 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 858
2014-05-13T16:11:11.472Z,1399997471.472 [ISUS] Loaded
2014-05-13T16:11:11.472Z,1399997471.472 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread.
2014-05-13T16:11:11.491Z,1399997471.491 [PAR_Licor] Loaded
2014-05-13T16:11:11.492Z,1399997471.492 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-05-13T16:11:11.533Z,1399997471.533 [WetLabsBB2FL] Loaded
2014-05-13T16:11:11.533Z,1399997471.533 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-05-13T16:11:11.535Z,1399997471.535 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407B64E0
2014-05-13T16:11:11.535Z,1399997471.535 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 859
2014-05-13T16:11:11.536Z,1399997471.536 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-05-13T16:11:11.536Z,1399997471.536 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-05-13T16:11:11.667Z,1399997471.667 [SBIT](DEBUG): Construct Startup Built In Test.
2014-05-13T16:11:11.684Z,1399997471.684 [SBIT] Loaded
2014-05-13T16:11:11.684Z,1399997471.684 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-05-13T16:11:11.685Z,1399997471.685 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-05-13T16:11:11.702Z,1399997471.702 [IBIT] Loaded
2014-05-13T16:11:11.702Z,1399997471.702 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-05-13T16:11:11.704Z,1399997471.704 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-05-13T16:11:11.784Z,1399997471.784 [CBIT] Loaded
2014-05-13T16:11:11.785Z,1399997471.785 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-05-13T16:11:11.785Z,1399997471.785 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-05-13T16:11:11.788Z,1399997471.788 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-05-13T16:11:11.947Z,1399997471.947 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-05-13T16:11:11.976Z,1399997471.976 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-05-13T16:11:12.120Z,1399997472.120 [BuoyancyServo] Loaded
2014-05-13T16:11:12.121Z,1399997472.121 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-05-13T16:11:12.133Z,1399997472.133 [ElevatorServo] Loaded
2014-05-13T16:11:12.134Z,1399997472.134 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-05-13T16:11:12.146Z,1399997472.146 [MassServo] Loaded
2014-05-13T16:11:12.146Z,1399997472.146 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-05-13T16:11:12.159Z,1399997472.159 [RudderServo] Loaded
2014-05-13T16:11:12.159Z,1399997472.159 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-05-13T16:11:12.171Z,1399997472.171 [ThrusterServo] Loaded
2014-05-13T16:11:12.171Z,1399997472.171 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-05-13T16:11:12.172Z,1399997472.172 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-05-13T16:11:12.172Z,1399997472.172 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-05-13T16:11:12.217Z,1399997472.217 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-05-13T16:11:12.219Z,1399997472.219 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-05-13T16:11:12.220Z,1399997472.220 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-05-13T16:11:12.227Z,1399997472.227 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-05-13T16:11:12.231Z,1399997472.231 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408854E0
2014-05-13T16:11:12.232Z,1399997472.232 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 860
2014-05-13T16:11:12.236Z,1399997472.236 [Supervisor](INFO): Main Thread ID is 761
2014-05-13T16:11:12.237Z,1399997472.237 [Supervisor](DEBUG): Running supervisor.
2014-05-13T16:11:12.237Z,1399997472.237 [CommandLine ThreadHandler](INFO): Handler Thread ID is 861
2014-05-13T16:11:12.244Z,1399997472.244 [controlThread ThreadHandler](INFO): Handler Thread ID is 862
2014-05-13T16:11:12.244Z,1399997472.244 [controlThread](DEBUG): Initializing ControlThread
2014-05-13T16:11:12.248Z,1399997472.248 [logger ThreadHandler](INFO): Handler Thread ID is 863
2014-05-13T16:11:12.284Z,1399997472.284 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 864
2014-05-13T16:11:12.296Z,1399997472.296 [AsyncPiEstimator ThreadHandler](INFO): Handler Thread ID is 865
2014-05-13T16:11:12.296Z,1399997472.296 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator.
2014-05-13T16:11:12.316Z,1399997472.316 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 866
2014-05-13T16:11:12.316Z,1399997472.316 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-05-13T16:11:12.324Z,1399997472.324 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-05-13T16:11:12.333Z,1399997472.333 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 868
2014-05-13T16:11:12.334Z,1399997472.334 [WetLabsBB2FL](INFO): Powering down
2014-05-13T16:11:12.360Z,1399997472.360 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 869
2014-05-13T16:11:12.389Z,1399997472.389 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-05-13T16:11:12.392Z,1399997472.392 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-05-13T16:11:12.393Z,1399997472.393 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-05-13T16:11:12.393Z,1399997472.393 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-05-13T16:11:12.393Z,1399997472.393 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-05-13T16:11:12.393Z,1399997472.393 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-05-13T16:11:12.393Z,1399997472.393 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-05-13T16:11:12.394Z,1399997472.394 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-05-13T16:11:12.394Z,1399997472.394 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-05-13T16:11:13.787Z,1399997473.787 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-05-13T16:11:13.816Z,1399997473.816 [InternalSim](DEBUG):  InternalSim initializing...
2014-05-13T16:11:14.167Z,1399997474.167 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-13T16:11:14.167Z,1399997474.167 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-05-13T16:11:14.168Z,1399997474.168 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-05-13T16:11:14.168Z,1399997474.168 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-05-13T16:11:14.168Z,1399997474.168 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-05-13T16:11:14.169Z,1399997474.169 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-05-13T16:11:14.169Z,1399997474.169 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-05-13T16:11:14.175Z,1399997474.175 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-05-13T16:11:14.176Z,1399997474.176 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-05-13T16:11:14.177Z,1399997474.177 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-05-13T16:11:14.177Z,1399997474.177 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-13T16:11:14.177Z,1399997474.177 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-05-13T16:11:14.178Z,1399997474.178 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-05-13T16:11:14.190Z,1399997474.190 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-05-13T16:11:14.191Z,1399997474.191 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-05-13T16:11:14.192Z,1399997474.192 [SBIT](INFO): Initialize SBIT Component.
2014-05-13T16:11:14.193Z,1399997474.193 [SBIT](IMPORTANT): Tethys CM Info: 
 $Rev:11288
2014-05-13T16:11:14.193Z,1399997474.193 [SBIT](IMPORTANT): Kernel Release:2.6.27.8
2014-05-13T16:11:14.193Z,1399997474.193 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-05-13T16:11:14.195Z,1399997474.195 [IBIT](INFO): Initialize IBIT Component.
2014-05-13T16:11:14.196Z,1399997474.196 [CBIT](DEBUG): Initialize CBIT Component.
2014-05-13T16:11:14.196Z,1399997474.196 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2014-05-13T16:11:14.196Z,1399997474.196 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2014-05-13T16:11:14.225Z,1399997474.225 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-05-13T16:11:14.249Z,1399997474.249 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-13T16:11:14.257Z,1399997474.257 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2014-05-13T16:11:14.274Z,1399997474.274 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-05-13T16:11:14.412Z,1399997474.412 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-05-13T16:11:14.414Z,1399997474.414 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-05-13T16:11:14.442Z,1399997474.442 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-13T16:11:14.483Z,1399997474.483 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-05-13T16:11:14.486Z,1399997474.486 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-13T16:11:14.521Z,1399997474.521 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-05-13T16:11:14.555Z,1399997474.555 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-05-13T16:11:14.558Z,1399997474.558 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-05-13T16:11:14.578Z,1399997474.578 [Radio_Freewave](INFO): Powering up
2014-05-13T16:11:14.599Z,1399997474.599 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:Control="Tethys/Control"
xmlns:Guidance="Tethys/Guidance" 
xmlns:Units="Tethys/Units"
xmlns:Universal="Tethys/Universal"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="Tethys http://aosn.mbari.org/tethys/Xml/Tethys.xsd
Tethys/Control http://aosn.mbari.org/tethys/Xml/Control.xsd
Tethys/Guidance http://aosn.mbari.org/tethys/Xml/Guidance.xsd
Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
Id="Default">

    <DefineArg Name="NeedGPS"><True/></DefineArg>

    <Aggregate Id="GPS">

        <When>
            <Arg Name="NeedGPS"/>
        </When>

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface>
            <Sequence/>
        </Guidance:GoToSurface>

<!-- Get GPS fix -->

        <ReadDatum Id="Read_GPS">
            <Universal:latitude_fix/>
        </ReadDatum>

        <Assign><Sequence/><Arg Name="NeedGPS"/><False/></Assign>

    </Aggregate>

    <Aggregate Id="Iridium">

        <Sequence/>

<!-- Run at high speed -->

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

<!-- Get to the surface -->

        <Guidance:GoToSurface>
            <Sequence/>
        </Guidance:GoToSurface>

<!-- Do data comms -->

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

    </Aggregate>

    <Aggregate Id="CallIridium">

        <When>
            <Elapsed><Universal:platform_communications/></Elapsed>
            <Gt><Units:minute/><Value>5.0</Value></Gt>
            <And><Universal:platform_conversation/><Eq><True/></Eq></And>
            <Or><Elapsed><Universal:platform_communications/></Elapsed><Gt><Units:hour/><Value>1.0</Value></Gt></Or>
        </When>

        <Assign><Sequence/><Arg Name="NeedGPS"/><True/></Assign>

        <Call RefId="Iridium"/>

    </Aggregate>

    <Aggregate Id="WaitAtTheSurface">

        <Sequence/>

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

        <Guidance:GoToSurface>
            <Parallel/>
        </Guidance:GoToSurface>

    </Aggregate>

</Mission>


2014-05-13T16:11:14.612Z,1399997474.612 [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,DeadReckonUsingMultipleVelocitySources,DeadReckonWithRespectToWater,DeadReckonWithRespectToSeafloor,DeadReckonUsingDVLWaterTrack,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2014-05-13T16:11:14.715Z,1399997474.715 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-05-13T16:11:14.909Z,1399997474.909 [DVL_micro](INFO): Initializing
2014-05-13T16:11:15.385Z,1399997475.385 [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-05-13T16:11:15.573Z,1399997475.573 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-05-13T16:11:15.585Z,1399997475.585 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-05-13T16:11:15.600Z,1399997475.600 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-05-13T16:11:15.613Z,1399997475.613 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-05-13T16:11:15.645Z,1399997475.645 [MassServo](DEBUG): Initializing EZServoServo.
2014-05-13T16:11:15.657Z,1399997475.657 [MassServo](DEBUG): Initializing MassServo.
2014-05-13T16:11:15.687Z,1399997475.687 [RudderServo](DEBUG): Initializing EZServoServo.
2014-05-13T16:11:15.697Z,1399997475.697 [RudderServo](DEBUG): Initializing RudderServo.
2014-05-13T16:11:15.703Z,1399997475.703 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-05-13T16:11:15.713Z,1399997475.713 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-05-13T16:11:15.786Z,1399997475.786 [CommandLine](FAULT): Scheduling is paused
2014-05-13T16:11:16.064Z,1399997476.064 [NAL9602](INFO): Powering up NAL9602
2014-05-13T16:11:16.422Z,1399997476.422 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2014-05-13T16:11:16.422Z,1399997476.422 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2014-05-13T16:11:16.422Z,1399997476.422 [BuoyancyServo] Communications Fault, FailCount= 1
2014-05-13T16:11:16.422Z,1399997476.422 [BuoyancyServo](ERROR): Communications Fault
2014-05-13T16:11:16.724Z,1399997476.724 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2014-05-13T16:11:17.237Z,1399997477.237 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-05-13T16:11:17.238Z,1399997477.238 [BuoyancyServo](INFO): Powering down
2014-05-13T16:11:19.646Z,1399997479.646 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2014-05-13T16:11:19.646Z,1399997479.646 [BuoyancyServo] No Fault, FailCount= 1
2014-05-13T16:11:20.087Z,1399997480.087 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-05-13T16:11:20.208Z,1399997480.208 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-05-13T16:11:27.107Z,1399997487.107 [NAL9602](INFO): NAL9602 initialized
2014-05-13T16:11:29.848Z,1399997489.848 [SBIT](IMPORTANT): Beginning Startup BIT
2014-05-13T16:11:29.855Z,1399997489.855 [CBIT](IMPORTANT): Beginning GF scan
2014-05-13T16:11:44.977Z,1399997504.977 [NAL9602](INFO): SBD MO Status=0, MOMSN=28380, MT Status=0, MTMSN=0
2014-05-13T16:11:44.977Z,1399997504.977 [NAL9602](INFO): No messages in MT queue
2014-05-13T16:11:53.350Z,1399997513.350 [NAL9602](IMPORTANT): GPS fix at: 1399997510.00
2014-05-13T16:11:56.541Z,1399997516.541 [CBIT](IMPORTANT): No ground fault detected
2014-05-13T16:12:00.929Z,1399997520.929 [NAL9602](INFO): Powering down
2014-05-13T16:12:23.959Z,1399997543.959 [SBIT](IMPORTANT): SBIT PASSED
2014-05-13T16:12:24.414Z,1399997544.414 [MissionManager](IMPORTANT): Started mission Startup
2014-05-13T16:12:24.414Z,1399997544.414 [Startup] Running Loop=1
2014-05-13T16:12:24.414Z,1399997544.414 [Startup](INFO): Aggregate::initialize Startup
2014-05-13T16:12:24.414Z,1399997544.414 [Startup:A.GoToSurface] Running Loop=1
2014-05-13T16:12:24.415Z,1399997544.415 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-13T16:12:24.433Z,1399997544.433 [Startup:StartupSatComms] Running Loop=1
2014-05-13T16:12:24.433Z,1399997544.433 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-05-13T16:12:24.433Z,1399997544.433 [Startup:StartupSatComms:A] Running Loop=1
2014-05-13T16:12:24.857Z,1399997544.857 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-05-13T16:12:25.319Z,1399997545.319 [NAL9602](INFO): Powering up
2014-05-13T16:12:36.386Z,1399997556.386 [NAL9602](INFO): NAL9602 initialized
2014-05-13T16:12:55.015Z,1399997575.015 [NAL9602](INFO): SBD MO Status=0, MOMSN=28381, MT Status=0, MTMSN=0
2014-05-13T16:12:55.016Z,1399997575.016 [NAL9602](INFO): No messages in MT queue
2014-05-13T16:13:05.562Z,1399997585.562 [NAL9602](IMPORTANT): GPS fix at: 1399997583.00
2014-05-13T16:13:05.610Z,1399997585.610 [Startup:StartupSatComms:A] Stopped
2014-05-13T16:13:05.610Z,1399997585.610 [Startup:StartupSatComms:B] Running Loop=1
2014-05-13T16:13:06.221Z,1399997586.221 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-05-13T16:13:41.791Z,1399997621.791 [NAL9602](INFO): SBD MO Status=2, MOMSN=28382, MT Status=2, MTMSN=0
2014-05-13T16:13:41.791Z,1399997621.791 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2014-05-13T16:14:01.194Z,1399997641.194 [NAL9602](INFO): SBD MO Status=1, MOMSN=28382, MT Status=0, MTMSN=0
2014-05-13T16:14:01.242Z,1399997641.242 [NAL9602](INFO): Sent 58 bytes from file Logs/20140513T152439/Courier0020.lzma
2014-05-13T16:14:01.242Z,1399997641.242 [NAL9602](INFO): Packets left to send: 0
2014-05-13T16:14:01.244Z,1399997641.244 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T152439/Courier0020.lzma.parts/0000.sbd
2014-05-13T16:14:01.244Z,1399997641.244 [NAL9602](INFO): Completed sending Logs/20140513T152439/Courier0020.lzma
2014-05-13T16:14:05.884Z,1399997645.884 [Startup:StartupSatComms:B](INFO): Timed out from 2014-05-13T16:13:05.6Z
2014-05-13T16:14:05.884Z,1399997645.884 [Startup:StartupSatComms:B] Stopped
2014-05-13T16:14:05.884Z,1399997645.884 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-05-13T16:14:05.916Z,1399997645.916 [Startup:StartupSatComms] Stopped
2014-05-13T16:14:05.916Z,1399997645.916 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-05-13T16:14:05.917Z,1399997645.917 [Startup](INFO): Completed Startup
2014-05-13T16:14:05.917Z,1399997645.917 [Startup] Stopped
2014-05-13T16:14:05.917Z,1399997645.917 [Startup](INFO): Aggregate::uninitialize Startup
2014-05-13T16:14:05.918Z,1399997645.918 [Startup:A.GoToSurface] Stopped
2014-05-13T16:14:05.918Z,1399997645.918 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-13T16:14:06.336Z,1399997646.336 [MissionManager](IMPORTANT): Started mission Default
2014-05-13T16:14:06.336Z,1399997646.336 [Default] Running Loop=1
2014-05-13T16:14:06.336Z,1399997646.336 [Default](INFO): Aggregate::initialize Default
2014-05-13T16:14:06.336Z,1399997646.336 [Default:Iridium] Running Loop=1
2014-05-13T16:14:06.336Z,1399997646.336 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-13T16:14:06.336Z,1399997646.336 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-13T16:14:06.336Z,1399997646.336 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-13T16:14:06.336Z,1399997646.336 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-13T16:14:06.337Z,1399997646.337 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-13T16:14:06.337Z,1399997646.337 [Default:CallIridium] Running Loop=1
2014-05-13T16:14:06.337Z,1399997646.337 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-13T16:14:06.338Z,1399997646.338 [Default:CallIridium:A] Running Loop=1
2014-05-13T16:14:06.340Z,1399997646.340 [Default:CallIridium:A] Stopped
2014-05-13T16:14:06.340Z,1399997646.340 [Default:CallIridium:B] Running Loop=1
2014-05-13T16:14:06.340Z,1399997646.340 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-13T16:14:06.369Z,1399997646.369 [Default:Iridium:B.GoToSurface] Stopped
2014-05-13T16:14:06.369Z,1399997646.369 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-13T16:14:06.369Z,1399997646.369 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-13T16:14:06.369Z,1399997646.369 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-13T16:14:06.375Z,1399997646.375 [Default:GPS] Running Loop=1
2014-05-13T16:14:06.375Z,1399997646.375 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-13T16:14:06.375Z,1399997646.375 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-13T16:14:06.375Z,1399997646.375 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-13T16:14:06.375Z,1399997646.375 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-13T16:14:06.375Z,1399997646.375 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-13T16:14:06.385Z,1399997646.385 [Default:GPS:B.GoToSurface] Stopped
2014-05-13T16:14:06.385Z,1399997646.385 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-13T16:14:06.385Z,1399997646.385 [Default:GPS:Read_GPS] Running Loop=1
2014-05-13T16:14:06.385Z,1399997646.385 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-13T16:14:06.870Z,1399997646.870 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-05-13T16:14:06.873Z,1399997646.873 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-05-13T16:14:11.072Z,1399997651.072 [NAL9602](INFO): SBD MO Status=1, MOMSN=28383, MT Status=0, MTMSN=0
2014-05-13T16:14:11.125Z,1399997651.125 [NAL9602](INFO): Sent 18 bytes from file Logs/20140513T160706/Courier0000.lzma
2014-05-13T16:14:11.125Z,1399997651.125 [NAL9602](INFO): Packets left to send: 0
2014-05-13T16:14:11.127Z,1399997651.127 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T160706/Courier0000.lzma.parts/0000.sbd
2014-05-13T16:14:11.127Z,1399997651.127 [NAL9602](INFO): Completed sending Logs/20140513T160706/Courier0000.lzma
2014-05-13T16:14:20.084Z,1399997660.084 [NAL9602](INFO): SBD MO Status=1, MOMSN=28384, MT Status=0, MTMSN=0
2014-05-13T16:14:20.131Z,1399997660.131 [NAL9602](INFO): Sent 332 bytes from file Logs/20140513T161103/Courier0000.lzma
2014-05-13T16:14:20.131Z,1399997660.131 [NAL9602](INFO): Packets left to send: 1
2014-05-13T16:14:20.133Z,1399997660.133 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T161103/Courier0000.lzma.parts/0001.sbd
2014-05-13T16:14:28.288Z,1399997668.288 [NAL9602](INFO): SBD MO Status=1, MOMSN=28385, MT Status=0, MTMSN=0
2014-05-13T16:14:28.352Z,1399997668.352 [NAL9602](INFO): Sent 27 bytes from file Logs/20140513T161103/Courier0000.lzma
2014-05-13T16:14:28.353Z,1399997668.353 [NAL9602](INFO): Packets left to send: 0
2014-05-13T16:14:28.354Z,1399997668.354 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T161103/Courier0000.lzma.parts/0000.sbd
2014-05-13T16:14:28.354Z,1399997668.354 [NAL9602](INFO): Completed sending Logs/20140513T161103/Courier0000.lzma
2014-05-13T16:14:35.005Z,1399997675.005 [NAL9602](INFO): SBD MO Status=1, MOMSN=28386, MT Status=0, MTMSN=0
2014-05-13T16:14:35.054Z,1399997675.054 [NAL9602](INFO): Sent 25 bytes from file Logs/20140513T161103/Courier0004.lzma
2014-05-13T16:14:35.054Z,1399997675.054 [NAL9602](INFO): Packets left to send: 0
2014-05-13T16:14:35.056Z,1399997675.056 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T161103/Courier0004.lzma.parts/0000.sbd
2014-05-13T16:14:35.056Z,1399997675.056 [NAL9602](INFO): Completed sending Logs/20140513T161103/Courier0004.lzma
2014-05-13T16:14:47.459Z,1399997687.459 [NAL9602](INFO): SBD MO Status=1, MOMSN=28387, MT Status=0, MTMSN=0
2014-05-13T16:14:47.509Z,1399997687.509 [NAL9602](INFO): Sent 153 bytes from file Logs/20140513T152439/Express0017.lzma
2014-05-13T16:14:47.509Z,1399997687.509 [NAL9602](INFO): Packets left to send: 0
2014-05-13T16:14:47.511Z,1399997687.511 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T152439/Express0017.lzma.parts/0000.sbd
2014-05-13T16:14:47.511Z,1399997687.511 [NAL9602](INFO): Completed sending Logs/20140513T152439/Express0017.lzma
2014-05-13T16:14:54.660Z,1399997694.660 [NAL9602](INFO): SBD MO Status=1, MOMSN=28388, MT Status=0, MTMSN=0
2014-05-13T16:14:54.717Z,1399997694.717 [NAL9602](INFO): Sent 191 bytes from file Logs/20140513T152439/Express0021.lzma
2014-05-13T16:14:54.717Z,1399997694.717 [NAL9602](INFO): Packets left to send: 0
2014-05-13T16:14:54.718Z,1399997694.718 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T152439/Express0021.lzma.parts/0000.sbd
2014-05-13T16:14:54.719Z,1399997694.719 [NAL9602](INFO): Completed sending Logs/20140513T152439/Express0021.lzma
2014-05-13T16:15:05.547Z,1399997705.547 [NAL9602](INFO): SBD MO Status=1, MOMSN=28389, MT Status=0, MTMSN=0
2014-05-13T16:15:05.602Z,1399997705.602 [NAL9602](INFO): Sent 18 bytes from file Logs/20140513T160706/Express0001.lzma
2014-05-13T16:15:05.602Z,1399997705.602 [NAL9602](INFO): Packets left to send: 0
2014-05-13T16:15:05.604Z,1399997705.604 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T160706/Express0001.lzma.parts/0000.sbd
2014-05-13T16:15:05.604Z,1399997705.604 [NAL9602](INFO): Completed sending Logs/20140513T160706/Express0001.lzma
2014-05-13T16:15:16.173Z,1399997716.173 [NAL9602](INFO): SBD MO Status=1, MOMSN=28390, MT Status=0, MTMSN=0
2014-05-13T16:15:16.234Z,1399997716.234 [NAL9602](INFO): Sent 332 bytes from file Logs/20140513T161103/Express0001.lzma
2014-05-13T16:15:16.234Z,1399997716.234 [NAL9602](INFO): Packets left to send: 2
2014-05-13T16:15:16.236Z,1399997716.236 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T161103/Express0001.lzma.parts/0002.sbd
2014-05-13T16:15:28.889Z,1399997728.889 [NAL9602](INFO): SBD MO Status=1, MOMSN=28391, MT Status=0, MTMSN=0
2014-05-13T16:15:28.941Z,1399997728.941 [NAL9602](INFO): Sent 332 bytes from file Logs/20140513T161103/Express0001.lzma
2014-05-13T16:15:28.942Z,1399997728.942 [NAL9602](INFO): Packets left to send: 1
2014-05-13T16:15:28.943Z,1399997728.943 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T161103/Express0001.lzma.parts/0001.sbd
2014-05-13T16:15:40.971Z,1399997740.971 [NAL9602](INFO): SBD MO Status=1, MOMSN=28392, MT Status=0, MTMSN=0
2014-05-13T16:15:41.016Z,1399997741.016 [NAL9602](INFO): Sent 221 bytes from file Logs/20140513T161103/Express0001.lzma
2014-05-13T16:15:41.016Z,1399997741.016 [NAL9602](INFO): Packets left to send: 0
2014-05-13T16:15:41.018Z,1399997741.018 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T161103/Express0001.lzma.parts/0000.sbd
2014-05-13T16:15:41.018Z,1399997741.018 [NAL9602](INFO): Completed sending Logs/20140513T161103/Express0001.lzma
2014-05-13T16:15:47.880Z,1399997747.880 [NAL9602](INFO): SBD MO Status=1, MOMSN=28393, MT Status=0, MTMSN=0
2014-05-13T16:15:47.927Z,1399997747.927 [NAL9602](INFO): Sent 109 bytes from file Logs/20140513T161103/Express0005.lzma
2014-05-13T16:15:47.927Z,1399997747.927 [NAL9602](INFO): Packets left to send: 0
2014-05-13T16:15:47.929Z,1399997747.929 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T161103/Express0005.lzma.parts/0000.sbd
2014-05-13T16:15:47.929Z,1399997747.929 [NAL9602](INFO): Completed sending Logs/20140513T161103/Express0005.lzma
2014-05-13T16:15:55.392Z,1399997755.392 [NAL9602](INFO): SBD MO Status=0, MOMSN=28394, MT Status=0, MTMSN=0
2014-05-13T16:15:55.492Z,1399997755.492 [Default:Iridium:Read_Iridium] Stopped
2014-05-13T16:15:55.493Z,1399997755.493 [Default:Iridium](INFO): Completed Default:Iridium
2014-05-13T16:15:55.493Z,1399997755.493 [Default:Iridium] Stopped
2014-05-13T16:15:55.493Z,1399997755.493 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-13T16:15:55.493Z,1399997755.493 [Default:Iridium:A.SetSpeed] Stopped
2014-05-13T16:15:55.493Z,1399997755.493 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-13T16:15:55.493Z,1399997755.493 [Default:WaitAtTheSurface] Running Loop=1
2014-05-13T16:15:55.493Z,1399997755.493 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2014-05-13T16:15:55.493Z,1399997755.493 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-05-13T16:15:55.493Z,1399997755.493 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize.
2014-05-13T16:15:55.493Z,1399997755.493 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-05-13T16:15:55.493Z,1399997755.493 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-13T16:15:55.924Z,1399997755.924 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1
2014-05-13T16:15:55.929Z,1399997755.929 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-05-13T16:15:55.934Z,1399997755.934 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B
2014-05-13T16:15:55.935Z,1399997755.935 [Default:CallIridium:B] Stopped
2014-05-13T16:15:55.935Z,1399997755.935 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-13T16:15:55.935Z,1399997755.935 [Default:CallIridium](INFO): Completed Default:CallIridium
2014-05-13T16:15:55.935Z,1399997755.935 [Default:CallIridium] Stopped
2014-05-13T16:15:55.935Z,1399997755.935 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-13T16:15:56.823Z,1399997756.823 [NAL9602](IMPORTANT): GPS fix at: 1399997754.00
2014-05-13T16:15:56.847Z,1399997756.847 [Default:GPS:Read_GPS] Stopped
2014-05-13T16:15:56.847Z,1399997756.847 [Default:GPS:D] Running Loop=1
2014-05-13T16:15:57.349Z,1399997757.349 [Default:GPS:D] Stopped
2014-05-13T16:15:57.350Z,1399997757.350 [Default:GPS](INFO): Completed Default:GPS
2014-05-13T16:15:57.350Z,1399997757.350 [Default:GPS] Stopped
2014-05-13T16:15:57.350Z,1399997757.350 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-13T16:15:57.350Z,1399997757.350 [Default:GPS:A.SetSpeed] Stopped
2014-05-13T16:15:57.350Z,1399997757.350 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-13T16:16:17.922Z,1399997777.922 [NAL9602](INFO): Powering down
2014-05-13T16:20:57.924Z,1399998057.924 [Default:CallIridium] Running Loop=1
2014-05-13T16:20:57.924Z,1399998057.924 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium
2014-05-13T16:20:57.924Z,1399998057.924 [Default:CallIridium:A] Running Loop=1
2014-05-13T16:20:57.924Z,1399998057.924 [Default:CallIridium:A] Stopped
2014-05-13T16:20:57.924Z,1399998057.924 [Default:CallIridium:B] Running Loop=1
2014-05-13T16:20:57.925Z,1399998057.925 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B
2014-05-13T16:21:02.999Z,1399998062.999 [Default:Iridium] Running Loop=1
2014-05-13T16:21:02.999Z,1399998062.999 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-05-13T16:21:02.999Z,1399998062.999 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-05-13T16:21:02.999Z,1399998062.999 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-05-13T16:21:02.999Z,1399998062.999 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-05-13T16:21:02.999Z,1399998062.999 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-13T16:21:03.000Z,1399998063.000 [Default:Iridium:B.GoToSurface] Stopped
2014-05-13T16:21:03.000Z,1399998063.000 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-13T16:21:03.000Z,1399998063.000 [Default:Iridium:Read_Iridium] Running Loop=1
2014-05-13T16:21:03.001Z,1399998063.001 [Default:GPS] Running Loop=1
2014-05-13T16:21:03.001Z,1399998063.001 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-05-13T16:21:03.001Z,1399998063.001 [Default:GPS:A.SetSpeed] Running Loop=1
2014-05-13T16:21:03.001Z,1399998063.001 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-05-13T16:21:03.001Z,1399998063.001 [Default:GPS:B.GoToSurface] Running Loop=1
2014-05-13T16:21:03.001Z,1399998063.001 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-05-13T16:21:03.002Z,1399998063.002 [Default:GPS:B.GoToSurface] Stopped
2014-05-13T16:21:03.002Z,1399998063.002 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-13T16:21:03.002Z,1399998063.002 [Default:GPS:Read_GPS] Running Loop=1
2014-05-13T16:21:04.150Z,1399998064.150 [NAL9602](INFO): Powering up
2014-05-13T16:21:14.738Z,1399998074.738 [NAL9602](INFO): NAL9602 initialized
2014-05-13T16:21:35.227Z,1399998095.227 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=28395, MT Status=1, MTMSN=1844
2014-05-13T16:21:35.281Z,1399998095.281 [NAL9602](INFO): Sent 76 bytes from file Logs/20140513T161103/Courier0008.lzma
2014-05-13T16:21:35.282Z,1399998095.282 [NAL9602](INFO): Packets left to send: 0
2014-05-13T16:21:35.469Z,1399998095.469 [NAL9602](INFO): Stored copy of sent data in Logs/20140513T161103/Courier0008.lzma.parts/0000.sbd
2014-05-13T16:21:35.469Z,1399998095.469 [NAL9602](INFO): Completed sending Logs/20140513T161103/Courier0008.lzma
2014-05-13T16:21:36.039Z,1399998096.039 [NAL9602](INFO): Received command:restart system
2014-05-13T16:21:36.139Z,1399998096.139 [CommandLine](IMPORTANT): got command restart system
2014-05-13T16:21:37.451Z,1399998097.451 [NAL9602](IMPORTANT): GPS fix at: 1399998095.00
2014-05-13T16:21:37.516Z,1399998097.516 [Default:GPS:Read_GPS] Stopped
2014-05-13T16:21:37.516Z,1399998097.516 [Default:GPS:D] Running Loop=1
2014-05-13T16:21:37.959Z,1399998097.959 [Default:GPS:D] Stopped
2014-05-13T16:21:37.960Z,1399998097.960 [Default:GPS](INFO): Completed Default:GPS
2014-05-13T16:21:37.960Z,1399998097.960 [Default:GPS] Stopped
2014-05-13T16:21:37.960Z,1399998097.960 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-05-13T16:21:37.960Z,1399998097.960 [Default:GPS:A.SetSpeed] Stopped
2014-05-13T16:21:37.960Z,1399998097.960 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-05-13T16:21:38.401Z,1399998098.401 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-13T16:21:38.402Z,1399998098.402 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:38.574Z,1399998098.574 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-05-13T16:21:38.574Z,1399998098.574 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:38.575Z,1399998098.575 [CommandLine](INFO): Join timeout helper Thread ID is 922
2014-05-13T16:21:38.576Z,1399998098.576 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-05-13T16:21:38.576Z,1399998098.576 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:38.576Z,1399998098.576 [NavChartDb](INFO): Join timeout helper Thread ID is 923
2014-05-13T16:21:38.623Z,1399998098.623 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-13T16:21:38.623Z,1399998098.623 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:38.638Z,1399998098.638 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-05-13T16:21:38.638Z,1399998098.638 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:38.639Z,1399998098.639 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 924
2014-05-13T16:21:38.955Z,1399998098.955 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-13T16:21:38.955Z,1399998098.955 [WetLabsBB2FL](INFO): Powering down
2014-05-13T16:21:38.956Z,1399998098.956 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:38.959Z,1399998098.959 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-05-13T16:21:38.959Z,1399998098.959 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:38.959Z,1399998098.959 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 925
2014-05-13T16:21:38.993Z,1399998098.993 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-13T16:21:38.993Z,1399998098.993 [CTD_NeilBrown](INFO): Powering down
2014-05-13T16:21:38.996Z,1399998098.996 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:38.000Z,1399998099.000 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler
2014-05-13T16:21:39.000Z,1399998099.000 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:39.002Z,1399998099.002 [AsyncPiEstimator](INFO): Join timeout helper Thread ID is 926
2014-05-13T16:21:39.299Z,1399998099.299 [AsyncPiEstimator ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-13T16:21:39.300Z,1399998099.300 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator.
2014-05-13T16:21:39.300Z,1399998099.300 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:39.308Z,1399998099.308 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-05-13T16:21:39.308Z,1399998099.308 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:39.309Z,1399998099.309 [Radio_Freewave](INFO): Join timeout helper Thread ID is 927
2014-05-13T16:21:39.560Z,1399998099.560 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-13T16:21:39.650Z,1399998099.650 [Radio_Freewave](INFO): Powering down
2014-05-13T16:21:40.053Z,1399998100.053 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.057Z,1399998100.057 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-05-13T16:21:40.057Z,1399998100.057 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.057Z,1399998100.057 [logger](INFO): Join timeout helper Thread ID is 930
2014-05-13T16:21:40.105Z,1399998100.105 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-13T16:21:40.105Z,1399998100.105 [logger ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.117Z,1399998100.117 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-05-13T16:21:40.118Z,1399998100.118 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.118Z,1399998100.118 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-05-13T16:21:40.118Z,1399998100.118 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.118Z,1399998100.118 [controlThread](INFO): Join timeout helper Thread ID is 931
2014-05-13T16:21:40.198Z,1399998100.198 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-05-13T16:21:40.199Z,1399998100.199 [controlThread](DEBUG): Uninitializing ControlThread
2014-05-13T16:21:40.199Z,1399998100.199 [AHRS_sp3003D](INFO): Powering down
2014-05-13T16:21:40.200Z,1399998100.200 [DVL_micro](INFO): uninitialize:Powering down
2014-05-13T16:21:40.201Z,1399998100.201 [NAL9602](INFO): Powering down
2014-05-13T16:21:40.204Z,1399998100.204 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-05-13T16:21:40.206Z,1399998100.206 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-05-13T16:21:40.206Z,1399998100.206 [Default] Stopped
2014-05-13T16:21:40.206Z,1399998100.206 [Default](INFO): Aggregate::uninitialize Default
2014-05-13T16:21:40.207Z,1399998100.207 [Default:Iridium] Stopped
2014-05-13T16:21:40.207Z,1399998100.207 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-05-13T16:21:40.207Z,1399998100.207 [Default:Iridium:A.SetSpeed] Stopped
2014-05-13T16:21:40.207Z,1399998100.207 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-05-13T16:21:40.207Z,1399998100.207 [Default:Iridium:Read_Iridium] Stopped
2014-05-13T16:21:40.207Z,1399998100.207 [Default:CallIridium] Stopped
2014-05-13T16:21:40.207Z,1399998100.207 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium
2014-05-13T16:21:40.207Z,1399998100.207 [Default:CallIridium:B] Stopped
2014-05-13T16:21:40.207Z,1399998100.207 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B
2014-05-13T16:21:40.208Z,1399998100.208 [Default:WaitAtTheSurface] Stopped
2014-05-13T16:21:40.208Z,1399998100.208 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2014-05-13T16:21:40.208Z,1399998100.208 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped
2014-05-13T16:21:40.208Z,1399998100.208 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2014-05-13T16:21:40.208Z,1399998100.208 [Default:WaitAtTheSurface:B.GoToSurface] Stopped
2014-05-13T16:21:40.208Z,1399998100.208 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-05-13T16:21:40.213Z,1399998100.213 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-05-13T16:21:40.213Z,1399998100.213 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-05-13T16:21:40.214Z,1399998100.214 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-05-13T16:21:40.214Z,1399998100.214 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-05-13T16:21:40.214Z,1399998100.214 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-05-13T16:21:40.214Z,1399998100.214 [BuoyancyServo](INFO): Powering down
2014-05-13T16:21:40.229Z,1399998100.229 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-05-13T16:21:40.229Z,1399998100.229 [ElevatorServo](INFO): Powering down
2014-05-13T16:21:40.230Z,1399998100.230 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-05-13T16:21:40.230Z,1399998100.230 [MassServo](INFO): Powering down
2014-05-13T16:21:40.231Z,1399998100.231 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-05-13T16:21:40.231Z,1399998100.231 [RudderServo](INFO): Powering down
2014-05-13T16:21:40.232Z,1399998100.232 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-05-13T16:21:40.232Z,1399998100.232 [ThrusterServo](INFO): Powering down
2014-05-13T16:21:40.233Z,1399998100.233 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-05-13T16:21:40.233Z,1399998100.233 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-05-13T16:21:40.233Z,1399998100.233 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-05-13T16:21:40.276Z,1399998100.276 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.280Z,1399998100.280 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.329Z,1399998100.329 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.355Z,1399998100.355 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.359Z,1399998100.359 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.386Z,1399998100.386 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-05-13T16:21:40.440Z,1399998100.440 [logger ThreadHandler](INFO): Thread cancelled.