2012-10-04T23:08:02.578Z,1349392082.578 [Supervisor](DEBUG): Initializing supervisor. 2012-10-04T23:08:02.587Z,1349392082.587 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2012-10-04T23:08:02.588Z,1349392082.588 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2012-10-04T23:08:02.591Z,1349392082.591 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2012-10-04T23:08:02.595Z,1349392082.595 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2012-10-04T23:08:02.606Z,1349392082.606 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2012-10-04T23:08:02.611Z,1349392082.611 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2012-10-04T23:08:02.612Z,1349392082.612 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread. 2012-10-04T23:08:02.612Z,1349392082.612 [Supervisor](INFO): Looking for Config files in directory: Config/ 2012-10-04T23:08:02.615Z,1349392082.615 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2012-10-04T23:08:02.938Z,1349392082.938 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2012-10-04T23:08:02.941Z,1349392082.941 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2012-10-04T23:08:03.146Z,1349392083.146 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2012-10-04T23:08:03.147Z,1349392083.147 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2012-10-04T23:08:03.242Z,1349392083.242 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2012-10-04T23:08:03.244Z,1349392083.244 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2012-10-04T23:08:03.470Z,1349392083.470 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2012-10-04T23:08:03.471Z,1349392083.471 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2012-10-04T23:08:03.622Z,1349392083.622 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2012-10-04T23:08:03.624Z,1349392083.625 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2012-10-04T23:08:03.892Z,1349392083.892 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2012-10-04T23:08:03.893Z,1349392083.893 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2012-10-04T23:08:04.082Z,1349392084.082 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2012-10-04T23:08:04.085Z,1349392084.085 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2012-10-04T23:08:04.376Z,1349392084.376 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2012-10-04T23:08:04.378Z,1349392084.378 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2012-10-04T23:08:04.492Z,1349392084.492 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2012-10-04T23:08:04.492Z,1349392084.492 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2012-10-04T23:08:04.948Z,1349392084.948 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2012-10-04T23:08:04.949Z,1349392084.949 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2012-10-04T23:08:05.077Z,1349392085.077 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2012-10-04T23:08:05.078Z,1349392085.078 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2012-10-04T23:08:05.172Z,1349392085.172 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2012-10-04T23:08:05.176Z,1349392085.176 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2012-10-04T23:08:05.291Z,1349392085.291 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2012-10-04T23:08:05.436Z,1349392085.436 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2012-10-04T23:08:05.535Z,1349392085.535 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2012-10-04T23:08:05.647Z,1349392085.647 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2012-10-04T23:08:05.759Z,1349392085.759 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2012-10-04T23:08:05.893Z,1349392085.893 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2012-10-04T23:08:06.004Z,1349392086.003 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2012-10-04T23:08:06.168Z,1349392086.168 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2012-10-04T23:08:06.204Z,1349392086.204 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2012-10-04T23:08:06.409Z,1349392086.409 [InternalSim] Loaded 2012-10-04T23:08:06.409Z,1349392086.409 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2012-10-04T23:08:06.410Z,1349392086.410 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2012-10-04T23:08:06.411Z,1349392086.411 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2012-10-04T23:08:06.503Z,1349392086.503 [SBIT](DEBUG): Construct Startup Built In Test. 2012-10-04T23:08:06.517Z,1349392086.517 [SBIT] Loaded 2012-10-04T23:08:06.517Z,1349392086.517 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2012-10-04T23:08:06.518Z,1349392086.518 [IBIT](DEBUG): Construct Initiated Built In Test. 2012-10-04T23:08:06.552Z,1349392086.552 [IBIT] Loaded 2012-10-04T23:08:06.552Z,1349392086.552 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2012-10-04T23:08:06.556Z,1349392086.556 [CBIT](DEBUG): Construct CBIT Built In Test. 2012-10-04T23:08:06.694Z,1349392086.694 [CBIT] Loaded 2012-10-04T23:08:06.694Z,1349392086.694 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2012-10-04T23:08:06.699Z,1349392086.699 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2012-10-04T23:08:06.700Z,1349392086.700 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2012-10-04T23:08:06.877Z,1349392086.877 [BuoyancyServo] Loaded 2012-10-04T23:08:06.878Z,1349392086.878 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2012-10-04T23:08:06.891Z,1349392086.891 [MassServo] Loaded 2012-10-04T23:08:06.891Z,1349392086.891 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2012-10-04T23:08:06.904Z,1349392086.904 [RudderServo] Loaded 2012-10-04T23:08:06.904Z,1349392086.904 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2012-10-04T23:08:06.905Z,1349392086.905 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2012-10-04T23:08:06.905Z,1349392086.905 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2012-10-04T23:08:06.942Z,1349392086.942 [DepthRateCalculator] Loaded 2012-10-04T23:08:06.943Z,1349392086.943 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2012-10-04T23:08:11.904Z,1349392091.904 [HFRadarModelCalc] Loaded 2012-10-04T23:08:11.905Z,1349392091.905 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2012-10-04T23:08:11.922Z,1349392091.922 [NavChart] Loaded 2012-10-04T23:08:11.923Z,1349392091.922 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2012-10-04T23:08:11.933Z,1349392091.933 [PitchRateCalculator] Loaded 2012-10-04T23:08:11.933Z,1349392091.933 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2012-10-04T23:08:11.940Z,1349392091.940 [SpeedCalculator] Loaded 2012-10-04T23:08:11.940Z,1349392091.940 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2012-10-04T23:08:11.956Z,1349392091.956 [TempGradientCalculator] Loaded 2012-10-04T23:08:11.957Z,1349392091.957 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2012-10-04T23:08:11.963Z,1349392091.963 [YawRateCalculator] Loaded 2012-10-04T23:08:11.963Z,1349392091.963 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2012-10-04T23:08:11.987Z,1349392091.987 [Navigation] Loaded 2012-10-04T23:08:11.988Z,1349392091.988 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2012-10-04T23:08:11.988Z,1349392091.988 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2012-10-04T23:08:11.989Z,1349392091.989 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2012-10-04T23:08:12.301Z,1349392092.301 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2012-10-04T23:08:12.302Z,1349392092.302 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2012-10-04T23:08:12.346Z,1349392092.346 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2012-10-04T23:08:12.346Z,1349392092.346 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2012-10-04T23:08:12.413Z,1349392092.413 [VerticalControl](DEBUG): Construct VerticalControl. 2012-10-04T23:08:12.463Z,1349392092.463 [VerticalControl] Loaded 2012-10-04T23:08:12.463Z,1349392092.463 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2012-10-04T23:08:12.464Z,1349392092.464 [HorizontalControl](DEBUG): Construct HorizontalControl. 2012-10-04T23:08:12.490Z,1349392092.490 [HorizontalControl] Loaded 2012-10-04T23:08:12.490Z,1349392092.490 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2012-10-04T23:08:12.491Z,1349392092.491 [SpeedControl](DEBUG): Construct SpeedControl. 2012-10-04T23:08:12.493Z,1349392092.493 [SpeedControl] Loaded 2012-10-04T23:08:12.493Z,1349392092.493 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2012-10-04T23:08:12.494Z,1349392092.494 [LoopControl](DEBUG): Construct LoopControl. 2012-10-04T23:08:12.495Z,1349392092.495 [LoopControl] Loaded 2012-10-04T23:08:12.495Z,1349392092.495 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2012-10-04T23:08:12.496Z,1349392092.496 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2012-10-04T23:08:12.496Z,1349392092.497 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2012-10-04T23:08:12.504Z,1349392092.504 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2012-10-04T23:08:12.510Z,1349392092.510 [AsyncPiEstimator] Loaded 2012-10-04T23:08:12.510Z,1349392092.510 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2012-10-04T23:08:12.515Z,1349392092.515 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406714E0 2012-10-04T23:08:12.516Z,1349392092.516 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2012-10-04T23:08:12.516Z,1349392092.516 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2012-10-04T23:08:12.704Z,1349392092.704 [AHRS_sp3003D] Loaded 2012-10-04T23:08:12.704Z,1349392092.704 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2012-10-04T23:08:12.723Z,1349392092.723 [Depth_Keller] Loaded 2012-10-04T23:08:12.724Z,1349392092.724 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2012-10-04T23:08:12.729Z,1349392092.730 [DropWeight] Loaded 2012-10-04T23:08:12.730Z,1349392092.730 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2012-10-04T23:08:12.865Z,1349392092.865 [DVL_micro] Loaded 2012-10-04T23:08:12.866Z,1349392092.866 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2012-10-04T23:08:12.871Z,1349392092.871 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 406F14E0 2012-10-04T23:08:12.968Z,1349392092.968 [NAL9602] Loaded 2012-10-04T23:08:12.968Z,1349392092.968 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2012-10-04T23:08:13.032Z,1349392093.032 [Onboard] Loaded 2012-10-04T23:08:13.032Z,1349392093.032 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2012-10-04T23:08:13.039Z,1349392093.039 [Radio_Freewave] Loaded 2012-10-04T23:08:13.039Z,1349392093.039 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2012-10-04T23:08:13.040Z,1349392093.040 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2012-10-04T23:08:13.041Z,1349392093.041 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2012-10-04T23:08:13.120Z,1349392093.120 [PAR_Licor] Loaded 2012-10-04T23:08:13.120Z,1349392093.121 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2012-10-04T23:08:13.138Z,1349392093.138 [Turbulence_NPS] Loaded 2012-10-04T23:08:13.138Z,1349392093.138 [ComponentRegistry](DEBUG): Component "Turbulence_NPS" handled in its own thread. 2012-10-04T23:08:13.143Z,1349392093.143 [Turbulence_NPS ThreadHandler](DEBUG): Created PCaller Thread at 407494E0 2012-10-04T23:08:13.178Z,1349392093.178 [WetLabsBB2FL] Loaded 2012-10-04T23:08:13.178Z,1349392093.178 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2012-10-04T23:08:13.183Z,1349392093.183 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407794E0 2012-10-04T23:08:13.184Z,1349392093.184 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2012-10-04T23:08:13.186Z,1349392093.186 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2012-10-04T23:08:13.187Z,1349392093.187 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2012-10-04T23:08:13.197Z,1349392093.197 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2012-10-04T23:08:13.199Z,1349392093.199 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407A94E0 2012-10-04T23:08:13.204Z,1349392093.204 [Supervisor](DEBUG): Running supervisor. 2012-10-04T23:08:13.205Z,1349392093.205 [CommandLine](INFO): Thread ID is 749 2012-10-04T23:08:13.208Z,1349392093.208 [controlThread](INFO): Thread ID is 748 2012-10-04T23:08:13.208Z,1349392093.208 [controlThread](DEBUG): Initializing ControlThread 2012-10-04T23:08:13.208Z,1349392093.208 [CycleStarter](INFO): Thread ID is 747 2012-10-04T23:08:13.209Z,1349392093.209 [InternalSim](DEBUG): InternalSim initializing... 2012-10-04T23:08:13.315Z,1349392093.315 [AsyncPiEstimator](INFO): Thread ID is 810 2012-10-04T23:08:13.315Z,1349392093.315 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2012-10-04T23:08:13.386Z,1349392093.386 [DVL_micro](INFO): Thread ID is 811 2012-10-04T23:08:13.469Z,1349392093.469 [Turbulence_NPS](INFO): Thread ID is 812 2012-10-04T23:08:13.470Z,1349392093.470 [Turbulence_NPS](DEBUG): Initializing Turbulence_NPS. 2012-10-04T23:08:13.471Z,1349392093.471 [Turbulence_NPS](INFO): Opening uart, block timeout 10ths=1 2012-10-04T23:08:13.495Z,1349392093.494 [DVL_micro](INFO): Initializing 2012-10-04T23:08:13.497Z,1349392093.497 [DVL_micro](INFO): start:Powering up 2012-10-04T23:08:13.497Z,1349392093.497 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-10-04T23:08:13.498Z,1349392093.498 [DVL_micro](INFO): Cycling power to configure device. 2012-10-04T23:08:13.525Z,1349392093.525 [WetLabsBB2FL](INFO): Thread ID is 813 2012-10-04T23:08:13.525Z,1349392093.525 [WetLabsBB2FL](INFO): Powering down 2012-10-04T23:08:13.542Z,1349392093.542 [SBIT](INFO): Initialize SBIT Component. 2012-10-04T23:08:13.542Z,1349392093.542 [SBIT](IMPORTANT): Tethys CM Info: $Rev: 9922 2012-10-04T23:08:13.552Z,1349392093.552 [NavChartDb](INFO): Thread ID is 814 2012-10-04T23:08:13.553Z,1349392093.553 [IBIT](INFO): Initialize IBIT Component. 2012-10-04T23:08:13.560Z,1349392093.560 [CBIT](DEBUG): Initialize CBIT Component. 2012-10-04T23:08:13.691Z,1349392093.691 [Turbulence_NPS](INFO): Pause powering down 2012-10-04T23:08:13.703Z,1349392093.703 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2012-10-04T23:08:13.703Z,1349392093.704 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2012-10-04T23:08:13.704Z,1349392093.704 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2012-10-04T23:08:13.705Z,1349392093.705 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2012-10-04T23:08:13.705Z,1349392093.705 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2012-10-04T23:08:13.706Z,1349392093.706 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2012-10-04T23:08:13.706Z,1349392093.706 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2012-10-04T23:08:13.932Z,1349392093.932 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2012-10-04T23:08:13.932Z,1349392093.932 [NavChart](DEBUG): Initialize NavChart Derivation. 2012-10-04T23:08:13.933Z,1349392093.933 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2012-10-04T23:08:13.933Z,1349392093.933 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2012-10-04T23:08:13.933Z,1349392093.933 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2012-10-04T23:08:13.935Z,1349392093.935 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2012-10-04T23:08:13.935Z,1349392093.935 [Navigation](DEBUG): Initializing Navigation. 2012-10-04T23:08:13.936Z,1349392093.936 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2012-10-04T23:08:13.937Z,1349392093.937 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2012-10-04T23:08:13.938Z,1349392093.938 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2012-10-04T23:08:13.939Z,1349392093.939 [LoopControl](DEBUG): Initialize LoopControlComponent. 2012-10-04T23:08:13.953Z,1349392093.953 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2012-10-04T23:08:14.323Z,1349392094.323 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2012-10-04T23:08:14.333Z,1349392094.333 [MissionManager](DEBUG): 2012-10-04T23:08:14.334Z,1349392094.334 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2012-10-04T23:08:14.437Z,1349392094.437 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2012-10-04T23:08:14.440Z,1349392094.440 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2012-10-04T23:08:14.442Z,1349392094.443 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-10-04T23:08:14.452Z,1349392094.452 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2012-10-04T23:08:14.459Z,1349392094.459 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2012-10-04T23:08:14.466Z,1349392094.466 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2012-10-04T23:08:14.475Z,1349392094.475 [Default:D.SetSpeed](DEBUG): Construct. 2012-10-04T23:08:14.482Z,1349392094.482 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2012-10-04T23:08:14.487Z,1349392094.487 [Default:F.Wait](DEBUG): Construct Wait. 2012-10-04T23:08:14.490Z,1349392094.490 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2012-10-04T23:08:14.494Z,1349392094.494 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,MassServo,RudderServo,SBIT,IBIT,CBIT,Reporter,logger, 2012-10-04T23:08:14.515Z,1349392094.515 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2012-10-04T23:08:14.687Z,1349392094.687 [Depth_Keller](INFO): A/D timeout, 2 tries over 158 ms 2012-10-04T23:08:14.688Z,1349392094.688 [Depth_Keller] Data Fault, FailCount= 1 2012-10-04T23:08:14.688Z,1349392094.688 [Depth_Keller](ERROR): Data Fault 2012-10-04T23:08:14.750Z,1349392094.750 [Radio_Freewave](INFO): Powering up 2012-10-04T23:08:14.968Z,1349392094.968 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2012-10-04T23:08:14.971Z,1349392094.971 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2012-10-04T23:08:14.978Z,1349392094.978 [MassServo](DEBUG): Initializing EZServoServo. 2012-10-04T23:08:14.979Z,1349392094.979 [MassServo](DEBUG): Initializing MassServo. 2012-10-04T23:08:14.988Z,1349392094.988 [RudderServo](DEBUG): Initializing EZServoServo. 2012-10-04T23:08:14.991Z,1349392094.991 [RudderServo](DEBUG): Initializing RudderServo. 2012-10-04T23:08:15.009Z,1349392095.009 [CBIT](ERROR): Data Fault in component: Depth_Keller 2012-10-04T23:08:15.009Z,1349392095.009 [CBIT](INFO): Clearing failed state for component Depth_Keller 2012-10-04T23:08:15.009Z,1349392095.009 [Depth_Keller] No Fault, FailCount= 1 2012-10-04T23:08:15.715Z,1349392095.715 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2012-10-04T23:08:15.716Z,1349392095.716 [DVL_micro](INFO): Querying output modes 2012-10-04T23:08:15.716Z,1349392095.716 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2012-10-04T23:08:15.719Z,1349392095.719 [DVL_micro](DEBUG): cmdResponse: 01 2012-10-04T23:08:15.719Z,1349392095.719 [DVL_micro](INFO): NQ1 output enabled 2012-10-04T23:08:15.720Z,1349392095.720 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2012-10-04T23:08:15.723Z,1349392095.723 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2012-10-04T23:08:15.729Z,1349392095.728 [DVL_micro](INFO): pause:Powering down 2012-10-04T23:08:18.384Z,1349392098.384 [NAL9602](INFO): Powering up NAL9602 2012-10-04T23:08:29.900Z,1349392109.899 [NAL9602](INFO): NAL9602 initialized 2012-10-04T23:08:30.290Z,1349392110.290 [SBIT](IMPORTANT): Beginning Startup BIT 2012-10-04T23:08:30.293Z,1349392110.293 [CBIT](IMPORTANT): Beginning GF scan 2012-10-04T23:08:32.424Z,1349392112.424 [Radio_Freewave](INFO): Powering down 2012-10-04T23:08:32.690Z,1349392112.690 [Radio_Freewave](INFO): Powering up 2012-10-04T23:08:58.487Z,1349392138.487 [CBIT](IMPORTANT): No ground fault detected 2012-10-04T23:09:24.830Z,1349392164.830 [SBIT](IMPORTANT): SBIT PASSED 2012-10-04T23:09:25.230Z,1349392165.230 [MissionManager](IMPORTANT): Started mission Startup 2012-10-04T23:09:25.230Z,1349392165.230 [Startup] Running Loop=1 2012-10-04T23:09:25.230Z,1349392165.230 [Startup](INFO): Aggregate::initialize Startup 2012-10-04T23:09:25.230Z,1349392165.230 [Startup:A.GoToSurface] Running Loop=1 2012-10-04T23:09:25.230Z,1349392165.230 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-10-04T23:09:25.236Z,1349392165.236 [Startup:StartupSatComms] Running Loop=1 2012-10-04T23:09:25.236Z,1349392165.236 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2012-10-04T23:09:25.236Z,1349392165.237 [Startup:StartupSatComms:A] Running Loop=1 2012-10-04T23:09:25.624Z,1349392165.625 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-10-04T23:10:25.628Z,1349392225.628 [Startup:StartupSatComms:A](INFO): Timed out from 2012-10-04T23:09:25.2Z 2012-10-04T23:10:25.628Z,1349392225.628 [Startup:StartupSatComms:A:A_Timeout] Running Loop=1 2012-10-04T23:10:25.628Z,1349392225.628 [Startup:StartupSatComms:A:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:A:A_Timeout 2012-10-04T23:10:25.629Z,1349392225.629 [Startup:StartupSatComms:A:A_Timeout](INFO): Completed Startup:StartupSatComms:A:A_Timeout 2012-10-04T23:10:25.629Z,1349392225.629 [Startup:StartupSatComms:A] Stopped 2012-10-04T23:10:25.629Z,1349392225.629 [Startup:StartupSatComms:B] Running Loop=1 2012-10-04T23:10:26.033Z,1349392226.033 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-10-04T23:10:28.397Z,1349392228.397 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:10:32.691Z,1349392232.691 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:10:36.599Z,1349392236.599 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:10:40.907Z,1349392240.907 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:10:45.615Z,1349392245.615 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:10:49.923Z,1349392249.923 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:10:54.631Z,1349392254.631 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:10:58.931Z,1349392258.931 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:03.239Z,1349392263.239 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:07.605Z,1349392267.605 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:11.505Z,1349392271.505 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:15.807Z,1349392275.807 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:20.511Z,1349392280.511 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:24.819Z,1349392284.819 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:25.632Z,1349392285.632 [Startup:StartupSatComms:B](INFO): Timed out from 2012-10-04T23:10:25.6Z 2012-10-04T23:11:25.632Z,1349392285.632 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1 2012-10-04T23:11:25.633Z,1349392285.633 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout 2012-10-04T23:11:25.633Z,1349392285.633 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout 2012-10-04T23:11:25.633Z,1349392285.633 [Startup:StartupSatComms:B] Stopped 2012-10-04T23:11:25.633Z,1349392285.633 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2012-10-04T23:11:25.633Z,1349392285.633 [Startup:StartupSatComms] Stopped 2012-10-04T23:11:25.633Z,1349392285.633 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2012-10-04T23:11:25.634Z,1349392285.634 [Startup](INFO): Completed Startup 2012-10-04T23:11:25.634Z,1349392285.634 [Startup] Stopped 2012-10-04T23:11:25.634Z,1349392285.634 [Startup](INFO): Aggregate::uninitialize Startup 2012-10-04T23:11:25.634Z,1349392285.634 [Startup:A.GoToSurface] Stopped 2012-10-04T23:11:25.635Z,1349392285.635 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-10-04T23:11:26.036Z,1349392286.036 [MissionManager](IMPORTANT): Started mission Default 2012-10-04T23:11:26.036Z,1349392286.036 [Default] Running Loop=1 2012-10-04T23:11:26.036Z,1349392286.036 [Default](INFO): Aggregate::initialize Default 2012-10-04T23:11:26.036Z,1349392286.036 [Default:D.SetSpeed] Running Loop=1 2012-10-04T23:11:26.036Z,1349392286.036 [Default:D.SetSpeed](DEBUG): Initialize. 2012-10-04T23:11:26.036Z,1349392286.036 [Default:E.GoToSurface] Running Loop=1 2012-10-04T23:11:26.036Z,1349392286.036 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-10-04T23:11:26.037Z,1349392286.037 [Default:Iridium] Running Loop=1 2012-10-04T23:11:26.037Z,1349392286.037 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2012-10-04T23:11:26.037Z,1349392286.037 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-10-04T23:11:26.037Z,1349392286.037 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2012-10-04T23:11:26.037Z,1349392286.037 [Default:Iridium:B.GoToSurface] Running Loop=1 2012-10-04T23:11:26.037Z,1349392286.037 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-10-04T23:11:26.038Z,1349392286.038 [Default:E.GoToSurface] Running Loop=1 2012-10-04T23:11:26.043Z,1349392286.043 [Default:D.SetSpeed] Running Loop=1 2012-10-04T23:11:26.048Z,1349392286.048 [Default:CallIridium] Running Loop=1 2012-10-04T23:11:26.048Z,1349392286.048 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2012-10-04T23:11:26.049Z,1349392286.049 [Default:CallIridium:A] Running Loop=1 2012-10-04T23:11:26.050Z,1349392286.050 [Default:CallIridium:A] Stopped 2012-10-04T23:11:26.050Z,1349392286.050 [Default:CallIridium:B] Running Loop=1 2012-10-04T23:11:26.051Z,1349392286.050 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2012-10-04T23:11:26.056Z,1349392286.056 [Default:Iridium:B.GoToSurface] Stopped 2012-10-04T23:11:26.056Z,1349392286.056 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-10-04T23:11:26.056Z,1349392286.056 [Default:Iridium:Read_Iridium] Running Loop=1 2012-10-04T23:11:26.056Z,1349392286.056 [Default:Iridium:A.SetSpeed] Running Loop=1 2012-10-04T23:11:26.061Z,1349392286.061 [Default:GPS] Running Loop=1 2012-10-04T23:11:26.061Z,1349392286.061 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2012-10-04T23:11:26.061Z,1349392286.061 [Default:GPS:A.SetSpeed] Running Loop=1 2012-10-04T23:11:26.061Z,1349392286.061 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2012-10-04T23:11:26.062Z,1349392286.062 [Default:GPS:B.GoToSurface] Running Loop=1 2012-10-04T23:11:26.062Z,1349392286.062 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2012-10-04T23:11:26.067Z,1349392286.067 [Default:GPS:B.GoToSurface] Stopped 2012-10-04T23:11:26.067Z,1349392286.067 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2012-10-04T23:11:26.067Z,1349392286.067 [Default:GPS:Read_GPS] Running Loop=1 2012-10-04T23:11:26.068Z,1349392286.068 [Default:GPS:A.SetSpeed] Running Loop=1 2012-10-04T23:11:26.437Z,1349392286.437 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2012-10-04T23:11:26.440Z,1349392286.440 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2012-10-04T23:11:29.524Z,1349392289.524 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:33.837Z,1349392293.837 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:38.543Z,1349392298.543 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:42.855Z,1349392302.855 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:47.563Z,1349392307.563 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:51.867Z,1349392311.867 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:11:56.183Z,1349392316.183 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:00.495Z,1349392320.495 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:04.409Z,1349392324.409 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:08.727Z,1349392328.727 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:13.439Z,1349392333.439 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:17.761Z,1349392337.761 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:22.455Z,1349392342.455 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:26.769Z,1349392346.769 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:31.471Z,1349392351.471 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:35.775Z,1349392355.775 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:40.487Z,1349392360.487 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:44.797Z,1349392364.797 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:49.095Z,1349392369.095 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:53.413Z,1349392373.413 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:12:57.317Z,1349392377.317 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:01.615Z,1349392381.615 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:06.323Z,1349392386.323 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:10.635Z,1349392390.635 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:15.343Z,1349392395.343 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:19.655Z,1349392399.655 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:24.367Z,1349392404.367 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:28.677Z,1349392408.677 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:33.375Z,1349392413.375 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:37.687Z,1349392417.687 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:42.391Z,1349392422.391 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:47.091Z,1349392427.091 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:51.413Z,1349392431.413 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:13:56.107Z,1349392436.107 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:00.421Z,1349392440.421 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:04.323Z,1349392444.323 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:08.635Z,1349392448.635 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:13.343Z,1349392453.343 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:17.653Z,1349392457.653 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:21.963Z,1349392461.963 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:26.271Z,1349392466.271 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:30.183Z,1349392470.183 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:34.495Z,1349392474.495 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:39.199Z,1349392479.199 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:43.519Z,1349392483.519 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:48.223Z,1349392488.223 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:52.535Z,1349392492.535 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:14:57.239Z,1349392497.239 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:15:01.557Z,1349392501.557 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:15:06.255Z,1349392506.255 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:15:10.567Z,1349392510.567 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0 2012-10-04T23:15:14.871Z,1349392514.871 [NAL9602](ERROR): Inadequate Iridium signal strength reported: 0