2014-04-25T22:34:27.876Z,1398465267.876 [Supervisor](DEBUG): Initializing supervisor. 2014-04-25T22:34:27.879Z,1398465267.879 [SyncHandler](DEBUG): Created PCaller Thread at 4033C4E0 2014-04-25T22:34:27.880Z,1398465267.880 [SyncHandler](INFO): Protected caller Thread ID is 1664 2014-04-25T22:34:27.880Z,1398465267.880 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2014-04-25T22:34:27.881Z,1398465267.881 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036C4E0 2014-04-25T22:34:27.882Z,1398465267.882 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1665 2014-04-25T22:34:27.888Z,1398465267.888 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2014-04-25T22:34:28.062Z,1398465268.062 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2014-04-25T22:34:28.064Z,1398465268.064 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039C4E0 2014-04-25T22:34:28.064Z,1398465268.064 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1666 2014-04-25T22:34:28.065Z,1398465268.065 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2014-04-25T22:34:28.066Z,1398465268.066 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CC4E0 2014-04-25T22:34:28.066Z,1398465268.066 [logger ThreadHandler](INFO): Protected caller Thread ID is 1667 2014-04-25T22:34:28.068Z,1398465268.068 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2014-04-25T22:34:28.069Z,1398465268.069 [Supervisor](INFO): Looking for Config files in directory: Config/ 2014-04-25T22:34:28.071Z,1398465268.071 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2014-04-25T22:34:28.487Z,1398465268.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2014-04-25T22:34:28.488Z,1398465268.488 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2014-04-25T22:34:28.757Z,1398465268.757 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2014-04-25T22:34:28.757Z,1398465268.757 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2014-04-25T22:34:28.850Z,1398465268.850 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2014-04-25T22:34:28.851Z,1398465268.851 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2014-04-25T22:34:29.045Z,1398465269.045 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2014-04-25T22:34:29.045Z,1398465269.045 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2014-04-25T22:34:29.212Z,1398465269.212 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2014-04-25T22:34:29.212Z,1398465269.212 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2014-04-25T22:34:29.507Z,1398465269.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2014-04-25T22:34:29.508Z,1398465269.508 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2014-04-25T22:34:29.695Z,1398465269.695 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2014-04-25T22:34:29.696Z,1398465269.696 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2014-04-25T22:34:30.039Z,1398465270.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2014-04-25T22:34:30.039Z,1398465270.039 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2014-04-25T22:34:31.837Z,1398465271.837 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2014-04-25T22:34:31.837Z,1398465271.837 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2014-04-25T22:34:32.340Z,1398465272.340 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2014-04-25T22:34:32.341Z,1398465272.341 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2014-04-25T22:34:32.457Z,1398465272.457 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2014-04-25T22:34:32.458Z,1398465272.458 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2014-04-25T22:34:32.553Z,1398465272.553 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2014-04-25T22:34:32.674Z,1398465272.674 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2014-04-25T22:34:32.675Z,1398465272.675 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2014-04-25T22:34:32.786Z,1398465272.786 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2014-04-25T22:34:32.787Z,1398465272.787 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2014-04-25T22:34:32.937Z,1398465272.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2014-04-25T22:34:32.939Z,1398465272.939 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2014-04-25T22:34:32.940Z,1398465272.940 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2014-04-25T22:34:33.054Z,1398465273.054 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2014-04-25T22:34:33.320Z,1398465273.320 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2014-04-25T22:34:33.563Z,1398465273.563 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2014-04-25T22:34:33.731Z,1398465273.731 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2014-04-25T22:34:33.888Z,1398465273.888 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2014-04-25T22:34:34.011Z,1398465274.011 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2014-04-25T22:34:34.103Z,1398465274.103 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2014-04-25T22:34:34.214Z,1398465274.214 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2014-04-25T22:34:34.321Z,1398465274.321 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2014-04-25T22:34:34.424Z,1398465274.424 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2014-04-25T22:34:34.520Z,1398465274.520 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Estimation.cfg 2014-04-25T22:34:34.625Z,1398465274.625 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/LOGIN/ 2014-04-25T22:34:34.625Z,1398465274.625 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2014-04-25T22:34:34.631Z,1398465274.631 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2014-04-25T22:34:35.277Z,1398465275.277 [AHRS_sp3003D] Loaded 2014-04-25T22:34:35.277Z,1398465275.277 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2014-04-25T22:34:35.578Z,1398465275.578 [Batt_Ocean_Server] Loaded 2014-04-25T22:34:35.578Z,1398465275.578 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2014-04-25T22:34:35.960Z,1398465275.960 [DataOverHttps] Loaded 2014-04-25T22:34:35.960Z,1398465275.960 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2014-04-25T22:34:35.974Z,1398465275.974 [Depth_Keller] Loaded 2014-04-25T22:34:35.974Z,1398465275.974 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2014-04-25T22:34:35.979Z,1398465275.979 [DropWeight] Loaded 2014-04-25T22:34:35.979Z,1398465275.979 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2014-04-25T22:34:36.143Z,1398465276.143 [DVL_micro] Loaded 2014-04-25T22:34:36.143Z,1398465276.143 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2014-04-25T22:34:36.244Z,1398465276.244 [NAL9602] Loaded 2014-04-25T22:34:36.245Z,1398465276.245 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2014-04-25T22:34:36.297Z,1398465276.297 [Onboard] Loaded 2014-04-25T22:34:36.297Z,1398465276.297 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2014-04-25T22:34:36.304Z,1398465276.304 [Radio_Freewave] Loaded 2014-04-25T22:34:36.305Z,1398465276.305 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2014-04-25T22:34:36.311Z,1398465276.311 [SCPI] Loaded 2014-04-25T22:34:36.312Z,1398465276.312 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2014-04-25T22:34:36.312Z,1398465276.312 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2014-04-25T22:34:36.313Z,1398465276.313 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2014-04-25T22:34:36.610Z,1398465276.610 [ExternalSim] Loaded 2014-04-25T22:34:36.611Z,1398465276.611 [ComponentRegistry](DEBUG): SyncComponent "ExternalSim" handled in the control thread. 2014-04-25T22:34:36.665Z,1398465276.665 [InternalSim] Loaded 2014-04-25T22:34:36.665Z,1398465276.665 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2014-04-25T22:34:36.665Z,1398465276.665 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2014-04-25T22:34:36.666Z,1398465276.666 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2014-04-25T22:34:36.964Z,1398465276.964 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2014-04-25T22:34:36.965Z,1398465276.965 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2014-04-25T22:34:36.973Z,1398465276.973 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2014-04-25T22:34:36.979Z,1398465276.979 [AsyncPiEstimator] Loaded 2014-04-25T22:34:36.979Z,1398465276.979 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2014-04-25T22:34:36.980Z,1398465276.980 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A24E0 2014-04-25T22:34:36.980Z,1398465276.980 [AsyncPiEstimator ThreadHandler](INFO): Protected caller Thread ID is 1752 2014-04-25T22:34:36.981Z,1398465276.981 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2014-04-25T22:34:36.982Z,1398465276.982 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2014-04-25T22:34:37.077Z,1398465277.077 [DeadReckonUsingMultipleVelocitySources] Loaded 2014-04-25T22:34:37.077Z,1398465277.077 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2014-04-25T22:34:37.094Z,1398465277.094 [NavChart] Loaded 2014-04-25T22:34:37.094Z,1398465277.094 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2014-04-25T22:34:37.098Z,1398465277.098 [UniversalFixResidualReporter] Loaded 2014-04-25T22:34:37.099Z,1398465277.099 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2014-04-25T22:34:37.099Z,1398465277.099 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2014-04-25T22:34:37.100Z,1398465277.100 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2014-04-25T22:34:37.167Z,1398465277.167 [VerticalControl](DEBUG): Construct VerticalControl. 2014-04-25T22:34:37.274Z,1398465277.274 [VerticalControl] Loaded 2014-04-25T22:34:37.274Z,1398465277.274 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2014-04-25T22:34:37.275Z,1398465277.275 [HorizontalControl](DEBUG): Construct HorizontalControl. 2014-04-25T22:34:37.342Z,1398465277.342 [HorizontalControl] Loaded 2014-04-25T22:34:37.342Z,1398465277.342 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2014-04-25T22:34:37.343Z,1398465277.343 [SpeedControl](DEBUG): Construct SpeedControl. 2014-04-25T22:34:37.344Z,1398465277.344 [SpeedControl] Loaded 2014-04-25T22:34:37.345Z,1398465277.345 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2014-04-25T22:34:37.345Z,1398465277.345 [LoopControl](DEBUG): Construct LoopControl. 2014-04-25T22:34:37.346Z,1398465277.346 [LoopControl] Loaded 2014-04-25T22:34:37.346Z,1398465277.346 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2014-04-25T22:34:37.347Z,1398465277.347 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2014-04-25T22:34:37.347Z,1398465277.347 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2014-04-25T22:34:37.376Z,1398465277.376 [DepthRateCalculator] Loaded 2014-04-25T22:34:37.376Z,1398465277.376 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2014-04-25T22:34:37.382Z,1398465277.382 [PitchRateCalculator] Loaded 2014-04-25T22:34:37.382Z,1398465277.382 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2014-04-25T22:34:37.390Z,1398465277.390 [SpeedCalculator] Loaded 2014-04-25T22:34:37.391Z,1398465277.391 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2014-04-25T22:34:37.407Z,1398465277.407 [TempGradientCalculator] Loaded 2014-04-25T22:34:37.407Z,1398465277.407 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2014-04-25T22:34:37.413Z,1398465277.413 [YawRateCalculator] Loaded 2014-04-25T22:34:37.413Z,1398465277.413 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2014-04-25T22:34:37.413Z,1398465277.413 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2014-04-25T22:34:37.414Z,1398465277.414 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2014-04-25T22:34:37.540Z,1398465277.540 [CTD_NeilBrown] Loaded 2014-04-25T22:34:37.541Z,1398465277.541 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2014-04-25T22:34:37.542Z,1398465277.542 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407444E0 2014-04-25T22:34:37.542Z,1398465277.542 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1753 2014-04-25T22:34:37.555Z,1398465277.555 [ISUS] Loaded 2014-04-25T22:34:37.555Z,1398465277.555 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2014-04-25T22:34:37.570Z,1398465277.570 [PAR_Licor] Loaded 2014-04-25T22:34:37.570Z,1398465277.570 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2014-04-25T22:34:37.606Z,1398465277.606 [WetLabsBB2FL] Loaded 2014-04-25T22:34:37.606Z,1398465277.606 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2014-04-25T22:34:37.607Z,1398465277.607 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407744E0 2014-04-25T22:34:37.607Z,1398465277.607 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1754 2014-04-25T22:34:37.608Z,1398465277.608 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2014-04-25T22:34:37.609Z,1398465277.609 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2014-04-25T22:34:37.724Z,1398465277.724 [SBIT](DEBUG): Construct Startup Built In Test. 2014-04-25T22:34:37.737Z,1398465277.737 [SBIT] Loaded 2014-04-25T22:34:37.738Z,1398465277.738 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2014-04-25T22:34:37.738Z,1398465277.738 [IBIT](DEBUG): Construct Initiated Built In Test. 2014-04-25T22:34:37.751Z,1398465277.751 [IBIT] Loaded 2014-04-25T22:34:37.751Z,1398465277.751 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2014-04-25T22:34:37.753Z,1398465277.753 [CBIT](DEBUG): Construct CBIT Built In Test. 2014-04-25T22:34:37.823Z,1398465277.823 [CBIT] Loaded 2014-04-25T22:34:37.823Z,1398465277.823 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2014-04-25T22:34:37.823Z,1398465277.823 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2014-04-25T22:34:37.824Z,1398465277.824 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2014-04-25T22:34:37.895Z,1398465277.895 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2014-04-25T22:34:37.895Z,1398465277.895 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2014-04-25T22:34:38.014Z,1398465278.014 [BuoyancyServo] Loaded 2014-04-25T22:34:38.014Z,1398465278.014 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2014-04-25T22:34:38.022Z,1398465278.022 [ElevatorServo] Loaded 2014-04-25T22:34:38.023Z,1398465278.023 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2014-04-25T22:34:38.032Z,1398465278.032 [MassServo] Loaded 2014-04-25T22:34:38.032Z,1398465278.033 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2014-04-25T22:34:38.041Z,1398465278.041 [RudderServo] Loaded 2014-04-25T22:34:38.041Z,1398465278.041 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2014-04-25T22:34:38.049Z,1398465278.049 [ThrusterServo] Loaded 2014-04-25T22:34:38.050Z,1398465278.050 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2014-04-25T22:34:38.050Z,1398465278.050 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2014-04-25T22:34:38.051Z,1398465278.051 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2014-04-25T22:34:38.089Z,1398465278.089 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2014-04-25T22:34:38.091Z,1398465278.091 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2014-04-25T22:34:38.092Z,1398465278.092 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2014-04-25T22:34:38.101Z,1398465278.101 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2014-04-25T22:34:38.102Z,1398465278.102 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408434E0 2014-04-25T22:34:38.102Z,1398465278.102 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1755 2014-04-25T22:34:38.108Z,1398465278.108 [Supervisor](INFO): Main Thread ID is 1663 2014-04-25T22:34:38.108Z,1398465278.108 [Supervisor](DEBUG): Running supervisor. 2014-04-25T22:34:38.109Z,1398465278.109 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1756 2014-04-25T22:34:38.111Z,1398465278.111 [controlThread ThreadHandler](INFO): Handler Thread ID is 1757 2014-04-25T22:34:38.112Z,1398465278.112 [controlThread](DEBUG): Initializing ControlThread 2014-04-25T22:34:38.115Z,1398465278.115 [logger ThreadHandler](INFO): Handler Thread ID is 1758 2014-04-25T22:34:38.133Z,1398465278.133 [AsyncPiEstimator ThreadHandler](INFO): Handler Thread ID is 1759 2014-04-25T22:34:38.133Z,1398465278.133 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2014-04-25T22:34:38.149Z,1398465278.149 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1760 2014-04-25T22:34:38.150Z,1398465278.150 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2014-04-25T22:34:38.153Z,1398465278.153 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-25T22:34:38.163Z,1398465278.163 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1762 2014-04-25T22:34:38.164Z,1398465278.164 [WetLabsBB2FL](INFO): Powering down 2014-04-25T22:34:38.198Z,1398465278.198 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1763 2014-04-25T22:34:38.206Z,1398465278.206 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2014-04-25T22:34:38.207Z,1398465278.207 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2014-04-25T22:34:38.207Z,1398465278.207 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2014-04-25T22:34:38.207Z,1398465278.207 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2014-04-25T22:34:38.208Z,1398465278.208 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2014-04-25T22:34:38.208Z,1398465278.208 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2014-04-25T22:34:38.208Z,1398465278.208 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2014-04-25T22:34:38.210Z,1398465278.210 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2014-04-25T22:34:38.210Z,1398465278.210 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2014-04-25T22:34:39.222Z,1398465279.222 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout 2014-04-25T22:34:39.223Z,1398465279.223 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing 2014-04-25T22:34:39.223Z,1398465279.223 [Batt_Ocean_Server] Communications Fault, FailCount= 1 2014-04-25T22:34:39.223Z,1398465279.223 [Batt_Ocean_Server](ERROR): Communications Fault 2014-04-25T22:34:39.229Z,1398465279.229 [ExternalSim](INFO): ExternalSim initializing... 2014-04-25T22:34:39.393Z,1398465279.393 [ExternalSim](DEBUG): beaconLat = 36.81340 2014-04-25T22:34:39.393Z,1398465279.393 [ExternalSim](DEBUG): beaconLon = -121.82240 2014-04-25T22:34:39.393Z,1398465279.393 [ExternalSim](DEBUG): beaconDepth = 25.00 2014-04-25T22:34:40.212Z,1398465280.212 [ExternalSim](DEBUG): Simulator initialized 2014-04-25T22:34:40.332Z,1398465280.332 [InternalSim](DEBUG): InternalSim initializing... 2014-04-25T22:34:40.432Z,1398465280.432 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-25T22:34:40.433Z,1398465280.433 [NavChart](DEBUG): Initialize NavChart Navigation. 2014-04-25T22:34:40.433Z,1398465280.433 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-25T22:34:40.433Z,1398465280.433 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2014-04-25T22:34:40.435Z,1398465280.435 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2014-04-25T22:34:40.436Z,1398465280.436 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2014-04-25T22:34:40.436Z,1398465280.436 [LoopControl](DEBUG): Initialize LoopControlComponent. 2014-04-25T22:34:40.437Z,1398465280.437 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-25T22:34:40.437Z,1398465280.437 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2014-04-25T22:34:40.437Z,1398465280.437 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2014-04-25T22:34:40.438Z,1398465280.438 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2014-04-25T22:34:40.438Z,1398465280.438 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2014-04-25T22:34:40.440Z,1398465280.440 [SBIT](INFO): Initialize SBIT Component. 2014-04-25T22:34:40.448Z,1398465280.448 [SBIT](IMPORTANT): Tethys CM Info: $Rev:11250 2014-04-25T22:34:40.449Z,1398465280.449 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2014-04-25T22:34:40.449Z,1398465280.449 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2014-04-25T22:34:40.450Z,1398465280.450 [IBIT](INFO): Initialize IBIT Component. 2014-04-25T22:34:40.450Z,1398465280.450 [CBIT](DEBUG): Initialize CBIT Component. 2014-04-25T22:34:40.451Z,1398465280.451 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2014-04-25T22:34:40.478Z,1398465280.478 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2014-04-25T22:34:40.500Z,1398465280.500 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:34:40.525Z,1398465280.525 [MissionManager](DEBUG): 2014-04-25T22:34:40.526Z,1398465280.526 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2014-04-25T22:34:40.607Z,1398465280.607 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2014-04-25T22:34:40.629Z,1398465280.629 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2014-04-25T22:34:40.632Z,1398465280.632 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:34:40.657Z,1398465280.657 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2014-04-25T22:34:40.660Z,1398465280.660 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:34:40.682Z,1398465280.682 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2014-04-25T22:34:40.708Z,1398465280.708 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct. 2014-04-25T22:34:40.723Z,1398465280.723 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:34:40.746Z,1398465280.746 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2014-04-25T22:34:40.751Z,1398465280.751 [controlThread](DEBUG): Component order: CycleStarter,ExternalSim,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,DataOverHttps,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,Radio_Freewave,SCPI,ISUS,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2014-04-25T22:34:40.854Z,1398465280.854 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-25T22:34:41.029Z,1398465281.029 [DVL_micro](INFO): Initializing 2014-04-25T22:34:41.170Z,1398465281.170 [Radio_Freewave](INFO): Powering up 2014-04-25T22:34:41.648Z,1398465281.648 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-25T22:34:41.648Z,1398465281.648 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-25T22:34:41.682Z,1398465281.682 [ElevatorServo](DEBUG): Initializing EZServoServo. 2014-04-25T22:34:41.682Z,1398465281.682 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2014-04-25T22:34:41.692Z,1398465281.692 [MassServo](DEBUG): Initializing EZServoServo. 2014-04-25T22:34:41.693Z,1398465281.693 [MassServo](DEBUG): Initializing MassServo. 2014-04-25T22:34:41.714Z,1398465281.714 [RudderServo](DEBUG): Initializing EZServoServo. 2014-04-25T22:34:41.715Z,1398465281.715 [RudderServo](DEBUG): Initializing RudderServo. 2014-04-25T22:34:41.727Z,1398465281.727 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-25T22:34:41.772Z,1398465281.772 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server 2014-04-25T22:34:41.772Z,1398465281.772 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server 2014-04-25T22:34:41.772Z,1398465281.772 [Batt_Ocean_Server] No Fault, FailCount= 1 2014-04-25T22:34:43.482Z,1398465283.482 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2014-04-25T22:34:45.412Z,1398465285.412 [Depth_Keller](ERROR): Pressure reading out of range: 1830.270752 decibar 2014-04-25T22:34:45.451Z,1398465285.451 [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-04-25T22:34:47.470Z,1398465287.470 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003707 2014-04-25T22:34:50.885Z,1398465290.885 [NAL9602](IMPORTANT): GPS fix at: 1398465290.88 2014-04-25T22:34:52.493Z,1398465292.493 [NAL9602](INFO): No messages in MT queue 2014-04-25T22:34:56.287Z,1398465296.287 [SBIT](IMPORTANT): Beginning Startup BIT 2014-04-25T22:34:56.289Z,1398465296.289 [CBIT](IMPORTANT): Beginning GF scan 2014-04-25T22:34:58.438Z,1398465298.438 [NAL9602](INFO): Powering down 2014-04-25T22:35:23.807Z,1398465323.807 [CBIT](IMPORTANT): No ground fault detected 2014-04-25T22:35:34.496Z,1398465334.496 [CommandLine](IMPORTANT): got command failComponent 2014-04-25T22:35:34.496Z,1398465334.496 [CommandLine](IMPORTANT): Failed components: 2014-04-25T22:35:34.497Z,1398465334.497 [CommandLine](IMPORTANT): No failed Components. 2014-04-25T22:35:50.611Z,1398465350.611 [SBIT](IMPORTANT): SBIT PASSED 2014-04-25T22:35:51.000Z,1398465351.000 [MissionManager](IMPORTANT): Started mission Startup 2014-04-25T22:35:51.000Z,1398465351.000 [Startup] Running Loop=1 2014-04-25T22:35:51.000Z,1398465351.000 [Startup](INFO): Aggregate::initialize Startup 2014-04-25T22:35:51.000Z,1398465351.000 [Startup:A.GoToSurface] Running Loop=1 2014-04-25T22:35:51.001Z,1398465351.001 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-25T22:35:51.006Z,1398465351.006 [Startup:StartupSatComms] Running Loop=1 2014-04-25T22:35:51.007Z,1398465351.007 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2014-04-25T22:35:51.007Z,1398465351.007 [Startup:StartupSatComms:A] Running Loop=1 2014-04-25T22:35:51.410Z,1398465351.410 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-25T22:35:51.801Z,1398465351.801 [NAL9602](INFO): Powering up 2014-04-25T22:35:57.711Z,1398465357.711 [NAL9602](IMPORTANT): GPS fix at: 1398465357.71 2014-04-25T22:35:57.745Z,1398465357.745 [Startup:StartupSatComms:A] Stopped 2014-04-25T22:35:57.745Z,1398465357.745 [Startup:StartupSatComms:B] Running Loop=1 2014-04-25T22:35:58.196Z,1398465358.196 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-25T22:35:59.621Z,1398465359.621 [NAL9602](INFO): No messages in MT queue 2014-04-25T22:36:01.540Z,1398465361.540 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140421T192253/Courier0132.lzma 2014-04-25T22:36:02.639Z,1398465362.639 [DataOverHttps](INFO): Moved sent file to Logs/20140421T192253/Courier0132.lzma.bak 2014-04-25T22:36:02.640Z,1398465362.640 [DataOverHttps](INFO): SBD MOMSN=798203 2014-04-25T22:36:06.128Z,1398465366.128 [NAL9602](INFO): Powering down 2014-04-25T22:36:14.976Z,1398465374.976 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20140425T220955/Courier0000.lzma 2014-04-25T22:36:15.839Z,1398465375.839 [DataOverHttps](INFO): Moved sent file to Logs/20140425T220955/Courier0000.lzma.bak 2014-04-25T22:36:15.839Z,1398465375.839 [DataOverHttps](INFO): SBD MOMSN=798205 2014-04-25T22:36:21.223Z,1398465381.223 [DataOverHttps](INFO): Sending 299 bytes from file Logs/20140425T223427/Courier0000.lzma 2014-04-25T22:36:22.062Z,1398465382.062 [DataOverHttps](INFO): Moved sent file to Logs/20140425T223427/Courier0000.lzma.bak 2014-04-25T22:36:22.062Z,1398465382.062 [DataOverHttps](INFO): SBD MOMSN=798208 2014-04-25T22:36:27.785Z,1398465387.785 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140421T192253/Express0133.lzma 2014-04-25T22:36:28.697Z,1398465388.697 [DataOverHttps](INFO): Moved sent file to Logs/20140421T192253/Express0133.lzma.bak 2014-04-25T22:36:28.697Z,1398465388.697 [DataOverHttps](INFO): SBD MOMSN=798211 2014-04-25T22:36:37.187Z,1398465397.187 [DataOverHttps](INFO): Sending 603 bytes from file Logs/20140425T220955/Express0001.lzma 2014-04-25T22:36:38.018Z,1398465398.018 [DataOverHttps](INFO): Moved sent file to Logs/20140425T220955/Express0001.lzma.bak 2014-04-25T22:36:38.018Z,1398465398.018 [DataOverHttps](INFO): SBD MOMSN=798213 2014-04-25T22:36:43.561Z,1398465403.561 [DataOverHttps](INFO): Sending 799 bytes from file Logs/20140425T223427/Express0001.lzma 2014-04-25T22:36:44.456Z,1398465404.456 [DataOverHttps](INFO): Moved sent file to Logs/20140425T223427/Express0001.lzma.bak 2014-04-25T22:36:44.457Z,1398465404.457 [DataOverHttps](INFO): SBD MOMSN=798224 2014-04-25T22:36:45.071Z,1398465405.071 [Startup:StartupSatComms:B] Stopped 2014-04-25T22:36:45.071Z,1398465405.071 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2014-04-25T22:36:45.071Z,1398465405.071 [Startup:StartupSatComms] Stopped 2014-04-25T22:36:45.071Z,1398465405.071 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2014-04-25T22:36:45.072Z,1398465405.072 [Startup](INFO): Completed Startup 2014-04-25T22:36:45.072Z,1398465405.072 [Startup] Stopped 2014-04-25T22:36:45.072Z,1398465405.072 [Startup](INFO): Aggregate::uninitialize Startup 2014-04-25T22:36:45.072Z,1398465405.072 [Startup:A.GoToSurface] Stopped 2014-04-25T22:36:45.073Z,1398465405.073 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-25T22:36:45.485Z,1398465405.485 [MissionManager](IMPORTANT): Started mission Default 2014-04-25T22:36:45.485Z,1398465405.485 [Default] Running Loop=1 2014-04-25T22:36:45.485Z,1398465405.485 [Default](INFO): Aggregate::initialize Default 2014-04-25T22:36:45.485Z,1398465405.485 [Default:Iridium] Running Loop=1 2014-04-25T22:36:45.485Z,1398465405.485 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-25T22:36:45.485Z,1398465405.485 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-25T22:36:45.485Z,1398465405.485 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-25T22:36:45.486Z,1398465405.486 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-25T22:36:45.486Z,1398465405.486 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-25T22:36:45.492Z,1398465405.492 [Default:Iridium:B.GoToSurface] Stopped 2014-04-25T22:36:45.492Z,1398465405.492 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-25T22:36:45.492Z,1398465405.492 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-25T22:36:45.492Z,1398465405.492 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-25T22:36:45.497Z,1398465405.497 [Default:GPS] Running Loop=1 2014-04-25T22:36:45.498Z,1398465405.498 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-25T22:36:45.498Z,1398465405.498 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-25T22:36:45.498Z,1398465405.498 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-25T22:36:45.498Z,1398465405.498 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-25T22:36:45.498Z,1398465405.498 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-25T22:36:45.534Z,1398465405.534 [Default:GPS:B.GoToSurface] Stopped 2014-04-25T22:36:45.534Z,1398465405.534 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-25T22:36:45.534Z,1398465405.534 [Default:GPS:Read_GPS] Running Loop=1 2014-04-25T22:36:45.534Z,1398465405.534 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-25T22:36:46.552Z,1398465406.552 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-25T22:36:46.555Z,1398465406.555 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-25T22:36:47.234Z,1398465407.234 [NAL9602](INFO): Powering up 2014-04-25T22:36:50.327Z,1398465410.327 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140425T223427/Courier0004.lzma 2014-04-25T22:36:51.219Z,1398465411.219 [DataOverHttps](INFO): Moved sent file to Logs/20140425T223427/Courier0004.lzma.bak 2014-04-25T22:36:51.219Z,1398465411.219 [DataOverHttps](INFO): SBD MOMSN=798241 2014-04-25T22:36:51.311Z,1398465411.311 [CommandLine](IMPORTANT): got command run ./Missions/Science/EcoHAB_box.xml 2014-04-25T22:36:51.312Z,1398465411.312 [MissionManager](INFO): Loading Mission: ./Missions/Science/EcoHAB_box.xml 2014-04-25T22:36:51.595Z,1398465411.595 [MissionManager](INFO): DefineArg EcoHAB_box.NeedCommsTime = 36.000000 h 2014-04-25T22:36:51.605Z,1398465411.605 [MissionManager](INFO): DefineArg EcoHAB_box.MinAltitude = 4.000000 m 2014-04-25T22:36:51.609Z,1398465411.609 [MissionManager](INFO): DefineArg EcoHAB_box.MaxDepth = 85.000000 m 2014-04-25T22:36:51.612Z,1398465411.612 [MissionManager](INFO): DefineArg EcoHAB_box.MinOffshore = 2000.000000 m 2014-04-25T22:36:51.616Z,1398465411.616 [MissionManager](INFO): DefineArg EcoHAB_box.Speed = 1.000000 m/s 2014-04-25T22:36:51.620Z,1398465411.620 [MissionManager](INFO): DefineArg EcoHAB_box.MissionTimeout = 9.000000 h 2014-04-25T22:36:51.629Z,1398465411.629 [MissionManager](INFO): DefineArg EcoHAB_box.MassDefault = 0.010000 n/a 2014-04-25T22:36:51.633Z,1398465411.633 [MissionManager](INFO): DefineArg EcoHAB_box.BuoyancyNeutral = 0.000280 n/a 2014-04-25T22:36:51.637Z,1398465411.637 [MissionManager](INFO): DefineArg EcoHAB_box.WpESPInshoreLat = 33.607614 arcdeg 2014-04-25T22:36:51.641Z,1398465411.641 [MissionManager](INFO): DefineArg EcoHAB_box.WpESPInshoreLon = -118.018798 arcdeg 2014-04-25T22:36:51.677Z,1398465411.677 [MissionManager](INFO): DefineArg EcoHAB_box.WpESPOffshoreLat = 33.585471 arcdeg 2014-04-25T22:36:51.680Z,1398465411.680 [MissionManager](INFO): DefineArg EcoHAB_box.WpESPOffshoreLon = -118.037372 arcdeg 2014-04-25T22:36:51.684Z,1398465411.684 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner1Lat = 33.586554 arcdeg 2014-04-25T22:36:51.716Z,1398465411.716 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner1Lon = -117.979903 arcdeg 2014-04-25T22:36:51.728Z,1398465411.728 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner2Lat = 33.563841 arcdeg 2014-04-25T22:36:51.732Z,1398465411.732 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner2Lon = -117.997449 arcdeg 2014-04-25T22:36:51.752Z,1398465411.752 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner3Lat = 33.606518 arcdeg 2014-04-25T22:36:51.755Z,1398465411.755 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner3Lon = -118.076276 arcdeg 2014-04-25T22:36:51.759Z,1398465411.759 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner4Lat = 33.628662 arcdeg 2014-04-25T22:36:51.779Z,1398465411.779 [MissionManager](INFO): DefineArg EcoHAB_box.WpCorner4Lon = -118.057712 arcdeg 2014-04-25T22:36:51.783Z,1398465411.783 [MissionManager](INFO): DefineArg EcoHAB_box.ApproachDepth = 10.000000 m 2014-04-25T22:36:51.799Z,1398465411.799 [MissionManager](INFO): DefineArg EcoHAB_box.ApproachTimeout = 4.000000 h 2014-04-25T22:36:51.803Z,1398465411.803 [MissionManager](INFO): DefineArg EcoHAB_box.ApproachNeedCommsTime = 20.000000 min 2014-04-25T22:36:51.823Z,1398465411.823 [MissionManager](INFO): DefineArg EcoHAB_box.Repeat = 13.000000 count 2014-04-25T22:36:51.834Z,1398465411.834 [MissionManager](INFO): DefineArg EcoHAB_box.CircleRadius = 500.000000 m 2014-04-25T22:36:51.838Z,1398465411.838 [MissionManager](INFO): DefineArg EcoHAB_box.CircleRepeat = 13.000000 count 2014-04-25T22:36:51.854Z,1398465411.854 [MissionManager](INFO): DefineArg EcoHAB_box.CircleDivisor = 2.000000 h 2014-04-25T22:36:51.857Z,1398465411.857 [MissionManager](INFO): DefineArg EcoHAB_box.CircleModulus = nan h 2014-04-25T22:36:51.885Z,1398465411.885 [MissionManager](INFO): DefineArg EcoHAB_box.CircleTimeout = 3.000000 h 2014-04-25T22:36:51.889Z,1398465411.889 [MissionManager](INFO): DefineArg EcoHAB_box.LapTimeout = 8.000000 h 2014-04-25T22:36:51.905Z,1398465411.905 [MissionManager](INFO): DefineArg EcoHAB_box.SCPITimeout = 420.000000 s 2014-04-25T22:36:51.913Z,1398465411.913 [MissionManager](INFO): DefineArg EcoHAB_box.YoYoMinDepth = 4.000000 m 2014-04-25T22:36:51.916Z,1398465411.916 [MissionManager](INFO): DefineArg EcoHAB_box.YoYoMaxDepth = 78.000000 m 2014-04-25T22:36:51.936Z,1398465411.936 [MissionManager](INFO): DefineArg EcoHAB_box.YoYoMinAltitude = 6.000000 m 2014-04-25T22:36:51.960Z,1398465411.960 [MissionManager](INFO): DefineArg EcoHAB_box.YoYoUpPitch = 20.000000 arcdeg 2014-04-25T22:36:51.963Z,1398465411.963 [MissionManager](INFO): DefineArg EcoHAB_box.YoYoDownPitch = -20.000000 arcdeg 2014-04-25T22:36:51.965Z,1398465411.965 [EcoHAB_box:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2014-04-25T22:36:51.989Z,1398465411.989 [EcoHAB_box:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2014-04-25T22:36:52.018Z,1398465412.018 [EcoHAB_box:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2014-04-25T22:36:52.040Z,1398465412.040 [MissionManager](INFO): Inserting Stack: Missions/Insert/NeedComms.xml 2014-04-25T22:36:52.131Z,1398465412.131 [MissionManager](INFO): DefineArg EcoHAB_box:NeedComms.CommsTimeout = 30.000000 min 2014-04-25T22:36:52.143Z,1398465412.143 [MissionManager](INFO): DefineArg EcoHAB_box:NeedComms.DiveInterval = 3.000000 h 2014-04-25T22:36:52.151Z,1398465412.151 [MissionManager](INFO): DefineArg EcoHAB_box:NeedComms.WaitForPitchUp = 10.000000 min 2014-04-25T22:36:52.163Z,1398465412.163 [MissionManager](INFO): DefineArg EcoHAB_box:NeedComms.SurfacePitch = 20.000000 arcdeg 2014-04-25T22:36:52.171Z,1398465412.171 [MissionManager](INFO): DefineArg EcoHAB_box:NeedComms.SurfaceSpeed = 1.000000 m/s 2014-04-25T22:36:52.184Z,1398465412.184 [EcoHAB_box:NeedComms:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:36:52.220Z,1398465412.220 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2014-04-25T22:36:52.281Z,1398465412.281 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceComms.SurfaceDepthRate = nan m/s 2014-04-25T22:36:52.284Z,1398465412.284 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceComms.SurfacePitch = 20.000000 arcdeg 2014-04-25T22:36:52.288Z,1398465412.288 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceComms.SurfaceSpeed = 1.000000 m/s 2014-04-25T22:36:52.304Z,1398465412.304 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceComms.IridiumTimeout = 30.000000 min 2014-04-25T22:36:52.307Z,1398465412.307 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceComms.UnpackSplitAtSurface = 0 bool 2014-04-25T22:36:52.321Z,1398465412.321 [EcoHAB_box:SurfaceComms:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:36:52.346Z,1398465412.346 [MissionManager](INFO): Inserting Stack: Missions/Insert/SurfaceCommsSplit.xml 2014-04-25T22:36:52.383Z,1398465412.383 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit.SurfacePitch = 20.000000 arcdeg 2014-04-25T22:36:52.395Z,1398465412.395 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit.SurfaceSpeed = 1.000000 m/s 2014-04-25T22:36:52.395Z,1398465412.395 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2014-04-25T22:36:52.456Z,1398465412.456 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.SurfaceDepthRate = nan m/s 2014-04-25T22:36:52.468Z,1398465412.468 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.SurfacePitch = 20.000000 arcdeg 2014-04-25T22:36:52.479Z,1398465412.479 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.SurfaceSpeed = 1.000000 m/s 2014-04-25T22:36:52.491Z,1398465412.491 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.IridiumTimeout = 30.000000 min 2014-04-25T22:36:52.503Z,1398465412.503 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.UnpackSplitAtSurface = 0 bool 2014-04-25T22:36:52.504Z,1398465412.504 [EcoHAB_box:SurfaceCommsSplit:SurfaceComms:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:36:52.542Z,1398465412.542 [MissionManager](INFO): RedefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.SurfacePitch = value:20.000000 arcdeg 2014-04-25T22:36:52.544Z,1398465412.544 [MissionManager](INFO): RedefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.SurfaceSpeed = value:1.000000 m/s 2014-04-25T22:36:52.555Z,1398465412.555 [MissionManager](INFO): RedefineArg EcoHAB_box:SurfaceCommsSplit:SurfaceComms.UnpackSplitAtSurface = value:1 bool 2014-04-25T22:36:52.555Z,1398465412.555 [MissionManager](INFO): Inserting Stack: Missions/Insert/SurfaceCommsShort.xml 2014-04-25T22:36:52.625Z,1398465412.625 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsShort.FloatTime = 180.000000 s 2014-04-25T22:36:52.634Z,1398465412.634 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsShort.Timeout = 1.000000 h 2014-04-25T22:36:52.643Z,1398465412.643 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsShort.Pitch = 20.000000 arcdeg 2014-04-25T22:36:52.651Z,1398465412.651 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceCommsShort.Speed = 1.000000 m/s 2014-04-25T22:36:52.657Z,1398465412.657 [EcoHAB_box:SurfaceCommsShort:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:36:52.674Z,1398465412.674 [MissionManager](INFO): Inserting Stack: Missions/Insert/SurfaceGPS.xml 2014-04-25T22:36:52.713Z,1398465412.713 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceGPS.HalfTimeout = 30.000000 s 2014-04-25T22:36:52.717Z,1398465412.717 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceGPS.SurfacePitch = 20.000000 arcdeg 2014-04-25T22:36:52.725Z,1398465412.725 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceGPS.SurfaceSpeed = 1.000000 m/s 2014-04-25T22:36:52.732Z,1398465412.732 [EcoHAB_box:SurfaceGPS:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:36:52.750Z,1398465412.750 [MissionManager](INFO): Inserting Stack: Missions/Insert/SurfaceSafety.xml 2014-04-25T22:36:52.783Z,1398465412.783 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety.MaxTime = 11.000000 h 2014-04-25T22:36:52.785Z,1398465412.785 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2014-04-25T22:36:52.834Z,1398465412.834 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.SurfaceDepthRate = nan m/s 2014-04-25T22:36:52.839Z,1398465412.839 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.SurfacePitch = 20.000000 arcdeg 2014-04-25T22:36:52.842Z,1398465412.842 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.SurfaceSpeed = 1.000000 m/s 2014-04-25T22:36:52.846Z,1398465412.846 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.IridiumTimeout = 30.000000 min 2014-04-25T22:36:52.849Z,1398465412.849 [MissionManager](INFO): DefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.UnpackSplitAtSurface = 0 bool 2014-04-25T22:36:52.850Z,1398465412.850 [EcoHAB_box:SurfaceSafety:SurfaceComms:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:36:52.863Z,1398465412.863 [MissionManager](INFO): RedefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.SurfacePitch = value:20.000000 arcdeg 2014-04-25T22:36:52.890Z,1398465412.890 [MissionManager](INFO): RedefineArg EcoHAB_box:SurfaceSafety:SurfaceComms.SurfaceSpeed = value:1.000000 m/s 2014-04-25T22:36:52.891Z,1398465412.891 [EcoHAB_box:L.Pitch](DEBUG): Construct. 2014-04-25T22:36:52.897Z,1398465412.897 [EcoHAB_box:M.Buoyancy](DEBUG): Construct Buoyancy. 2014-04-25T22:36:52.915Z,1398465412.915 [MissionManager](INFO): Inserting Stack: Missions/Insert/CircleWaypointRepeatedly.xml 2014-04-25T22:36:52.941Z,1398465412.941 [NAL9602](IMPORTANT): GPS fix at: 1398465412.93 2014-04-25T22:36:53.062Z,1398465413.062 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.Timeout = 90.000000 min 2014-04-25T22:36:53.086Z,1398465413.086 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.LapTimeout = 240.000000 min 2014-04-25T22:36:53.091Z,1398465413.091 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.MaxLaps = 32.000000 count 2014-04-25T22:36:53.095Z,1398465413.095 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.CenterLat = nan arcdeg 2014-04-25T22:36:53.111Z,1398465413.111 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.CenterLon = nan arcdeg 2014-04-25T22:36:53.115Z,1398465413.115 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.Radius = 250.000000 m 2014-04-25T22:36:53.119Z,1398465413.119 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.MaxError = 250.000000 m 2014-04-25T22:36:53.137Z,1398465413.137 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.TurnToPort = 0 bool 2014-04-25T22:36:53.143Z,1398465413.143 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.KwpHeading = 0.010000 rad/m 2014-04-25T22:36:53.147Z,1398465413.147 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.FloatTime = 60.000000 s 2014-04-25T22:36:53.165Z,1398465413.165 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.Pitch = 20.000000 arcdeg 2014-04-25T22:36:53.177Z,1398465413.177 [MissionManager](INFO): DefineArg EcoHAB_box:CircleWaypointRepeatedly.Speed = 1.000000 m/s 2014-04-25T22:36:53.185Z,1398465413.185 [EcoHAB_box:CircleWaypointRepeatedly:Repeater:Lap:B.Circle](DEBUG): Construct. 2014-04-25T22:36:53.205Z,1398465413.205 [EcoHAB_box:CircleWaypointRepeatedly:Repeater:GTS:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-25T22:36:53.292Z,1398465413.292 [EcoHAB_box:Lap:WpESPInshore.Waypoint](DEBUG): Construct Waypoint. 2014-04-25T22:36:53.311Z,1398465413.311 [EcoHAB_box:Lap:WpCorner1.Waypoint](DEBUG): Construct Waypoint. 2014-04-25T22:36:53.317Z,1398465413.317 [EcoHAB_box:Lap:WpCorner2.Waypoint](DEBUG): Construct Waypoint. 2014-04-25T22:36:53.336Z,1398465413.336 [EcoHAB_box:Lap:WpESPOffshore.Waypoint](DEBUG): Construct Waypoint. 2014-04-25T22:36:53.379Z,1398465413.379 [EcoHAB_box:Lap:WpCorner3.Waypoint](DEBUG): Construct Waypoint. 2014-04-25T22:36:53.386Z,1398465413.386 [EcoHAB_box:Lap:WpCorner4.Waypoint](DEBUG): Construct Waypoint. 2014-04-25T22:36:53.434Z,1398465413.434 [EcoHAB_box:Lap:WpESPInshore.Waypoint](DEBUG): Construct Waypoint. 2014-04-25T22:36:53.459Z,1398465413.459 [EcoHAB_box:Approach:B.Pitch](DEBUG): Construct. 2014-04-25T22:36:53.478Z,1398465413.478 [EcoHAB_box:Approach:C.SetSpeed](DEBUG): Construct. 2014-04-25T22:36:53.481Z,1398465413.481 [EcoHAB_box:Approach:WpApproach.Waypoint](DEBUG): Construct Waypoint. 2014-04-25T22:36:53.504Z,1398465413.504 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2014-04-25T22:36:53.802Z,1398465413.802 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.SampleISUS = 0 bool 2014-04-25T22:36:53.822Z,1398465413.822 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.SampleISUSmaxPitch = 60.000000 arcdeg 2014-04-25T22:36:53.826Z,1398465413.826 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.SampleISUSminPitch = -60.000000 arcdeg 2014-04-25T22:36:53.845Z,1398465413.845 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.PeakDetectChlActive = 0 bool 2014-04-25T22:36:53.849Z,1398465413.849 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.PeakDetectNO3Active = 0 bool 2014-04-25T22:36:53.864Z,1398465413.864 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2014-04-25T22:36:53.868Z,1398465413.868 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.ComputeWaterCurrent = 0 bool 2014-04-25T22:36:53.891Z,1398465413.891 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.ComputeWaterCurrentMinDepth = 2.000000 m 2014-04-25T22:36:53.895Z,1398465413.895 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.ComputeWaterCurrentMaxDepth = 5.000000 m 2014-04-25T22:36:53.915Z,1398465413.915 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledAanderaaO2 = 0.000000 n/a 2014-04-25T22:36:53.919Z,1398465413.919 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledNeilBrown = 1.000000 n/a 2014-04-25T22:36:53.935Z,1398465413.935 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledTurbulence_NPS = 0.000000 n/a 2014-04-25T22:36:53.948Z,1398465413.948 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledWetLabsBB2FL = 1.000000 n/a 2014-04-25T22:36:53.952Z,1398465413.952 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledDVL = 1.000000 n/a 2014-04-25T22:36:53.972Z,1398465413.972 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:Science.EnabledISUS = 1.000000 n/a 2014-04-25T22:36:53.988Z,1398465413.988 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakChl = 0.000000 ug/l 2014-04-25T22:36:53.991Z,1398465413.991 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakChlDepth = 0.000000 m 2014-04-25T22:36:54.007Z,1398465414.007 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakChlLatitude = nan arcdeg 2014-04-25T22:36:54.011Z,1398465414.011 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakChlLongitude = nan arcdeg 2014-04-25T22:36:54.031Z,1398465414.031 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakNO3 = 0.000000 umol/l 2014-04-25T22:36:54.035Z,1398465414.035 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakNO3Depth = 0.000000 m 2014-04-25T22:36:54.038Z,1398465414.038 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakNO3Latitude = nan arcdeg 2014-04-25T22:36:54.058Z,1398465414.058 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:Science.PeakNO3Longitude = nan arcdeg 2014-04-25T22:36:54.116Z,1398465414.116 [EcoHAB_box:ScienceOps:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2014-04-25T22:36:54.133Z,1398465414.133 [EcoHAB_box:ScienceOps:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2014-04-25T22:36:54.158Z,1398465414.158 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.PeakDetectChlActive = value:1 bool 2014-04-25T22:36:54.176Z,1398465414.176 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.SampleISUS = value:1 bool 2014-04-25T22:36:54.179Z,1398465414.179 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.SampleISUSmaxPitch = value:30.000000 arcdeg 2014-04-25T22:36:54.181Z,1398465414.181 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.SampleISUSminPitch = value:10.000000 arcdeg 2014-04-25T22:36:54.183Z,1398465414.183 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.ComputeWaterCurrent = value:0 bool 2014-04-25T22:36:54.205Z,1398465414.205 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:Science.UpwardDerivativeOfTemperatureActive = value:0 bool 2014-04-25T22:36:54.206Z,1398465414.206 [MissionManager](INFO): Inserting Stack: Missions/Insert/VerticalTemperatureHomogeneityIndex.xml 2014-04-25T22:36:54.594Z,1398465414.594 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthShallow = 5.000000 m 2014-04-25T22:36:54.597Z,1398465414.597 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthMidShallow = 10.000000 m 2014-04-25T22:36:54.621Z,1398465414.621 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthMidDeep = 15.000000 m 2014-04-25T22:36:54.625Z,1398465414.625 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthDeep = 20.000000 m 2014-04-25T22:36:54.646Z,1398465414.646 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.Verbosity = 1.000000 count 2014-04-25T22:36:54.649Z,1398465414.649 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.TemperatureShallow = 0.000000 K 2014-04-25T22:36:54.669Z,1398465414.669 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.TemperatureMidShallow = 0.000000 K 2014-04-25T22:36:54.673Z,1398465414.673 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.TemperatureMidDeep = 0.000000 K 2014-04-25T22:36:54.693Z,1398465414.693 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.TemperatureDeep = 0.000000 K 2014-04-25T22:36:54.696Z,1398465414.696 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DTShallow = 0.000000 K 2014-04-25T22:36:54.709Z,1398465414.709 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DTMidShallow = 0.000000 K 2014-04-25T22:36:54.713Z,1398465414.713 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DTMidDeep = 0.000000 K 2014-04-25T22:36:54.759Z,1398465414.759 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.DTDeep = 0.000000 K 2014-04-25T22:36:54.763Z,1398465414.763 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.Zero = 0.000000 count 2014-04-25T22:36:54.779Z,1398465414.779 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.One = 1.000000 count 2014-04-25T22:36:54.783Z,1398465414.783 [MissionManager](INFO): DefineArg EcoHAB_box:ScienceOps:VTHIdx.Two = 2.000000 count 2014-04-25T22:36:54.803Z,1398465414.803 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:VTHIdx.TemperatureMean = 0.000000 K 2014-04-25T22:36:54.815Z,1398465414.815 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:VTHIdx.TemperatureDelta = 0.000000 K 2014-04-25T22:36:54.819Z,1398465414.819 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:VTHIdx.DetectLatitude = nan arcdeg 2014-04-25T22:36:54.839Z,1398465414.839 [MissionManager](INFO): DefineOutput EcoHAB_box:ScienceOps:VTHIdx.DetectLongitude = nan arcdeg 2014-04-25T22:36:54.843Z,1398465414.843 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectShallow.ValueDetect](DEBUG): Construct ValueDetect. 2014-04-25T22:36:54.866Z,1398465414.866 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidShallow.ValueDetect](DEBUG): Construct ValueDetect. 2014-04-25T22:36:54.888Z,1398465414.888 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectMidDeep.ValueDetect](DEBUG): Construct ValueDetect. 2014-04-25T22:36:54.896Z,1398465414.896 [EcoHAB_box:ScienceOps:VTHIdx:GetTemperatures:DetectDeep.ValueDetect](DEBUG): Construct ValueDetect. 2014-04-25T22:36:55.045Z,1398465415.045 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthShallow = value:5.000000 m 2014-04-25T22:36:55.047Z,1398465415.047 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthMidShallow = value:10.000000 m 2014-04-25T22:36:55.058Z,1398465415.058 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthMidDeep = value:20.000000 m 2014-04-25T22:36:55.067Z,1398465415.067 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:VTHIdx.DepthDeep = value:25.000000 m 2014-04-25T22:36:55.082Z,1398465415.082 [MissionManager](INFO): RedefineArg EcoHAB_box:ScienceOps:VTHIdx.Verbosity = value:1.000000 count 2014-04-25T22:36:55.095Z,1398465415.095 [EcoHAB_box:ScienceOps:D.SetSpeed](DEBUG): Construct. 2014-04-25T22:36:55.107Z,1398465415.107 [EcoHAB_box:ScienceOps:E.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2014-04-25T22:36:55.170Z,1398465415.170 [EcoHAB_box:ScienceOps:F.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2014-04-25T22:36:55.194Z,1398465415.194 [EcoHAB_box:ScienceOps:G.YoYo](DEBUG): Construct YoYo. 2014-04-25T22:36:55.334Z,1398465415.334 [MissionManager](DEBUG): This mission runs yoyos counterclockwise around a box. Two sides of the box pass through the planned locations for both Environmental Sample Processor (ESP) buoys during the Spring 2014 EcoHAB deployment. High-level NeedComms directive intended to assist debugging in the field. Elapsed time after previous surface fix when vehicle will begin to ascend for additional surface fix, if the vehicle has a positive pitch. If the vehicle has a negative pitch, it will wait up to 10 minutes more to begin ascent. The timing operates based on Universal:time_fix to avoid repeated attempts after the Iridium timeout. 36 Minimum altitude for the entire mission. 4 Maximum depth for the entire mission. 85 Minimum offshore distance for the entire mission. 2000 Vehicle speed. 1 Maximum duration of mission 9 Static setting for mass during the mission. Defaults to massDefault setting in the Config/Control.cfg file. Buoyancy bladder position while performing the YoYo behavior. Defaults to buoyancyNeutral setting in the Config/Control.cfg file. Latitude of inshore ESP buoy. 33.607614 Longitude of offshore ESP buoy. -118.018798 Latitude of offshore ESP buoy. 33.585471 Longitude of offshore ESP buoy. -118.037372 Latitude of waypoint for first corner of box. 33.586554427309956 Longitude of waypoint for first corner of box. -117.97990263671926 Latitude of waypoint for second corner of box. 33.563841488839024 Longitude of waypoint for second corner of box. -117.99744852771295 Latitude of waypoint for third corner of box. 33.60651834669941 Longitude of waypoint for third corner of box. -118.076275825578 Latitude of waypoint for fourth corner of box. 33.628662266112016 Longitude of waypoint for fourth corner of box. -118.05771227683994 Depth for initial approach to WpCorner1. 10.0 Maximum duration of initial approach 4 Elapsed time after previous surface communications when vehicle will begin to ascend for additional surface communications. Only active during the approach. 20 Number of times to repeat the science loop 13 Radius of circle around Inshore ESP during wait time 500 Maximum number of times to circle the wayopint at the start of each lap. 13 UTC time between reporting events. (e.g., "set CircleDivisor 8 hour" for reports at 0000, 0800, 1600 UTC) 2 Current time modulo CircleDivisor (internal variable). NaN Timeout for circling buoy at start of each lap (internal variable). 3 Maximum duration of lap around box. 8 Request data from the SCPI for this long. 420 Minimum depth during yo-yo's. 4.0 Maximum depth during yo-yo's. 78.0 Min altitude while in yo-yo mode. 6.0 Pitch when yo-yo's are ascending. 20.0 Pitch when yo-yo's are descending. -20.0 Calculate (current time) mod (CircleDivisor) and determine when to stop circling the start-of-lap waypoint. CircleModulus calculated as: CircleTimeout updated to: Circle a waypoint at the nominal location of the Inshore ESP buoy until timeout specified by CircleDivisor and current time. Convenience aggregate to notify operator of estimated circling time _before_ starting to circle the waypoint. May be commented out, since the Timeout in CircleWaypointRepeatedly will still achieve the desired behavior. CircleInshoreESPBuoy should complete in , due to timeout in CircleWaypointRepeatedly aggregate. **** Finished circling. **** Run around the box. 2.0 **** Finished circling. **** Get to start point. Check in periodically, but do not split logs Circle then lap many times, collecting science data. Get science data, including PeakDetectChl 30.0 10.0 5 10 20 25 1 Turn on the SCPI camera. (SCPI.sampleTime is set in Sensor.cfg) 40 2014-04-25T22:36:55.343Z,1398465415.343 [CommandLine](IMPORTANT): Running ./Missions/Science/EcoHAB_box.xml 2014-04-25T22:36:55.714Z,1398465415.714 [Default] Stopped 2014-04-25T22:36:55.714Z,1398465415.714 [Default](INFO): Aggregate::uninitialize Default 2014-04-25T22:36:55.714Z,1398465415.714 [Default:GPS] Stopped 2014-04-25T22:36:55.714Z,1398465415.714 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-25T22:36:55.715Z,1398465415.715 [Default:GPS:A.SetSpeed] Stopped 2014-04-25T22:36:55.715Z,1398465415.715 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-25T22:36:55.715Z,1398465415.715 [Default:GPS:Read_GPS] Stopped 2014-04-25T22:36:55.715Z,1398465415.715 [Default:Iridium] Stopped 2014-04-25T22:36:55.715Z,1398465415.715 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-25T22:36:55.715Z,1398465415.715 [Default:Iridium:A.SetSpeed] Stopped 2014-04-25T22:36:55.715Z,1398465415.715 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-25T22:36:55.715Z,1398465415.715 [Default:Iridium:Read_Iridium] Stopped 2014-04-25T22:36:55.715Z,1398465415.715 [MissionManager](IMPORTANT): Started mission EcoHAB_box 2014-04-25T22:36:55.715Z,1398465415.715 [EcoHAB_box] Running Loop=1 2014-04-25T22:36:55.716Z,1398465415.716 [EcoHAB_box](INFO): Aggregate::initialize EcoHAB_box 2014-04-25T22:36:55.716Z,1398465415.716 [EcoHAB_box:A.AltitudeEnvelope] Running Loop=1 2014-04-25T22:36:55.716Z,1398465415.716 [EcoHAB_box:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2014-04-25T22:36:55.716Z,1398465415.716 [EcoHAB_box:B.DepthEnvelope] Running Loop=1 2014-04-25T22:36:55.716Z,1398465415.716 [EcoHAB_box:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2014-04-25T22:36:55.716Z,1398465415.716 [EcoHAB_box:C.OffshoreEnvelope] Running Loop=1 2014-04-25T22:36:55.716Z,1398465415.716 [EcoHAB_box:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2014-04-25T22:36:55.717Z,1398465415.717 [EcoHAB_box:L.Pitch] Running Loop=1 2014-04-25T22:36:55.717Z,1398465415.717 [EcoHAB_box:L.Pitch](DEBUG): Initialize. 2014-04-25T22:36:55.717Z,1398465415.717 [EcoHAB_box:M.Buoyancy] Running Loop=1 2014-04-25T22:36:55.717Z,1398465415.717 [EcoHAB_box:M.Buoyancy](DEBUG): Initialize Buoyancy Component. 2014-04-25T22:36:55.717Z,1398465415.717 [EcoHAB_box:E] Running Loop=1 2014-04-25T22:36:55.718Z,1398465415.718 [EcoHAB_box:M.Buoyancy] Running Loop=1 2014-04-25T22:36:55.723Z,1398465415.723 [EcoHAB_box:L.Pitch] Running Loop=1 2014-04-25T22:36:55.731Z,1398465415.731 [EcoHAB_box:E] Stopped 2014-04-25T22:36:55.731Z,1398465415.731 [EcoHAB_box:F] Running Loop=1 2014-04-25T22:36:55.731Z,1398465415.731 [EcoHAB_box:C.OffshoreEnvelope] Running Loop=1 2014-04-25T22:36:55.737Z,1398465415.737 [EcoHAB_box:B.DepthEnvelope] Running Loop=1 2014-04-25T22:36:55.767Z,1398465415.767 [EcoHAB_box:A.AltitudeEnvelope] Running Loop=1 2014-04-25T22:36:56.209Z,1398465416.209 [NAL9602](INFO): No messages in MT queue 2014-04-25T22:36:56.230Z,1398465416.230 [EcoHAB_box:F] Stopped 2014-04-25T22:36:56.231Z,1398465416.231 [EcoHAB_box:SurfaceComms] Running Loop=1 2014-04-25T22:36:56.231Z,1398465416.231 [EcoHAB_box:SurfaceComms](INFO): Aggregate::initialize EcoHAB_box:SurfaceComms 2014-04-25T22:36:56.231Z,1398465416.231 [EcoHAB_box:SurfaceComms:A.GoToSurface] Running Loop=1 2014-04-25T22:36:56.231Z,1398465416.231 [EcoHAB_box:SurfaceComms:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-25T22:36:56.743Z,1398465416.743 [EcoHAB_box:SurfaceComms:B] Running Loop=1 2014-04-25T22:36:56.743Z,1398465416.743 [EcoHAB_box:SurfaceComms:B](INFO): Aggregate::initialize EcoHAB_box:SurfaceComms:B 2014-04-25T22:36:56.744Z,1398465416.744 [EcoHAB_box:SurfaceComms:B:A] Running Loop=1 2014-04-25T22:36:57.234Z,1398465417.234 [EcoHAB_box:SurfaceComms:B] Stopped 2014-04-25T22:36:57.234Z,1398465417.234 [EcoHAB_box:SurfaceComms:B](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceComms:B 2014-04-25T22:36:57.234Z,1398465417.234 [EcoHAB_box:SurfaceComms:B:A] Stopped 2014-04-25T22:36:57.234Z,1398465417.234 [EcoHAB_box:SurfaceComms:C] Running Loop=1 2014-04-25T22:36:57.234Z,1398465417.234 [EcoHAB_box:SurfaceComms:C](INFO): Aggregate::initialize EcoHAB_box:SurfaceComms:C 2014-04-25T22:36:57.234Z,1398465417.234 [EcoHAB_box:SurfaceComms:C:A] Running Loop=1 2014-04-25T22:36:57.719Z,1398465417.719 [EcoHAB_box:M.Buoyancy] Preempted 2014-04-25T22:36:57.719Z,1398465417.719 [EcoHAB_box:L.Pitch] Preempted 2014-04-25T22:36:57.720Z,1398465417.720 [EcoHAB_box:SurfaceComms:C:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-25T22:36:58.386Z,1398465418.386 [CommandLine](IMPORTANT): got command get latitude 2014-04-25T22:36:58.387Z,1398465418.387 [CommandLine](IMPORTANT): latitude 33.610000 arcdeg 2014-04-25T22:36:59.151Z,1398465419.151 [DataOverHttps](INFO): Sending 102 bytes from file Logs/20140425T223427/Express0005.lzma 2014-04-25T22:37:00.046Z,1398465420.046 [DataOverHttps](INFO): Moved sent file to Logs/20140425T223427/Express0005.lzma.bak 2014-04-25T22:37:00.046Z,1398465420.046 [DataOverHttps](INFO): SBD MOMSN=798243 2014-04-25T22:37:02.652Z,1398465422.652 [NAL9602](IMPORTANT): GPS fix at: 1398465422.65 2014-04-25T22:37:02.671Z,1398465422.671 [EcoHAB_box:SurfaceComms:C:A] Stopped 2014-04-25T22:37:02.671Z,1398465422.671 [EcoHAB_box:SurfaceComms:C:B] Running Loop=1 2014-04-25T22:37:03.110Z,1398465423.110 [EcoHAB_box:SurfaceComms:C:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-25T22:37:08.888Z,1398465428.888 [DataOverHttps](INFO): Sending 75 bytes from file Logs/20140425T223427/Courier0008.lzma 2014-04-25T22:37:08.896Z,1398465428.896 [NAL9602](INFO): Powering down 2014-04-25T22:37:09.712Z,1398465429.712 [DataOverHttps](INFO): Moved sent file to Logs/20140425T223427/Courier0008.lzma.bak 2014-04-25T22:37:09.712Z,1398465429.712 [DataOverHttps](INFO): SBD MOMSN=798246 2014-04-25T22:37:15.223Z,1398465435.223 [DataOverHttps](INFO): Sending 243 bytes from file Logs/20140425T223427/Express0009.lzma 2014-04-25T22:37:16.159Z,1398465436.159 [DataOverHttps](INFO): Moved sent file to Logs/20140425T223427/Express0009.lzma.bak 2014-04-25T22:37:16.159Z,1398465436.159 [DataOverHttps](INFO): SBD MOMSN=798248 2014-04-25T22:37:16.727Z,1398465436.727 [EcoHAB_box:SurfaceComms:C:B] Stopped 2014-04-25T22:37:16.727Z,1398465436.727 [EcoHAB_box:SurfaceComms:C:C] Running Loop=1 2014-04-25T22:37:17.183Z,1398465437.183 [EcoHAB_box:SurfaceComms:C:C](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-25T22:37:18.088Z,1398465438.088 [NAL9602](INFO): Powering up 2014-04-25T22:37:23.348Z,1398465443.348 [NAL9602](IMPORTANT): GPS fix at: 1398465443.34 2014-04-25T22:37:23.377Z,1398465443.377 [EcoHAB_box:SurfaceComms:C:C] Stopped 2014-04-25T22:37:23.378Z,1398465443.378 [EcoHAB_box:SurfaceComms:C](INFO): Completed EcoHAB_box:SurfaceComms:C 2014-04-25T22:37:23.378Z,1398465443.378 [EcoHAB_box:SurfaceComms:C] Stopped 2014-04-25T22:37:23.378Z,1398465443.378 [EcoHAB_box:SurfaceComms:C](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceComms:C 2014-04-25T22:37:23.379Z,1398465443.379 [EcoHAB_box:SurfaceComms](INFO): Completed EcoHAB_box:SurfaceComms 2014-04-25T22:37:23.379Z,1398465443.379 [EcoHAB_box:SurfaceComms] Stopped 2014-04-25T22:37:23.379Z,1398465443.379 [EcoHAB_box:SurfaceComms](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceComms 2014-04-25T22:37:23.379Z,1398465443.379 [EcoHAB_box:SurfaceComms:A.GoToSurface] Stopped 2014-04-25T22:37:23.379Z,1398465443.379 [EcoHAB_box:SurfaceComms:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-25T22:37:23.380Z,1398465443.380 [EcoHAB_box:SurfaceGPS] Running Loop=1 2014-04-25T22:37:23.380Z,1398465443.380 [EcoHAB_box:SurfaceGPS](INFO): Aggregate::initialize EcoHAB_box:SurfaceGPS 2014-04-25T22:37:23.380Z,1398465443.380 [EcoHAB_box:SurfaceGPS:A.GoToSurface] Running Loop=1 2014-04-25T22:37:23.380Z,1398465443.380 [EcoHAB_box:SurfaceGPS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-25T22:37:23.828Z,1398465443.828 [EcoHAB_box:M.Buoyancy] Running Loop=1 2014-04-25T22:37:23.829Z,1398465443.829 [EcoHAB_box:L.Pitch] Running Loop=1 2014-04-25T22:37:23.835Z,1398465443.835 [EcoHAB_box:SurfaceGPS:GetFix] Running Loop=1 2014-04-25T22:37:23.835Z,1398465443.835 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Aggregate::initialize EcoHAB_box:SurfaceGPS:GetFix 2014-04-25T22:37:23.835Z,1398465443.835 [EcoHAB_box:SurfaceGPS:GetFix:A] Running Loop=1 2014-04-25T22:37:24.317Z,1398465444.317 [EcoHAB_box:SurfaceGPS:GetFix:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-25T22:37:24.709Z,1398465444.709 [NAL9602](INFO): No messages in MT queue 2014-04-25T22:37:28.734Z,1398465448.734 [NAL9602](IMPORTANT): GPS fix at: 1398465448.73 2014-04-25T22:37:28.755Z,1398465448.755 [EcoHAB_box:SurfaceGPS:GetFix:A] Stopped 2014-04-25T22:37:28.756Z,1398465448.756 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Completed EcoHAB_box:SurfaceGPS:GetFix 2014-04-25T22:37:28.756Z,1398465448.756 [EcoHAB_box:SurfaceGPS:GetFix] Stopped 2014-04-25T22:37:28.756Z,1398465448.756 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceGPS:GetFix 2014-04-25T22:37:28.756Z,1398465448.756 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Running loop #2 2014-04-25T22:37:28.756Z,1398465448.756 [EcoHAB_box:SurfaceGPS:GetFix] Running Loop=2 2014-04-25T22:37:28.756Z,1398465448.756 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Aggregate::initialize EcoHAB_box:SurfaceGPS:GetFix 2014-04-25T22:37:28.756Z,1398465448.756 [EcoHAB_box:SurfaceGPS:GetFix:A] Running Loop=1 2014-04-25T22:37:33.161Z,1398465453.161 [NAL9602](IMPORTANT): GPS fix at: 1398465453.15 2014-04-25T22:37:33.180Z,1398465453.180 [EcoHAB_box:SurfaceGPS:GetFix:A] Stopped 2014-04-25T22:37:33.180Z,1398465453.180 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Completed EcoHAB_box:SurfaceGPS:GetFix 2014-04-25T22:37:33.181Z,1398465453.181 [EcoHAB_box:SurfaceGPS:GetFix] Stopped 2014-04-25T22:37:33.181Z,1398465453.181 [EcoHAB_box:SurfaceGPS:GetFix](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceGPS:GetFix 2014-04-25T22:37:33.181Z,1398465453.181 [EcoHAB_box:SurfaceGPS](INFO): Completed EcoHAB_box:SurfaceGPS 2014-04-25T22:37:33.182Z,1398465453.182 [EcoHAB_box:SurfaceGPS] Stopped 2014-04-25T22:37:33.182Z,1398465453.182 [EcoHAB_box:SurfaceGPS](INFO): Aggregate::uninitialize EcoHAB_box:SurfaceGPS 2014-04-25T22:37:33.182Z,1398465453.182 [EcoHAB_box:SurfaceGPS:A.GoToSurface] Stopped 2014-04-25T22:37:33.182Z,1398465453.182 [EcoHAB_box:SurfaceGPS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-25T22:37:33.182Z,1398465453.182 [EcoHAB_box:Approach] Running Loop=1 2014-04-25T22:37:33.183Z,1398465453.183 [EcoHAB_box:Approach](INFO): Aggregate::initialize EcoHAB_box:Approach 2014-04-25T22:37:33.183Z,1398465453.183 [EcoHAB_box:Approach:B.Pitch] Running Loop=1 2014-04-25T22:37:33.183Z,1398465453.183 [EcoHAB_box:Approach:B.Pitch](DEBUG): Initialize. 2014-04-25T22:37:33.183Z,1398465453.183 [EcoHAB_box:Approach:C.SetSpeed] Running Loop=1 2014-04-25T22:37:33.183Z,1398465453.183 [EcoHAB_box:Approach:C.SetSpeed](DEBUG): Initialize. 2014-04-25T22:37:33.183Z,1398465453.183 [EcoHAB_box:Approach:WpApproach.Waypoint] Running Loop=1 2014-04-25T22:37:33.183Z,1398465453.183 [EcoHAB_box:Approach:WpApproach.Waypoint](DEBUG): Initialize WaypointComponent. 2014-04-25T22:37:33.647Z,1398465453.647 [EcoHAB_box:Approach:C.SetSpeed] Running Loop=1 2014-04-25T22:37:33.665Z,1398465453.665 [EcoHAB_box:Approach:B.Pitch] Running Loop=1 2014-04-25T22:37:37.900Z,1398465457.900 [Radio_Freewave](INFO): Powering down 2014-04-25T22:37:39.428Z,1398465459.428 [NAL9602](INFO): Powering down 2014-04-25T22:37:45.083Z,1398465465.083 [CommandLine](IMPORTANT): got command get depth 2014-04-25T22:37:45.083Z,1398465465.083 [CommandLine](IMPORTANT): depth 1.654200 m 2014-04-25T22:37:47.863Z,1398465467.863 [CommandLine](IMPORTANT): got command get depth 2014-04-25T22:37:47.864Z,1398465467.864 [CommandLine](IMPORTANT): depth 1.818957 m 2014-04-25T22:37:50.487Z,1398465470.487 [CommandLine](IMPORTANT): got command get depth 2014-04-25T22:37:50.488Z,1398465470.488 [CommandLine](IMPORTANT): depth 1.833857 m 2014-04-25T22:37:55.030Z,1398465475.030 [CommandLine](IMPORTANT): got command report mod depth 2014-04-25T22:37:55.600Z,1398465475.600 [Reporter](INFO): depth 1.535037 m 2014-04-25T22:37:56.069Z,1398465476.069 [Reporter](INFO): depth 1.476245 m 2014-04-25T22:37:56.543Z,1398465476.543 [Reporter](INFO): depth 1.426967 m 2014-04-25T22:37:56.986Z,1398465476.986 [Reporter](INFO): depth 1.374745 m 2014-04-25T22:37:57.560Z,1398465477.560 [Reporter](INFO): depth 1.323912 m 2014-04-25T22:37:58.060Z,1398465478.060 [Reporter](INFO): depth 1.255339 m 2014-04-25T22:37:58.661Z,1398465478.661 [Reporter](INFO): depth 1.193092 m 2014-04-25T22:37:59.091Z,1398465479.091 [Reporter](INFO): depth 1.115482 m 2014-04-25T22:37:59.570Z,1398465479.570 [Reporter](INFO): depth 1.057969 m 2014-04-25T22:38:00.004Z,1398465480.004 [Reporter](INFO): depth 0.992068 m 2014-04-25T22:38:00.508Z,1398465480.508 [Reporter](INFO): depth 0.931410 m 2014-04-25T22:38:01.013Z,1398465481.013 [Reporter](INFO): depth 0.859419 m 2014-04-25T22:38:01.569Z,1398465481.569 [Reporter](INFO): depth 0.785996 m 2014-04-25T22:38:02.067Z,1398465482.067 [Reporter](INFO): depth 0.703596 m 2014-04-25T22:38:02.524Z,1398465482.524 [Reporter](INFO): depth 0.628410 m 2014-04-25T22:38:03.072Z,1398465483.072 [Reporter](INFO): depth 0.558559 m 2014-04-25T22:38:03.463Z,1398465483.463 [Radio_Freewave](INFO): Powering up 2014-04-25T22:38:03.662Z,1398465483.662 [Reporter](INFO): depth 0.474297 m 2014-04-25T22:38:04.174Z,1398465484.174 [Reporter](INFO): depth 0.382922 m 2014-04-25T22:38:04.558Z,1398465484.558 [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-04-25T22:38:04.704Z,1398465484.704 [Reporter](INFO): depth 0.303179 m 2014-04-25T22:38:05.212Z,1398465485.212 [Reporter](INFO): depth 0.220022 m 2014-04-25T22:38:05.657Z,1398465485.657 [Reporter](INFO): depth 0.140100 m 2014-04-25T22:38:06.162Z,1398465486.162 [Reporter](INFO): depth 0.070113 m 2014-04-25T22:38:06.677Z,1398465486.677 [Reporter](INFO): depth -0.007101 m 2014-04-25T22:38:07.146Z,1398465487.146 [Reporter](INFO): depth -0.006381 m 2014-04-25T22:38:07.706Z,1398465487.706 [Reporter](INFO): depth 0.020674 m 2014-04-25T22:38:08.218Z,1398465488.218 [Reporter](INFO): depth 0.033636 m 2014-04-25T22:38:08.713Z,1398465488.713 [Reporter](INFO): depth 0.034140 m 2014-04-25T22:38:09.198Z,1398465489.198 [Reporter](INFO): depth 0.026909 m 2014-04-25T22:38:09.635Z,1398465489.635 [Reporter](INFO): depth 0.014033 m 2014-04-25T22:38:10.159Z,1398465490.159 [Reporter](INFO): depth -0.001230 m 2014-04-25T22:38:10.655Z,1398465490.655 [Reporter](INFO): depth 0.001201 m 2014-04-25T22:38:11.101Z,1398465491.101 [Reporter](INFO): depth 0.002782 m 2014-04-25T22:38:11.603Z,1398465491.603 [Reporter](INFO): depth -0.000605 m 2014-04-25T22:38:12.046Z,1398465492.046 [Reporter](INFO): depth -0.000078 m 2014-04-25T22:38:12.559Z,1398465492.559 [Reporter](INFO): depth -0.000065 m 2014-04-25T22:38:13.008Z,1398465493.008 [Reporter](INFO): depth -0.000062 m 2014-04-25T22:38:13.521Z,1398465493.521 [Reporter](INFO): depth -0.000054 m 2014-04-25T22:38:13.535Z,1398465493.535 [CommandLine](IMPORTANT): got command report clear 2014-04-25T22:38:16.151Z,1398465496.151 [CommandLine](IMPORTANT): got command show best depth 2014-04-25T22:38:16.151Z,1398465496.151 [CommandLine](IMPORTANT): depth best is Depth_Keller.depth 2014-04-25T22:39:02.628Z,1398465542.628 [Radio_Freewave](INFO): Powering down 2014-04-25T22:39:07.414Z,1398465547.414 [CommandLine](IMPORTANT): got command restart application 2014-04-25T22:39:08.419Z,1398465548.419 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2014-04-25T22:39:08.419Z,1398465548.419 [CommandLine ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:08.464Z,1398465548.464 [EcoHAB_box] Stopped 2014-04-25T22:39:08.464Z,1398465548.464 [EcoHAB_box](INFO): Aggregate::uninitialize EcoHAB_box 2014-04-25T22:39:08.464Z,1398465548.464 [EcoHAB_box:A.AltitudeEnvelope] Stopped 2014-04-25T22:39:08.464Z,1398465548.464 [EcoHAB_box:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2014-04-25T22:39:08.464Z,1398465548.464 [EcoHAB_box:B.DepthEnvelope] Stopped 2014-04-25T22:39:08.464Z,1398465548.464 [EcoHAB_box:B.DepthEnvelope](DEBUG): Uninitialize. 2014-04-25T22:39:08.464Z,1398465548.464 [EcoHAB_box:C.OffshoreEnvelope] Stopped 2014-04-25T22:39:08.465Z,1398465548.465 [EcoHAB_box:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2014-04-25T22:39:08.465Z,1398465548.465 [EcoHAB_box:L.Pitch] Stopped 2014-04-25T22:39:08.465Z,1398465548.465 [EcoHAB_box:M.Buoyancy] Stopped 2014-04-25T22:39:08.465Z,1398465548.465 [EcoHAB_box:M.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2014-04-25T22:39:08.465Z,1398465548.465 [EcoHAB_box:Approach] Stopped 2014-04-25T22:39:08.465Z,1398465548.465 [EcoHAB_box:Approach](INFO): Aggregate::uninitialize EcoHAB_box:Approach 2014-04-25T22:39:08.465Z,1398465548.465 [EcoHAB_box:Approach:B.Pitch] Stopped 2014-04-25T22:39:08.465Z,1398465548.465 [EcoHAB_box:Approach:C.SetSpeed] Stopped 2014-04-25T22:39:08.466Z,1398465548.466 [EcoHAB_box:Approach:C.SetSpeed](DEBUG): Uninitialize. 2014-04-25T22:39:08.466Z,1398465548.466 [EcoHAB_box:Approach:WpApproach.Waypoint] Stopped 2014-04-25T22:39:08.466Z,1398465548.466 [EcoHAB_box:Approach:WpApproach.Waypoint](DEBUG): Uninitialize WaypointComponent. 2014-04-25T22:39:08.592Z,1398465548.592 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2014-04-25T22:39:08.592Z,1398465548.592 [CommandLine ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:08.593Z,1398465548.593 [CommandLine](INFO): Join timeout helper Thread ID is 1817 2014-04-25T22:39:08.600Z,1398465548.600 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2014-04-25T22:39:08.600Z,1398465548.600 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:08.600Z,1398465548.600 [NavChartDb](INFO): Join timeout helper Thread ID is 1818 2014-04-25T22:39:08.740Z,1398465548.740 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2014-04-25T22:39:08.741Z,1398465548.741 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:08.748Z,1398465548.748 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2014-04-25T22:39:08.748Z,1398465548.748 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:08.748Z,1398465548.748 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1819 2014-04-25T22:39:09.024Z,1398465549.024 [MissionManager](IMPORTANT): Started mission Default 2014-04-25T22:39:09.024Z,1398465549.024 [Default] Running Loop=1 2014-04-25T22:39:09.024Z,1398465549.024 [Default](INFO): Aggregate::initialize Default 2014-04-25T22:39:09.025Z,1398465549.025 [Default:Iridium] Running Loop=1 2014-04-25T22:39:09.025Z,1398465549.025 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-25T22:39:09.025Z,1398465549.025 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-25T22:39:09.025Z,1398465549.025 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-25T22:39:09.025Z,1398465549.025 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-25T22:39:09.025Z,1398465549.025 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-25T22:39:09.027Z,1398465549.027 [Default:GPS] Running Loop=1 2014-04-25T22:39:09.027Z,1398465549.027 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-25T22:39:09.027Z,1398465549.027 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-25T22:39:09.027Z,1398465549.027 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-25T22:39:09.027Z,1398465549.027 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-25T22:39:09.027Z,1398465549.027 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-25T22:39:09.103Z,1398465549.103 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2014-04-25T22:39:09.104Z,1398465549.104 [WetLabsBB2FL](INFO): Powering down 2014-04-25T22:39:09.105Z,1398465549.105 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.108Z,1398465549.108 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2014-04-25T22:39:09.109Z,1398465549.109 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.109Z,1398465549.109 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1821 2014-04-25T22:39:09.393Z,1398465549.393 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2014-04-25T22:39:09.393Z,1398465549.393 [CTD_NeilBrown](INFO): Powering down 2014-04-25T22:39:09.394Z,1398465549.394 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.409Z,1398465549.409 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2014-04-25T22:39:09.409Z,1398465549.409 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.410Z,1398465549.410 [AsyncPiEstimator](INFO): Join timeout helper Thread ID is 1822 2014-04-25T22:39:09.469Z,1398465549.469 [AsyncPiEstimator ThreadHandler](INFO): Uninitializing protected caller thread. 2014-04-25T22:39:09.470Z,1398465549.470 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2014-04-25T22:39:09.470Z,1398465549.470 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.491Z,1398465549.491 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2014-04-25T22:39:09.491Z,1398465549.491 [logger ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.492Z,1398465549.492 [logger](INFO): Join timeout helper Thread ID is 1823 2014-04-25T22:39:09.492Z,1398465549.492 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2014-04-25T22:39:09.492Z,1398465549.492 [logger ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.498Z,1398465549.498 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2014-04-25T22:39:09.498Z,1398465549.498 [CommandLine ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.498Z,1398465549.498 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2014-04-25T22:39:09.498Z,1398465549.498 [controlThread ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.499Z,1398465549.499 [controlThread](INFO): Join timeout helper Thread ID is 1824 2014-04-25T22:39:09.561Z,1398465549.561 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2014-04-25T22:39:09.561Z,1398465549.561 [controlThread](DEBUG): Uninitializing ControlThread 2014-04-25T22:39:09.562Z,1398465549.562 [AHRS_sp3003D](INFO): Powering down 2014-04-25T22:39:09.563Z,1398465549.563 [DVL_micro](INFO): uninitialize:Powering down 2014-04-25T22:39:09.564Z,1398465549.564 [NAL9602](INFO): Powering down 2014-04-25T22:39:09.578Z,1398465549.578 [Radio_Freewave](INFO): Powering down 2014-04-25T22:39:09.582Z,1398465549.582 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-25T22:39:09.583Z,1398465549.583 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2014-04-25T22:39:09.584Z,1398465549.584 [Default] Stopped 2014-04-25T22:39:09.584Z,1398465549.584 [Default](INFO): Aggregate::uninitialize Default 2014-04-25T22:39:09.584Z,1398465549.584 [Default:GPS] Stopped 2014-04-25T22:39:09.585Z,1398465549.585 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-25T22:39:09.585Z,1398465549.585 [Default:GPS:A.SetSpeed] Stopped 2014-04-25T22:39:09.585Z,1398465549.585 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-25T22:39:09.585Z,1398465549.585 [Default:GPS:B.GoToSurface] Stopped 2014-04-25T22:39:09.589Z,1398465549.589 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-25T22:39:09.590Z,1398465549.590 [Default:Iridium] Stopped 2014-04-25T22:39:09.590Z,1398465549.590 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-25T22:39:09.590Z,1398465549.590 [Default:Iridium:A.SetSpeed] Stopped 2014-04-25T22:39:09.590Z,1398465549.590 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-25T22:39:09.590Z,1398465549.590 [Default:Iridium:B.GoToSurface] Stopped 2014-04-25T22:39:09.590Z,1398465549.590 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-25T22:39:09.606Z,1398465549.606 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2014-04-25T22:39:09.606Z,1398465549.606 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2014-04-25T22:39:09.606Z,1398465549.606 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2014-04-25T22:39:09.607Z,1398465549.607 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2014-04-25T22:39:09.607Z,1398465549.607 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2014-04-25T22:39:09.608Z,1398465549.608 [BuoyancyServo](INFO): Powering down 2014-04-25T22:39:09.626Z,1398465549.626 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2014-04-25T22:39:09.626Z,1398465549.626 [ElevatorServo](INFO): Powering down 2014-04-25T22:39:09.628Z,1398465549.628 [MassServo](DEBUG): Uninitialize Mass Servo. 2014-04-25T22:39:09.628Z,1398465549.628 [MassServo](INFO): Powering down 2014-04-25T22:39:09.629Z,1398465549.629 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2014-04-25T22:39:09.629Z,1398465549.629 [RudderServo](INFO): Powering down 2014-04-25T22:39:09.630Z,1398465549.630 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2014-04-25T22:39:09.631Z,1398465549.631 [SBIT](DEBUG): Uninitialize SBIT Component. 2014-04-25T22:39:09.631Z,1398465549.631 [IBIT](DEBUG): Uninitialize IBIT Component. 2014-04-25T22:39:09.631Z,1398465549.631 [CBIT](DEBUG): Uninitialize CBIT Component. 2014-04-25T22:39:09.663Z,1398465549.663 [controlThread ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.766Z,1398465549.766 [AsyncPiEstimator ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.789Z,1398465549.789 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:09.793Z,1398465549.793 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:10.297Z,1398465550.297 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2014-04-25T22:39:10.357Z,1398465550.357 [logger ThreadHandler](INFO): Thread cancelled.