2014-04-18T20:49:49.747Z,1397854189.747 [Supervisor](DEBUG): Initializing supervisor. 2014-04-18T20:49:49.753Z,1397854189.753 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2014-04-18T20:49:49.754Z,1397854189.754 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2014-04-18T20:49:49.757Z,1397854189.757 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2014-04-18T20:49:49.760Z,1397854189.760 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2014-04-18T20:49:49.771Z,1397854189.771 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2014-04-18T20:49:49.773Z,1397854189.773 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2014-04-18T20:49:49.774Z,1397854189.774 [ComponentRegistry](DEBUG): SyncComponent "logger" handled in the control thread. 2014-04-18T20:49:49.775Z,1397854189.775 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2014-04-18T20:49:49.776Z,1397854189.776 [Supervisor](INFO): Looking for Config files in directory: Config/ 2014-04-18T20:49:49.781Z,1397854189.781 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2014-04-18T20:49:50.194Z,1397854190.194 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2014-04-18T20:49:50.195Z,1397854190.195 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2014-04-18T20:49:50.507Z,1397854190.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2014-04-18T20:49:50.507Z,1397854190.507 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2014-04-18T20:49:50.605Z,1397854190.605 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2014-04-18T20:49:50.608Z,1397854190.608 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2014-04-18T20:49:50.835Z,1397854190.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2014-04-18T20:49:50.836Z,1397854190.836 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2014-04-18T20:49:51.016Z,1397854191.016 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2014-04-18T20:49:51.018Z,1397854191.018 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2014-04-18T20:49:51.356Z,1397854191.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2014-04-18T20:49:51.357Z,1397854191.357 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2014-04-18T20:49:51.556Z,1397854191.556 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2014-04-18T20:49:51.558Z,1397854191.558 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2014-04-18T20:49:51.945Z,1397854191.945 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2014-04-18T20:49:51.948Z,1397854191.948 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2014-04-18T20:49:52.073Z,1397854192.073 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2014-04-18T20:49:52.074Z,1397854192.074 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2014-04-18T20:49:52.634Z,1397854192.634 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2014-04-18T20:49:52.634Z,1397854192.634 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2014-04-18T20:49:52.845Z,1397854192.845 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2014-04-18T20:49:52.846Z,1397854192.846 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2014-04-18T20:49:52.945Z,1397854192.945 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2014-04-18T20:49:53.059Z,1397854193.059 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2014-04-18T20:49:53.061Z,1397854193.061 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2014-04-18T20:49:53.179Z,1397854193.179 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2014-04-18T20:49:53.180Z,1397854193.180 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2014-04-18T20:49:53.331Z,1397854193.331 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2014-04-18T20:49:53.333Z,1397854193.333 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2014-04-18T20:49:53.337Z,1397854193.337 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2014-04-18T20:49:53.456Z,1397854193.456 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2014-04-18T20:49:53.604Z,1397854193.604 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2014-04-18T20:49:53.712Z,1397854193.712 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2014-04-18T20:49:53.819Z,1397854193.819 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2014-04-18T20:49:53.997Z,1397854193.997 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2014-04-18T20:49:54.133Z,1397854194.133 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2014-04-18T20:49:54.233Z,1397854194.233 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2014-04-18T20:49:54.345Z,1397854194.345 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2014-04-18T20:49:54.457Z,1397854194.457 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2014-04-18T20:49:54.460Z,1397854194.460 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2014-04-18T20:49:55.063Z,1397854195.063 [AHRS_sp3003D] Loaded 2014-04-18T20:49:55.063Z,1397854195.063 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2014-04-18T20:49:55.384Z,1397854195.384 [Batt_Ocean_Server] Loaded 2014-04-18T20:49:55.385Z,1397854195.385 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2014-04-18T20:49:55.561Z,1397854195.561 [DataOverHttps] Loaded 2014-04-18T20:49:55.561Z,1397854195.561 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2014-04-18T20:49:55.574Z,1397854195.574 [Depth_Keller] Loaded 2014-04-18T20:49:55.575Z,1397854195.575 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2014-04-18T20:49:55.579Z,1397854195.579 [DropWeight] Loaded 2014-04-18T20:49:55.580Z,1397854195.580 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2014-04-18T20:49:55.734Z,1397854195.734 [DVL_micro] Loaded 2014-04-18T20:49:55.734Z,1397854195.734 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2014-04-18T20:49:55.845Z,1397854195.845 [NAL9602] Loaded 2014-04-18T20:49:55.845Z,1397854195.845 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2014-04-18T20:49:55.900Z,1397854195.900 [Onboard] Loaded 2014-04-18T20:49:55.900Z,1397854195.900 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2014-04-18T20:49:55.912Z,1397854195.912 [Radio_Freewave] Loaded 2014-04-18T20:49:55.912Z,1397854195.912 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2014-04-18T20:49:55.919Z,1397854195.919 [SCPI] Loaded 2014-04-18T20:49:55.919Z,1397854195.919 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2014-04-18T20:49:55.919Z,1397854195.919 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2014-04-18T20:49:55.920Z,1397854195.920 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2014-04-18T20:49:56.121Z,1397854196.121 [InternalSim] Loaded 2014-04-18T20:49:56.121Z,1397854196.121 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2014-04-18T20:49:56.122Z,1397854196.122 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2014-04-18T20:49:56.123Z,1397854196.123 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2014-04-18T20:49:56.423Z,1397854196.423 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2014-04-18T20:49:56.423Z,1397854196.423 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2014-04-18T20:49:56.432Z,1397854196.432 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2014-04-18T20:49:56.437Z,1397854196.437 [AsyncPiEstimator] Loaded 2014-04-18T20:49:56.437Z,1397854196.437 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2014-04-18T20:49:56.439Z,1397854196.439 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 406714E0 2014-04-18T20:49:56.440Z,1397854196.440 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2014-04-18T20:49:56.440Z,1397854196.440 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2014-04-18T20:49:56.543Z,1397854196.543 [DeadReckonUsingMultipleVelocitySources] Loaded 2014-04-18T20:49:56.544Z,1397854196.544 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2014-04-18T20:49:56.564Z,1397854196.564 [NavChart] Loaded 2014-04-18T20:49:56.564Z,1397854196.564 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2014-04-18T20:49:56.568Z,1397854196.568 [UniversalFixResidualReporter] Loaded 2014-04-18T20:49:56.569Z,1397854196.569 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2014-04-18T20:49:56.569Z,1397854196.569 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2014-04-18T20:49:56.570Z,1397854196.570 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2014-04-18T20:49:56.641Z,1397854196.641 [VerticalControl](DEBUG): Construct VerticalControl. 2014-04-18T20:49:56.762Z,1397854196.762 [VerticalControl] Loaded 2014-04-18T20:49:56.762Z,1397854196.762 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2014-04-18T20:49:56.763Z,1397854196.763 [HorizontalControl](DEBUG): Construct HorizontalControl. 2014-04-18T20:49:56.832Z,1397854196.832 [HorizontalControl] Loaded 2014-04-18T20:49:56.833Z,1397854196.833 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2014-04-18T20:49:56.833Z,1397854196.833 [SpeedControl](DEBUG): Construct SpeedControl. 2014-04-18T20:49:56.835Z,1397854196.835 [SpeedControl] Loaded 2014-04-18T20:49:56.835Z,1397854196.835 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2014-04-18T20:49:56.836Z,1397854196.836 [LoopControl](DEBUG): Construct LoopControl. 2014-04-18T20:49:56.836Z,1397854196.836 [LoopControl] Loaded 2014-04-18T20:49:56.837Z,1397854196.837 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2014-04-18T20:49:56.837Z,1397854196.837 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2014-04-18T20:49:56.838Z,1397854196.838 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2014-04-18T20:49:56.870Z,1397854196.870 [DepthRateCalculator] Loaded 2014-04-18T20:49:56.870Z,1397854196.870 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2014-04-18T20:49:56.876Z,1397854196.876 [PitchRateCalculator] Loaded 2014-04-18T20:49:56.876Z,1397854196.876 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2014-04-18T20:49:56.883Z,1397854196.883 [SpeedCalculator] Loaded 2014-04-18T20:49:56.883Z,1397854196.883 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2014-04-18T20:49:56.903Z,1397854196.903 [TempGradientCalculator] Loaded 2014-04-18T20:49:56.903Z,1397854196.903 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2014-04-18T20:49:56.909Z,1397854196.909 [YawRateCalculator] Loaded 2014-04-18T20:49:56.909Z,1397854196.909 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2014-04-18T20:49:56.910Z,1397854196.910 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2014-04-18T20:49:56.910Z,1397854196.910 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2014-04-18T20:49:57.043Z,1397854197.043 [CTD_NeilBrown] Loaded 2014-04-18T20:49:57.043Z,1397854197.043 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2014-04-18T20:49:57.048Z,1397854197.048 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407134E0 2014-04-18T20:49:57.061Z,1397854197.061 [ISUS] Loaded 2014-04-18T20:49:57.061Z,1397854197.061 [ComponentRegistry](DEBUG): SyncComponent "ISUS" handled in the control thread. 2014-04-18T20:49:57.080Z,1397854197.080 [PAR_Licor] Loaded 2014-04-18T20:49:57.080Z,1397854197.080 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2014-04-18T20:49:57.119Z,1397854197.119 [WetLabsBB2FL] Loaded 2014-04-18T20:49:57.120Z,1397854197.120 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2014-04-18T20:49:57.124Z,1397854197.124 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407434E0 2014-04-18T20:49:57.125Z,1397854197.125 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2014-04-18T20:49:57.127Z,1397854197.127 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2014-04-18T20:49:57.316Z,1397854197.316 [SBIT](DEBUG): Construct Startup Built In Test. 2014-04-18T20:49:57.339Z,1397854197.339 [SBIT] Loaded 2014-04-18T20:49:57.339Z,1397854197.339 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2014-04-18T20:49:57.340Z,1397854197.340 [IBIT](DEBUG): Construct Initiated Built In Test. 2014-04-18T20:49:57.369Z,1397854197.369 [IBIT] Loaded 2014-04-18T20:49:57.369Z,1397854197.369 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2014-04-18T20:49:57.371Z,1397854197.371 [CBIT](DEBUG): Construct CBIT Built In Test. 2014-04-18T20:49:57.472Z,1397854197.472 [CBIT] Loaded 2014-04-18T20:49:57.473Z,1397854197.473 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2014-04-18T20:49:57.473Z,1397854197.473 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2014-04-18T20:49:57.475Z,1397854197.475 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2014-04-18T20:49:57.575Z,1397854197.575 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2014-04-18T20:49:57.575Z,1397854197.575 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2014-04-18T20:49:57.714Z,1397854197.714 [BuoyancyServo] Loaded 2014-04-18T20:49:57.714Z,1397854197.714 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2014-04-18T20:49:57.771Z,1397854197.771 [ElevatorServo] Loaded 2014-04-18T20:49:57.772Z,1397854197.772 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2014-04-18T20:49:57.784Z,1397854197.784 [MassServo] Loaded 2014-04-18T20:49:57.784Z,1397854197.784 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2014-04-18T20:49:57.796Z,1397854197.796 [RudderServo] Loaded 2014-04-18T20:49:57.796Z,1397854197.796 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2014-04-18T20:49:57.820Z,1397854197.820 [ThrusterServo] Loaded 2014-04-18T20:49:57.821Z,1397854197.821 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2014-04-18T20:49:57.821Z,1397854197.821 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2014-04-18T20:49:57.822Z,1397854197.822 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2014-04-18T20:49:57.916Z,1397854197.916 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2014-04-18T20:49:57.918Z,1397854197.918 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2014-04-18T20:49:57.919Z,1397854197.919 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2014-04-18T20:49:57.925Z,1397854197.925 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2014-04-18T20:49:57.949Z,1397854197.949 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 408114E0 2014-04-18T20:49:57.954Z,1397854197.954 [Supervisor](DEBUG): Running supervisor. 2014-04-18T20:49:57.959Z,1397854197.959 [CommandLine](INFO): Thread ID is 779 2014-04-18T20:49:57.990Z,1397854197.990 [controlThread](INFO): Thread ID is 778 2014-04-18T20:49:57.990Z,1397854197.990 [controlThread](DEBUG): Initializing ControlThread 2014-04-18T20:49:57.991Z,1397854197.991 [CycleStarter](INFO): Thread ID is 777 2014-04-18T20:49:58.006Z,1397854198.006 [AsyncPiEstimator](INFO): Thread ID is 852 2014-04-18T20:49:58.007Z,1397854198.007 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2014-04-18T20:49:58.019Z,1397854198.019 [CTD_NeilBrown](INFO): Thread ID is 853 2014-04-18T20:49:58.019Z,1397854198.019 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2014-04-18T20:49:58.021Z,1397854198.021 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-18T20:49:58.042Z,1397854198.042 [WetLabsBB2FL](INFO): Thread ID is 854 2014-04-18T20:49:58.043Z,1397854198.043 [WetLabsBB2FL](INFO): Powering down 2014-04-18T20:49:58.084Z,1397854198.084 [NavChartDb](INFO): Thread ID is 858 2014-04-18T20:49:58.102Z,1397854198.102 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2014-04-18T20:49:58.105Z,1397854198.105 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2014-04-18T20:49:58.106Z,1397854198.106 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2014-04-18T20:49:58.106Z,1397854198.106 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2014-04-18T20:49:58.106Z,1397854198.106 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2014-04-18T20:49:58.106Z,1397854198.106 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2014-04-18T20:49:58.107Z,1397854198.107 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2014-04-18T20:49:58.107Z,1397854198.107 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2014-04-18T20:49:58.107Z,1397854198.107 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2014-04-18T20:49:59.905Z,1397854199.905 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2014-04-18T20:49:59.980Z,1397854199.980 [InternalSim](DEBUG): InternalSim initializing... 2014-04-18T20:50:00.382Z,1397854200.382 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-18T20:50:00.382Z,1397854200.382 [NavChart](DEBUG): Initialize NavChart Navigation. 2014-04-18T20:50:00.382Z,1397854200.382 [UniversalFixResidualReporter](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-18T20:50:00.383Z,1397854200.383 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2014-04-18T20:50:00.385Z,1397854200.385 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2014-04-18T20:50:00.397Z,1397854200.397 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2014-04-18T20:50:00.409Z,1397854200.409 [LoopControl](DEBUG): Initialize LoopControlComponent. 2014-04-18T20:50:00.410Z,1397854200.410 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-18T20:50:00.410Z,1397854200.410 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2014-04-18T20:50:00.410Z,1397854200.410 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2014-04-18T20:50:00.411Z,1397854200.411 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2014-04-18T20:50:00.411Z,1397854200.411 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2014-04-18T20:50:00.413Z,1397854200.413 [SBIT](INFO): Initialize SBIT Component. 2014-04-18T20:50:00.414Z,1397854200.414 [SBIT](IMPORTANT): Tethys CM Info: $Rev:11220 2014-04-18T20:50:00.414Z,1397854200.414 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2014-04-18T20:50:00.415Z,1397854200.415 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2014-04-18T20:50:00.415Z,1397854200.415 [IBIT](INFO): Initialize IBIT Component. 2014-04-18T20:50:00.416Z,1397854200.416 [CBIT](DEBUG): Initialize CBIT Component. 2014-04-18T20:50:00.416Z,1397854200.416 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2014-04-18T20:50:00.417Z,1397854200.417 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2014-04-18T20:50:00.443Z,1397854200.443 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2014-04-18T20:50:00.472Z,1397854200.472 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-18T20:50:00.497Z,1397854200.497 [MissionManager](DEBUG): 2014-04-18T20:50:00.498Z,1397854200.498 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2014-04-18T20:50:00.558Z,1397854200.558 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2014-04-18T20:50:00.560Z,1397854200.560 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2014-04-18T20:50:00.564Z,1397854200.564 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-18T20:50:00.572Z,1397854200.572 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2014-04-18T20:50:00.588Z,1397854200.588 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-18T20:50:00.595Z,1397854200.595 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2014-04-18T20:50:00.621Z,1397854200.621 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct. 2014-04-18T20:50:00.625Z,1397854200.625 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-18T20:50:00.644Z,1397854200.644 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2014-04-18T20:50:00.658Z,1397854200.658 [controlThread](DEBUG): Component order: CycleStarter,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,logger,LogSplitter, 2014-04-18T20:50:00.722Z,1397854200.722 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-18T20:50:00.758Z,1397854200.758 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:50:00.883Z,1397854200.883 [DVL_micro](INFO): Initializing 2014-04-18T20:50:00.896Z,1397854200.896 [NAL9602](INFO): Powering up NAL9602 2014-04-18T20:50:00.978Z,1397854200.978 [Radio_Freewave](INFO): Powering up 2014-04-18T20:50:01.346Z,1397854201.346 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-18T20:50:01.359Z,1397854201.359 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-18T20:50:01.366Z,1397854201.366 [ElevatorServo](DEBUG): Initializing EZServoServo. 2014-04-18T20:50:01.371Z,1397854201.371 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2014-04-18T20:50:01.377Z,1397854201.377 [MassServo](DEBUG): Initializing EZServoServo. 2014-04-18T20:50:01.383Z,1397854201.383 [MassServo](DEBUG): Initializing MassServo. 2014-04-18T20:50:01.389Z,1397854201.389 [RudderServo](DEBUG): Initializing EZServoServo. 2014-04-18T20:50:01.395Z,1397854201.395 [RudderServo](DEBUG): Initializing RudderServo. 2014-04-18T20:50:01.401Z,1397854201.401 [ThrusterServo](DEBUG): Initializing EZServoServo. 2014-04-18T20:50:01.415Z,1397854201.415 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-18T20:50:10.053Z,1397854210.053 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:50:10.053Z,1397854210.053 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:50:10.057Z,1397854210.057 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:50:10.115Z,1397854210.115 [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-18T20:50:11.078Z,1397854211.078 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:50:12.953Z,1397854212.953 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:50:12.955Z,1397854212.955 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:50:12.956Z,1397854212.956 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:50:12.957Z,1397854212.957 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:50:13.013Z,1397854213.013 [NAL9602](INFO): NAL9602 initialized 2014-04-18T20:50:13.712Z,1397854213.712 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:50:14.261Z,1397854214.261 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:50:14.262Z,1397854214.262 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-18T20:50:14.263Z,1397854214.263 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:50:14.266Z,1397854214.266 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003806 2014-04-18T20:50:16.632Z,1397854216.632 [SBIT](IMPORTANT): Beginning Startup BIT 2014-04-18T20:50:16.635Z,1397854216.635 [CBIT](IMPORTANT): Beginning GF scan 2014-04-18T20:50:31.462Z,1397854231.462 [NAL9602](INFO): SBD MO Status=0, MOMSN=26698, MT Status=0, MTMSN=0 2014-04-18T20:50:31.462Z,1397854231.462 [NAL9602](INFO): No messages in MT queue 2014-04-18T20:50:33.675Z,1397854233.675 [NAL9602](IMPORTANT): GPS fix at: 1397854231.00 2014-04-18T20:50:41.799Z,1397854241.799 [NAL9602](INFO): Powering down 2014-04-18T20:50:44.294Z,1397854244.294 [CBIT](IMPORTANT): No ground fault detected 2014-04-18T20:51:01.182Z,1397854261.182 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:51:01.825Z,1397854261.825 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:51:01.825Z,1397854261.825 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:51:01.826Z,1397854261.826 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:02.426Z,1397854262.426 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:03.453Z,1397854263.453 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:03.455Z,1397854263.455 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:51:03.456Z,1397854263.456 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:51:03.457Z,1397854263.457 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:51:03.922Z,1397854263.922 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:04.395Z,1397854264.395 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:04.396Z,1397854264.396 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-18T20:51:04.396Z,1397854264.396 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:51:11.124Z,1397854271.124 [SBIT](IMPORTANT): SBIT PASSED 2014-04-18T20:51:11.534Z,1397854271.534 [MissionManager](IMPORTANT): Started mission Startup 2014-04-18T20:51:11.534Z,1397854271.534 [Startup] Running Loop=1 2014-04-18T20:51:11.534Z,1397854271.534 [Startup](INFO): Aggregate::initialize Startup 2014-04-18T20:51:11.534Z,1397854271.534 [Startup:A.GoToSurface] Running Loop=1 2014-04-18T20:51:11.534Z,1397854271.534 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-18T20:51:11.541Z,1397854271.541 [Startup:StartupSatComms] Running Loop=1 2014-04-18T20:51:11.541Z,1397854271.541 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2014-04-18T20:51:11.542Z,1397854271.542 [Startup:StartupSatComms:A] Running Loop=1 2014-04-18T20:51:12.068Z,1397854272.068 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-18T20:51:12.486Z,1397854272.486 [NAL9602](INFO): Powering up 2014-04-18T20:51:23.466Z,1397854283.466 [NAL9602](INFO): NAL9602 initialized 2014-04-18T20:51:39.207Z,1397854299.207 [NAL9602](INFO): SBD MO Status=0, MOMSN=26699, MT Status=0, MTMSN=0 2014-04-18T20:51:39.207Z,1397854299.207 [NAL9602](INFO): No messages in MT queue 2014-04-18T20:51:40.482Z,1397854300.482 [NAL9602](IMPORTANT): GPS fix at: 1397854298.00 2014-04-18T20:51:40.499Z,1397854300.499 [Startup:StartupSatComms:A] Stopped 2014-04-18T20:51:40.499Z,1397854300.499 [Startup:StartupSatComms:B] Running Loop=1 2014-04-18T20:51:40.951Z,1397854300.951 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-18T20:51:42.026Z,1397854302.026 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:51:42.752Z,1397854302.752 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:51:42.753Z,1397854302.753 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:51:42.754Z,1397854302.754 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:43.315Z,1397854303.315 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:44.659Z,1397854304.659 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:44.661Z,1397854304.661 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:51:44.663Z,1397854304.663 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140418T075913/Courier0412.lzma 2014-04-18T20:51:44.663Z,1397854304.663 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:51:44.665Z,1397854304.665 [DataOverHttps](DEBUG): Wrote 326 bytes 2014-04-18T20:51:45.130Z,1397854305.130 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:45.563Z,1397854305.563 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:45.564Z,1397854305.564 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=787358&filename=Logs%2F20140418T075913%2FCourier0412.lzma 2014-04-18T20:51:45.566Z,1397854305.566 [DataOverHttps](INFO): Moved sent file to Logs/20140418T075913/Courier0412.lzma.bak 2014-04-18T20:51:45.567Z,1397854305.567 [DataOverHttps](INFO): SBD MOMSN=787358 2014-04-18T20:51:45.567Z,1397854305.567 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:51:46.159Z,1397854306.159 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:51:46.697Z,1397854306.697 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:51:46.697Z,1397854306.697 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:51:46.698Z,1397854306.698 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:47.201Z,1397854307.201 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:48.413Z,1397854308.413 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:48.415Z,1397854308.415 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:51:48.416Z,1397854308.416 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:51:48.417Z,1397854308.417 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:51:48.972Z,1397854308.972 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:49.445Z,1397854309.445 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:49.446Z,1397854309.446 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true 2014-04-18T20:51:49.446Z,1397854309.446 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:51:49.456Z,1397854309.456 [NAL9602](INFO): Powering down 2014-04-18T20:51:49.905Z,1397854309.905 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:51:50.342Z,1397854310.342 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:51:50.342Z,1397854310.342 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:51:50.346Z,1397854310.346 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:50.767Z,1397854310.767 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:51.778Z,1397854311.778 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:51.780Z,1397854311.780 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:51:51.780Z,1397854311.780 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:51:51.782Z,1397854311.782 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:51:52.205Z,1397854312.205 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:52.748Z,1397854312.748 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:52.749Z,1397854312.749 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true 2014-04-18T20:51:52.749Z,1397854312.749 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:51:53.183Z,1397854313.183 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:51:53.624Z,1397854313.624 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:51:53.624Z,1397854313.624 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:51:53.625Z,1397854313.625 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:54.056Z,1397854314.056 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:55.076Z,1397854315.076 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:55.078Z,1397854315.078 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:51:55.078Z,1397854315.078 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:51:55.080Z,1397854315.080 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:51:55.527Z,1397854315.527 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:56.015Z,1397854316.015 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:56.016Z,1397854316.016 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true 2014-04-18T20:51:56.016Z,1397854316.016 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:51:56.436Z,1397854316.436 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:51:56.886Z,1397854316.886 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:51:56.886Z,1397854316.886 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:51:56.887Z,1397854316.887 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:57.305Z,1397854317.305 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:58.333Z,1397854318.333 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:51:58.335Z,1397854318.335 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:51:58.335Z,1397854318.335 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:51:58.336Z,1397854318.336 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:51:58.791Z,1397854318.791 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:59.281Z,1397854319.281 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:51:59.282Z,1397854319.282 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true 2014-04-18T20:51:59.282Z,1397854319.282 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:51:59.709Z,1397854319.709 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:00.125Z,1397854320.125 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:00.126Z,1397854320.126 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:00.127Z,1397854320.127 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:00.542Z,1397854320.542 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:01.469Z,1397854321.469 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:01.471Z,1397854321.471 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:01.471Z,1397854321.471 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:01.473Z,1397854321.473 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:52:01.900Z,1397854321.900 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:02.373Z,1397854322.373 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:02.374Z,1397854322.374 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-18T20:52:02.374Z,1397854322.374 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:02.856Z,1397854322.856 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:03.291Z,1397854323.291 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:03.291Z,1397854323.291 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:03.292Z,1397854323.292 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:03.723Z,1397854323.723 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:04.638Z,1397854324.638 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:04.640Z,1397854324.640 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:04.643Z,1397854324.643 [DataOverHttps](INFO): Sending 294 bytes from file Logs/20140418T204949/Courier0000.lzma 2014-04-18T20:52:04.643Z,1397854324.643 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:04.646Z,1397854324.646 [DataOverHttps](DEBUG): Wrote 1035 bytes 2014-04-18T20:52:05.081Z,1397854325.081 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:05.554Z,1397854325.554 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:05.555Z,1397854325.555 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=787361&filename=Logs%2F20140418T204949%2FCourier0000.lzma 2014-04-18T20:52:05.555Z,1397854325.555 [DataOverHttps](INFO): Moved sent file to Logs/20140418T204949/Courier0000.lzma.bak 2014-04-18T20:52:05.556Z,1397854325.556 [DataOverHttps](INFO): SBD MOMSN=787361 2014-04-18T20:52:05.556Z,1397854325.556 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:06.140Z,1397854326.140 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:06.552Z,1397854326.552 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:06.552Z,1397854326.552 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:06.553Z,1397854326.553 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:06.972Z,1397854326.972 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:07.915Z,1397854327.915 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:07.917Z,1397854327.917 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:07.917Z,1397854327.917 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:07.919Z,1397854327.919 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:52:08.404Z,1397854328.404 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:08.919Z,1397854328.919 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:08.920Z,1397854328.920 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-18T20:52:08.920Z,1397854328.920 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:09.376Z,1397854329.376 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:09.804Z,1397854329.804 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:09.804Z,1397854329.804 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:09.806Z,1397854329.806 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:10.225Z,1397854330.225 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:11.172Z,1397854331.172 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:11.174Z,1397854331.174 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:11.176Z,1397854331.176 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20140418T075913/Express0413.lzma 2014-04-18T20:52:11.176Z,1397854331.176 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:11.178Z,1397854331.178 [DataOverHttps](DEBUG): Wrote 326 bytes 2014-04-18T20:52:11.615Z,1397854331.615 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:12.092Z,1397854332.092 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:12.093Z,1397854332.093 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=787364&filename=Logs%2F20140418T075913%2FExpress0413.lzma 2014-04-18T20:52:12.095Z,1397854332.095 [DataOverHttps](INFO): Moved sent file to Logs/20140418T075913/Express0413.lzma.bak 2014-04-18T20:52:12.096Z,1397854332.096 [DataOverHttps](INFO): SBD MOMSN=787364 2014-04-18T20:52:12.096Z,1397854332.096 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:12.585Z,1397854332.585 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:13.055Z,1397854333.055 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:13.055Z,1397854333.055 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:13.056Z,1397854333.056 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:13.486Z,1397854333.486 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:14.401Z,1397854334.401 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:14.403Z,1397854334.403 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:14.403Z,1397854334.403 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:14.405Z,1397854334.405 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:52:14.832Z,1397854334.832 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:15.314Z,1397854335.314 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:15.315Z,1397854335.315 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true 2014-04-18T20:52:15.315Z,1397854335.315 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:15.738Z,1397854335.738 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:16.174Z,1397854336.174 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:16.174Z,1397854336.174 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:16.176Z,1397854336.176 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:16.591Z,1397854336.591 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:17.506Z,1397854337.506 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:17.508Z,1397854337.508 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:17.508Z,1397854337.508 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:17.510Z,1397854337.510 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:52:17.937Z,1397854337.937 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:18.468Z,1397854338.468 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:18.468Z,1397854338.468 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true 2014-04-18T20:52:18.469Z,1397854338.469 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:18.906Z,1397854338.906 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:19.323Z,1397854339.323 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:19.323Z,1397854339.323 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:19.325Z,1397854339.325 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:19.748Z,1397854339.748 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:20.617Z,1397854340.617 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:20.619Z,1397854340.619 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:20.619Z,1397854340.619 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:20.621Z,1397854340.621 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:52:21.088Z,1397854341.088 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:21.555Z,1397854341.555 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:21.555Z,1397854341.555 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true 2014-04-18T20:52:21.555Z,1397854341.555 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:21.971Z,1397854341.971 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:22.396Z,1397854342.396 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:22.396Z,1397854342.396 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:22.397Z,1397854342.397 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:22.817Z,1397854342.817 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:23.752Z,1397854343.752 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:23.754Z,1397854343.754 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:23.754Z,1397854343.754 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:23.755Z,1397854343.755 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:52:24.233Z,1397854344.233 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:24.703Z,1397854344.703 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:24.704Z,1397854344.704 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true 2014-04-18T20:52:24.704Z,1397854344.704 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:25.132Z,1397854345.132 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:25.553Z,1397854345.553 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:25.553Z,1397854345.553 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:25.554Z,1397854345.554 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:26.005Z,1397854346.005 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:26.927Z,1397854346.927 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:26.929Z,1397854346.929 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:26.929Z,1397854346.929 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:26.930Z,1397854346.930 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:52:27.397Z,1397854347.397 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:27.872Z,1397854347.872 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:27.873Z,1397854347.873 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-18T20:52:27.873Z,1397854347.873 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:28.297Z,1397854348.297 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:28.776Z,1397854348.776 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:28.776Z,1397854348.776 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:28.777Z,1397854348.777 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:29.210Z,1397854349.210 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:30.088Z,1397854350.088 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:30.090Z,1397854350.090 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:30.093Z,1397854350.093 [DataOverHttps](INFO): Sending 715 bytes from file Logs/20140418T204949/Express0001.lzma 2014-04-18T20:52:30.093Z,1397854350.093 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:30.097Z,1397854350.097 [DataOverHttps](DEBUG): Wrote 2097 bytes 2014-04-18T20:52:30.528Z,1397854350.528 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:31.039Z,1397854351.039 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:31.040Z,1397854351.040 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=787366&filename=Logs%2F20140418T204949%2FExpress0001.lzma 2014-04-18T20:52:31.041Z,1397854351.041 [DataOverHttps](INFO): Moved sent file to Logs/20140418T204949/Express0001.lzma.bak 2014-04-18T20:52:31.041Z,1397854351.041 [DataOverHttps](INFO): SBD MOMSN=787366 2014-04-18T20:52:31.041Z,1397854351.041 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:31.530Z,1397854351.530 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:31.550Z,1397854351.550 [Startup:StartupSatComms:B] Stopped 2014-04-18T20:52:31.550Z,1397854351.550 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2014-04-18T20:52:31.550Z,1397854351.550 [Startup:StartupSatComms] Stopped 2014-04-18T20:52:31.550Z,1397854351.550 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2014-04-18T20:52:31.551Z,1397854351.551 [Startup](INFO): Completed Startup 2014-04-18T20:52:31.551Z,1397854351.551 [Startup] Stopped 2014-04-18T20:52:31.552Z,1397854351.552 [Startup](INFO): Aggregate::uninitialize Startup 2014-04-18T20:52:31.552Z,1397854351.552 [Startup:A.GoToSurface] Stopped 2014-04-18T20:52:31.552Z,1397854351.552 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-18T20:52:31.971Z,1397854351.971 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:31.971Z,1397854351.971 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:31.972Z,1397854351.972 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:31.998Z,1397854351.998 [MissionManager](IMPORTANT): Started mission Default 2014-04-18T20:52:31.999Z,1397854351.999 [Default] Running Loop=1 2014-04-18T20:52:31.999Z,1397854351.999 [Default](INFO): Aggregate::initialize Default 2014-04-18T20:52:31.999Z,1397854351.999 [Default:Iridium] Running Loop=1 2014-04-18T20:52:31.999Z,1397854351.999 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-18T20:52:31.999Z,1397854351.999 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-18T20:52:31.999Z,1397854351.999 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-18T20:52:31.999Z,1397854351.999 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-18T20:52:31.999Z,1397854351.999 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-18T20:52:32.006Z,1397854352.006 [Default:Iridium:B.GoToSurface] Stopped 2014-04-18T20:52:32.006Z,1397854352.006 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-18T20:52:32.006Z,1397854352.006 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-18T20:52:32.006Z,1397854352.006 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-18T20:52:32.014Z,1397854352.014 [Default:GPS] Running Loop=1 2014-04-18T20:52:32.014Z,1397854352.014 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-18T20:52:32.014Z,1397854352.014 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-18T20:52:32.014Z,1397854352.014 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-18T20:52:32.015Z,1397854352.015 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-18T20:52:32.015Z,1397854352.015 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-18T20:52:32.020Z,1397854352.020 [Default:GPS:B.GoToSurface] Stopped 2014-04-18T20:52:32.020Z,1397854352.020 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-18T20:52:32.020Z,1397854352.020 [Default:GPS:Read_GPS] Running Loop=1 2014-04-18T20:52:32.020Z,1397854352.020 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-18T20:52:32.479Z,1397854352.479 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:32.952Z,1397854352.952 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-18T20:52:32.956Z,1397854352.956 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-18T20:52:33.827Z,1397854353.827 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:33.829Z,1397854353.829 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:33.829Z,1397854353.829 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:33.832Z,1397854353.832 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:52:33.855Z,1397854353.855 [NAL9602](INFO): Powering up 2014-04-18T20:52:34.372Z,1397854354.372 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:34.795Z,1397854354.795 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:34.796Z,1397854354.796 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-18T20:52:34.796Z,1397854354.796 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:35.220Z,1397854355.220 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:35.636Z,1397854355.636 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:35.636Z,1397854355.636 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:35.638Z,1397854355.638 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:36.075Z,1397854356.075 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:36.950Z,1397854356.950 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:36.953Z,1397854356.953 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:36.954Z,1397854356.954 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20140418T204949/Courier0004.lzma 2014-04-18T20:52:36.955Z,1397854356.955 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:36.956Z,1397854356.956 [DataOverHttps](DEBUG): Wrote 393 bytes 2014-04-18T20:52:37.481Z,1397854357.481 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:37.896Z,1397854357.896 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:37.897Z,1397854357.897 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=787381&filename=Logs%2F20140418T204949%2FCourier0004.lzma 2014-04-18T20:52:37.898Z,1397854357.898 [DataOverHttps](INFO): Moved sent file to Logs/20140418T204949/Courier0004.lzma.bak 2014-04-18T20:52:37.898Z,1397854357.898 [DataOverHttps](INFO): SBD MOMSN=787381 2014-04-18T20:52:37.898Z,1397854357.898 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:38.389Z,1397854358.389 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:38.859Z,1397854358.859 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:38.859Z,1397854358.859 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:38.860Z,1397854358.860 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:39.290Z,1397854359.290 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:40.160Z,1397854360.160 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:40.162Z,1397854360.162 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:40.162Z,1397854360.162 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:40.163Z,1397854360.163 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:52:40.678Z,1397854360.678 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:41.101Z,1397854361.101 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:41.102Z,1397854361.102 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-18T20:52:41.102Z,1397854361.102 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:41.522Z,1397854361.522 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:41.962Z,1397854361.962 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:41.962Z,1397854361.962 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:41.964Z,1397854361.964 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:42.395Z,1397854362.395 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:43.296Z,1397854363.296 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:43.298Z,1397854363.298 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:43.300Z,1397854363.300 [DataOverHttps](INFO): Sending 93 bytes from file Logs/20140418T204949/Express0005.lzma 2014-04-18T20:52:43.300Z,1397854363.300 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:43.302Z,1397854363.302 [DataOverHttps](DEBUG): Wrote 519 bytes 2014-04-18T20:52:43.831Z,1397854363.831 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:44.312Z,1397854364.312 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:44.313Z,1397854364.313 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=true&momsn=787383&filename=Logs%2F20140418T204949%2FExpress0005.lzma 2014-04-18T20:52:44.313Z,1397854364.313 [DataOverHttps](INFO): Moved sent file to Logs/20140418T204949/Express0005.lzma.bak 2014-04-18T20:52:44.314Z,1397854364.314 [DataOverHttps](INFO): SBD MOMSN=787383 2014-04-18T20:52:44.314Z,1397854364.314 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:44.813Z,1397854364.813 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:52:44.853Z,1397854364.853 [NAL9602](ERROR): NAL9602 initialize error - Can't enter command mode: -MSSTM: no network service 2014-04-18T20:52:44.853Z,1397854364.853 [NAL9602] Communications Fault, FailCount= 1 2014-04-18T20:52:44.853Z,1397854364.853 [NAL9602](ERROR): Communications Fault 2014-04-18T20:52:44.871Z,1397854364.871 [Default:Iridium:Read_Iridium] Stopped 2014-04-18T20:52:44.872Z,1397854364.872 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-18T20:52:44.872Z,1397854364.872 [Default:Iridium] Stopped 2014-04-18T20:52:44.878Z,1397854364.878 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-18T20:52:44.878Z,1397854364.878 [Default:Iridium:A.SetSpeed] Stopped 2014-04-18T20:52:44.878Z,1397854364.878 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-18T20:52:44.878Z,1397854364.878 [Default:WaitAtTheSurface] Running Loop=1 2014-04-18T20:52:44.878Z,1397854364.878 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2014-04-18T20:52:44.878Z,1397854364.878 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-18T20:52:44.878Z,1397854364.878 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize. 2014-04-18T20:52:44.878Z,1397854364.878 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-18T20:52:44.878Z,1397854364.878 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-18T20:52:44.887Z,1397854364.887 [CBIT](ERROR): Communications Fault in component: NAL9602 2014-04-18T20:52:45.315Z,1397854365.315 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:52:45.315Z,1397854365.315 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:52:45.317Z,1397854365.317 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:45.327Z,1397854365.327 [NAL9602](INFO): Powering down 2014-04-18T20:52:45.348Z,1397854365.348 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-18T20:52:45.354Z,1397854365.354 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-18T20:52:45.772Z,1397854365.772 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:46.682Z,1397854366.682 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:52:46.684Z,1397854366.684 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:52:46.684Z,1397854366.684 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:52:46.685Z,1397854366.685 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:52:46.741Z,1397854366.741 [CBIT](INFO): Clearing failed state for component NAL9602 2014-04-18T20:52:46.741Z,1397854366.741 [NAL9602] No Fault, FailCount= 1 2014-04-18T20:52:47.220Z,1397854367.220 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:47.667Z,1397854367.667 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:52:47.668Z,1397854367.668 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-18T20:52:47.668Z,1397854367.668 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:52:50.753Z,1397854370.753 [NAL9602](INFO): Powering up NAL9602 2014-04-18T20:53:01.338Z,1397854381.338 [NAL9602](INFO): NAL9602 initialized 2014-04-18T20:53:14.729Z,1397854394.729 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2014-04-18T20:53:14.729Z,1397854394.729 [DVL_micro] Data Fault, FailCount= 1 2014-04-18T20:53:14.730Z,1397854394.730 [DVL_micro](ERROR): Data Fault 2014-04-18T20:53:14.759Z,1397854394.759 [CBIT](ERROR): Data Fault in component: DVL_micro 2014-04-18T20:53:15.193Z,1397854395.193 [DVL_micro](INFO): uninitialize:Powering down 2014-04-18T20:53:15.621Z,1397854395.621 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-18T20:53:15.621Z,1397854395.621 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-18T20:53:15.622Z,1397854395.622 [DVL_micro](ERROR): Hardware Fault 2014-04-18T20:53:16.101Z,1397854396.101 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-18T20:53:16.102Z,1397854396.102 [DVL_micro] No Fault, FailCount= 1 2014-04-18T20:53:16.505Z,1397854396.505 [DVL_micro](INFO): Initializing 2014-04-18T20:53:41.972Z,1397854421.972 [NAL9602](INFO): SBD MO Status=2, MOMSN=26700, MT Status=2, MTMSN=0 2014-04-18T20:53:41.972Z,1397854421.972 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-18T20:53:45.024Z,1397854425.024 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:53:45.499Z,1397854425.499 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:53:45.499Z,1397854425.499 [DataOverHttps](DEBUG): sslConnect 2014-04-18T20:53:45.500Z,1397854425.500 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:53:45.945Z,1397854425.945 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:53:46.941Z,1397854426.941 [DataOverHttps](DEBUG): sslConnecting 2014-04-18T20:53:46.943Z,1397854426.943 [DataOverHttps](DEBUG): dataWrite 2014-04-18T20:53:46.943Z,1397854426.943 [DataOverHttps](DEBUG): dataWriting 2014-04-18T20:53:46.944Z,1397854426.944 [DataOverHttps](DEBUG): Wrote 206 bytes 2014-04-18T20:53:47.384Z,1397854427.384 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:53:47.860Z,1397854427.860 [DataOverHttps](DEBUG): dataRead 2014-04-18T20:53:47.861Z,1397854427.861 [DataOverHttps](DEBUG): received: vehicle=daphne&busy=false 2014-04-18T20:53:47.861Z,1397854427.861 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:53:50.543Z,1397854430.543 [NAL9602](INFO): SBD MO Status=0, MOMSN=26700, MT Status=0, MTMSN=0 2014-04-18T20:53:50.543Z,1397854430.543 [NAL9602](INFO): No messages in MT queue 2014-04-18T20:53:51.882Z,1397854431.882 [NAL9602](IMPORTANT): GPS fix at: 1397854430.00 2014-04-18T20:53:51.901Z,1397854431.901 [Default:GPS:Read_GPS] Stopped 2014-04-18T20:53:51.901Z,1397854431.901 [Default:GPS:D] Running Loop=1 2014-04-18T20:53:52.352Z,1397854432.352 [Default:GPS:D] Stopped 2014-04-18T20:53:52.353Z,1397854432.353 [Default:GPS](INFO): Completed Default:GPS 2014-04-18T20:53:52.353Z,1397854432.353 [Default:GPS] Stopped 2014-04-18T20:53:52.353Z,1397854432.353 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-18T20:53:52.353Z,1397854432.353 [Default:GPS:A.SetSpeed] Stopped 2014-04-18T20:53:52.353Z,1397854432.353 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-18T20:54:12.956Z,1397854452.956 [NAL9602](INFO): Powering down 2014-04-18T20:54:47.928Z,1397854487.928 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:54:52.951Z,1397854492.951 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:54:57.927Z,1397854497.927 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:55:02.955Z,1397854502.955 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:55:07.927Z,1397854507.927 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:55:13.014Z,1397854513.014 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:55:17.923Z,1397854517.923 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:55:22.962Z,1397854522.962 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:55:22.962Z,1397854522.962 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2014-04-18T20:55:22.962Z,1397854522.962 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:55:52.976Z,1397854552.976 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:55:57.912Z,1397854557.912 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:02.915Z,1397854562.915 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:07.919Z,1397854567.919 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:12.899Z,1397854572.899 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:17.939Z,1397854577.939 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:22.918Z,1397854582.918 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:27.951Z,1397854587.951 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:27.951Z,1397854587.951 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2014-04-18T20:56:27.951Z,1397854587.951 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:56:27.954Z,1397854587.954 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2014-04-18T20:56:27.954Z,1397854587.954 [DVL_micro] Data Fault, FailCount= 1 2014-04-18T20:56:27.954Z,1397854587.954 [DVL_micro](ERROR): Data Fault 2014-04-18T20:56:27.983Z,1397854587.983 [CBIT](ERROR): Data Fault in component: DVL_micro 2014-04-18T20:56:32.989Z,1397854592.989 [DVL_micro](INFO): uninitialize:Powering down 2014-04-18T20:56:37.948Z,1397854597.948 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-18T20:56:37.948Z,1397854597.948 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-18T20:56:37.948Z,1397854597.948 [DVL_micro](ERROR): Hardware Fault 2014-04-18T20:56:42.956Z,1397854602.956 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-18T20:56:42.956Z,1397854602.956 [DVL_micro] No Fault, FailCount= 1 2014-04-18T20:56:47.950Z,1397854607.950 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:56:47.950Z,1397854607.950 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.088623 2014-04-18T20:56:47.959Z,1397854607.959 [DVL_micro](INFO): Initializing 2014-04-18T20:56:47.978Z,1397854607.978 [Default:CallIridium] Running Loop=1 2014-04-18T20:56:47.978Z,1397854607.978 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-18T20:56:47.978Z,1397854607.978 [Default:CallIridium:A] Running Loop=1 2014-04-18T20:56:47.980Z,1397854607.980 [Default:CallIridium:A] Stopped 2014-04-18T20:56:47.980Z,1397854607.980 [Default:CallIridium:B] Running Loop=1 2014-04-18T20:56:47.981Z,1397854607.981 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-18T20:56:52.949Z,1397854612.949 [Default:Iridium] Running Loop=1 2014-04-18T20:56:52.949Z,1397854612.949 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-18T20:56:52.949Z,1397854612.949 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-18T20:56:52.949Z,1397854612.949 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-18T20:56:52.950Z,1397854612.950 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-18T20:56:52.950Z,1397854612.950 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-18T20:56:52.950Z,1397854612.950 [Default:Iridium:B.GoToSurface] Stopped 2014-04-18T20:56:52.950Z,1397854612.950 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-18T20:56:52.951Z,1397854612.951 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-18T20:56:52.951Z,1397854612.951 [Default:GPS] Running Loop=1 2014-04-18T20:56:52.951Z,1397854612.951 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-18T20:56:52.951Z,1397854612.951 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-18T20:56:52.951Z,1397854612.951 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-18T20:56:52.951Z,1397854612.951 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-18T20:56:52.951Z,1397854612.951 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-18T20:56:52.952Z,1397854612.952 [Default:GPS:B.GoToSurface] Stopped 2014-04-18T20:56:52.952Z,1397854612.952 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-18T20:56:52.952Z,1397854612.952 [Default:GPS:Read_GPS] Running Loop=1 2014-04-18T20:56:53.424Z,1397854613.424 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:56:54.335Z,1397854614.335 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:54.338Z,1397854614.338 [NAL9602](INFO): Powering up 2014-04-18T20:56:54.778Z,1397854614.778 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:55.207Z,1397854615.207 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:55.623Z,1397854615.623 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:56.064Z,1397854616.064 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:56.481Z,1397854616.481 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:56.898Z,1397854616.898 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:57.314Z,1397854617.314 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:57.778Z,1397854617.778 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:58.203Z,1397854618.203 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:58.616Z,1397854618.616 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:59.109Z,1397854619.109 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:56:59.579Z,1397854619.579 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:00.013Z,1397854620.013 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:00.431Z,1397854620.431 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:00.889Z,1397854620.889 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:01.308Z,1397854621.308 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:01.733Z,1397854621.733 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:02.210Z,1397854622.210 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:02.623Z,1397854622.623 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:03.051Z,1397854623.051 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:03.468Z,1397854623.468 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:03.884Z,1397854623.884 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:04.339Z,1397854624.339 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:04.844Z,1397854624.844 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:04.904Z,1397854624.904 [NAL9602](INFO): NAL9602 initialized 2014-04-18T20:57:05.398Z,1397854625.398 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:05.819Z,1397854625.819 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:06.260Z,1397854626.260 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:06.697Z,1397854626.697 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:07.133Z,1397854627.133 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:07.592Z,1397854627.592 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:08.027Z,1397854628.027 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:08.527Z,1397854628.527 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:08.944Z,1397854628.944 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:09.369Z,1397854629.369 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:09.843Z,1397854629.843 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:10.282Z,1397854630.282 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:10.745Z,1397854630.745 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:11.167Z,1397854631.167 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:11.640Z,1397854631.640 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:12.065Z,1397854632.065 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:12.486Z,1397854632.486 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:12.902Z,1397854632.902 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:13.319Z,1397854633.319 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:13.740Z,1397854633.740 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:14.772Z,1397854634.772 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:15.386Z,1397854635.386 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:17.924Z,1397854637.924 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:18.407Z,1397854638.407 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:18.827Z,1397854638.827 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:19.248Z,1397854639.248 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:19.739Z,1397854639.739 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:20.173Z,1397854640.173 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:20.594Z,1397854640.594 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:21.057Z,1397854641.057 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:21.544Z,1397854641.544 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:21.964Z,1397854641.964 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:22.393Z,1397854642.393 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:22.830Z,1397854642.830 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:23.258Z,1397854643.258 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:23.691Z,1397854643.691 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:57:23.691Z,1397854643.691 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2014-04-18T20:57:23.691Z,1397854643.691 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:57:26.392Z,1397854646.392 [NAL9602](INFO): SBD MO Status=1, MOMSN=26701, MT Status=0, MTMSN=0 2014-04-18T20:57:26.441Z,1397854646.441 [NAL9602](INFO): Sent 74 bytes from file Logs/20140418T204949/Courier0008.lzma 2014-04-18T20:57:26.441Z,1397854646.441 [NAL9602](INFO): Packets left to send: 0 2014-04-18T20:57:26.443Z,1397854646.443 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T204949/Courier0008.lzma.parts/0000.sbd 2014-04-18T20:57:26.443Z,1397854646.443 [NAL9602](INFO): Completed sending Logs/20140418T204949/Courier0008.lzma 2014-04-18T20:57:37.336Z,1397854657.336 [NAL9602](INFO): SBD MO Status=1, MOMSN=26702, MT Status=0, MTMSN=0 2014-04-18T20:57:37.386Z,1397854657.386 [NAL9602](INFO): Sent 220 bytes from file Logs/20140418T204949/Express0009.lzma 2014-04-18T20:57:37.386Z,1397854657.386 [NAL9602](INFO): Packets left to send: 0 2014-04-18T20:57:37.388Z,1397854657.388 [NAL9602](INFO): Stored copy of sent data in Logs/20140418T204949/Express0009.lzma.parts/0000.sbd 2014-04-18T20:57:37.388Z,1397854657.388 [NAL9602](INFO): Completed sending Logs/20140418T204949/Express0009.lzma 2014-04-18T20:57:48.094Z,1397854668.094 [NAL9602](INFO): SBD MO Status=0, MOMSN=26703, MT Status=0, MTMSN=0 2014-04-18T20:57:48.178Z,1397854668.178 [Default:Iridium:Read_Iridium] Stopped 2014-04-18T20:57:48.179Z,1397854668.179 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-18T20:57:48.179Z,1397854668.179 [Default:Iridium] Stopped 2014-04-18T20:57:48.179Z,1397854668.179 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-18T20:57:48.179Z,1397854668.179 [Default:Iridium:A.SetSpeed] Stopped 2014-04-18T20:57:48.179Z,1397854668.179 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-18T20:57:48.635Z,1397854668.635 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-18T20:57:48.635Z,1397854668.635 [Default:CallIridium:B] Stopped 2014-04-18T20:57:48.635Z,1397854668.635 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-18T20:57:48.635Z,1397854668.635 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-18T20:57:48.635Z,1397854668.635 [Default:CallIridium] Stopped 2014-04-18T20:57:48.636Z,1397854668.636 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-18T20:57:49.538Z,1397854669.538 [NAL9602](IMPORTANT): GPS fix at: 1397854667.00 2014-04-18T20:57:49.558Z,1397854669.558 [Default:GPS:Read_GPS] Stopped 2014-04-18T20:57:49.558Z,1397854669.558 [Default:GPS:D] Running Loop=1 2014-04-18T20:57:50.003Z,1397854670.003 [Default:GPS:D] Stopped 2014-04-18T20:57:50.004Z,1397854670.004 [Default:GPS](INFO): Completed Default:GPS 2014-04-18T20:57:50.004Z,1397854670.004 [Default:GPS] Stopped 2014-04-18T20:57:50.004Z,1397854670.004 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-18T20:57:50.004Z,1397854670.004 [Default:GPS:A.SetSpeed] Stopped 2014-04-18T20:57:50.004Z,1397854670.004 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-18T20:57:55.606Z,1397854675.606 [DataOverHttps](DEBUG): tcpConnect 2014-04-18T20:58:00.622Z,1397854680.622 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:58:05.546Z,1397854685.546 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:58:10.658Z,1397854690.658 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:58:10.667Z,1397854690.667 [NAL9602](INFO): Powering down 2014-04-18T20:58:15.565Z,1397854695.565 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:58:20.597Z,1397854700.597 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:58:25.577Z,1397854705.577 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:58:30.605Z,1397854710.605 [DataOverHttps](DEBUG): tcpConnecting 2014-04-18T20:58:30.605Z,1397854710.605 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2014-04-18T20:58:30.605Z,1397854710.605 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:58:39.484Z,1397854719.484 [CommandLine](IMPORTANT): got command restart system 2014-04-18T20:58:41.841Z,1397854721.841 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2014-04-18T20:58:41.842Z,1397854721.842 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2014-04-18T20:58:42.082Z,1397854722.082 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2014-04-18T20:58:42.174Z,1397854722.174 [WetLabsBB2FL](INFO): Powering down 2014-04-18T20:58:42.182Z,1397854722.182 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2014-04-18T20:58:42.463Z,1397854722.463 [CTD_NeilBrown](INFO): Powering down 2014-04-18T20:58:42.482Z,1397854722.482 [ComponentRegistry](INFO): Shutting down AsyncPiEstimator ThreadHandler 2014-04-18T20:58:42.675Z,1397854722.675 [AsyncPiEstimator](DEBUG): Uninitialize AsyncPiEstimator. 2014-04-18T20:58:42.684Z,1397854722.684 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2014-04-18T20:58:42.684Z,1397854722.684 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2014-04-18T20:58:45.107Z,1397854725.107 [controlThread](DEBUG): Uninitializing ControlThread 2014-04-18T20:58:45.108Z,1397854725.108 [AHRS_sp3003D](INFO): Powering down 2014-04-18T20:58:45.108Z,1397854725.108 [DataOverHttps](DEBUG): disconnect 2014-04-18T20:58:45.109Z,1397854725.109 [DVL_micro](INFO): uninitialize:Powering down 2014-04-18T20:58:45.110Z,1397854725.110 [NAL9602](INFO): Powering down 2014-04-18T20:58:45.135Z,1397854725.135 [Radio_Freewave](INFO): Powering down 2014-04-18T20:58:45.139Z,1397854725.139 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-18T20:58:45.140Z,1397854725.140 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2014-04-18T20:58:45.141Z,1397854725.141 [Default] Stopped 2014-04-18T20:58:45.141Z,1397854725.141 [Default](INFO): Aggregate::uninitialize Default 2014-04-18T20:58:45.141Z,1397854725.141 [Default:WaitAtTheSurface] Stopped 2014-04-18T20:58:45.141Z,1397854725.141 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface 2014-04-18T20:58:45.141Z,1397854725.141 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Stopped 2014-04-18T20:58:45.141Z,1397854725.141 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Uninitialize. 2014-04-18T20:58:45.141Z,1397854725.141 [Default:WaitAtTheSurface:B.GoToSurface] Stopped 2014-04-18T20:58:45.142Z,1397854725.142 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-18T20:58:45.152Z,1397854725.152 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2014-04-18T20:58:45.153Z,1397854725.153 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2014-04-18T20:58:45.153Z,1397854725.153 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2014-04-18T20:58:45.153Z,1397854725.153 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2014-04-18T20:58:45.154Z,1397854725.154 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2014-04-18T20:58:45.154Z,1397854725.154 [BuoyancyServo](INFO): Powering down 2014-04-18T20:58:45.171Z,1397854725.171 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2014-04-18T20:58:45.171Z,1397854725.171 [ElevatorServo](INFO): Powering down 2014-04-18T20:58:45.172Z,1397854725.172 [MassServo](DEBUG): Uninitialize Mass Servo. 2014-04-18T20:58:45.173Z,1397854725.173 [MassServo](INFO): Powering down 2014-04-18T20:58:45.174Z,1397854725.174 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2014-04-18T20:58:45.174Z,1397854725.174 [RudderServo](INFO): Powering down 2014-04-18T20:58:45.175Z,1397854725.175 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2014-04-18T20:58:45.175Z,1397854725.175 [ThrusterServo](INFO): Powering down 2014-04-18T20:58:45.176Z,1397854725.176 [SBIT](DEBUG): Uninitialize SBIT Component. 2014-04-18T20:58:45.176Z,1397854725.176 [IBIT](DEBUG): Uninitialize IBIT Component. 2014-04-18T20:58:45.177Z,1397854725.177 [CBIT](DEBUG): Uninitialize CBIT Component.