2013-03-11T23:08:02.829Z,1363043282.829 [Supervisor](DEBUG): Initializing supervisor. 2013-03-11T23:08:02.834Z,1363043282.834 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2013-03-11T23:08:02.835Z,1363043282.835 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2013-03-11T23:08:02.838Z,1363043282.838 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2013-03-11T23:08:02.842Z,1363043282.842 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2013-03-11T23:08:02.853Z,1363043282.853 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2013-03-11T23:08:02.854Z,1363043282.854 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2013-03-11T23:08:02.855Z,1363043282.855 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2013-03-11T23:08:02.858Z,1363043282.858 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2013-03-11T23:08:02.859Z,1363043282.859 [Supervisor](INFO): Looking for Config files in directory: Config/ 2013-03-11T23:08:02.863Z,1363043282.863 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2013-03-11T23:08:03.174Z,1363043283.174 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2013-03-11T23:08:03.175Z,1363043283.174 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2013-03-11T23:08:03.375Z,1363043283.375 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2013-03-11T23:08:03.376Z,1363043283.376 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2013-03-11T23:08:03.470Z,1363043283.470 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2013-03-11T23:08:03.472Z,1363043283.472 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2013-03-11T23:08:03.675Z,1363043283.675 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2013-03-11T23:08:03.676Z,1363043283.676 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2013-03-11T23:08:03.823Z,1363043283.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2013-03-11T23:08:03.825Z,1363043283.825 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2013-03-11T23:08:04.081Z,1363043284.081 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2013-03-11T23:08:04.082Z,1363043284.082 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2013-03-11T23:08:04.271Z,1363043284.271 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2013-03-11T23:08:04.273Z,1363043284.273 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2013-03-11T23:08:04.548Z,1363043284.548 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2013-03-11T23:08:04.550Z,1363043284.550 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2013-03-11T23:08:04.663Z,1363043284.663 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2013-03-11T23:08:04.664Z,1363043284.664 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2013-03-11T23:08:05.104Z,1363043285.104 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2013-03-11T23:08:05.105Z,1363043285.105 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2013-03-11T23:08:05.238Z,1363043285.238 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2013-03-11T23:08:05.238Z,1363043285.238 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2013-03-11T23:08:06.527Z,1363043286.527 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2013-03-11T23:08:07.233Z,1363043287.233 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2013-03-11T23:08:07.348Z,1363043287.348 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2013-03-11T23:08:07.492Z,1363043287.492 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2013-03-11T23:08:07.590Z,1363043287.590 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2013-03-11T23:08:07.704Z,1363043287.704 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2013-03-11T23:08:07.814Z,1363043287.814 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2013-03-11T23:08:07.948Z,1363043287.948 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2013-03-11T23:08:08.052Z,1363043288.052 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2013-03-11T23:08:08.150Z,1363043288.150 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2013-03-11T23:08:08.177Z,1363043288.178 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2013-03-11T23:08:08.383Z,1363043288.383 [InternalSim] Loaded 2013-03-11T23:08:08.383Z,1363043288.383 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2013-03-11T23:08:08.384Z,1363043288.384 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2013-03-11T23:08:08.384Z,1363043288.384 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2013-03-11T23:08:08.466Z,1363043288.466 [SBIT](DEBUG): Construct Startup Built In Test. 2013-03-11T23:08:08.498Z,1363043288.498 [SBIT] Loaded 2013-03-11T23:08:08.499Z,1363043288.499 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2013-03-11T23:08:08.500Z,1363043288.500 [IBIT](DEBUG): Construct Initiated Built In Test. 2013-03-11T23:08:08.532Z,1363043288.532 [IBIT] Loaded 2013-03-11T23:08:08.533Z,1363043288.533 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2013-03-11T23:08:08.536Z,1363043288.536 [CBIT](DEBUG): Construct CBIT Built In Test. 2013-03-11T23:08:08.667Z,1363043288.667 [CBIT] Loaded 2013-03-11T23:08:08.667Z,1363043288.667 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2013-03-11T23:08:08.667Z,1363043288.667 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2013-03-11T23:08:08.668Z,1363043288.668 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2013-03-11T23:08:08.852Z,1363043288.852 [BuoyancyServo] Loaded 2013-03-11T23:08:08.852Z,1363043288.852 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2013-03-11T23:08:08.865Z,1363043288.865 [ElevatorServo] Loaded 2013-03-11T23:08:08.865Z,1363043288.865 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2013-03-11T23:08:08.881Z,1363043288.881 [MassServo] Loaded 2013-03-11T23:08:08.881Z,1363043288.881 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2013-03-11T23:08:08.893Z,1363043288.893 [RudderServo] Loaded 2013-03-11T23:08:08.893Z,1363043288.894 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2013-03-11T23:08:08.905Z,1363043288.905 [ThrusterServo] Loaded 2013-03-11T23:08:08.906Z,1363043288.906 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2013-03-11T23:08:08.906Z,1363043288.906 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2013-03-11T23:08:08.907Z,1363043288.907 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2013-03-11T23:08:08.939Z,1363043288.940 [DepthRateCalculator] Loaded 2013-03-11T23:08:08.940Z,1363043288.940 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2013-03-11T23:08:13.176Z,1363043293.176 [HFRadarModelCalc] Loaded 2013-03-11T23:08:13.177Z,1363043293.177 [ComponentRegistry](DEBUG): SyncComponent "HFRadarModelCalc" handled in the control thread. 2013-03-11T23:08:13.193Z,1363043293.193 [NavChart] Loaded 2013-03-11T23:08:13.193Z,1363043293.193 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2013-03-11T23:08:13.199Z,1363043293.199 [PitchRateCalculator] Loaded 2013-03-11T23:08:13.199Z,1363043293.199 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2013-03-11T23:08:13.206Z,1363043293.205 [SpeedCalculator] Loaded 2013-03-11T23:08:13.206Z,1363043293.206 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2013-03-11T23:08:13.225Z,1363043293.225 [TempGradientCalculator] Loaded 2013-03-11T23:08:13.225Z,1363043293.225 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2013-03-11T23:08:13.231Z,1363043293.231 [YawRateCalculator] Loaded 2013-03-11T23:08:13.231Z,1363043293.231 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2013-03-11T23:08:13.277Z,1363043293.277 [Navigation] Loaded 2013-03-11T23:08:13.277Z,1363043293.277 [ComponentRegistry](DEBUG): SyncComponent "Navigation" handled in the control thread. 2013-03-11T23:08:13.277Z,1363043293.277 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2013-03-11T23:08:13.278Z,1363043293.278 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2013-03-11T23:08:13.561Z,1363043293.560 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2013-03-11T23:08:13.561Z,1363043293.561 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2013-03-11T23:08:13.599Z,1363043293.599 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2013-03-11T23:08:13.600Z,1363043293.600 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2013-03-11T23:08:13.665Z,1363043293.665 [VerticalControl](DEBUG): Construct VerticalControl. 2013-03-11T23:08:13.771Z,1363043293.771 [VerticalControl] Loaded 2013-03-11T23:08:13.772Z,1363043293.772 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2013-03-11T23:08:13.773Z,1363043293.773 [HorizontalControl](DEBUG): Construct HorizontalControl. 2013-03-11T23:08:13.834Z,1363043293.834 [HorizontalControl] Loaded 2013-03-11T23:08:13.834Z,1363043293.834 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2013-03-11T23:08:13.835Z,1363043293.835 [SpeedControl](DEBUG): Construct SpeedControl. 2013-03-11T23:08:13.837Z,1363043293.837 [SpeedControl] Loaded 2013-03-11T23:08:13.837Z,1363043293.837 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2013-03-11T23:08:13.838Z,1363043293.838 [LoopControl](DEBUG): Construct LoopControl. 2013-03-11T23:08:13.839Z,1363043293.839 [LoopControl] Loaded 2013-03-11T23:08:13.839Z,1363043293.839 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2013-03-11T23:08:13.839Z,1363043293.839 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2013-03-11T23:08:13.840Z,1363043293.840 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2013-03-11T23:08:13.848Z,1363043293.848 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2013-03-11T23:08:13.853Z,1363043293.853 [AsyncPiEstimator] Loaded 2013-03-11T23:08:13.853Z,1363043293.853 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2013-03-11T23:08:13.858Z,1363043293.858 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406A44E0 2013-03-11T23:08:13.859Z,1363043293.859 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2013-03-11T23:08:13.860Z,1363043293.860 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2013-03-11T23:08:14.047Z,1363043294.046 [AHRS_sp3003D] Loaded 2013-03-11T23:08:14.047Z,1363043294.047 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2013-03-11T23:08:14.335Z,1363043294.335 [Batt_Ocean_Server] Loaded 2013-03-11T23:08:14.335Z,1363043294.335 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2013-03-11T23:08:14.353Z,1363043294.353 [Depth_Keller] Loaded 2013-03-11T23:08:14.353Z,1363043294.353 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2013-03-11T23:08:14.359Z,1363043294.359 [DropWeight] Loaded 2013-03-11T23:08:14.359Z,1363043294.359 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2013-03-11T23:08:14.556Z,1363043294.556 [DVL_micro] Loaded 2013-03-11T23:08:14.557Z,1363043294.557 [ComponentRegistry](DEBUG): Component "DVL_micro" handled in its own thread. 2013-03-11T23:08:14.558Z,1363043294.558 [DVL_micro ThreadHandler](DEBUG): Created PCaller Thread at 407284E0 2013-03-11T23:08:14.651Z,1363043294.651 [NAL9602] Loaded 2013-03-11T23:08:14.651Z,1363043294.651 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2013-03-11T23:08:14.707Z,1363043294.707 [Onboard] Loaded 2013-03-11T23:08:14.707Z,1363043294.707 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2013-03-11T23:08:14.718Z,1363043294.718 [Radio_Freewave] Loaded 2013-03-11T23:08:14.718Z,1363043294.718 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2013-03-11T23:08:14.719Z,1363043294.719 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2013-03-11T23:08:14.720Z,1363043294.720 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2013-03-11T23:08:14.809Z,1363043294.809 [Aanderaa_O2] Loaded 2013-03-11T23:08:14.810Z,1363043294.810 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2013-03-11T23:08:14.847Z,1363043294.847 [CTD_NeilBrown] Loaded 2013-03-11T23:08:14.848Z,1363043294.848 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2013-03-11T23:08:14.850Z,1363043294.850 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4077A4E0 2013-03-11T23:08:14.867Z,1363043294.867 [PAR_Licor] Loaded 2013-03-11T23:08:14.867Z,1363043294.867 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2013-03-11T23:08:14.901Z,1363043294.901 [WetLabsBB2FL] Loaded 2013-03-11T23:08:14.902Z,1363043294.902 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2013-03-11T23:08:14.906Z,1363043294.906 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407AA4E0 2013-03-11T23:08:14.907Z,1363043294.907 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2013-03-11T23:08:14.909Z,1363043294.909 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2013-03-11T23:08:14.910Z,1363043294.910 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2013-03-11T23:08:14.920Z,1363043294.920 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2013-03-11T23:08:14.922Z,1363043294.922 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407DA4E0 2013-03-11T23:08:14.927Z,1363043294.927 [Supervisor](DEBUG): Running supervisor. 2013-03-11T23:08:14.928Z,1363043294.928 [CommandLine](INFO): Thread ID is 749 2013-03-11T23:08:14.931Z,1363043294.931 [controlThread](INFO): Thread ID is 748 2013-03-11T23:08:14.931Z,1363043294.931 [controlThread](DEBUG): Initializing ControlThread 2013-03-11T23:08:14.932Z,1363043294.932 [CycleStarter](INFO): Thread ID is 747 2013-03-11T23:08:14.932Z,1363043294.932 [InternalSim](DEBUG): InternalSim initializing... 2013-03-11T23:08:15.043Z,1363043295.043 [logger](INFO): Thread ID is 750 2013-03-11T23:08:15.143Z,1363043295.143 [AsyncPiEstimator](INFO): Thread ID is 811 2013-03-11T23:08:15.143Z,1363043295.143 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2013-03-11T23:08:15.251Z,1363043295.251 [DVL_micro](INFO): Thread ID is 812 2013-03-11T23:08:15.270Z,1363043295.270 [DVL_micro](INFO): Initializing 2013-03-11T23:08:15.270Z,1363043295.270 [DVL_micro](INFO): start:Powering up 2013-03-11T23:08:15.271Z,1363043295.271 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-03-11T23:08:15.272Z,1363043295.272 [DVL_micro](INFO): Cycling power to configure device. 2013-03-11T23:08:15.276Z,1363043295.276 [CTD_NeilBrown](INFO): Thread ID is 813 2013-03-11T23:08:15.277Z,1363043295.277 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2013-03-11T23:08:15.279Z,1363043295.279 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2013-03-11T23:08:15.339Z,1363043295.339 [WetLabsBB2FL](INFO): Thread ID is 814 2013-03-11T23:08:15.339Z,1363043295.339 [WetLabsBB2FL](INFO): Powering down 2013-03-11T23:08:15.375Z,1363043295.375 [NavChartDb](INFO): Thread ID is 815 2013-03-11T23:08:15.384Z,1363043295.384 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2013-03-11T23:08:15.385Z,1363043295.385 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2013-03-11T23:08:15.385Z,1363043295.385 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2013-03-11T23:08:15.385Z,1363043295.385 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2013-03-11T23:08:15.386Z,1363043295.386 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2013-03-11T23:08:15.386Z,1363043295.386 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2013-03-11T23:08:15.386Z,1363043295.386 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2013-03-11T23:08:15.386Z,1363043295.386 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2013-03-11T23:08:15.387Z,1363043295.387 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2013-03-11T23:08:15.391Z,1363043295.391 [SBIT](INFO): Initialize SBIT Component. 2013-03-11T23:08:15.391Z,1363043295.391 [SBIT](IMPORTANT): Tethys CM Info: $Rev: 10234 2013-03-11T23:08:15.392Z,1363043295.392 [IBIT](INFO): Initialize IBIT Component. 2013-03-11T23:08:15.393Z,1363043295.393 [CBIT](DEBUG): Initialize CBIT Component. 2013-03-11T23:08:15.393Z,1363043295.393 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2013-03-11T23:08:15.393Z,1363043295.393 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2013-03-11T23:08:15.420Z,1363043295.420 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2013-03-11T23:08:15.421Z,1363043295.421 [NavChart](DEBUG): Initialize NavChart Derivation. 2013-03-11T23:08:15.421Z,1363043295.421 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2013-03-11T23:08:15.422Z,1363043295.422 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2013-03-11T23:08:15.481Z,1363043295.481 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2013-03-11T23:08:15.491Z,1363043295.491 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2013-03-11T23:08:15.491Z,1363043295.491 [Navigation](DEBUG): Initializing Navigation. 2013-03-11T23:08:15.492Z,1363043295.492 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2013-03-11T23:08:15.494Z,1363043295.494 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2013-03-11T23:08:15.503Z,1363043295.503 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2013-03-11T23:08:15.503Z,1363043295.503 [LoopControl](DEBUG): Initialize LoopControlComponent. 2013-03-11T23:08:17.075Z,1363043297.075 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout 2013-03-11T23:08:17.075Z,1363043297.075 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing 2013-03-11T23:08:17.075Z,1363043297.075 [Batt_Ocean_Server] Communications Fault, FailCount= 1 2013-03-11T23:08:17.075Z,1363043297.075 [Batt_Ocean_Server](ERROR): Communications Fault 2013-03-11T23:08:17.084Z,1363043297.084 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2013-03-11T23:08:17.127Z,1363043297.127 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-11T23:08:17.146Z,1363043297.145 [MissionManager](DEBUG): 2013-03-11T23:08:17.162Z,1363043297.162 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2013-03-11T23:08:17.238Z,1363043297.238 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2013-03-11T23:08:17.244Z,1363043297.244 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2013-03-11T23:08:17.264Z,1363043297.264 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-11T23:08:17.292Z,1363043297.292 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2013-03-11T23:08:17.295Z,1363043297.295 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-11T23:08:17.309Z,1363043297.309 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2013-03-11T23:08:17.318Z,1363043297.318 [Default:D.SetSpeed](DEBUG): Construct. 2013-03-11T23:08:17.337Z,1363043297.337 [Default:E.GoToSurface](DEBUG): Construct GoToSurface. 2013-03-11T23:08:17.343Z,1363043297.343 [DVL_micro](INFO): Opening uart, block timeout 10ths=20 2013-03-11T23:08:17.343Z,1363043297.343 [DVL_micro](INFO): Querying output modes 2013-03-11T23:08:17.344Z,1363043297.344 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD0606 2013-03-11T23:08:17.355Z,1363043297.355 [DVL_micro](DEBUG): cmdResponse: 01 03 2013-03-11T23:08:17.355Z,1363043297.355 [DVL_micro](INFO): NQ1 output enabled 2013-03-11T23:08:17.355Z,1363043297.355 [DVL_micro](INFO): ADCP output enabled 2013-03-11T23:08:17.355Z,1363043297.355 [DVL_micro](DEBUG): commandDVL: #&!LQNQ.COMD2525 2013-03-11T23:08:17.367Z,1363043297.367 [DVL_micro](DEBUG): cmdResponse: AUTO_VEL_ON 2013-03-11T23:08:17.372Z,1363043297.372 [DVL_micro](INFO): pause:Powering down 2013-03-11T23:08:17.375Z,1363043297.375 [Default:F.Wait](DEBUG): Construct Wait. 2013-03-11T23:08:17.378Z,1363043297.378 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2013-03-11T23:08:17.399Z,1363043297.399 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,NAL9602,Onboard,Radio_Freewave,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,HFRadarModelCalc,NavChart,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,Navigation,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter, 2013-03-11T23:08:17.443Z,1363043297.443 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2013-03-11T23:08:17.474Z,1363043297.474 [Depth_Keller](ERROR): Pressure reading out of range: 1831.078247 decibar 2013-03-11T23:08:17.575Z,1363043297.575 [Radio_Freewave](INFO): Powering up 2013-03-11T23:08:17.931Z,1363043297.931 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2013-03-11T23:08:17.939Z,1363043297.939 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2013-03-11T23:08:17.945Z,1363043297.945 [ElevatorServo](DEBUG): Initializing EZServoServo. 2013-03-11T23:08:17.971Z,1363043297.971 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2013-03-11T23:08:17.977Z,1363043297.977 [MassServo](DEBUG): Initializing EZServoServo. 2013-03-11T23:08:17.987Z,1363043297.987 [MassServo](DEBUG): Initializing MassServo. 2013-03-11T23:08:17.992Z,1363043297.992 [RudderServo](DEBUG): Initializing EZServoServo. 2013-03-11T23:08:18.010Z,1363043298.010 [RudderServo](DEBUG): Initializing RudderServo. 2013-03-11T23:08:18.016Z,1363043298.016 [ThrusterServo](DEBUG): Initializing EZServoServo. 2013-03-11T23:08:18.019Z,1363043298.019 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2013-03-11T23:08:18.068Z,1363043298.068 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server 2013-03-11T23:08:18.068Z,1363043298.069 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server 2013-03-11T23:08:18.069Z,1363043298.069 [Batt_Ocean_Server] No Fault, FailCount= 1 2013-03-11T23:08:19.831Z,1363043299.831 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2013-03-11T23:08:19.970Z,1363043299.970 [NAL9602](INFO): Powering up NAL9602 2013-03-11T23:08:21.851Z,1363043301.851 [Aanderaa_O2](INFO): Powering down 2013-03-11T23:08:30.683Z,1363043310.683 [NAL9602](INFO): NAL9602 initialized 2013-03-11T23:08:30.776Z,1363043310.776 [SBIT](IMPORTANT): Beginning Startup BIT 2013-03-11T23:08:30.779Z,1363043310.779 [CBIT](IMPORTANT): Beginning GF scan 2013-03-11T23:08:57.511Z,1363043337.511 [CBIT](IMPORTANT): No ground fault detected 2013-03-11T23:08:57.840Z,1363043337.840 [NAL9602](IMPORTANT): GPS fix at: 1363043336.00 2013-03-11T23:09:05.072Z,1363043345.072 [NAL9602](INFO): Powering down 2013-03-11T23:09:24.787Z,1363043364.787 [SBIT](IMPORTANT): SBIT PASSED 2013-03-11T23:09:25.187Z,1363043365.187 [MissionManager](IMPORTANT): Started mission Startup 2013-03-11T23:09:25.187Z,1363043365.187 [Startup] Running Loop=1 2013-03-11T23:09:25.187Z,1363043365.187 [Startup](INFO): Aggregate::initialize Startup 2013-03-11T23:09:25.187Z,1363043365.187 [Startup:A.GoToSurface] Running Loop=1 2013-03-11T23:09:25.187Z,1363043365.187 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-11T23:09:25.193Z,1363043365.193 [Startup:StartupSatComms] Running Loop=1 2013-03-11T23:09:25.193Z,1363043365.193 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2013-03-11T23:09:25.193Z,1363043365.193 [Startup:StartupSatComms:A] Running Loop=1 2013-03-11T23:09:25.587Z,1363043365.587 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-03-11T23:09:25.972Z,1363043365.972 [NAL9602](INFO): Powering up 2013-03-11T23:09:36.495Z,1363043376.495 [NAL9602](INFO): NAL9602 initialized 2013-03-11T23:10:03.615Z,1363043403.615 [NAL9602](IMPORTANT): GPS fix at: 1363043402.00 2013-03-11T23:10:03.630Z,1363043403.630 [Startup:StartupSatComms:A] Stopped 2013-03-11T23:10:03.630Z,1363043403.630 [Startup:StartupSatComms:B] Running Loop=1 2013-03-11T23:10:04.040Z,1363043404.039 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-03-11T23:10:23.196Z,1363043423.196 [NAL9602](INFO): SBD MO Status=1, MOMSN=6809, MT Status=0, MTMSN=0 2013-03-11T23:10:23.247Z,1363043423.247 [NAL9602](INFO): Sent 332 bytes from file Logs/20130311T230017/shore0000.lzma 2013-03-11T23:10:23.247Z,1363043423.247 [NAL9602](INFO): Packets left to send: 1 2013-03-11T23:10:23.249Z,1363043423.249 [NAL9602](INFO): Stored copy of sent data in Logs/20130311T230017/shore0000.lzma.parts/0001.sbd 2013-03-11T23:10:37.093Z,1363043437.093 [NAL9602](INFO): SBD MO Status=1, MOMSN=6810, MT Status=0, MTMSN=0 2013-03-11T23:10:37.143Z,1363043437.143 [NAL9602](INFO): Sent 326 bytes from file Logs/20130311T230017/shore0000.lzma 2013-03-11T23:10:37.143Z,1363043437.143 [NAL9602](INFO): Packets left to send: 0 2013-03-11T23:10:37.144Z,1363043437.144 [NAL9602](INFO): Stored copy of sent data in Logs/20130311T230017/shore0000.lzma.parts/0000.sbd 2013-03-11T23:10:53.055Z,1363043453.055 [NAL9602](INFO): SBD MO Status=1, MOMSN=6811, MT Status=0, MTMSN=0 2013-03-11T23:10:53.103Z,1363043453.103 [NAL9602](INFO): Sent 332 bytes from file Logs/20130311T230441/shore0000.lzma 2013-03-11T23:10:53.103Z,1363043453.103 [NAL9602](INFO): Packets left to send: 2 2013-03-11T23:10:53.105Z,1363043453.105 [NAL9602](INFO): Stored copy of sent data in Logs/20130311T230441/shore0000.lzma.parts/0002.sbd 2013-03-11T23:11:01.678Z,1363043461.678 [NAL9602](INFO): SBD MO Status=2, MOMSN=6812, MT Status=2, MTMSN=0 2013-03-11T23:11:01.678Z,1363043461.678 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-03-11T23:11:03.691Z,1363043463.691 [Startup:StartupSatComms:B](INFO): Timed out from 2013-03-11T23:10:03.6Z 2013-03-11T23:11:03.691Z,1363043463.691 [Startup:StartupSatComms:B:A_Timeout] Running Loop=1 2013-03-11T23:11:03.691Z,1363043463.691 [Startup:StartupSatComms:B:A_Timeout](INFO): Aggregate::initialize Startup:StartupSatComms:B:A_Timeout 2013-03-11T23:11:03.691Z,1363043463.691 [Startup:StartupSatComms:B:A_Timeout](INFO): Completed Startup:StartupSatComms:B:A_Timeout 2013-03-11T23:11:03.691Z,1363043463.691 [Startup:StartupSatComms:B] Stopped 2013-03-11T23:11:03.691Z,1363043463.691 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2013-03-11T23:11:03.691Z,1363043463.691 [Startup:StartupSatComms] Stopped 2013-03-11T23:11:03.692Z,1363043463.691 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2013-03-11T23:11:03.692Z,1363043463.692 [Startup](INFO): Completed Startup 2013-03-11T23:11:03.692Z,1363043463.693 [Startup] Stopped 2013-03-11T23:11:03.693Z,1363043463.693 [Startup](INFO): Aggregate::uninitialize Startup 2013-03-11T23:11:03.693Z,1363043463.693 [Startup:A.GoToSurface] Stopped 2013-03-11T23:11:03.693Z,1363043463.693 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-11T23:11:04.095Z,1363043464.095 [MissionManager](IMPORTANT): Started mission Default 2013-03-11T23:11:04.095Z,1363043464.095 [Default] Running Loop=1 2013-03-11T23:11:04.095Z,1363043464.095 [Default](INFO): Aggregate::initialize Default 2013-03-11T23:11:04.095Z,1363043464.095 [Default:D.SetSpeed] Running Loop=1 2013-03-11T23:11:04.095Z,1363043464.095 [Default:D.SetSpeed](DEBUG): Initialize. 2013-03-11T23:11:04.096Z,1363043464.096 [Default:E.GoToSurface] Running Loop=1 2013-03-11T23:11:04.096Z,1363043464.096 [Default:E.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-11T23:11:04.096Z,1363043464.096 [Default:Iridium] Running Loop=1 2013-03-11T23:11:04.096Z,1363043464.096 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-03-11T23:11:04.096Z,1363043464.096 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-03-11T23:11:04.096Z,1363043464.096 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-03-11T23:11:04.097Z,1363043464.097 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-03-11T23:11:04.097Z,1363043464.097 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-11T23:11:04.097Z,1363043464.097 [Default:E.GoToSurface] Running Loop=1 2013-03-11T23:11:04.103Z,1363043464.103 [Default:D.SetSpeed] Running Loop=1 2013-03-11T23:11:04.108Z,1363043464.108 [Default:CallIridium] Running Loop=1 2013-03-11T23:11:04.108Z,1363043464.109 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-03-11T23:11:04.109Z,1363043464.109 [Default:CallIridium:A] Running Loop=1 2013-03-11T23:11:04.111Z,1363043464.111 [Default:CallIridium:A] Stopped 2013-03-11T23:11:04.111Z,1363043464.111 [Default:CallIridium:B] Running Loop=1 2013-03-11T23:11:04.111Z,1363043464.111 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-03-11T23:11:04.116Z,1363043464.116 [Default:Iridium:B.GoToSurface] Stopped 2013-03-11T23:11:04.117Z,1363043464.117 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-11T23:11:04.117Z,1363043464.117 [Default:Iridium:Read_Iridium] Running Loop=1 2013-03-11T23:11:04.117Z,1363043464.117 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-03-11T23:11:04.122Z,1363043464.122 [Default:GPS] Running Loop=1 2013-03-11T23:11:04.122Z,1363043464.122 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-03-11T23:11:04.122Z,1363043464.122 [Default:GPS:A.SetSpeed] Running Loop=1 2013-03-11T23:11:04.122Z,1363043464.122 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-03-11T23:11:04.123Z,1363043464.123 [Default:GPS:B.GoToSurface] Running Loop=1 2013-03-11T23:11:04.123Z,1363043464.123 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-11T23:11:04.128Z,1363043464.128 [Default:GPS:B.GoToSurface] Stopped 2013-03-11T23:11:04.128Z,1363043464.128 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-11T23:11:04.128Z,1363043464.128 [Default:GPS:Read_GPS] Running Loop=1 2013-03-11T23:11:04.129Z,1363043464.129 [Default:GPS:A.SetSpeed] Running Loop=1 2013-03-11T23:11:04.525Z,1363043464.525 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2013-03-11T23:11:04.527Z,1363043464.527 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2013-03-11T23:11:08.052Z,1363043468.052 [NAL9602](IMPORTANT): GPS fix at: 1363043466.00 2013-03-11T23:11:08.069Z,1363043468.069 [Default:GPS:Read_GPS] Stopped 2013-03-11T23:11:08.069Z,1363043468.069 [Default:GPS:D] Running Loop=1 2013-03-11T23:11:08.499Z,1363043468.499 [Default:GPS:D] Stopped 2013-03-11T23:11:08.500Z,1363043468.500 [Default:GPS](INFO): Completed Default:GPS 2013-03-11T23:11:08.500Z,1363043468.500 [Default:GPS] Stopped 2013-03-11T23:11:08.500Z,1363043468.500 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2013-03-11T23:11:08.500Z,1363043468.500 [Default:GPS:A.SetSpeed] Stopped 2013-03-11T23:11:08.500Z,1363043468.500 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2013-03-11T23:11:29.729Z,1363043489.729 [NAL9602](INFO): SBD MO Status=2, MOMSN=6812, MT Status=2, MTMSN=0 2013-03-11T23:11:29.729Z,1363043489.729 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-03-11T23:12:59.257Z,1363043579.257 [NAL9602](INFO): SBD MO Status=1, MOMSN=6812, MT Status=0, MTMSN=0 2013-03-11T23:12:59.307Z,1363043579.307 [NAL9602](INFO): Sent 332 bytes from file Logs/20130311T230441/shore0000.lzma 2013-03-11T23:12:59.307Z,1363043579.307 [NAL9602](INFO): Packets left to send: 1 2013-03-11T23:12:59.309Z,1363043579.309 [NAL9602](INFO): Stored copy of sent data in Logs/20130311T230441/shore0000.lzma.parts/0001.sbd 2013-03-11T23:13:17.981Z,1363043597.981 [NAL9602](INFO): SBD MO Status=2, MOMSN=6813, MT Status=2, MTMSN=0 2013-03-11T23:13:17.981Z,1363043597.981 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2013-03-11T23:13:44.651Z,1363043624.651 [NAL9602](INFO): SBD MO Status=1, MOMSN=6813, MT Status=0, MTMSN=0 2013-03-11T23:13:44.699Z,1363043624.699 [NAL9602](INFO): Sent 133 bytes from file Logs/20130311T230441/shore0000.lzma 2013-03-11T23:13:44.699Z,1363043624.699 [NAL9602](INFO): Packets left to send: 0 2013-03-11T23:13:44.700Z,1363043624.700 [NAL9602](INFO): Stored copy of sent data in Logs/20130311T230441/shore0000.lzma.parts/0000.sbd 2013-03-11T23:14:07.293Z,1363043647.293 [NAL9602](INFO): SBD MO Status=1, MOMSN=6814, MT Status=0, MTMSN=0 2013-03-11T23:14:07.343Z,1363043647.343 [NAL9602](INFO): Sent 208 bytes from file Logs/20130311T230441/shore0001.lzma 2013-03-11T23:14:07.343Z,1363043647.343 [NAL9602](INFO): Packets left to send: 0 2013-03-11T23:14:07.345Z,1363043647.345 [NAL9602](INFO): Stored copy of sent data in Logs/20130311T230441/shore0001.lzma.parts/0000.sbd 2013-03-11T23:14:15.961Z,1363043655.961 [NAL9602](INFO): SBD MO Status=1, MOMSN=6815, MT Status=0, MTMSN=0 2013-03-11T23:14:16.011Z,1363043656.011 [NAL9602](INFO): Sent 332 bytes from file Logs/20130311T230802/shore0000.lzma 2013-03-11T23:14:16.011Z,1363043656.011 [NAL9602](INFO): Packets left to send: 2 2013-03-11T23:14:16.013Z,1363043656.013 [NAL9602](INFO): Stored copy of sent data in Logs/20130311T230802/shore0000.lzma.parts/0002.sbd 2013-03-11T23:14:25.457Z,1363043665.457 [NAL9602](INFO): SBD MO Status=1, MOMSN=6816, MT Status=0, MTMSN=0 2013-03-11T23:14:25.507Z,1363043665.507 [NAL9602](INFO): Sent 332 bytes from file Logs/20130311T230802/shore0000.lzma 2013-03-11T23:14:25.507Z,1363043665.507 [NAL9602](INFO): Packets left to send: 1 2013-03-11T23:14:25.508Z,1363043665.508 [NAL9602](INFO): Stored copy of sent data in Logs/20130311T230802/shore0000.lzma.parts/0001.sbd 2013-03-11T23:14:41.261Z,1363043681.261 [NAL9602](INFO): SBD MO Status=1, MOMSN=6817, MT Status=0, MTMSN=0 2013-03-11T23:14:41.311Z,1363043681.311 [NAL9602](INFO): Sent 102 bytes from file Logs/20130311T230802/shore0000.lzma 2013-03-11T23:14:41.311Z,1363043681.311 [NAL9602](INFO): Packets left to send: 0 2013-03-11T23:14:41.312Z,1363043681.312 [NAL9602](INFO): Stored copy of sent data in Logs/20130311T230802/shore0000.lzma.parts/0000.sbd 2013-03-11T23:14:59.256Z,1363043699.256 [NAL9602](INFO): SBD MO Status=0, MOMSN=6818, MT Status=0, MTMSN=0 2013-03-11T23:14:59.360Z,1363043699.360 [Default:Iridium:Read_Iridium] Stopped 2013-03-11T23:14:59.360Z,1363043699.360 [Default:Iridium](INFO): Completed Default:Iridium 2013-03-11T23:14:59.360Z,1363043699.360 [Default:Iridium] Stopped 2013-03-11T23:14:59.360Z,1363043699.360 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2013-03-11T23:14:59.360Z,1363043699.360 [Default:Iridium:A.SetSpeed] Stopped 2013-03-11T23:14:59.361Z,1363043699.361 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2013-03-11T23:14:59.361Z,1363043699.361 [Default:F.Wait] Running Loop=1 2013-03-11T23:14:59.361Z,1363043699.361 [Default:F.Wait](DEBUG): Initialize Wait Component. 2013-03-11T23:14:59.693Z,1363043699.693 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2013-03-11T23:14:59.693Z,1363043699.693 [Default:CallIridium:B] Stopped 2013-03-11T23:14:59.693Z,1363043699.693 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2013-03-11T23:14:59.694Z,1363043699.694 [Default:CallIridium](INFO): Completed Default:CallIridium 2013-03-11T23:14:59.694Z,1363043699.694 [Default:CallIridium] Stopped 2013-03-11T23:14:59.694Z,1363043699.694 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2013-03-11T23:15:05.123Z,1363043705.123 [CommandLine](IMPORTANT): got command get platform_battery_voltage 2013-03-11T23:15:05.124Z,1363043705.124 [CommandLine](IMPORTANT): platform_battery_voltage 16.213188 volt 2013-03-11T23:15:09.868Z,1363043709.868 [NAL9602](INFO): Powering down 2013-03-11T23:19:59.832Z,1363043999.832 [Default:CallIridium] Running Loop=1 2013-03-11T23:19:59.832Z,1363043999.832 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2013-03-11T23:19:59.832Z,1363043999.832 [Default:CallIridium:A] Running Loop=1 2013-03-11T23:19:59.833Z,1363043999.833 [Default:CallIridium:A] Stopped 2013-03-11T23:19:59.833Z,1363043999.833 [Default:CallIridium:B] Running Loop=1 2013-03-11T23:19:59.833Z,1363043999.833 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2013-03-11T23:20:04.871Z,1363044004.871 [Default:Iridium] Running Loop=1 2013-03-11T23:20:04.872Z,1363044004.872 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2013-03-11T23:20:04.872Z,1363044004.872 [Default:Iridium:A.SetSpeed] Running Loop=1 2013-03-11T23:20:04.872Z,1363044004.872 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2013-03-11T23:20:04.872Z,1363044004.872 [Default:Iridium:B.GoToSurface] Running Loop=1 2013-03-11T23:20:04.872Z,1363044004.872 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-11T23:20:04.873Z,1363044004.873 [Default:Iridium:B.GoToSurface] Stopped 2013-03-11T23:20:04.873Z,1363044004.873 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-11T23:20:04.873Z,1363044004.873 [Default:Iridium:Read_Iridium] Running Loop=1 2013-03-11T23:20:04.873Z,1363044004.873 [Default:GPS] Running Loop=1 2013-03-11T23:20:04.873Z,1363044004.873 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2013-03-11T23:20:04.873Z,1363044004.874 [Default:GPS:A.SetSpeed] Running Loop=1 2013-03-11T23:20:04.873Z,1363044004.874 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2013-03-11T23:20:04.874Z,1363044004.874 [Default:GPS:B.GoToSurface] Running Loop=1 2013-03-11T23:20:04.874Z,1363044004.874 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2013-03-11T23:20:04.875Z,1363044004.875 [Default:GPS:B.GoToSurface] Stopped 2013-03-11T23:20:04.875Z,1363044004.875 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2013-03-11T23:20:04.875Z,1363044004.875 [Default:GPS:Read_GPS] Running Loop=1 2013-03-11T23:20:05.468Z,1363044005.468 [NAL9602](INFO): Powering up 2013-03-11T23:20:16.447Z,1363044016.447 [NAL9602](INFO): NAL9602 initialized