2014-07-29T00:20:48.531Z,1406593248.531 [Supervisor](DEBUG): Initializing supervisor.
2014-07-29T00:20:48.537Z,1406593248.537 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0
2014-07-29T00:20:48.537Z,1406593248.537 [SyncHandler](INFO): Protected caller Thread ID is 777
2014-07-29T00:20:48.538Z,1406593248.538 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2014-07-29T00:20:48.540Z,1406593248.540 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0
2014-07-29T00:20:48.541Z,1406593248.541 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 778
2014-07-29T00:20:48.544Z,1406593248.544 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2014-07-29T00:20:48.555Z,1406593248.555 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2014-07-29T00:20:48.556Z,1406593248.556 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0
2014-07-29T00:20:48.557Z,1406593248.557 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 779
2014-07-29T00:20:48.558Z,1406593248.558 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2014-07-29T00:20:48.560Z,1406593248.560 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0
2014-07-29T00:20:48.561Z,1406593248.561 [logger ThreadHandler](INFO): Protected caller Thread ID is 780
2014-07-29T00:20:48.563Z,1406593248.563 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2014-07-29T00:20:48.564Z,1406593248.564 [Supervisor](INFO): Looking for Config files in directory: Config/
2014-07-29T00:20:48.568Z,1406593248.568 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2014-07-29T00:20:48.939Z,1406593248.939 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2014-07-29T00:20:48.940Z,1406593248.940 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2014-07-29T00:20:49.115Z,1406593249.115 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2014-07-29T00:20:49.115Z,1406593249.115 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2014-07-29T00:20:49.231Z,1406593249.231 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2014-07-29T00:20:49.231Z,1406593249.231 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2014-07-29T00:20:49.371Z,1406593249.371 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2014-07-29T00:20:49.371Z,1406593249.371 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2014-07-29T00:20:49.470Z,1406593249.470 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2014-07-29T00:20:49.619Z,1406593249.619 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2014-07-29T00:20:49.622Z,1406593249.622 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2014-07-29T00:20:49.718Z,1406593249.718 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2014-07-29T00:20:49.718Z,1406593249.718 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2014-07-29T00:20:49.914Z,1406593249.914 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2014-07-29T00:20:49.915Z,1406593249.915 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2014-07-29T00:20:50.234Z,1406593250.234 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2014-07-29T00:20:50.235Z,1406593250.235 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2014-07-29T00:20:50.571Z,1406593250.571 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2014-07-29T00:20:50.572Z,1406593250.572 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2014-07-29T00:20:51.126Z,1406593251.126 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2014-07-29T00:20:51.127Z,1406593251.127 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2014-07-29T00:20:51.342Z,1406593251.342 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2014-07-29T00:20:51.344Z,1406593251.344 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2014-07-29T00:20:51.462Z,1406593251.462 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2014-07-29T00:20:51.463Z,1406593251.463 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2014-07-29T00:20:52.963Z,1406593252.963 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2014-07-29T00:20:52.963Z,1406593252.963 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2014-07-29T00:20:53.093Z,1406593253.093 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2014-07-29T00:20:53.095Z,1406593253.095 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2014-07-29T00:20:53.687Z,1406593253.687 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2014-07-29T00:20:53.802Z,1406593253.802 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2014-07-29T00:20:53.936Z,1406593253.936 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg
2014-07-29T00:20:54.055Z,1406593254.055 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2014-07-29T00:20:54.163Z,1406593254.163 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2014-07-29T00:20:54.307Z,1406593254.307 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2014-07-29T00:20:54.465Z,1406593254.465 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2014-07-29T00:20:54.579Z,1406593254.579 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2014-07-29T00:20:54.678Z,1406593254.678 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2014-07-29T00:20:54.784Z,1406593254.784 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2014-07-29T00:20:54.892Z,1406593254.892 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2014-07-29T00:20:55.016Z,1406593255.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2014-07-29T00:20:55.115Z,1406593255.115 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2014-07-29T00:20:55.116Z,1406593255.116 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2014-07-29T00:20:55.122Z,1406593255.122 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2014-07-29T00:20:55.198Z,1406593255.198 [VerticalControl](DEBUG): Construct VerticalControl.
2014-07-29T00:20:55.328Z,1406593255.328 [VerticalControl] Loaded
2014-07-29T00:20:55.328Z,1406593255.328 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2014-07-29T00:20:55.329Z,1406593255.329 [HorizontalControl](DEBUG): Construct HorizontalControl.
2014-07-29T00:20:55.408Z,1406593255.408 [HorizontalControl] Loaded
2014-07-29T00:20:55.409Z,1406593255.409 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2014-07-29T00:20:55.409Z,1406593255.409 [SpeedControl](DEBUG): Construct SpeedControl.
2014-07-29T00:20:55.415Z,1406593255.415 [SpeedControl] Loaded
2014-07-29T00:20:55.415Z,1406593255.415 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2014-07-29T00:20:55.416Z,1406593255.416 [LoopControl](DEBUG): Construct LoopControl.
2014-07-29T00:20:55.416Z,1406593255.416 [LoopControl] Loaded
2014-07-29T00:20:55.417Z,1406593255.417 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2014-07-29T00:20:55.417Z,1406593255.417 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2014-07-29T00:20:55.418Z,1406593255.418 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2014-07-29T00:20:55.546Z,1406593255.546 [SBIT](DEBUG): Construct Startup Built In Test.
2014-07-29T00:20:55.562Z,1406593255.562 [SBIT] Loaded
2014-07-29T00:20:55.562Z,1406593255.562 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2014-07-29T00:20:55.563Z,1406593255.563 [IBIT](DEBUG): Construct Initiated Built In Test.
2014-07-29T00:20:55.591Z,1406593255.591 [IBIT] Loaded
2014-07-29T00:20:55.591Z,1406593255.591 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2014-07-29T00:20:55.594Z,1406593255.594 [CBIT](DEBUG): Construct CBIT Built In Test.
2014-07-29T00:20:55.725Z,1406593255.725 [CBIT] Loaded
2014-07-29T00:20:55.725Z,1406593255.725 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2014-07-29T00:20:55.725Z,1406593255.725 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2014-07-29T00:20:55.726Z,1406593255.726 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2014-07-29T00:20:55.757Z,1406593255.757 [DepthRateCalculator] Loaded
2014-07-29T00:20:55.757Z,1406593255.757 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2014-07-29T00:20:55.762Z,1406593255.762 [PitchRateCalculator] Loaded
2014-07-29T00:20:55.763Z,1406593255.763 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2014-07-29T00:20:55.778Z,1406593255.778 [SpeedCalculator] Loaded
2014-07-29T00:20:55.778Z,1406593255.778 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2014-07-29T00:20:55.794Z,1406593255.794 [TempGradientCalculator] Loaded
2014-07-29T00:20:55.795Z,1406593255.795 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2014-07-29T00:20:55.800Z,1406593255.800 [YawRateCalculator] Loaded
2014-07-29T00:20:55.800Z,1406593255.800 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2014-07-29T00:20:55.801Z,1406593255.801 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2014-07-29T00:20:55.801Z,1406593255.801 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2014-07-29T00:21:01.145Z,1406593261.145 [HFRadarModelCalc] Loaded
2014-07-29T00:21:01.145Z,1406593261.145 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread.
2014-07-29T00:21:05.330Z,1406593265.330 [HFRadarCompactModelForecaster] Loaded
2014-07-29T00:21:05.331Z,1406593265.331 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread.
2014-07-29T00:21:06.485Z,1406593266.485 [HFRCMSpaceInterpolator] Loaded
2014-07-29T00:21:06.485Z,1406593266.485 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread.
2014-07-29T00:21:06.487Z,1406593266.487 [HFRCMTimeInterpolator] Loaded
2014-07-29T00:21:06.488Z,1406593266.488 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread.
2014-07-29T00:21:07.607Z,1406593267.607 [HFRCMReconstructedInterpolator] Loaded
2014-07-29T00:21:07.607Z,1406593267.607 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread.
2014-07-29T00:21:07.619Z,1406593267.619 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded
2014-07-29T00:21:07.619Z,1406593267.619 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread.
2014-07-29T00:21:07.654Z,1406593267.654 [HFRCMVirtualSurfaceDrifter] Loaded
2014-07-29T00:21:07.654Z,1406593267.654 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread.
2014-07-29T00:21:07.655Z,1406593267.655 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2014-07-29T00:21:07.655Z,1406593267.655 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2014-07-29T00:21:07.960Z,1406593267.960 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2014-07-29T00:21:07.960Z,1406593267.960 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2014-07-29T00:21:08.064Z,1406593268.064 [DeadReckonUsingMultipleVelocitySources] Loaded
2014-07-29T00:21:08.064Z,1406593268.064 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2014-07-29T00:21:08.113Z,1406593268.113 [DeadReckonWithRespectToWater] Loaded
2014-07-29T00:21:08.114Z,1406593268.114 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToWater" handled in the control thread.
2014-07-29T00:21:08.168Z,1406593268.168 [DeadReckonWithRespectToSeafloor] Loaded
2014-07-29T00:21:08.168Z,1406593268.168 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2014-07-29T00:21:08.233Z,1406593268.233 [DeadReckonUsingDVLWaterTrack] Loaded
2014-07-29T00:21:08.233Z,1406593268.233 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingDVLWaterTrack" handled in the control thread.
2014-07-29T00:21:08.284Z,1406593268.284 [DeadReckonUsingCompactModelForecast] Loaded
2014-07-29T00:21:08.284Z,1406593268.284 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingCompactModelForecast" handled in the control thread.
2014-07-29T00:21:08.305Z,1406593268.305 [NavChart] Loaded
2014-07-29T00:21:08.305Z,1406593268.305 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2014-07-29T00:21:08.310Z,1406593268.310 [UniversalFixResidualReporter] Loaded
2014-07-29T00:21:08.310Z,1406593268.310 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2014-07-29T00:21:08.311Z,1406593268.311 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2014-07-29T00:21:08.311Z,1406593268.311 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2014-07-29T00:21:08.325Z,1406593268.325 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2014-07-29T00:21:08.325Z,1406593268.325 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2014-07-29T00:21:08.537Z,1406593268.537 [CTD_NeilBrown] Loaded
2014-07-29T00:21:08.537Z,1406593268.537 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2014-07-29T00:21:08.540Z,1406593268.540 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407B94E0
2014-07-29T00:21:08.540Z,1406593268.540 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 862
2014-07-29T00:21:08.555Z,1406593268.555 [PAR_Licor] Loaded
2014-07-29T00:21:08.555Z,1406593268.555 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2014-07-29T00:21:08.595Z,1406593268.595 [WetLabsBB2FL] Loaded
2014-07-29T00:21:08.595Z,1406593268.595 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2014-07-29T00:21:08.600Z,1406593268.600 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407E94E0
2014-07-29T00:21:08.600Z,1406593268.600 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 863
2014-07-29T00:21:08.600Z,1406593268.600 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2014-07-29T00:21:08.601Z,1406593268.601 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2014-07-29T00:21:09.165Z,1406593269.165 [AHRS_sp3003D] Loaded
2014-07-29T00:21:09.166Z,1406593269.166 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread.
2014-07-29T00:21:09.453Z,1406593269.453 [Batt_Ocean_Server] Loaded
2014-07-29T00:21:09.454Z,1406593269.454 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread.
2014-07-29T00:21:09.634Z,1406593269.634 [DataOverHttps] Loaded
2014-07-29T00:21:09.634Z,1406593269.634 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2014-07-29T00:21:09.648Z,1406593269.648 [Depth_Keller] Loaded
2014-07-29T00:21:09.648Z,1406593269.648 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2014-07-29T00:21:09.653Z,1406593269.653 [DropWeight] Loaded
2014-07-29T00:21:09.654Z,1406593269.654 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2014-07-29T00:21:09.797Z,1406593269.797 [DVL_micro] Loaded
2014-07-29T00:21:09.798Z,1406593269.798 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2014-07-29T00:21:09.903Z,1406593269.903 [NAL9602] Loaded
2014-07-29T00:21:09.904Z,1406593269.904 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2014-07-29T00:21:09.950Z,1406593269.950 [Onboard] Loaded
2014-07-29T00:21:09.950Z,1406593269.950 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2014-07-29T00:21:09.957Z,1406593269.957 [Radio_Freewave] Loaded
2014-07-29T00:21:09.957Z,1406593269.957 [ComponentRegistry](DEBUG): Component "Radio_Freewave" handled in its own thread.
2014-07-29T00:21:09.962Z,1406593269.962 [Radio_Freewave ThreadHandler](DEBUG): Created PCaller Thread at 40A1B4E0
2014-07-29T00:21:09.962Z,1406593269.962 [Radio_Freewave ThreadHandler](INFO): Protected caller Thread ID is 864
2014-07-29T00:21:09.969Z,1406593269.969 [SCPI] Loaded
2014-07-29T00:21:09.969Z,1406593269.969 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread.
2014-07-29T00:21:09.970Z,1406593269.970 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2014-07-29T00:21:09.971Z,1406593269.971 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2014-07-29T00:21:10.106Z,1406593270.106 [BuoyancyServo] Loaded
2014-07-29T00:21:10.106Z,1406593270.106 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2014-07-29T00:21:10.119Z,1406593270.119 [ElevatorServo] Loaded
2014-07-29T00:21:10.119Z,1406593270.119 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2014-07-29T00:21:10.130Z,1406593270.130 [MassServo] Loaded
2014-07-29T00:21:10.131Z,1406593270.131 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2014-07-29T00:21:10.142Z,1406593270.142 [RudderServo] Loaded
2014-07-29T00:21:10.143Z,1406593270.143 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2014-07-29T00:21:10.158Z,1406593270.158 [ThrusterServo] Loaded
2014-07-29T00:21:10.159Z,1406593270.159 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2014-07-29T00:21:10.159Z,1406593270.159 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2014-07-29T00:21:10.160Z,1406593270.160 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2014-07-29T00:21:10.445Z,1406593270.445 [ExternalSim] Loaded
2014-07-29T00:21:10.446Z,1406593270.446 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread.
2014-07-29T00:21:10.502Z,1406593270.502 [InternalSim] Loaded
2014-07-29T00:21:10.502Z,1406593270.502 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2014-07-29T00:21:10.507Z,1406593270.507 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2014-07-29T00:21:10.508Z,1406593270.508 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2014-07-29T00:21:10.554Z,1406593270.554 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2014-07-29T00:21:10.556Z,1406593270.556 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2014-07-29T00:21:10.557Z,1406593270.557 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2014-07-29T00:21:10.563Z,1406593270.563 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2014-07-29T00:21:10.567Z,1406593270.567 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ACC4E0
2014-07-29T00:21:10.567Z,1406593270.567 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 865
2014-07-29T00:21:10.572Z,1406593270.572 [Supervisor](INFO): Main Thread ID is 773
2014-07-29T00:21:10.572Z,1406593270.572 [Supervisor](DEBUG): Running supervisor.
2014-07-29T00:21:10.573Z,1406593270.573 [CommandLine ThreadHandler](INFO): Handler Thread ID is 866
2014-07-29T00:21:10.579Z,1406593270.579 [controlThread ThreadHandler](INFO): Handler Thread ID is 867
2014-07-29T00:21:10.580Z,1406593270.580 [controlThread](DEBUG): Initializing ControlThread
2014-07-29T00:21:10.580Z,1406593270.580 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2014-07-29T00:21:10.582Z,1406593270.582 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2014-07-29T00:21:10.583Z,1406593270.583 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2014-07-29T00:21:10.584Z,1406593270.584 [LoopControl](DEBUG): Initialize LoopControlComponent.
2014-07-29T00:21:10.584Z,1406593270.584 [SBIT](INFO): Initialize SBIT Component.
2014-07-29T00:21:10.584Z,1406593270.584 [SBIT](IMPORTANT): Tethys CM Info: SVN revision: 11424
2014-07-29T00:21:10.585Z,1406593270.585 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2014-07-29T00:21:10.585Z,1406593270.585 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014
2014-07-29T00:21:10.586Z,1406593270.586 [IBIT](INFO): Initialize IBIT Component.
2014-07-29T00:21:10.587Z,1406593270.587 [CBIT](DEBUG): Initialize CBIT Component.
2014-07-29T00:21:10.587Z,1406593270.587 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2014-07-29T00:21:10.591Z,1406593270.591 [logger ThreadHandler](INFO): Handler Thread ID is 868
2014-07-29T00:21:10.611Z,1406593270.611 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-07-29T00:21:10.611Z,1406593270.611 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2014-07-29T00:21:10.612Z,1406593270.612 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2014-07-29T00:21:10.612Z,1406593270.612 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2014-07-29T00:21:10.613Z,1406593270.613 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2014-07-29T00:21:10.623Z,1406593270.623 [HFRadarCompactModelForecaster](DEBUG): Found new ECs!
2014-07-29T00:21:10.628Z,1406593270.628 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 869
2014-07-29T00:21:10.631Z,1406593270.631 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2014-07-29T00:21:10.635Z,1406593270.635 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2014-07-29T00:21:10.659Z,1406593270.659 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 871
2014-07-29T00:21:10.661Z,1406593270.661 [WetLabsBB2FL](INFO): Powering down
2014-07-29T00:21:10.686Z,1406593270.686 [Radio_Freewave ThreadHandler](INFO): Handler Thread ID is 872
2014-07-29T00:21:10.702Z,1406593270.702 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 873
2014-07-29T00:21:10.717Z,1406593270.717 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources
2014-07-29T00:21:10.718Z,1406593270.718 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2014-07-29T00:21:10.718Z,1406593270.718 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2014-07-29T00:21:10.718Z,1406593270.718 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2014-07-29T00:21:10.718Z,1406593270.718 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2014-07-29T00:21:10.719Z,1406593270.719 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2014-07-29T00:21:10.719Z,1406593270.719 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2014-07-29T00:21:10.719Z,1406593270.719 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2014-07-29T00:21:10.720Z,1406593270.720 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2014-07-29T00:21:20.195Z,1406593280.195 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201407282100: published 50 modes in rows, 61 hours in columns
2014-07-29T00:21:20.218Z,1406593280.218 [HFRadarCompactModelForecaster](IMPORTANT): expansionCoefficients_[0][48] = 9.046450 for 2014-07-28T21:00:00.000Z
2014-07-29T00:21:20.219Z,1406593280.219 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0.
2014-07-29T00:21:20.220Z,1406593280.220 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component.
2014-07-29T00:21:20.221Z,1406593280.221 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s.
2014-07-29T00:21:20.230Z,1406593280.230 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component.
2014-07-29T00:21:20.230Z,1406593280.230 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component.
2014-07-29T00:21:20.231Z,1406593280.231 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-07-29T00:21:20.231Z,1406593280.231 [DeadReckonWithRespectToWater](DEBUG): Initializing DeadReckonWithRespectToWater component.
2014-07-29T00:21:20.231Z,1406593280.231 [DeadReckonWithRespectToSeafloor](DEBUG): Initializing DeadReckonWithRespectToSeafloor component.
2014-07-29T00:21:20.232Z,1406593280.232 [DeadReckonUsingDVLWaterTrack](DEBUG): Initializing DeadReckonUsingDVLWaterTrack component.
2014-07-29T00:21:20.232Z,1406593280.232 [DeadReckonUsingCompactModelForecast](DEBUG): Initializing DeadReckonUsingCompactModelForecast component.
2014-07-29T00:21:20.233Z,1406593280.233 [NavChart](DEBUG): Initialize NavChart Navigation.
2014-07-29T00:21:20.233Z,1406593280.233 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2014-07-29T00:21:21.723Z,1406593281.723 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized
2014-07-29T00:21:21.756Z,1406593281.756 [ExternalSim](INFO): ExternalSim initializing...
2014-07-29T00:21:21.926Z,1406593281.926 [ExternalSim](DEBUG): beaconLat = 36.81340
2014-07-29T00:21:21.926Z,1406593281.926 [ExternalSim](DEBUG): beaconLon = -121.82240
2014-07-29T00:21:21.926Z,1406593281.926 [ExternalSim](DEBUG): beaconDepth = 25.00
2014-07-29T00:21:22.185Z,1406593282.185 [ExternalSim](DEBUG): Simulator initialized
2014-07-29T00:21:22.360Z,1406593282.360 [InternalSim](DEBUG):  InternalSim initializing...
2014-07-29T00:21:22.475Z,1406593282.475 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2014-07-29T00:21:22.514Z,1406593282.514 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2014-07-29T00:21:22.539Z,1406593282.539 [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-07-29T00:21:22.540Z,1406593282.540 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2014-07-29T00:21:22.612Z,1406593282.612 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool
2014-07-29T00:21:22.621Z,1406593282.621 [Default:GPS:A.SetSpeed](DEBUG): Construct.
2014-07-29T00:21:22.624Z,1406593282.624 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-07-29T00:21:22.656Z,1406593282.656 [Default:Iridium:A.SetSpeed](DEBUG): Construct.
2014-07-29T00:21:22.679Z,1406593282.679 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface.
2014-07-29T00:21:22.702Z,1406593282.702 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2014-07-29T00:21:22.768Z,1406593282.768 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct.
2014-07-29T00:21:22.799Z,1406593282.799 [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>
            <Progression/>
        </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>
            <Progression/>
        </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>

    </Aggregate>

</Mission>


2014-07-29T00:21:22.811Z,1406593282.811 [controlThread](DEBUG): Component order: CycleStarter,ExternalSim,InternalSim,PAR_Licor,AHRS_sp3003D,Batt_Ocean_Server,DataOverHttps,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,SCPI,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarModelCalc,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,HFRCMReconstructedInterpolator,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-07-29T00:21:23.006Z,1406593283.006 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D.
2014-07-29T00:21:23.050Z,1406593283.050 [Radio_Freewave](INFO): Powering up
2014-07-29T00:21:23.198Z,1406593283.198 [DVL_micro](INFO): Initializing
2014-07-29T00:21:23.857Z,1406593283.857 [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-07-29T00:21:31.222Z,1406593291.222 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2014-07-29T00:21:31.242Z,1406593291.242 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2014-07-29T00:21:31.253Z,1406593291.253 [ElevatorServo](DEBUG): Initializing EZServoServo.
2014-07-29T00:21:31.259Z,1406593291.259 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2014-07-29T00:21:31.265Z,1406593291.265 [MassServo](DEBUG): Initializing EZServoServo.
2014-07-29T00:21:31.270Z,1406593291.270 [MassServo](DEBUG): Initializing MassServo.
2014-07-29T00:21:31.300Z,1406593291.300 [RudderServo](DEBUG): Initializing EZServoServo.
2014-07-29T00:21:31.307Z,1406593291.307 [RudderServo](DEBUG): Initializing RudderServo.
2014-07-29T00:21:31.313Z,1406593291.313 [ThrusterServo](DEBUG): Initializing EZServoServo.
2014-07-29T00:21:31.319Z,1406593291.319 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2014-07-29T00:21:32.401Z,1406593292.401 [SBIT](IMPORTANT): Beginning Startup BIT
2014-07-29T00:21:32.404Z,1406593292.404 [CBIT](IMPORTANT): Beginning GF scan
2014-07-29T00:21:35.637Z,1406593295.637 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.007612
2014-07-29T00:21:38.074Z,1406593298.074 [NAL9602](IMPORTANT): GPS fix at: 1406593298.00
2014-07-29T00:21:44.949Z,1406593304.949 [NAL9602](INFO): Powering down
2014-07-29T00:21:59.223Z,1406593319.223 [CBIT](IMPORTANT): No ground fault detected
2014-07-29T00:22:01.437Z,1406593321.437 [CommandLine](IMPORTANT): got command run ./Missions/Maintenance/dat_on.xml
2014-07-29T00:22:01.437Z,1406593321.437 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/dat_on.xml
2014-07-29T00:22:01.460Z,1406593321.460 [MissionManager](INFO): DefineArg dat_on.MassDefault = 0.000000 n/a
2014-07-29T00:22:01.478Z,1406593321.478 [dat_on:A.Pitch](DEBUG): Construct.
2014-07-29T00:22:01.527Z,1406593321.527 [dat_on:TestDrive:C.Wait](DEBUG): Construct Wait.
2014-07-29T00:22:01.543Z,1406593321.543 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance"
       xmlns:Sensor="Tethys/Sensor" 
       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/Sensor http://aosn.mbari.org/tethys/Xml/Sensor.xsd
                           Tethys/Units http://aosn.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://aosn.mbari.org/tethys/Xml/Universal.xsd"
       Id="dat_on">

    <DefineArg Name="MassDefault"><Control:VerticalControl.massDefault/></DefineArg>

    <Timeout Duration="P15M"/>

    <Guidance:Pitch>
        <Parallel/>
        <Setting><Guidance:Pitch.massPosition/><Arg Name="MassDefault"/></Setting>
    </Guidance:Pitch>

    <Aggregate Id="TestDrive">

        <Sequence/>

        <ReadData>
            <Sensor:DAT.range/>
        </ReadData>

        <Aggregate Id="Data">

            <When>
                <True/>
            </When>

            <SendData Service="Express">
                <Control:HorizontalControl.latitudeCmd/><Units:degree/>
                <Control:HorizontalControl.longitudeCmd/><Units:degree/>
            </SendData>

            <Syslog Severity="None">Pause a cycle</Syslog>

        </Aggregate>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>2</Value></Setting>
        </Guidance:Wait>

    </Aggregate>

</Mission>


2014-07-29T00:22:01.545Z,1406593321.545 [CommandLine](IMPORTANT): Running ./Missions/Maintenance/dat_on.xml
2014-07-29T00:22:26.314Z,1406593346.314 [SBIT](IMPORTANT): SBIT PASSED
2014-07-29T00:22:26.724Z,1406593346.724 [MissionManager](IMPORTANT): Started mission Startup
2014-07-29T00:22:26.724Z,1406593346.724 [Startup] Running Loop=1
2014-07-29T00:22:26.724Z,1406593346.724 [Startup](INFO): Aggregate::initialize Startup
2014-07-29T00:22:26.724Z,1406593346.724 [Startup:A.GoToSurface] Running Loop=1
2014-07-29T00:22:26.724Z,1406593346.724 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-07-29T00:22:26.725Z,1406593346.725 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2014-07-29T00:22:26.726Z,1406593346.726 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2014-07-29T00:22:26.726Z,1406593346.726 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2014-07-29T00:22:26.748Z,1406593346.748 [Startup:StartupSatComms] Running Loop=1
2014-07-29T00:22:26.748Z,1406593346.748 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms
2014-07-29T00:22:26.749Z,1406593346.749 [Startup:StartupSatComms:A] Running Loop=1
2014-07-29T00:22:27.193Z,1406593347.193 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-07-29T00:22:27.648Z,1406593347.648 [NAL9602](INFO): Powering up
2014-07-29T00:22:30.842Z,1406593350.842 [CommandLine](IMPORTANT): got command show variable DAT
2014-07-29T00:22:30.848Z,1406593350.848 [CommandLine](IMPORTANT): HorizontalControl.loadAtStartup (bool)
2014-07-29T00:22:30.849Z,1406593350.849 [CommandLine](IMPORTANT): LoopControl.loadAtStartup (bool)
2014-07-29T00:22:30.849Z,1406593350.849 [CommandLine](IMPORTANT): SpeedControl.loadAtStartup (bool)
2014-07-29T00:22:30.849Z,1406593350.849 [CommandLine](IMPORTANT): VerticalControl.loadAtStartup (bool)
2014-07-29T00:22:30.861Z,1406593350.861 [CommandLine](IMPORTANT): CBIT.loadAtStartup (bool)
2014-07-29T00:22:30.862Z,1406593350.862 [CommandLine](IMPORTANT): SBIT.loadAtStartup (bool)
2014-07-29T00:22:30.862Z,1406593350.862 [CommandLine](IMPORTANT): IBIT.loadAtStartup (bool)
2014-07-29T00:22:30.862Z,1406593350.862 [CommandLine](IMPORTANT): DepthRateCalculator.loadAtStartup (bool)
2014-07-29T00:22:30.871Z,1406593350.871 [CommandLine](IMPORTANT): TempGradientCalculator.loadAtStartup (bool)
2014-07-29T00:22:30.872Z,1406593350.872 [CommandLine](IMPORTANT): PitchRateCalculator.loadAtStartup (bool)
2014-07-29T00:22:30.872Z,1406593350.872 [CommandLine](IMPORTANT): SpeedCalculator.loadAtStartup (bool)
2014-07-29T00:22:30.873Z,1406593350.873 [CommandLine](IMPORTANT): YawRateCalculator.loadAtStartup (bool)
2014-07-29T00:22:30.873Z,1406593350.873 [CommandLine](IMPORTANT): HFRadarModelCalc.loadAtStartup (bool)
2014-07-29T00:22:30.874Z,1406593350.874 [CommandLine](IMPORTANT): HFRadarCompactModelForecaster.loadAtStartup (bool)
2014-07-29T00:22:30.874Z,1406593350.874 [CommandLine](IMPORTANT): HFRCMSpaceInterpolator.loadAtStartup (bool)
2014-07-29T00:22:30.875Z,1406593350.875 [CommandLine](IMPORTANT): HFRCMTimeInterpolator.loadAtStartup (bool)
2014-07-29T00:22:30.884Z,1406593350.884 [CommandLine](IMPORTANT): HFRCMReconstructedInterpolator.loadAtStartup (bool)
2014-07-29T00:22:30.884Z,1406593350.884 [CommandLine](IMPORTANT): HFRCMSurfaceCurrentAtVehicleLocation.loadAtStartup (bool)
2014-07-29T00:22:30.885Z,1406593350.885 [CommandLine](IMPORTANT): HFRCMVirtualSurfaceDrifter.loadAtStartup (bool)
2014-07-29T00:22:30.885Z,1406593350.885 [CommandLine](IMPORTANT): DeadReckonUsingMultipleVelocitySources.loadAtStartup (bool)
2014-07-29T00:22:30.886Z,1406593350.886 [CommandLine](IMPORTANT): DeadReckonWithRespectToWater.loadAtStartup (bool)
2014-07-29T00:22:30.886Z,1406593350.886 [CommandLine](IMPORTANT): DeadReckonWithRespectToSeafloor.loadAtStartup (bool)
2014-07-29T00:22:30.899Z,1406593350.899 [CommandLine](IMPORTANT): DeadReckonUsingDVLWaterTrack.loadAtStartup (bool)
2014-07-29T00:22:30.900Z,1406593350.900 [CommandLine](IMPORTANT): DeadReckonUsingCompactModelForecast.loadAtStartup (bool)
2014-07-29T00:22:30.901Z,1406593350.901 [CommandLine](IMPORTANT): NavChart.loadAtStartup (bool)
2014-07-29T00:22:30.903Z,1406593350.903 [CommandLine](IMPORTANT): UniversalFixResidualReporter.loadAtStartup (bool)
2014-07-29T00:22:30.912Z,1406593350.912 [CommandLine](IMPORTANT): AsyncPiEstimator.loadAtStartup (bool)
2014-07-29T00:22:30.912Z,1406593350.912 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup (bool)
2014-07-29T00:22:30.913Z,1406593350.913 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup (bool)
2014-07-29T00:22:30.913Z,1406593350.913 [CommandLine](IMPORTANT): ISUS.loadAtStartup (bool)
2014-07-29T00:22:30.914Z,1406593350.914 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup (bool)
2014-07-29T00:22:30.915Z,1406593350.915 [CommandLine](IMPORTANT): Turbulence_NPS.loadAtStartup (bool)
2014-07-29T00:22:30.927Z,1406593350.927 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup (bool)
2014-07-29T00:22:30.928Z,1406593350.928 [CommandLine](IMPORTANT): AHRS_3DMGX3.loadAtStartup (bool)
2014-07-29T00:22:30.929Z,1406593350.929 [CommandLine](IMPORTANT): AHRS_sp3003D.loadAtStartup (bool)
2014-07-29T00:22:30.929Z,1406593350.930 [CommandLine](IMPORTANT): Batt_Ocean_Server.loadAtStartup (bool)
2014-07-29T00:22:30.930Z,1406593350.930 [CommandLine](IMPORTANT): DataOverHttps.loadAtStartup (bool)
2014-07-29T00:22:30.930Z,1406593350.930 [CommandLine](IMPORTANT): DataOverHttps.power (watt)
2014-07-29T00:22:30.931Z,1406593350.931 [CommandLine](IMPORTANT): DataOverHttps.connectionTimeout (second)
2014-07-29T00:22:30.938Z,1406593350.938 [CommandLine](IMPORTANT): DataOverHttps.period (second)
2014-07-29T00:22:30.939Z,1406593350.939 [CommandLine](IMPORTANT): DataOverHttps.timeout (minute)
2014-07-29T00:22:30.943Z,1406593350.943 [CommandLine](IMPORTANT): DataOverHttps.verbosity (count)
2014-07-29T00:22:30.944Z,1406593350.944 [CommandLine](IMPORTANT): DAT.loadAtStartup (bool)
2014-07-29T00:22:30.944Z,1406593350.944 [CommandLine](IMPORTANT): DAT.simulateHardware (bool)
2014-07-29T00:22:30.945Z,1406593350.945 [CommandLine](IMPORTANT): Depth_Keller.loadAtStartup (bool)
2014-07-29T00:22:30.945Z,1406593350.945 [CommandLine](IMPORTANT): DropWeight.loadAtStartup (bool)
2014-07-29T00:22:30.946Z,1406593350.946 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup (bool)
2014-07-29T00:22:30.946Z,1406593350.946 [CommandLine](IMPORTANT): NAL9602.loadAtStartup (bool)
2014-07-29T00:22:30.947Z,1406593350.947 [CommandLine](IMPORTANT): Onboard.loadAtStartup (bool)
2014-07-29T00:22:30.964Z,1406593350.964 [CommandLine](IMPORTANT): PNI_TCM.loadAtStartup (bool)
2014-07-29T00:22:30.965Z,1406593350.965 [CommandLine](IMPORTANT): Radio_CDMA.loadAtStartup (bool)
2014-07-29T00:22:30.965Z,1406593350.965 [CommandLine](IMPORTANT): Radio_Freewave.loadAtStartup (bool)
2014-07-29T00:22:30.966Z,1406593350.966 [CommandLine](IMPORTANT): Rowe_600.loadAtStartup (bool)
2014-07-29T00:22:30.967Z,1406593350.967 [CommandLine](IMPORTANT): SCPI.loadAtStartup (bool)
2014-07-29T00:22:30.980Z,1406593350.980 [CommandLine](IMPORTANT): BuoyancyServo.loadAtStartup (bool)
2014-07-29T00:22:30.981Z,1406593350.981 [CommandLine](IMPORTANT): ElevatorServo.loadAtStartup (bool)
2014-07-29T00:22:30.981Z,1406593350.981 [CommandLine](IMPORTANT): MassServo.loadAtStartup (bool)
2014-07-29T00:22:30.982Z,1406593350.982 [CommandLine](IMPORTANT): RudderServo.loadAtStartup (bool)
2014-07-29T00:22:30.984Z,1406593350.984 [CommandLine](IMPORTANT): ThrusterServo.loadAtStartup (bool)
2014-07-29T00:22:30.984Z,1406593350.984 [CommandLine](IMPORTANT): ExternalSim.loadAtStartup (bool)
2014-07-29T00:22:30.985Z,1406593350.985 [CommandLine](IMPORTANT): InternalSim.loadAtStartup (bool)
2014-07-29T00:22:30.985Z,1406593350.985 [CommandLine](IMPORTANT): NavigationSim.loadAtStartup (bool)
2014-07-29T00:22:31.002Z,1406593351.002 [CommandLine](IMPORTANT): Config/Simulator.oceanModelData (none)
2014-07-29T00:22:31.015Z,1406593351.015 [CommandLine](IMPORTANT): Vehicle.sendDataToShore (bool)
2014-07-29T00:22:31.033Z,1406593351.033 [CommandLine](IMPORTANT): DAT.loadControl (none)
2014-07-29T00:22:31.033Z,1406593351.033 [CommandLine](IMPORTANT): DAT.uart (none)
2014-07-29T00:22:31.033Z,1406593351.033 [CommandLine](IMPORTANT): DAT.baud (bit_per_second)
2014-07-29T00:22:31.094Z,1406593351.094 [CommandLine](IMPORTANT): DataOverHttps.platform_communications (bool)
2014-07-29T00:22:31.114Z,1406593351.114 [CommandLine](IMPORTANT): DataOverHttps.durationOfLastRun (second)
2014-07-29T00:22:31.118Z,1406593351.118 [CommandLine](IMPORTANT): dat_on.MassDefault (none)
2014-07-29T00:22:33.210Z,1406593353.210 [NAL9602](IMPORTANT): GPS fix at: 1406593353.20
2014-07-29T00:22:33.273Z,1406593353.273 [Startup:StartupSatComms:A] Stopped
2014-07-29T00:22:33.273Z,1406593353.273 [Startup:StartupSatComms:B] Running Loop=1
2014-07-29T00:22:33.728Z,1406593353.728 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-07-29T00:22:36.366Z,1406593356.366 [Depth_Keller](ERROR): Pressure reading out of range: 1830.489868 decibar
2014-07-29T00:22:36.887Z,1406593356.887 [Radio_Freewave](INFO): Powering down
2014-07-29T00:22:37.947Z,1406593357.947 [Radio_Freewave](INFO): Powering up
2014-07-29T00:22:38.757Z,1406593358.757 [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-07-29T00:22:39.306Z,1406593359.306 [DataOverHttps](INFO): Sending 293 bytes from file Logs/20140729T002048/Courier0000.lzma
2014-07-29T00:22:40.544Z,1406593360.544 [DataOverHttps](INFO): Moved sent file to Logs/20140729T002048/Courier0000.lzma.bak
2014-07-29T00:22:40.544Z,1406593360.544 [DataOverHttps](INFO): SBD MOMSN=1049823
2014-07-29T00:22:43.638Z,1406593363.638 [NAL9602](INFO): Powering down
2014-07-29T00:22:52.396Z,1406593372.396 [DataOverHttps](INFO): Sending 2048 bytes from file Logs/20140729T002048/Express0001.lzma
2014-07-29T00:22:53.294Z,1406593373.294 [DataOverHttps](INFO): Moved sent file to Logs/20140729T002048/Express0001.lzma.bak
2014-07-29T00:22:53.294Z,1406593373.294 [DataOverHttps](INFO): SBD MOMSN=1049826
2014-07-29T00:22:59.609Z,1406593379.609 [HFRadarModelCalc](IMPORTANT): Forecast time 20140728T210000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-07-29T00:22:59.612Z,1406593379.612 [HFRadarModelCalc](IMPORTANT): expansionCoefficients_[0][48] = 9.046450 for 2014-07-28T21:00:00.000Z
2014-07-29T00:23:00.364Z,1406593380.364 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-07-29T00:23:00.382Z,1406593380.382 [Startup:StartupSatComms:B] Stopped
2014-07-29T00:23:00.383Z,1406593380.383 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2014-07-29T00:23:00.383Z,1406593380.383 [Startup:StartupSatComms] Stopped
2014-07-29T00:23:00.383Z,1406593380.383 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms
2014-07-29T00:23:00.384Z,1406593380.384 [Startup](INFO): Completed Startup
2014-07-29T00:23:00.384Z,1406593380.384 [Startup] Stopped
2014-07-29T00:23:00.384Z,1406593380.384 [Startup](INFO): Aggregate::uninitialize Startup
2014-07-29T00:23:00.384Z,1406593380.384 [Startup:A.GoToSurface] Stopped
2014-07-29T00:23:00.384Z,1406593380.384 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-07-29T00:23:01.115Z,1406593381.115 [MissionManager](IMPORTANT): Started mission dat_on
2014-07-29T00:23:01.115Z,1406593381.115 [dat_on] Running Loop=1
2014-07-29T00:23:01.115Z,1406593381.115 [dat_on](INFO): Aggregate::initialize dat_on
2014-07-29T00:23:01.115Z,1406593381.115 [dat_on:A.Pitch] Running Loop=1
2014-07-29T00:23:01.115Z,1406593381.115 [dat_on:A.Pitch](DEBUG): Initialize.
2014-07-29T00:23:01.116Z,1406593381.116 [dat_on:TestDrive] Running Loop=1
2014-07-29T00:23:01.116Z,1406593381.116 [dat_on:TestDrive](INFO): Aggregate::initialize dat_on:TestDrive
2014-07-29T00:23:01.116Z,1406593381.116 [dat_on:TestDrive:A] Running Loop=1
2014-07-29T00:23:01.116Z,1406593381.116 [dat_on:TestDrive:C.Wait] Running Loop=1
2014-07-29T00:23:01.116Z,1406593381.116 [dat_on:TestDrive:C.Wait](DEBUG): Initialize Wait Component.
2014-07-29T00:23:01.122Z,1406593381.122 [dat_on:TestDrive:Data] Running Loop=1
2014-07-29T00:23:01.122Z,1406593381.122 [dat_on:TestDrive:Data](INFO): Aggregate::initialize dat_on:TestDrive:Data
2014-07-29T00:23:01.138Z,1406593381.138 [dat_on:TestDrive:Data:A] Running Loop=1
2014-07-29T00:23:01.143Z,1406593381.143 [dat_on:TestDrive:Data:A] Stopped
2014-07-29T00:23:01.143Z,1406593381.143 [dat_on:TestDrive:Data:B] Running Loop=1
2014-07-29T00:23:01.143Z,1406593381.143 [dat_on:TestDrive:A] Running Loop=1
2014-07-29T00:23:01.143Z,1406593381.143 [dat_on:TestDrive:A](CRITICAL): Unable to read non-existent URI:DAT.range
2014-07-29T00:23:01.144Z,1406593381.144 [dat_on:TestDrive:A](CRITICAL): Unable to read non-existent data element: DAT.range
2014-07-29T00:23:01.145Z,1406593381.145 [dat_on:A.Pitch] Running Loop=1
2014-07-29T00:23:01.182Z,1406593381.182 [CommandLine](FAULT): Scheduling is paused
2014-07-29T00:23:02.135Z,1406593382.135 [dat_on:TestDrive:Data:B] Stopped
2014-07-29T00:23:02.135Z,1406593382.135 [dat_on:TestDrive:Data](INFO): Completed dat_on:TestDrive:Data
2014-07-29T00:23:02.135Z,1406593382.135 [dat_on:TestDrive:Data] Stopped
2014-07-29T00:23:02.135Z,1406593382.135 [dat_on:TestDrive:Data](INFO): Aggregate::uninitialize dat_on:TestDrive:Data
2014-07-29T00:23:02.135Z,1406593382.135 [dat_on:TestDrive:A](CRITICAL): Unable to read non-existent URI:DAT.range
2014-07-29T00:23:02.136Z,1406593382.136 [dat_on:TestDrive:A](CRITICAL): Unable to read non-existent data element: DAT.range
2014-07-29T00:23:02.136Z,1406593382.136 [dat_on] Stopped
2014-07-29T00:23:02.136Z,1406593382.136 [dat_on](INFO): Aggregate::uninitialize dat_on
2014-07-29T00:23:02.136Z,1406593382.136 [dat_on:A.Pitch] Stopped
2014-07-29T00:23:02.136Z,1406593382.136 [dat_on:TestDrive] Stopped
2014-07-29T00:23:02.137Z,1406593382.137 [dat_on:TestDrive](INFO): Aggregate::uninitialize dat_on:TestDrive
2014-07-29T00:23:02.137Z,1406593382.137 [dat_on:TestDrive:A] Stopped
2014-07-29T00:23:02.137Z,1406593382.137 [dat_on:TestDrive:C.Wait] Stopped
2014-07-29T00:23:02.137Z,1406593382.137 [dat_on:TestDrive:C.Wait](DEBUG): Uninitialize Wait Component.
2014-07-29T00:23:02.736Z,1406593382.736 [MissionManager](IMPORTANT): Started mission Default
2014-07-29T00:23:02.736Z,1406593382.736 [Default] Running Loop=1
2014-07-29T00:23:02.736Z,1406593382.736 [Default](INFO): Aggregate::initialize Default
2014-07-29T00:23:02.736Z,1406593382.736 [Default:Iridium] Running Loop=1
2014-07-29T00:23:02.741Z,1406593382.741 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium
2014-07-29T00:23:02.741Z,1406593382.741 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-07-29T00:23:02.741Z,1406593382.741 [Default:Iridium:A.SetSpeed](DEBUG): Initialize.
2014-07-29T00:23:02.741Z,1406593382.741 [Default:Iridium:B.GoToSurface] Running Loop=1
2014-07-29T00:23:02.741Z,1406593382.741 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-07-29T00:23:02.741Z,1406593382.741 [Default:Iridium:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2014-07-29T00:23:02.742Z,1406593382.742 [Default:Iridium:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2014-07-29T00:23:02.742Z,1406593382.742 [Default:Iridium:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2014-07-29T00:23:02.757Z,1406593382.757 [Default:Iridium:Read_Iridium] Running Loop=1
2014-07-29T00:23:02.757Z,1406593382.757 [Default:Iridium:A.SetSpeed] Running Loop=1
2014-07-29T00:23:02.787Z,1406593382.787 [Default:GPS] Running Loop=1
2014-07-29T00:23:02.787Z,1406593382.787 [Default:GPS](INFO): Aggregate::initialize Default:GPS
2014-07-29T00:23:02.787Z,1406593382.787 [Default:GPS:A.SetSpeed] Running Loop=1
2014-07-29T00:23:02.787Z,1406593382.787 [Default:GPS:A.SetSpeed](DEBUG): Initialize.
2014-07-29T00:23:02.787Z,1406593382.787 [Default:GPS:B.GoToSurface] Running Loop=1
2014-07-29T00:23:02.787Z,1406593382.787 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2014-07-29T00:23:02.787Z,1406593382.787 [Default:GPS:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2014-07-29T00:23:02.788Z,1406593382.788 [Default:GPS:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2014-07-29T00:23:02.788Z,1406593382.788 [Default:GPS:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s.
2014-07-29T00:23:02.831Z,1406593382.831 [Default:GPS:Read_GPS] Running Loop=1
2014-07-29T00:23:02.831Z,1406593382.831 [Default:GPS:A.SetSpeed] Running Loop=1
2014-07-29T00:23:03.460Z,1406593383.460 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2014-07-29T00:23:03.464Z,1406593383.464 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2014-07-29T00:23:05.431Z,1406593385.431 [NAL9602](INFO): Powering up
2014-07-29T00:23:07.865Z,1406593387.865 [DataOverHttps](INFO): Sending 156 bytes from file Logs/20140729T002048/Courier0004.lzma
2014-07-29T00:23:08.770Z,1406593388.770 [DataOverHttps](INFO): Moved sent file to Logs/20140729T002048/Courier0004.lzma.bak
2014-07-29T00:23:08.770Z,1406593388.770 [DataOverHttps](INFO): SBD MOMSN=1049915
2014-07-29T00:23:11.878Z,1406593391.878 [NAL9602](IMPORTANT): GPS fix at: 1406593391.87
2014-07-29T00:23:11.959Z,1406593391.959 [Default:GPS:Read_GPS] Stopped
2014-07-29T00:23:11.959Z,1406593391.959 [Default:GPS:D] Running Loop=1
2014-07-29T00:23:12.868Z,1406593392.868 [Default:GPS:D] Stopped
2014-07-29T00:23:12.869Z,1406593392.869 [Default:GPS](INFO): Completed Default:GPS
2014-07-29T00:23:12.869Z,1406593392.869 [Default:GPS] Stopped
2014-07-29T00:23:12.869Z,1406593392.869 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS
2014-07-29T00:23:12.869Z,1406593392.869 [Default:GPS:A.SetSpeed] Stopped
2014-07-29T00:23:12.869Z,1406593392.869 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize.
2014-07-29T00:23:12.869Z,1406593392.869 [Default:GPS:B.GoToSurface] Stopped
2014-07-29T00:23:12.869Z,1406593392.869 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-07-29T00:23:18.431Z,1406593398.431 [NAL9602](INFO): Powering down
2014-07-29T00:23:23.038Z,1406593403.038 [DataOverHttps](INFO): Sending 710 bytes from file Logs/20140729T002048/Express0005.lzma
2014-07-29T00:23:23.934Z,1406593403.934 [DataOverHttps](INFO): Moved sent file to Logs/20140729T002048/Express0005.lzma.bak
2014-07-29T00:23:23.934Z,1406593403.934 [DataOverHttps](INFO): SBD MOMSN=1049921
2014-07-29T00:23:29.547Z,1406593409.547 [HFRadarModelCalc](IMPORTANT): Forecast time 20140728T210000: published 50 modes in rows, 61 hours in columns, 3050 elements.
2014-07-29T00:23:29.550Z,1406593409.550 [HFRadarModelCalc](IMPORTANT): expansionCoefficients_[0][48] = 9.046450 for 2014-07-28T21:00:00.000Z
2014-07-29T00:23:30.346Z,1406593410.346 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients.
2014-07-29T00:23:30.365Z,1406593410.365 [Default:Iridium:Read_Iridium] Stopped
2014-07-29T00:23:30.366Z,1406593410.366 [Default:Iridium](INFO): Completed Default:Iridium
2014-07-29T00:23:30.366Z,1406593410.366 [Default:Iridium] Stopped
2014-07-29T00:23:30.366Z,1406593410.366 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium
2014-07-29T00:23:30.367Z,1406593410.367 [Default:Iridium:A.SetSpeed] Stopped
2014-07-29T00:23:30.367Z,1406593410.367 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.
2014-07-29T00:23:30.367Z,1406593410.367 [Default:Iridium:B.GoToSurface] Stopped
2014-07-29T00:23:30.367Z,1406593410.367 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2014-07-29T00:23:30.367Z,1406593410.367 [Default:WaitAtTheSurface] Running Loop=1
2014-07-29T00:23:30.367Z,1406593410.367 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface
2014-07-29T00:23:30.367Z,1406593410.367 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-07-29T00:23:30.367Z,1406593410.367 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize.
2014-07-29T00:23:31.109Z,1406593411.109 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1
2014-07-29T00:23:48.051Z,1406593428.051 [CommandLine](IMPORTANT): got command restart application
2014-07-29T00:23:49.060Z,1406593429.060 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2014-07-29T00:23:49.061Z,1406593429.061 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:49.152Z,1406593429.152 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2014-07-29T00:23:49.152Z,1406593429.152 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:49.153Z,1406593429.153 [CommandLine](INFO): Join timeout helper Thread ID is 915
2014-07-29T00:23:49.159Z,1406593429.159 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2014-07-29T00:23:49.159Z,1406593429.159 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:49.159Z,1406593429.159 [NavChartDb](INFO): Join timeout helper Thread ID is 916
2014-07-29T00:23:49.309Z,1406593429.309 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2014-07-29T00:23:49.309Z,1406593429.309 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:49.317Z,1406593429.317 [ComponentRegistry](INFO): Shutting down Radio_Freewave ThreadHandler
2014-07-29T00:23:49.317Z,1406593429.317 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:49.317Z,1406593429.317 [Radio_Freewave](INFO): Join timeout helper Thread ID is 917
2014-07-29T00:23:49.690Z,1406593429.690 [Radio_Freewave ThreadHandler](INFO): Uninitializing protected caller thread.
2014-07-29T00:23:49.782Z,1406593429.782 [Radio_Freewave](INFO): Powering down
2014-07-29T00:23:50.187Z,1406593430.187 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:50.202Z,1406593430.202 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2014-07-29T00:23:50.202Z,1406593430.202 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:50.203Z,1406593430.203 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 919
2014-07-29T00:23:50.227Z,1406593430.227 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2014-07-29T00:23:50.227Z,1406593430.227 [WetLabsBB2FL](INFO): Powering down
2014-07-29T00:23:50.228Z,1406593430.228 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:50.246Z,1406593430.246 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2014-07-29T00:23:50.246Z,1406593430.246 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:50.247Z,1406593430.247 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 920
2014-07-29T00:23:50.347Z,1406593430.347 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2014-07-29T00:23:50.347Z,1406593430.347 [CTD_NeilBrown](INFO): Powering down
2014-07-29T00:23:50.348Z,1406593430.348 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:50.367Z,1406593430.367 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2014-07-29T00:23:50.368Z,1406593430.368 [logger ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:50.368Z,1406593430.368 [logger](INFO): Join timeout helper Thread ID is 921
2014-07-29T00:23:50.415Z,1406593430.415 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2014-07-29T00:23:50.415Z,1406593430.415 [logger ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:50.423Z,1406593430.423 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2014-07-29T00:23:50.423Z,1406593430.423 [CommandLine ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:50.424Z,1406593430.424 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2014-07-29T00:23:50.424Z,1406593430.424 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:50.424Z,1406593430.424 [controlThread](INFO): Join timeout helper Thread ID is 922
2014-07-29T00:23:50.999Z,1406593430.999 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2014-07-29T00:23:50.999Z,1406593430.999 [controlThread](DEBUG): Uninitializing ControlThread
2014-07-29T00:23:51.000Z,1406593431.000 [AHRS_sp3003D](INFO): Powering down
2014-07-29T00:23:51.002Z,1406593431.002 [DVL_micro](INFO): uninitialize:Powering down
2014-07-29T00:23:51.003Z,1406593431.003 [NAL9602](INFO): Powering down
2014-07-29T00:23:51.004Z,1406593431.004 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2014-07-29T00:23:51.007Z,1406593431.007 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2014-07-29T00:23:51.007Z,1406593431.007 [Default] Stopped
2014-07-29T00:23:51.007Z,1406593431.007 [Default](INFO): Aggregate::uninitialize Default
2014-07-29T00:23:51.008Z,1406593431.008 [Default:WaitAtTheSurface] Stopped
2014-07-29T00:23:51.008Z,1406593431.008 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface
2014-07-29T00:23:51.008Z,1406593431.008 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped
2014-07-29T00:23:51.008Z,1406593431.008 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize.
2014-07-29T00:23:51.012Z,1406593431.012 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2014-07-29T00:23:51.012Z,1406593431.012 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2014-07-29T00:23:51.013Z,1406593431.013 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2014-07-29T00:23:51.013Z,1406593431.013 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2014-07-29T00:23:51.013Z,1406593431.013 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2014-07-29T00:23:51.013Z,1406593431.013 [BuoyancyServo](INFO): Powering down
2014-07-29T00:23:51.028Z,1406593431.028 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2014-07-29T00:23:51.028Z,1406593431.028 [ElevatorServo](INFO): Powering down
2014-07-29T00:23:51.029Z,1406593431.029 [MassServo](DEBUG): Uninitialize Mass Servo.
2014-07-29T00:23:51.029Z,1406593431.029 [MassServo](INFO): Powering down
2014-07-29T00:23:51.030Z,1406593431.030 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2014-07-29T00:23:51.030Z,1406593431.030 [RudderServo](INFO): Powering down
2014-07-29T00:23:51.031Z,1406593431.031 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2014-07-29T00:23:51.031Z,1406593431.031 [ThrusterServo](INFO): Powering down
2014-07-29T00:23:51.032Z,1406593431.032 [SBIT](DEBUG): Uninitialize SBIT Component.
2014-07-29T00:23:51.032Z,1406593431.032 [IBIT](DEBUG): Uninitialize IBIT Component.
2014-07-29T00:23:51.032Z,1406593431.032 [CBIT](DEBUG): Uninitialize CBIT Component.
2014-07-29T00:23:51.075Z,1406593431.075 [controlThread ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:51.144Z,1406593431.144 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:51.148Z,1406593431.148 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:51.154Z,1406593431.154 [Radio_Freewave ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:51.211Z,1406593431.211 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2014-07-29T00:23:51.261Z,1406593431.261 [logger ThreadHandler](INFO): Thread cancelled.