2014-04-13T05:12:42.735Z,1397365962.735 [Supervisor](DEBUG): Initializing supervisor. 2014-04-13T05:12:42.738Z,1397365962.738 [SyncHandler](DEBUG): Created PCaller Thread at 4033B4E0 2014-04-13T05:12:42.739Z,1397365962.739 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2014-04-13T05:12:42.744Z,1397365962.744 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4036B4E0 2014-04-13T05:12:42.752Z,1397365962.752 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2014-04-13T05:12:42.789Z,1397365962.789 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2014-04-13T05:12:42.791Z,1397365962.791 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4039B4E0 2014-04-13T05:12:42.791Z,1397365962.791 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2014-04-13T05:12:42.797Z,1397365962.797 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403CB4E0 2014-04-13T05:12:42.799Z,1397365962.799 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2014-04-13T05:12:42.800Z,1397365962.800 [Supervisor](INFO): Looking for Config files in directory: Config/ 2014-04-13T05:12:42.816Z,1397365962.816 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2014-04-13T05:12:43.371Z,1397365963.371 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2014-04-13T05:12:43.372Z,1397365963.372 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2014-04-13T05:12:43.800Z,1397365963.800 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2014-04-13T05:12:43.800Z,1397365963.800 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2014-04-13T05:12:43.946Z,1397365963.946 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2014-04-13T05:12:43.949Z,1397365963.949 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2014-04-13T05:12:44.258Z,1397365964.258 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2014-04-13T05:12:44.259Z,1397365964.259 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2014-04-13T05:12:44.521Z,1397365964.521 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2014-04-13T05:12:44.524Z,1397365964.524 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2014-04-13T05:12:44.989Z,1397365964.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2014-04-13T05:12:44.990Z,1397365964.990 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2014-04-13T05:12:45.329Z,1397365965.329 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2014-04-13T05:12:45.374Z,1397365965.374 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2014-04-13T05:12:45.900Z,1397365965.900 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2014-04-13T05:12:45.913Z,1397365965.913 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2014-04-13T05:12:46.113Z,1397365966.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2014-04-13T05:12:46.114Z,1397365966.114 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2014-04-13T05:12:46.919Z,1397365966.919 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2014-04-13T05:12:46.920Z,1397365966.920 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2014-04-13T05:12:47.093Z,1397365967.093 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2014-04-13T05:12:47.094Z,1397365967.094 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2014-04-13T05:12:47.245Z,1397365967.245 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2014-04-13T05:12:47.443Z,1397365967.443 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2014-04-13T05:12:47.445Z,1397365967.445 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2014-04-13T05:12:47.607Z,1397365967.607 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2014-04-13T05:12:47.608Z,1397365967.608 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2014-04-13T05:12:47.824Z,1397365967.824 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2014-04-13T05:12:47.826Z,1397365967.826 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2014-04-13T05:12:47.846Z,1397365967.846 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2014-04-13T05:12:48.014Z,1397365968.014 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2014-04-13T05:12:48.253Z,1397365968.253 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2014-04-13T05:12:48.411Z,1397365968.411 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2014-04-13T05:12:48.535Z,1397365968.535 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2014-04-13T05:12:48.744Z,1397365968.744 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2014-04-13T05:12:48.890Z,1397365968.890 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2014-04-13T05:12:49.042Z,1397365969.042 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2014-04-13T05:12:49.239Z,1397365969.239 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2014-04-13T05:12:49.418Z,1397365969.418 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2014-04-13T05:12:49.422Z,1397365969.422 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2014-04-13T05:12:50.195Z,1397365970.195 [AHRS_sp3003D] Loaded 2014-04-13T05:12:50.195Z,1397365970.195 [ComponentRegistry](DEBUG): SyncComponent "AHRS_sp3003D" handled in the control thread. 2014-04-13T05:12:50.517Z,1397365970.517 [Batt_Ocean_Server] Loaded 2014-04-13T05:12:50.517Z,1397365970.517 [ComponentRegistry](DEBUG): SyncComponent "Batt_Ocean_Server" handled in the control thread. 2014-04-13T05:12:50.531Z,1397365970.531 [Depth_Keller] Loaded 2014-04-13T05:12:50.531Z,1397365970.531 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2014-04-13T05:12:50.536Z,1397365970.536 [DropWeight] Loaded 2014-04-13T05:12:50.536Z,1397365970.536 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2014-04-13T05:12:50.693Z,1397365970.693 [DVL_micro] Loaded 2014-04-13T05:12:50.693Z,1397365970.693 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2014-04-13T05:12:50.800Z,1397365970.800 [NAL9602] Loaded 2014-04-13T05:12:50.800Z,1397365970.800 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2014-04-13T05:12:50.859Z,1397365970.859 [Onboard] Loaded 2014-04-13T05:12:50.859Z,1397365970.859 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2014-04-13T05:12:50.867Z,1397365970.867 [Radio_Freewave] Loaded 2014-04-13T05:12:50.867Z,1397365970.867 [ComponentRegistry](DEBUG): SyncComponent "Radio_Freewave" handled in the control thread. 2014-04-13T05:12:50.874Z,1397365970.874 [SCPI] Loaded 2014-04-13T05:12:50.874Z,1397365970.874 [ComponentRegistry](DEBUG): SyncComponent "SCPI" handled in the control thread. 2014-04-13T05:12:50.874Z,1397365970.874 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2014-04-13T05:12:50.875Z,1397365970.875 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2014-04-13T05:12:51.881Z,1397365971.881 [InternalSim] Loaded 2014-04-13T05:12:51.882Z,1397365971.882 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread. 2014-04-13T05:12:51.886Z,1397365971.886 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2014-04-13T05:12:51.887Z,1397365971.887 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2014-04-13T05:12:52.189Z,1397365972.189 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2014-04-13T05:12:52.189Z,1397365972.189 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2014-04-13T05:12:52.198Z,1397365972.198 [AsyncPiEstimator](DEBUG): Construct AsyncPiEstimator. 2014-04-13T05:12:52.203Z,1397365972.203 [AsyncPiEstimator] Loaded 2014-04-13T05:12:52.203Z,1397365972.203 [ComponentRegistry](DEBUG): Component "AsyncPiEstimator" handled in its own thread. 2014-04-13T05:12:52.207Z,1397365972.207 [AsyncPiEstimator ThreadHandler](DEBUG): Created PCaller Thread at 4069E4E0 2014-04-13T05:12:52.207Z,1397365972.207 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2014-04-13T05:12:52.208Z,1397365972.208 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2014-04-13T05:12:52.313Z,1397365972.313 [DeadReckonUsingMultipleVelocitySources] Loaded 2014-04-13T05:12:52.313Z,1397365972.313 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2014-04-13T05:12:52.330Z,1397365972.330 [NavChart] Loaded 2014-04-13T05:12:52.330Z,1397365972.330 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2014-04-13T05:12:52.331Z,1397365972.331 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2014-04-13T05:12:52.331Z,1397365972.331 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2014-04-13T05:12:52.403Z,1397365972.403 [VerticalControl](DEBUG): Construct VerticalControl. 2014-04-13T05:12:52.525Z,1397365972.525 [VerticalControl] Loaded 2014-04-13T05:12:52.525Z,1397365972.525 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2014-04-13T05:12:52.526Z,1397365972.526 [HorizontalControl](DEBUG): Construct HorizontalControl. 2014-04-13T05:12:52.600Z,1397365972.600 [HorizontalControl] Loaded 2014-04-13T05:12:52.600Z,1397365972.600 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2014-04-13T05:12:52.601Z,1397365972.601 [SpeedControl](DEBUG): Construct SpeedControl. 2014-04-13T05:12:52.603Z,1397365972.603 [SpeedControl] Loaded 2014-04-13T05:12:52.603Z,1397365972.603 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2014-04-13T05:12:52.604Z,1397365972.604 [LoopControl](DEBUG): Construct LoopControl. 2014-04-13T05:12:52.604Z,1397365972.604 [LoopControl] Loaded 2014-04-13T05:12:52.605Z,1397365972.605 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2014-04-13T05:12:52.605Z,1397365972.605 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2014-04-13T05:12:52.606Z,1397365972.606 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2014-04-13T05:12:52.639Z,1397365972.639 [DepthRateCalculator] Loaded 2014-04-13T05:12:52.639Z,1397365972.639 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2014-04-13T05:12:52.644Z,1397365972.644 [PitchRateCalculator] Loaded 2014-04-13T05:12:52.645Z,1397365972.645 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2014-04-13T05:12:52.656Z,1397365972.656 [SpeedCalculator] Loaded 2014-04-13T05:12:52.656Z,1397365972.656 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2014-04-13T05:12:52.662Z,1397365972.662 [YawRateCalculator] Loaded 2014-04-13T05:12:52.662Z,1397365972.662 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2014-04-13T05:12:52.662Z,1397365972.662 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2014-04-13T05:12:52.663Z,1397365972.663 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2014-04-13T05:12:52.802Z,1397365972.802 [CTD_NeilBrown] Loaded 2014-04-13T05:12:52.802Z,1397365972.802 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2014-04-13T05:12:52.803Z,1397365972.803 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407404E0 2014-04-13T05:12:52.818Z,1397365972.818 [PAR_Licor] Loaded 2014-04-13T05:12:52.819Z,1397365972.819 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2014-04-13T05:12:52.857Z,1397365972.857 [WetLabsBB2FL] Loaded 2014-04-13T05:12:52.858Z,1397365972.858 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2014-04-13T05:12:52.860Z,1397365972.860 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407704E0 2014-04-13T05:12:52.860Z,1397365972.860 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2014-04-13T05:12:52.863Z,1397365972.863 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2014-04-13T05:12:52.987Z,1397365972.987 [SBIT](DEBUG): Construct Startup Built In Test. 2014-04-13T05:12:52.999Z,1397365972.999 [SBIT] Loaded 2014-04-13T05:12:52.999Z,1397365972.999 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2014-04-13T05:12:52.000Z,1397365973.000 [IBIT](DEBUG): Construct Initiated Built In Test. 2014-04-13T05:12:53.017Z,1397365973.017 [IBIT] Loaded 2014-04-13T05:12:53.017Z,1397365973.017 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2014-04-13T05:12:53.019Z,1397365973.019 [CBIT](DEBUG): Construct CBIT Built In Test. 2014-04-13T05:12:53.096Z,1397365973.096 [CBIT] Loaded 2014-04-13T05:12:53.096Z,1397365973.096 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2014-04-13T05:12:53.097Z,1397365973.097 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2014-04-13T05:12:53.099Z,1397365973.099 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2014-04-13T05:12:53.171Z,1397365973.171 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2014-04-13T05:12:53.172Z,1397365973.172 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2014-04-13T05:12:53.296Z,1397365973.296 [BuoyancyServo] Loaded 2014-04-13T05:12:53.297Z,1397365973.297 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2014-04-13T05:12:53.309Z,1397365973.309 [ElevatorServo] Loaded 2014-04-13T05:12:53.309Z,1397365973.309 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2014-04-13T05:12:53.320Z,1397365973.320 [MassServo] Loaded 2014-04-13T05:12:53.321Z,1397365973.321 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2014-04-13T05:12:53.337Z,1397365973.337 [RudderServo] Loaded 2014-04-13T05:12:53.337Z,1397365973.337 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2014-04-13T05:12:53.348Z,1397365973.348 [ThrusterServo] Loaded 2014-04-13T05:12:53.349Z,1397365973.349 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2014-04-13T05:12:53.349Z,1397365973.349 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2014-04-13T05:12:53.350Z,1397365973.350 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2014-04-13T05:12:53.393Z,1397365973.393 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2014-04-13T05:12:53.395Z,1397365973.395 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2014-04-13T05:12:53.396Z,1397365973.396 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2014-04-13T05:12:53.402Z,1397365973.402 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2014-04-13T05:12:53.404Z,1397365973.404 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 4083E4E0 2014-04-13T05:12:53.409Z,1397365973.409 [Supervisor](DEBUG): Running supervisor. 2014-04-13T05:12:53.410Z,1397365973.410 [CommandLine](INFO): Thread ID is 771 2014-04-13T05:12:53.417Z,1397365973.417 [controlThread](INFO): Thread ID is 770 2014-04-13T05:12:53.417Z,1397365973.417 [controlThread](DEBUG): Initializing ControlThread 2014-04-13T05:12:53.418Z,1397365973.418 [CycleStarter](INFO): Thread ID is 769 2014-04-13T05:12:53.421Z,1397365973.421 [logger](INFO): Thread ID is 772 2014-04-13T05:12:53.457Z,1397365973.457 [AsyncPiEstimator](INFO): Thread ID is 847 2014-04-13T05:12:53.458Z,1397365973.458 [AsyncPiEstimator](DEBUG): Initialize AsyncPiEstimator. 2014-04-13T05:12:53.475Z,1397365973.475 [CTD_NeilBrown](INFO): Thread ID is 848 2014-04-13T05:12:53.475Z,1397365973.475 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2014-04-13T05:12:53.477Z,1397365973.477 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-13T05:12:53.489Z,1397365973.489 [WetLabsBB2FL](INFO): Thread ID is 849 2014-04-13T05:12:53.491Z,1397365973.491 [WetLabsBB2FL](INFO): Powering down 2014-04-13T05:12:53.519Z,1397365973.519 [NavChartDb](INFO): Thread ID is 850 2014-04-13T05:12:53.555Z,1397365973.555 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2014-04-13T05:12:53.557Z,1397365973.557 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2014-04-13T05:12:53.558Z,1397365973.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2014-04-13T05:12:53.558Z,1397365973.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2014-04-13T05:12:53.558Z,1397365973.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2014-04-13T05:12:53.558Z,1397365973.558 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2014-04-13T05:12:53.559Z,1397365973.559 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2014-04-13T05:12:53.559Z,1397365973.559 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2014-04-13T05:12:53.559Z,1397365973.559 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2014-04-13T05:12:54.843Z,1397365974.843 [Batt_Ocean_Server](ERROR): Batt_Ocean_Server A initialization uart error: serial timeout 2014-04-13T05:12:54.843Z,1397365974.843 [Batt_Ocean_Server](ERROR): Ocean Server Batteries failed to initialize. Re-initializing 2014-04-13T05:12:54.843Z,1397365974.843 [Batt_Ocean_Server] Communications Fault, FailCount= 1 2014-04-13T05:12:54.843Z,1397365974.843 [Batt_Ocean_Server](ERROR): Communications Fault 2014-04-13T05:12:54.857Z,1397365974.857 [InternalSim](DEBUG): InternalSim initializing... 2014-04-13T05:12:55.112Z,1397365975.112 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2014-04-13T05:12:55.112Z,1397365975.112 [NavChart](DEBUG): Initialize NavChart Navigation. 2014-04-13T05:12:55.113Z,1397365975.113 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2014-04-13T05:12:55.114Z,1397365975.114 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2014-04-13T05:12:55.115Z,1397365975.115 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2014-04-13T05:12:55.116Z,1397365975.116 [LoopControl](DEBUG): Initialize LoopControlComponent. 2014-04-13T05:12:55.116Z,1397365975.116 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2014-04-13T05:12:55.117Z,1397365975.117 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2014-04-13T05:12:55.117Z,1397365975.117 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2014-04-13T05:12:55.117Z,1397365975.117 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2014-04-13T05:12:55.119Z,1397365975.119 [SBIT](INFO): Initialize SBIT Component. 2014-04-13T05:12:55.143Z,1397365975.143 [SBIT](IMPORTANT): Tethys CM Info: $Rev:11196 2014-04-13T05:12:55.144Z,1397365975.144 [SBIT](IMPORTANT): Kernel Release:2.6.27.8 2014-04-13T05:12:55.144Z,1397365975.144 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2014-04-13T05:12:55.145Z,1397365975.145 [IBIT](INFO): Initialize IBIT Component. 2014-04-13T05:12:55.145Z,1397365975.145 [CBIT](DEBUG): Initialize CBIT Component. 2014-04-13T05:12:55.146Z,1397365975.146 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2014-04-13T05:12:55.146Z,1397365975.146 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET. 2014-04-13T05:12:55.173Z,1397365975.173 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2014-04-13T05:12:55.205Z,1397365975.205 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T05:12:55.214Z,1397365975.214 [MissionManager](DEBUG): 2014-04-13T05:12:55.214Z,1397365975.214 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2014-04-13T05:12:55.293Z,1397365975.293 [MissionManager](INFO): DefineArg Default.NeedGPS = 1 bool 2014-04-13T05:12:55.295Z,1397365975.295 [Default:GPS:A.SetSpeed](DEBUG): Construct. 2014-04-13T05:12:55.310Z,1397365975.310 [Default:GPS:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T05:12:55.351Z,1397365975.351 [Default:Iridium:A.SetSpeed](DEBUG): Construct. 2014-04-13T05:12:55.354Z,1397365975.354 [Default:Iridium:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T05:12:55.373Z,1397365975.373 [Default:Iridium:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2014-04-13T05:12:55.395Z,1397365975.395 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Construct. 2014-04-13T05:12:55.398Z,1397365975.398 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T05:12:55.414Z,1397365975.414 [MissionManager](DEBUG): 400 400 Burn 300 Dropped drop weight due to communications timeout 5.0 1.0 5 2014-04-13T05:12:55.420Z,1397365975.420 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,AHRS_sp3003D,Batt_Ocean_Server,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,Radio_Freewave,SCPI,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2014-04-13T05:12:55.511Z,1397365975.511 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-13T05:12:55.683Z,1397365975.683 [DVL_micro](INFO): Initializing 2014-04-13T05:12:55.789Z,1397365975.789 [Radio_Freewave](INFO): Powering up 2014-04-13T05:12:56.075Z,1397365976.075 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:12:56.221Z,1397365976.221 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2014-04-13T05:12:56.241Z,1397365976.241 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2014-04-13T05:12:56.247Z,1397365976.247 [ElevatorServo](DEBUG): Initializing EZServoServo. 2014-04-13T05:12:56.253Z,1397365976.253 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2014-04-13T05:12:56.278Z,1397365976.278 [MassServo](DEBUG): Initializing EZServoServo. 2014-04-13T05:12:56.285Z,1397365976.285 [MassServo](DEBUG): Initializing MassServo. 2014-04-13T05:12:56.291Z,1397365976.291 [RudderServo](DEBUG): Initializing EZServoServo. 2014-04-13T05:12:56.297Z,1397365976.297 [RudderServo](DEBUG): Initializing RudderServo. 2014-04-13T05:12:56.303Z,1397365976.303 [ThrusterServo](DEBUG): Initializing EZServoServo. 2014-04-13T05:12:56.309Z,1397365976.309 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2014-04-13T05:12:56.370Z,1397365976.370 [CommandLine](FAULT): Scheduling is paused 2014-04-13T05:12:56.372Z,1397365976.372 [CBIT](ERROR): Communications Fault in component: Batt_Ocean_Server 2014-04-13T05:12:56.373Z,1397365976.373 [CBIT](INFO): Clearing failed state for component Batt_Ocean_Server 2014-04-13T05:12:56.373Z,1397365976.373 [Batt_Ocean_Server] No Fault, FailCount= 1 2014-04-13T05:12:58.137Z,1397365978.137 [Batt_Ocean_Server](INFO): Ocean Server Batteries initialized 2014-04-13T05:12:58.174Z,1397365978.174 [NAL9602](INFO): Powering up NAL9602 2014-04-13T05:12:58.189Z,1397365978.189 [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-13T05:12:58.269Z,1397365978.269 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:12:59.035Z,1397365979.035 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:12:59.639Z,1397365979.639 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:00.121Z,1397365980.121 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:00.694Z,1397365980.694 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:01.167Z,1397365981.167 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:01.887Z,1397365981.887 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:02.554Z,1397365982.554 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:02.996Z,1397365982.996 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:03.674Z,1397365983.674 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:04.124Z,1397365984.124 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:04.689Z,1397365984.689 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:05.250Z,1397365985.250 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:05.732Z,1397365985.732 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:06.236Z,1397365986.236 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:06.903Z,1397365986.903 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:07.477Z,1397365987.477 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:08.085Z,1397365988.085 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:08.681Z,1397365988.681 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:09.161Z,1397365989.161 [NAL9602](INFO): NAL9602 initialized 2014-04-13T05:13:09.188Z,1397365989.188 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:09.632Z,1397365989.632 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:10.142Z,1397365990.142 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:10.578Z,1397365990.578 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:10.629Z,1397365990.629 [SBIT](IMPORTANT): Beginning Startup BIT 2014-04-13T05:13:10.632Z,1397365990.632 [CBIT](IMPORTANT): Beginning GF scan 2014-04-13T05:13:11.185Z,1397365991.185 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:11.703Z,1397365991.703 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:12.250Z,1397365992.250 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:12.725Z,1397365992.725 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:13.306Z,1397365993.306 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:13.989Z,1397365993.990 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:14.630Z,1397365994.630 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:15.100Z,1397365995.100 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:15.577Z,1397365995.577 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:16.184Z,1397365996.184 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:16.677Z,1397365996.677 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:17.138Z,1397365997.138 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:17.870Z,1397365997.870 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:18.366Z,1397365998.366 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:18.966Z,1397365998.966 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:68 Calculated:92 2014-04-13T05:13:18.966Z,1397365998.966 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 32.3 30.9 32.1 32.6 -363.4 -404.0 -358.5 -373.8 -3-310 -365 8 7 8 8 -6.5 -40.3 -404.4 1 -3.4 14.6 -406.2 1 -45 16 -370 2 48 1 -370 2 3.60 -0.64 200.9 30.9 14.6 0.005 35.0 1489 68 2014-04-13T05:13:19.076Z,1397365999.076 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:19.548Z,1397365999.548 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:20.048Z,1397366000.048 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:20.580Z,1397366000.580 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:21.124Z,1397366001.124 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:21.661Z,1397366001.661 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:22.154Z,1397366002.154 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:22.612Z,1397366002.612 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:23.099Z,1397366003.099 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:23.572Z,1397366003.572 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:24.262Z,1397366004.262 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:24.675Z,1397366004.675 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:25.136Z,1397366005.136 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:25.663Z,1397366005.663 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:26.149Z,1397366006.149 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:26.979Z,1397366006.979 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:27.597Z,1397366007.597 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=25253, MT Status=1, MTMSN=1751 2014-04-13T05:13:27.598Z,1397366007.598 [NAL9602](INFO): Data available in MT queue 2014-04-13T05:13:27.659Z,1397366007.659 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:28.532Z,1397366008.532 [NAL9602](INFO): Received command:sched asap "load Science/science_to.xml;set science_to.MaxDepth 25.0 meter;set science_to.YoYoMaxDepth 20.0 meter;set science_to.Wpt1Lat 33.58515 degree;set science_to.Wpt1Lon -117.982505 degree;set science_to.Wpt2Lat 33.56436 degree" 3rkt2 1 3 2014-04-13T05:13:28.549Z,1397366008.549 [CommandLine](IMPORTANT): got command schedule asap "load Science/science_to.xml;set science_to.MaxDepth 25.0 meter;set science_to.YoYoMaxDepth 20.0 meter;set science_to.Wpt1Lat 33.58515 degree;set science_to.Wpt1Lon -117.982505 degree;set science_to.Wpt2Lat 33.56436 degree" 3rkt2 1 3.000000 2014-04-13T05:13:28.549Z,1397366008.549 [CommandLine](IMPORTANT): Scheduling command #1 of 3 with id=3rkt2 2014-04-13T05:13:28.550Z,1397366008.550 [CommandLine](IMPORTANT): Scheduled #1 (#1 of 3 with id='3rkt2'): "load Science/science_to.xml;set science_to.MaxDepth 25.0 meter;set science_to.YoYoMaxDepth 20.0 meter;set science_to.Wpt1Lat 33.58515 degree;set science_to.Wpt1Lon -117.982505 degree;set science_to.Wpt2Lat 33.56436 degree" ASAP 2014-04-13T05:13:28.579Z,1397366008.579 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:29.102Z,1397366009.102 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:29.791Z,1397366009.791 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:30.332Z,1397366010.332 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:30.909Z,1397366010.909 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:31.438Z,1397366011.438 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:31.938Z,1397366011.938 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:32.495Z,1397366012.495 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:33.012Z,1397366013.012 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:33.565Z,1397366013.565 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:34.082Z,1397366014.082 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:34.735Z,1397366014.735 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:35.188Z,1397366015.188 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:35.668Z,1397366015.668 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:36.104Z,1397366016.104 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:36.632Z,1397366016.632 [DeadReckonUsingMultipleVelocitySources](DEBUG): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2014-04-13T05:13:37.092Z,1397366017.092 [NAL9602](IMPORTANT): GPS fix at: 1397365981.00 2014-04-13T05:13:37.156Z,1397366017.156 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T05:13:37.779Z,1397366017.779 [CBIT](IMPORTANT): No ground fault detected 2014-04-13T05:13:44.286Z,1397366024.286 [NAL9602](INFO): Powering down 2014-04-13T05:14:05.010Z,1397366045.010 [SBIT](IMPORTANT): SBIT PASSED 2014-04-13T05:14:05.504Z,1397366045.504 [MissionManager](IMPORTANT): Started mission Startup 2014-04-13T05:14:05.504Z,1397366045.504 [Startup] Running Loop=1 2014-04-13T05:14:05.505Z,1397366045.505 [Startup](INFO): Aggregate::initialize Startup 2014-04-13T05:14:05.505Z,1397366045.505 [Startup:A.GoToSurface] Running Loop=1 2014-04-13T05:14:05.505Z,1397366045.505 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T05:14:05.511Z,1397366045.511 [Startup:StartupSatComms] Running Loop=1 2014-04-13T05:14:05.511Z,1397366045.511 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2014-04-13T05:14:05.511Z,1397366045.511 [Startup:StartupSatComms:A] Running Loop=1 2014-04-13T05:14:05.969Z,1397366045.969 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T05:14:06.340Z,1397366046.340 [NAL9602](INFO): Powering up 2014-04-13T05:14:16.858Z,1397366056.858 [NAL9602](INFO): NAL9602 initialized 2014-04-13T05:14:32.954Z,1397366072.954 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=25254, MT Status=1, MTMSN=1752 2014-04-13T05:14:32.954Z,1397366072.954 [NAL9602](INFO): Data available in MT queue 2014-04-13T05:14:33.692Z,1397366073.692 [NAL9602](INFO): Received command:sched asap "set science_to.Wpt2Lon -117.998585 degree;set science_to.Wpt3Lat 33.606468 degree;set science_to.Wpt3Lon -118.076374 degree;set science_to.Wpt4Lat 33.627258 degree;set science_to.Wpt4Lon -118.060314 degree" 3rkt2 2 3 2014-04-13T05:14:33.782Z,1397366073.782 [CommandLine](IMPORTANT): got command schedule asap "set science_to.Wpt2Lon -117.998585 degree;set science_to.Wpt3Lat 33.606468 degree;set science_to.Wpt3Lon -118.076374 degree;set science_to.Wpt4Lat 33.627258 degree;set science_to.Wpt4Lon -118.060314 degree" 3rkt2 2 3.000000 2014-04-13T05:14:33.783Z,1397366073.783 [CommandLine](IMPORTANT): Scheduling command #2 of 3 with id=3rkt2 2014-04-13T05:14:33.783Z,1397366073.783 [CommandLine](IMPORTANT): Scheduled #2 (#2 of 3 with id='3rkt2'): "set science_to.Wpt2Lon -117.998585 degree;set science_to.Wpt3Lat 33.606468 degree;set science_to.Wpt3Lon -118.076374 degree;set science_to.Wpt4Lat 33.627258 degree;set science_to.Wpt4Lon -118.060314 degree" ASAP 2014-04-13T05:15:02.075Z,1397366102.075 [NAL9602](IMPORTANT): GPS fix at: 1397366066.00 2014-04-13T05:15:02.089Z,1397366102.089 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T05:15:02.091Z,1397366102.091 [Startup:StartupSatComms:A] Stopped 2014-04-13T05:15:02.091Z,1397366102.091 [Startup:StartupSatComms:B] Running Loop=1 2014-04-13T05:15:02.653Z,1397366102.653 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-13T05:15:23.273Z,1397366123.273 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=25255, MT Status=1, MTMSN=1753 2014-04-13T05:15:23.321Z,1397366123.321 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T040209/Courier0048.lzma 2014-04-13T05:15:23.322Z,1397366123.322 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:15:23.323Z,1397366123.323 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Courier0048.lzma.parts/0000.sbd 2014-04-13T05:15:23.324Z,1397366123.324 [NAL9602](INFO): Completed sending Logs/20140413T040209/Courier0048.lzma 2014-04-13T05:15:24.006Z,1397366124.006 [NAL9602](INFO): Received command:sched asap "set science_to.NeedCommsTime 30 minute;set science_to.Timeout 8 hour;run " 3rkt2 3 3 2014-04-13T05:15:24.092Z,1397366124.092 [CommandLine](IMPORTANT): got command schedule asap "set science_to.NeedCommsTime 30 minute;set science_to.Timeout 8 hour;run " 3rkt2 3 3.000000 2014-04-13T05:15:24.092Z,1397366124.092 [CommandLine](IMPORTANT): Scheduling command #3 of 3 with id=3rkt2 2014-04-13T05:15:24.093Z,1397366124.093 [CommandLine](IMPORTANT): Scheduled #3 (#3 of 3 with id='3rkt2'): "set science_to.NeedCommsTime 30 minute;set science_to.Timeout 8 hour;run " ASAP 2014-04-13T05:15:24.261Z,1397366124.261 [CommandLine](IMPORTANT): got command load ./Missions/Science/science_to.xml 2014-04-13T05:15:24.261Z,1397366124.261 [MissionManager](INFO): Loading Mission: ./Missions/Science/science_to.xml 2014-04-13T05:15:24.392Z,1397366124.392 [MissionManager](INFO): DefineArg science_to.MinAltitude = 10.000000 m 2014-04-13T05:15:24.395Z,1397366124.395 [MissionManager](INFO): DefineArg science_to.MaxDepth = 105.000000 m 2014-04-13T05:15:24.398Z,1397366124.398 [MissionManager](INFO): DefineArg science_to.MinOffshore = 2000.000000 m 2014-04-13T05:15:24.401Z,1397366124.401 [MissionManager](INFO): DefineArg science_to.YoYoMinDepth = 3.000000 m 2014-04-13T05:15:24.404Z,1397366124.404 [MissionManager](INFO): DefineArg science_to.YoYoMaxDepth = 100.000000 m 2014-04-13T05:15:24.407Z,1397366124.407 [MissionManager](INFO): DefineArg science_to.YoYoUpPitch = 20.000000 arcdeg 2014-04-13T05:15:24.410Z,1397366124.410 [MissionManager](INFO): DefineArg science_to.YoYoDownPitch = -20.000000 arcdeg 2014-04-13T05:15:24.413Z,1397366124.413 [MissionManager](INFO): DefineArg science_to.Wpt1Lat = 0.000000 arcdeg 2014-04-13T05:15:24.444Z,1397366124.444 [MissionManager](INFO): DefineArg science_to.Wpt1Lon = 0.000000 arcdeg 2014-04-13T05:15:24.447Z,1397366124.447 [MissionManager](INFO): DefineArg science_to.Wpt2Lat = 0.000000 arcdeg 2014-04-13T05:15:24.450Z,1397366124.450 [MissionManager](INFO): DefineArg science_to.Wpt2Lon = 0.000000 arcdeg 2014-04-13T05:15:24.453Z,1397366124.453 [MissionManager](INFO): DefineArg science_to.Wpt3Lat = 0.000000 arcdeg 2014-04-13T05:15:24.467Z,1397366124.467 [MissionManager](INFO): DefineArg science_to.Wpt3Lon = 0.000000 arcdeg 2014-04-13T05:15:24.469Z,1397366124.469 [MissionManager](INFO): DefineArg science_to.Wpt4Lat = 0.000000 arcdeg 2014-04-13T05:15:24.473Z,1397366124.473 [MissionManager](INFO): DefineArg science_to.Wpt4Lon = 0.000000 arcdeg 2014-04-13T05:15:24.488Z,1397366124.488 [MissionManager](INFO): DefineArg science_to.NeedCommsTime = 120.000000 min 2014-04-13T05:15:24.491Z,1397366124.491 [MissionManager](INFO): DefineArg science_to.Speed = 1.000000 m/s 2014-04-13T05:15:24.494Z,1397366124.494 [MissionManager](INFO): DefineArg science_to.Timeout = 36.000000 h 2014-04-13T05:15:24.497Z,1397366124.497 [MissionManager](INFO): DefineArg science_to.BuoyancyNeutral = 0.000300 n/a 2014-04-13T05:15:24.532Z,1397366124.532 [MissionManager](INFO): DefineArg science_to.MassDefault = 0.000000 n/a 2014-04-13T05:15:24.536Z,1397366124.536 [MissionManager](INFO): DefineArg science_to.ZeroDeg = 0.000000 arcdeg 2014-04-13T05:15:24.538Z,1397366124.538 [science_to:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2014-04-13T05:15:24.589Z,1397366124.589 [science_to:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2014-04-13T05:15:24.608Z,1397366124.608 [science_to:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2014-04-13T05:15:24.639Z,1397366124.639 [science_to:D.Pitch](DEBUG): Construct. 2014-04-13T05:15:24.655Z,1397366124.655 [MissionManager](INFO): Inserting Stack: Missions/Insert/Surface.xml 2014-04-13T05:15:24.683Z,1397366124.683 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.SurfaceDepthRate = nan m/s 2014-04-13T05:15:24.686Z,1397366124.686 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.SurfacePitch = 20.000000 arcdeg 2014-04-13T05:15:24.690Z,1397366124.690 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.SurfaceSpeed = 1.000000 m/s 2014-04-13T05:15:24.693Z,1397366124.693 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.IridiumTimeout = 30.000000 min 2014-04-13T05:15:24.696Z,1397366124.696 [MissionManager](INFO): DefineArg science_to:SURFACECOMMS.UnpackSplitAtSurface = 0 bool 2014-04-13T05:15:24.697Z,1397366124.697 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Construct GoToSurface. 2014-04-13T05:15:24.710Z,1397366124.710 [MissionManager](INFO): RedefineArg science_to:SURFACECOMMS.SurfacePitch = value:20.000000 arcdeg 2014-04-13T05:15:24.728Z,1397366124.728 [MissionManager](INFO): RedefineArg science_to:SURFACECOMMS.SurfaceSpeed = reader:science_to.Speed 2014-04-13T05:15:24.735Z,1397366124.735 [MissionManager](INFO): Inserting Stack: Missions/Insert/Science.xml 2014-04-13T05:15:24.863Z,1397366124.863 [MissionManager](INFO): DefineArg science_to:Science.SampleISUS = 0 bool 2014-04-13T05:15:24.866Z,1397366124.866 [MissionManager](INFO): DefineArg science_to:Science.SampleISUSmaxPitch = 60.000000 arcdeg 2014-04-13T05:15:24.869Z,1397366124.869 [MissionManager](INFO): DefineArg science_to:Science.SampleISUSminPitch = -60.000000 arcdeg 2014-04-13T05:15:24.872Z,1397366124.872 [MissionManager](INFO): DefineArg science_to:Science.PeakDetectChlActive = 0 bool 2014-04-13T05:15:24.874Z,1397366124.874 [MissionManager](INFO): DefineArg science_to:Science.PeakDetectNO3Active = 0 bool 2014-04-13T05:15:24.877Z,1397366124.877 [MissionManager](INFO): DefineArg science_to:Science.UpwardDerivativeOfTemperatureActive = 0 bool 2014-04-13T05:15:24.880Z,1397366124.880 [MissionManager](INFO): DefineArg science_to:Science.ComputeWaterCurrent = 0 bool 2014-04-13T05:15:24.883Z,1397366124.883 [MissionManager](INFO): DefineArg science_to:Science.ComputeWaterCurrentMinDepth = 2.000000 m 2014-04-13T05:15:24.886Z,1397366124.886 [MissionManager](INFO): DefineArg science_to:Science.ComputeWaterCurrentMaxDepth = 5.000000 m 2014-04-13T05:15:24.889Z,1397366124.889 [MissionManager](INFO): DefineArg science_to:Science.EnabledAanderaaO2 = 0.000000 n/a 2014-04-13T05:15:24.892Z,1397366124.892 [MissionManager](INFO): DefineArg science_to:Science.EnabledNeilBrown = 1.000000 n/a 2014-04-13T05:15:24.895Z,1397366124.895 [MissionManager](INFO): DefineArg science_to:Science.EnabledTurbulence_NPS = 0.000000 n/a 2014-04-13T05:15:24.899Z,1397366124.899 [MissionManager](INFO): DefineArg science_to:Science.EnabledWetLabsBB2FL = 1.000000 n/a 2014-04-13T05:15:24.902Z,1397366124.902 [MissionManager](INFO): DefineArg science_to:Science.EnabledDVL = 1.000000 n/a 2014-04-13T05:15:24.905Z,1397366124.905 [MissionManager](INFO): DefineArg science_to:Science.EnabledISUS = 0.000000 n/a 2014-04-13T05:15:24.908Z,1397366124.908 [MissionManager](INFO): DefineOutput science_to:Science.PeakChl = 0.000000 ug/l 2014-04-13T05:15:24.944Z,1397366124.944 [MissionManager](INFO): DefineOutput science_to:Science.PeakChlDepth = 0.000000 m 2014-04-13T05:15:24.950Z,1397366124.950 [MissionManager](INFO): DefineOutput science_to:Science.PeakChlLatitude = nan arcdeg 2014-04-13T05:15:24.953Z,1397366124.953 [MissionManager](INFO): DefineOutput science_to:Science.PeakChlLongitude = nan arcdeg 2014-04-13T05:15:24.956Z,1397366124.956 [MissionManager](INFO): DefineOutput science_to:Science.PeakNO3 = 0.000000 umol/l 2014-04-13T05:15:24.959Z,1397366124.959 [MissionManager](INFO): DefineOutput science_to:Science.PeakNO3Depth = 0.000000 m 2014-04-13T05:15:24.962Z,1397366124.962 [MissionManager](INFO): DefineOutput science_to:Science.PeakNO3Latitude = nan arcdeg 2014-04-13T05:15:24.965Z,1397366124.965 [MissionManager](INFO): DefineOutput science_to:Science.PeakNO3Longitude = nan arcdeg 2014-04-13T05:15:25.009Z,1397366125.009 [science_to:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2014-04-13T05:15:25.062Z,1397366125.062 [science_to:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Construct PeakDetectVsDepth. 2014-04-13T05:15:25.090Z,1397366125.090 [MissionManager](INFO): RedefineArg science_to:Science.SampleISUS = value:1 bool 2014-04-13T05:15:25.096Z,1397366125.096 [MissionManager](INFO): RedefineArg science_to:Science.PeakDetectChlActive = value:1 bool 2014-04-13T05:15:25.097Z,1397366125.097 [science_to:H.Buoyancy](DEBUG): Construct Buoyancy. 2014-04-13T05:15:25.105Z,1397366125.105 [science_to:I.SetSpeed](DEBUG): Construct. 2014-04-13T05:15:25.130Z,1397366125.130 [science_to:J.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2014-04-13T05:15:25.150Z,1397366125.150 [science_to:K.YoYo](DEBUG): Construct YoYo. 2014-04-13T05:15:25.165Z,1397366125.165 [science_to:Wpt1:A.Waypoint](DEBUG): Construct Waypoint. 2014-04-13T05:15:25.174Z,1397366125.174 [science_to:Wpt2:A.Waypoint](DEBUG): Construct Waypoint. 2014-04-13T05:15:25.181Z,1397366125.181 [science_to:Wpt3:A.Waypoint](DEBUG): Construct Waypoint. 2014-04-13T05:15:25.189Z,1397366125.189 [science_to:Wpt4:A.Waypoint](DEBUG): Construct Waypoint. 2014-04-13T05:15:25.229Z,1397366125.229 [MissionManager](DEBUG): Vehicle yo-yo's to the specified waypoint, with science turned on. Minimum height above the sea floor for the entire mission. 10.0 Maximum depth for the entire mission. 105.0 Minimum offshore distance for the entire mission. 2000.0 Minimum depth while performing the YoYo behavior. 3.0 Maximum depth while performing the YoYo behavior. 100.0 Vehicle up pitch while performing the YoYo behavior. 20.0 Vehicle down pitch while performing the YoYo behavior. -20.0 Latitude of waypoint 1. If zero, waypoint is skipped. 0 Longitude of waypoint 1. If zero, waypoint is skipped. 0 Latitude of waypoint 2. If zero, waypoint is skipped. 0 Longitude of waypoint 2. If zero, waypoint is skipped. 0 Latitude of waypoint 3. If zero, waypoint is skipped. 0 Longitude of waypoint 3. If zero, waypoint is skipped. 0 Latitude of waypoint 4. If zero, waypoint is skipped. 0 Longitude of waypoint 4. If zero, waypoint is skipped. 0 Elapsed time after previous surface communications when vehicle will begin to ascend for additional surface communications, if the vehicle has a positive pitch. If the vehicle has a negative pitch, it will wait up to 10 minutes more to begin ascent. 120 Speed while performing the YoYo behavior. 1 Maximum length of mission 36 Buoyancy bladder position while performing the YoYo behavior. Defaults to buoyancyNeutral setting in the Config/Control.cfg file. Set to NaN cc for active buoyancy Static setting for mass during the mission. Set to NaN mm for active mass position Constant value. Do not change. 0 0 Safety behavior that keeps vehicle off sea floor Safety behavior that keeps vehicle from going too deep 0 Safety behavior that keeps vehicle away from the shore 20 0 10 If we're executing here or below, lets' get science data! 2014-04-13T05:15:25.229Z,1397366125.229 [CommandLine](IMPORTANT): Loaded ./Missions/Science/science_to.xml 2014-04-13T05:15:32.422Z,1397366132.422 [CommandLine](IMPORTANT): got command set science_to.MaxDepth 25.000000 meter 2014-04-13T05:15:32.423Z,1397366132.423 [CommandLine](IMPORTANT): got command set science_to.YoYoMaxDepth 20.000000 meter 2014-04-13T05:15:32.424Z,1397366132.424 [CommandLine](IMPORTANT): got command set science_to.Wpt1Lat 33.585152 degree 2014-04-13T05:15:32.424Z,1397366132.424 [CommandLine](IMPORTANT): got command set science_to.Wpt1Lon -117.982506 degree 2014-04-13T05:15:32.425Z,1397366132.425 [CommandLine](IMPORTANT): got command set science_to.Wpt2Lat 33.564362 degree 2014-04-13T05:15:36.762Z,1397366136.762 [NAL9602](INFO): SBD MO Status=1, MOMSN=25256, MT Status=0, MTMSN=0 2014-04-13T05:15:36.810Z,1397366136.810 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Courier0000.lzma 2014-04-13T05:15:36.810Z,1397366136.810 [NAL9602](INFO): Packets left to send: 1 2014-04-13T05:15:36.812Z,1397366136.812 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Courier0000.lzma.parts/0001.sbd 2014-04-13T05:15:39.637Z,1397366139.637 [CommandLine](IMPORTANT): got command set science_to.Wpt2Lon -117.998589 degree 2014-04-13T05:15:39.638Z,1397366139.638 [CommandLine](IMPORTANT): got command set science_to.Wpt3Lat 33.606468 degree 2014-04-13T05:15:39.671Z,1397366139.671 [CommandLine](IMPORTANT): got command set science_to.Wpt3Lon -118.076370 degree 2014-04-13T05:15:39.671Z,1397366139.671 [CommandLine](IMPORTANT): got command set science_to.Wpt4Lat 33.627258 degree 2014-04-13T05:15:39.672Z,1397366139.672 [CommandLine](IMPORTANT): got command set science_to.Wpt4Lon -118.060310 degree 2014-04-13T05:15:42.720Z,1397366142.720 [CommandLine](IMPORTANT): got command set science_to.NeedCommsTime 30.000000 minute 2014-04-13T05:15:42.721Z,1397366142.721 [CommandLine](IMPORTANT): got command set science_to.Timeout 8.000000 hour 2014-04-13T05:15:42.722Z,1397366142.722 [CommandLine](IMPORTANT): got command run 2014-04-13T05:15:42.768Z,1397366142.768 [CommandLine](IMPORTANT): Running 2014-04-13T05:15:47.992Z,1397366147.992 [NAL9602](INFO): SBD MO Status=1, MOMSN=25257, MT Status=0, MTMSN=0 2014-04-13T05:15:48.044Z,1397366148.044 [NAL9602](INFO): Sent 25 bytes from file Logs/20140413T051242/Courier0000.lzma 2014-04-13T05:15:48.044Z,1397366148.044 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:15:48.045Z,1397366148.045 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Courier0000.lzma.parts/0000.sbd 2014-04-13T05:15:48.045Z,1397366148.045 [NAL9602](INFO): Completed sending Logs/20140413T051242/Courier0000.lzma 2014-04-13T05:15:55.797Z,1397366155.797 [NAL9602](INFO): SBD MO Status=1, MOMSN=25258, MT Status=0, MTMSN=0 2014-04-13T05:15:55.864Z,1397366155.864 [NAL9602](INFO): Sent 18 bytes from file Logs/20140413T040209/Express0049.lzma 2014-04-13T05:15:55.864Z,1397366155.864 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:15:55.866Z,1397366155.866 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T040209/Express0049.lzma.parts/0000.sbd 2014-04-13T05:15:55.866Z,1397366155.866 [NAL9602](INFO): Completed sending Logs/20140413T040209/Express0049.lzma 2014-04-13T05:16:02.403Z,1397366162.403 [Startup:StartupSatComms:B](INFO): Timed out from 2014-04-13T05:15:02.1Z 2014-04-13T05:16:02.403Z,1397366162.403 [Startup:StartupSatComms:B] Stopped 2014-04-13T05:16:02.403Z,1397366162.403 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2014-04-13T05:16:02.403Z,1397366162.403 [Startup:StartupSatComms] Stopped 2014-04-13T05:16:02.404Z,1397366162.404 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2014-04-13T05:16:02.404Z,1397366162.404 [Startup](INFO): Completed Startup 2014-04-13T05:16:02.404Z,1397366162.404 [Startup] Stopped 2014-04-13T05:16:02.405Z,1397366162.405 [Startup](INFO): Aggregate::uninitialize Startup 2014-04-13T05:16:02.405Z,1397366162.405 [Startup:A.GoToSurface] Stopped 2014-04-13T05:16:02.405Z,1397366162.405 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T05:16:02.817Z,1397366162.817 [MissionManager](IMPORTANT): Started mission science_to 2014-04-13T05:16:02.817Z,1397366162.817 [science_to] Running Loop=1 2014-04-13T05:16:02.817Z,1397366162.817 [science_to](INFO): Aggregate::initialize science_to 2014-04-13T05:16:02.817Z,1397366162.817 [science_to:B.DepthEnvelope] Running Loop=1 2014-04-13T05:16:02.817Z,1397366162.817 [science_to:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2014-04-13T05:16:02.817Z,1397366162.817 [science_to:D.Pitch] Running Loop=1 2014-04-13T05:16:02.817Z,1397366162.817 [science_to:D.Pitch](DEBUG): Initialize. 2014-04-13T05:16:02.818Z,1397366162.818 [science_to:Science] Running Loop=1 2014-04-13T05:16:02.818Z,1397366162.818 [science_to:Science](INFO): Aggregate::initialize science_to:Science 2014-04-13T05:16:02.818Z,1397366162.818 [science_to:Science:A] Running Loop=1 2014-04-13T05:16:02.818Z,1397366162.818 [science_to:Science:B] Running Loop=1 2014-04-13T05:16:02.818Z,1397366162.818 [science_to:Science:C] Running Loop=1 2014-04-13T05:16:02.818Z,1397366162.818 [science_to:Science:D] Running Loop=1 2014-04-13T05:16:02.819Z,1397366162.819 [science_to:Science:E] Running Loop=1 2014-04-13T05:16:02.819Z,1397366162.819 [science_to:Science:F] Running Loop=1 2014-04-13T05:16:02.819Z,1397366162.819 [science_to:Science:G] Running Loop=1 2014-04-13T05:16:02.819Z,1397366162.819 [science_to:Science:PeakDetectChl] Running Loop=1 2014-04-13T05:16:02.819Z,1397366162.819 [science_to:Science:PeakDetectChl](INFO): Aggregate::initialize science_to:Science:PeakDetectChl 2014-04-13T05:16:02.819Z,1397366162.819 [science_to:Science:PeakDetectChl:A.PeakDetectVsDepth] Running Loop=1 2014-04-13T05:16:02.819Z,1397366162.819 [science_to:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Initialize. 2014-04-13T05:16:02.821Z,1397366162.821 [science_to:Science:PeakDetectNO3] Running Loop=1 2014-04-13T05:16:02.821Z,1397366162.821 [science_to:Science:PeakDetectNO3](INFO): Aggregate::initialize science_to:Science:PeakDetectNO3 2014-04-13T05:16:02.821Z,1397366162.821 [science_to:Science:PeakDetectNO3:A.PeakDetectVsDepth] Running Loop=1 2014-04-13T05:16:02.822Z,1397366162.822 [science_to:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Initialize. 2014-04-13T05:16:02.824Z,1397366162.824 [science_to:H.Buoyancy] Running Loop=1 2014-04-13T05:16:02.824Z,1397366162.824 [science_to:H.Buoyancy](DEBUG): Initialize Buoyancy Component. 2014-04-13T05:16:02.824Z,1397366162.824 [science_to:I.SetSpeed] Running Loop=1 2014-04-13T05:16:02.824Z,1397366162.824 [science_to:I.SetSpeed](DEBUG): Initialize. 2014-04-13T05:16:02.824Z,1397366162.824 [science_to:J.DepthEnvelope] Running Loop=1 2014-04-13T05:16:02.824Z,1397366162.824 [science_to:J.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2014-04-13T05:16:02.824Z,1397366162.824 [science_to:K.YoYo] Running Loop=1 2014-04-13T05:16:02.824Z,1397366162.824 [science_to:K.YoYo](DEBUG): Initialize YoYoComponent. 2014-04-13T05:16:02.825Z,1397366162.825 [science_to:SURFACECOMMS] Running Loop=1 2014-04-13T05:16:02.825Z,1397366162.825 [science_to:SURFACECOMMS](INFO): Aggregate::initialize science_to:SURFACECOMMS 2014-04-13T05:16:02.825Z,1397366162.825 [science_to:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T05:16:02.825Z,1397366162.825 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T05:16:02.827Z,1397366162.827 [science_to:K.YoYo] Running Loop=1 2014-04-13T05:16:02.832Z,1397366162.832 [science_to:J.DepthEnvelope] Running Loop=1 2014-04-13T05:16:02.838Z,1397366162.838 [science_to:I.SetSpeed] Running Loop=1 2014-04-13T05:16:02.862Z,1397366162.862 [science_to:H.Buoyancy] Running Loop=1 2014-04-13T05:16:02.872Z,1397366162.872 [science_to:Science] Running Loop=1 2014-04-13T05:16:02.876Z,1397366162.876 [science_to:Science:PeakDetectNO3] Stopped 2014-04-13T05:16:02.876Z,1397366162.876 [science_to:Science:PeakDetectNO3](INFO): Aggregate::uninitialize science_to:Science:PeakDetectNO3 2014-04-13T05:16:02.876Z,1397366162.876 [science_to:Science:PeakDetectNO3:A.PeakDetectVsDepth] Stopped 2014-04-13T05:16:02.876Z,1397366162.876 [science_to:Science:PeakDetectNO3:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2014-04-13T05:16:02.877Z,1397366162.877 [science_to:Science:PeakDetectChl] Running Loop=1 2014-04-13T05:16:02.892Z,1397366162.892 [science_to:Science:G] Running Loop=1 2014-04-13T05:16:02.893Z,1397366162.893 [science_to:Science:G](DEBUG): Initialize ReadDataComponent to sense mass_concentration_of_chlorophyll_in_sea_water 2014-04-13T05:16:02.895Z,1397366162.895 [science_to:Science:F] Stopped 2014-04-13T05:16:02.895Z,1397366162.895 [science_to:Science:E] Stopped 2014-04-13T05:16:02.895Z,1397366162.895 [science_to:Science:D] Running Loop=1 2014-04-13T05:16:02.896Z,1397366162.896 [science_to:Science:D](DEBUG): Initialize ReadDataComponent to sense sea_water_temperature 2014-04-13T05:16:02.896Z,1397366162.896 [science_to:Science:D](DEBUG): Initialize ReadDataComponent to sense sea_water_salinity 2014-04-13T05:16:02.898Z,1397366162.898 [science_to:Science:C] Stopped 2014-04-13T05:16:02.898Z,1397366162.898 [science_to:Science:B] Stopped 2014-04-13T05:16:02.898Z,1397366162.898 [science_to:Science:A] Stopped 2014-04-13T05:16:02.906Z,1397366162.906 [science_to:SURFACECOMMS:B] Running Loop=1 2014-04-13T05:16:02.907Z,1397366162.907 [science_to:SURFACECOMMS:B](INFO): Aggregate::initialize science_to:SURFACECOMMS:B 2014-04-13T05:16:02.907Z,1397366162.907 [science_to:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T05:16:02.907Z,1397366162.907 [science_to:D.Pitch] Running Loop=1 2014-04-13T05:16:02.912Z,1397366162.912 [science_to:OffshoreWrapper] Running Loop=1 2014-04-13T05:16:02.912Z,1397366162.912 [science_to:OffshoreWrapper](INFO): Aggregate::initialize science_to:OffshoreWrapper 2014-04-13T05:16:02.912Z,1397366162.912 [science_to:OffshoreWrapper:A.OffshoreEnvelope] Running Loop=1 2014-04-13T05:16:02.912Z,1397366162.912 [science_to:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2014-04-13T05:16:02.912Z,1397366162.912 [science_to:OffshoreWrapper:A.OffshoreEnvelope] Running Loop=1 2014-04-13T05:16:02.918Z,1397366162.918 [science_to:B.DepthEnvelope] Running Loop=1 2014-04-13T05:16:02.923Z,1397366162.923 [science_to:AltEnvWrapper] Running Loop=1 2014-04-13T05:16:02.923Z,1397366162.923 [science_to:AltEnvWrapper](INFO): Aggregate::initialize science_to:AltEnvWrapper 2014-04-13T05:16:02.923Z,1397366162.923 [science_to:AltEnvWrapper:A.AltitudeEnvelope] Running Loop=1 2014-04-13T05:16:02.923Z,1397366162.923 [science_to:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2014-04-13T05:16:02.924Z,1397366162.924 [science_to:AltEnvWrapper:A.AltitudeEnvelope] Running Loop=1 2014-04-13T05:16:03.197Z,1397366163.197 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=4 2014-04-13T05:16:03.198Z,1397366163.198 [WetLabsBB2FL](INFO): Powering up 2014-04-13T05:16:03.285Z,1397366163.285 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-13T05:16:03.393Z,1397366163.393 [science_to:SURFACECOMMS:B] Stopped 2014-04-13T05:16:03.393Z,1397366163.393 [science_to:SURFACECOMMS:B](INFO): Aggregate::uninitialize science_to:SURFACECOMMS:B 2014-04-13T05:16:03.393Z,1397366163.393 [science_to:SURFACECOMMS:B:A] Stopped 2014-04-13T05:16:03.394Z,1397366163.394 [science_to:SURFACECOMMS:C] Running Loop=1 2014-04-13T05:16:03.394Z,1397366163.394 [science_to:SURFACECOMMS:C](INFO): Aggregate::initialize science_to:SURFACECOMMS:C 2014-04-13T05:16:03.394Z,1397366163.394 [science_to:SURFACECOMMS:C:A] Running Loop=1 2014-04-13T05:16:03.761Z,1397366163.761 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:16:03.761Z,1397366163.761 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 30.6 31.8 33.8 32.8 -610.0 -434.5 -239.6 -415.5 -625 -436 -255 -489 7 7 8 8 -494.3 -25.4 -458.3 1 241.9 406.6 -480.9 1 -493 70 -486 2 306 393 -486 2 4.05 -2.60 240.2 3 0.005 35.0 1489 92 2014-04-13T05:16:03.805Z,1397366163.805 [science_to:K.YoYo] Preempted 2014-04-13T05:16:03.805Z,1397366163.805 [science_to:J.DepthEnvelope] Preempted 2014-04-13T05:16:03.805Z,1397366163.805 [science_to:I.SetSpeed] Preempted 2014-04-13T05:16:03.805Z,1397366163.805 [science_to:H.Buoyancy] Preempted 2014-04-13T05:16:03.805Z,1397366163.805 [science_to:Science] Preempted 2014-04-13T05:16:03.805Z,1397366163.805 [science_to:Science:D] Preempted 2014-04-13T05:16:03.805Z,1397366163.805 [science_to:Science:G] Preempted 2014-04-13T05:16:03.805Z,1397366163.805 [science_to:Science:PeakDetectChl] Preempted 2014-04-13T05:16:03.807Z,1397366163.807 [science_to:SURFACECOMMS:C:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T05:16:04.445Z,1397366164.445 [WetLabsBB2FL](INFO): Powering down 2014-04-13T05:16:07.327Z,1397366167.327 [NAL9602](INFO): SBD MO Status=1, MOMSN=25259, MT Status=0, MTMSN=0 2014-04-13T05:16:07.382Z,1397366167.382 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Express0001.lzma 2014-04-13T05:16:07.382Z,1397366167.382 [NAL9602](INFO): Packets left to send: 3 2014-04-13T05:16:07.384Z,1397366167.384 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0001.lzma.parts/0003.sbd 2014-04-13T05:16:09.632Z,1397366169.632 [NAL9602](IMPORTANT): GPS fix at: 1397366133.00 2014-04-13T05:16:09.698Z,1397366169.698 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T05:16:09.702Z,1397366169.702 [science_to:SURFACECOMMS:C:A] Stopped 2014-04-13T05:16:09.702Z,1397366169.702 [science_to:SURFACECOMMS:C:B] Running Loop=1 2014-04-13T05:16:10.131Z,1397366170.131 [science_to:SURFACECOMMS:C:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-13T05:16:20.083Z,1397366180.083 [NAL9602](INFO): SBD MO Status=1, MOMSN=25260, MT Status=0, MTMSN=0 2014-04-13T05:16:20.134Z,1397366180.134 [NAL9602](INFO): Sent 74 bytes from file Logs/20140413T051242/Courier0004.lzma 2014-04-13T05:16:20.134Z,1397366180.134 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:16:20.136Z,1397366180.136 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Courier0004.lzma.parts/0000.sbd 2014-04-13T05:16:20.136Z,1397366180.136 [NAL9602](INFO): Completed sending Logs/20140413T051242/Courier0004.lzma 2014-04-13T05:16:30.860Z,1397366190.860 [NAL9602](INFO): SBD MO Status=1, MOMSN=25261, MT Status=0, MTMSN=0 2014-04-13T05:16:30.910Z,1397366190.910 [NAL9602](INFO): Sent 25 bytes from file Logs/20140413T051242/Courier0008.lzma 2014-04-13T05:16:30.910Z,1397366190.910 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:16:30.912Z,1397366190.912 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Courier0008.lzma.parts/0000.sbd 2014-04-13T05:16:30.912Z,1397366190.912 [NAL9602](INFO): Completed sending Logs/20140413T051242/Courier0008.lzma 2014-04-13T05:16:40.244Z,1397366200.244 [NAL9602](INFO): SBD MO Status=1, MOMSN=25262, MT Status=0, MTMSN=0 2014-04-13T05:16:40.293Z,1397366200.293 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Express0001.lzma 2014-04-13T05:16:40.293Z,1397366200.293 [NAL9602](INFO): Packets left to send: 2 2014-04-13T05:16:40.294Z,1397366200.294 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0001.lzma.parts/0002.sbd 2014-04-13T05:16:49.475Z,1397366209.475 [NAL9602](INFO): SBD MO Status=1, MOMSN=25263, MT Status=0, MTMSN=0 2014-04-13T05:16:49.523Z,1397366209.523 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Express0001.lzma 2014-04-13T05:16:49.523Z,1397366209.523 [NAL9602](INFO): Packets left to send: 1 2014-04-13T05:16:49.525Z,1397366209.525 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0001.lzma.parts/0001.sbd 2014-04-13T05:16:58.621Z,1397366218.621 [NAL9602](INFO): SBD MO Status=1, MOMSN=25264, MT Status=0, MTMSN=0 2014-04-13T05:16:58.673Z,1397366218.673 [NAL9602](INFO): Sent 40 bytes from file Logs/20140413T051242/Express0001.lzma 2014-04-13T05:16:58.673Z,1397366218.673 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:16:58.674Z,1397366218.674 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0001.lzma.parts/0000.sbd 2014-04-13T05:16:58.675Z,1397366218.675 [NAL9602](INFO): Completed sending Logs/20140413T051242/Express0001.lzma 2014-04-13T05:17:07.799Z,1397366227.799 [NAL9602](INFO): SBD MO Status=1, MOMSN=25265, MT Status=0, MTMSN=0 2014-04-13T05:17:07.855Z,1397366227.855 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Express0005.lzma 2014-04-13T05:17:07.855Z,1397366227.855 [NAL9602](INFO): Packets left to send: 2 2014-04-13T05:17:07.857Z,1397366227.857 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0005.lzma.parts/0002.sbd 2014-04-13T05:17:17.597Z,1397366237.597 [NAL9602](INFO): SBD MO Status=1, MOMSN=25266, MT Status=0, MTMSN=0 2014-04-13T05:17:17.647Z,1397366237.647 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Express0005.lzma 2014-04-13T05:17:17.647Z,1397366237.647 [NAL9602](INFO): Packets left to send: 1 2014-04-13T05:17:17.648Z,1397366237.648 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0005.lzma.parts/0001.sbd 2014-04-13T05:17:25.044Z,1397366245.044 [NAL9602](INFO): SBD MO Status=1, MOMSN=25267, MT Status=0, MTMSN=0 2014-04-13T05:17:25.094Z,1397366245.094 [NAL9602](INFO): Sent 4 bytes from file Logs/20140413T051242/Express0005.lzma 2014-04-13T05:17:25.094Z,1397366245.094 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:17:25.095Z,1397366245.095 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0005.lzma.parts/0000.sbd 2014-04-13T05:17:25.096Z,1397366245.096 [NAL9602](INFO): Completed sending Logs/20140413T051242/Express0005.lzma 2014-04-13T05:17:33.699Z,1397366253.699 [NAL9602](INFO): SBD MO Status=1, MOMSN=25268, MT Status=0, MTMSN=0 2014-04-13T05:17:33.756Z,1397366253.756 [NAL9602](INFO): Sent 95 bytes from file Logs/20140413T051242/Express0009.lzma 2014-04-13T05:17:33.756Z,1397366253.756 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:17:33.757Z,1397366253.757 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0009.lzma.parts/0000.sbd 2014-04-13T05:17:33.758Z,1397366253.758 [NAL9602](INFO): Completed sending Logs/20140413T051242/Express0009.lzma 2014-04-13T05:17:41.290Z,1397366261.290 [NAL9602](INFO): SBD MO Status=0, MOMSN=25269, MT Status=0, MTMSN=0 2014-04-13T05:17:41.393Z,1397366261.393 [science_to:SURFACECOMMS:C:B] Stopped 2014-04-13T05:17:41.394Z,1397366261.394 [science_to:SURFACECOMMS:C:C] Running Loop=1 2014-04-13T05:17:41.820Z,1397366261.820 [science_to:SURFACECOMMS:C:C](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T05:17:44.020Z,1397366264.020 [NAL9602](IMPORTANT): GPS fix at: 1397366228.00 2014-04-13T05:17:44.033Z,1397366264.033 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T05:17:44.049Z,1397366264.049 [science_to:SURFACECOMMS:C:C] Stopped 2014-04-13T05:17:44.049Z,1397366264.049 [science_to:SURFACECOMMS:C](INFO): Completed science_to:SURFACECOMMS:C 2014-04-13T05:17:44.049Z,1397366264.049 [science_to:SURFACECOMMS:C] Stopped 2014-04-13T05:17:44.049Z,1397366264.049 [science_to:SURFACECOMMS:C](INFO): Aggregate::uninitialize science_to:SURFACECOMMS:C 2014-04-13T05:17:44.050Z,1397366264.050 [science_to:SURFACECOMMS](INFO): Completed science_to:SURFACECOMMS 2014-04-13T05:17:44.050Z,1397366264.050 [science_to:SURFACECOMMS] Stopped 2014-04-13T05:17:44.050Z,1397366264.050 [science_to:SURFACECOMMS](INFO): Aggregate::uninitialize science_to:SURFACECOMMS 2014-04-13T05:17:44.051Z,1397366264.051 [science_to:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T05:17:44.051Z,1397366264.051 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T05:17:44.055Z,1397366264.055 [science_to:Wpt1] Running Loop=1 2014-04-13T05:17:44.055Z,1397366264.055 [science_to:Wpt1](INFO): Aggregate::initialize science_to:Wpt1 2014-04-13T05:17:44.055Z,1397366264.055 [science_to:Wpt1:A.Waypoint] Running Loop=1 2014-04-13T05:17:44.055Z,1397366264.055 [science_to:Wpt1:A.Waypoint](DEBUG): Initialize WaypointComponent. 2014-04-13T05:17:44.505Z,1397366264.505 [science_to:K.YoYo] Running Loop=1 2014-04-13T05:17:44.506Z,1397366264.506 [science_to:J.DepthEnvelope] Running Loop=1 2014-04-13T05:17:44.507Z,1397366264.507 [science_to:I.SetSpeed] Running Loop=1 2014-04-13T05:17:44.507Z,1397366264.507 [science_to:H.Buoyancy] Running Loop=1 2014-04-13T05:17:44.507Z,1397366264.507 [science_to:Science] Running Loop=1 2014-04-13T05:17:44.508Z,1397366264.508 [science_to:Science:PeakDetectChl] Running Loop=1 2014-04-13T05:17:44.509Z,1397366264.509 [science_to:Science:G] Running Loop=1 2014-04-13T05:17:44.509Z,1397366264.509 [science_to:Science:D] Running Loop=1 2014-04-13T05:17:44.526Z,1397366264.526 [WetLabsBB2FL](INFO): Opening uart, block timeout 10ths=4 2014-04-13T05:17:44.526Z,1397366264.526 [WetLabsBB2FL](INFO): Powering up 2014-04-13T05:17:44.640Z,1397366264.640 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2014-04-13T05:17:45.871Z,1397366265.871 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:72 Calculated:94 2014-04-13T05:17:45.872Z,1397366265.872 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 29.6 33.3 38.1 32.9 -545.4 -387.9 -303.8 -461.2 -527 -348 -341 -507 6 8 1.4 97.8 -457.9 1 220.6 64.9 -519.9 1 -248 212 -464 2 325 -28 -464 2 -2.61 -12.27 215.5 29.6 14.6 0.005 35.0 1489 72 2014-04-13T05:17:47.174Z,1397366267.174 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:89 Calculated:95 2014-04-13T05:17:47.174Z,1397366267.174 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 30.3 32.8 34.4 31.8 280.3 307.5 450.3 428.6 232 327 7 8 9 7 -226.9 -161.6 395.5 1 207.0 283.1 333.1 1 -291 -38 353 2 237 173 353 2 -1.87 -14.15 208.6 30.3 14.6 0.005 35.0 1489 89 2014-04-13T05:17:50.924Z,1397366270.924 [NAL9602](INFO): Powering down 2014-04-13T05:17:52.315Z,1397366272.315 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:101 Calculated:122 2014-04-13T05:17:52.315Z,1397366272.315 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 3 32.5 31.0 151.5 485.6 689.6 374.4 185 529 775 318 8 8 8 7 -718.2 148.4 458.7 1 743.1 149.4 416.7 1 -787 281 487 2 831 87 487 2 -5.13 -2.12 205.7 31.0 14.7 0.005 35.0 1489 101 2014-04-13T05:17:53.765Z,1397366273.765 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:71 Calculated:91 2014-04-13T05:17:53.765Z,1397366273.765 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 31.4.3 31.1 -386.1 -185.1 -148.9 -330.4 -356 -144 -101 -361 7 8 9 7 -316.6 193.9 -283.3 1 329.0 52.1 -327.3 1 -340 289 -259 2 443 -56 -259 2 -10.84 -2.33 213.1 31.1 14.7 0.005 35.0 1489 71 2014-04-13T05:18:08.511Z,1397366288.511 [Radio_Freewave](INFO): Powering down 2014-04-13T05:18:27.187Z,1397366307.187 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:18:27.187Z,1397366307.187 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 24.9 30.5 33.0 26.1 -240.4 -45.7 228.8 54.9 -358 -123 176 62 5 26.2 -134.3 -0.7 1 -275.3 -547.0 -187.5 1 -712 -246 -65 2 -280 -700 -65 2 -9.32 -19.46 49.1 24.9 14.7 0.005 35.0 1489 108 2014-04-13T05:18:58.533Z,1397366338.533 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T05:18:58.534Z,1397366338.534 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 .2 20.3 23.5 18.7 -292.0 61.8 297.5 -23.7 -328 -1 381 55 3 4 5 3 -786.8 114.1 11.7 1 -365.8 -660.9 -248.3 1 -946 -74 28 2 -267 -910 28 2 -3.88 -18.66 69.1 17.2 14.6 0.005 35.0 1489 107 2014-04-13T05:19:33.485Z,1397366373.485 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:19:33.486Z,1397366373.486 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 19.1 15.8 13.0 14.8 -293.5 34.3 393.6 46.1 -168 72 345 -6 4 3 1 2 -917.0 -15.7 48.7 1 477.6 -680.2 390.7 1 -684 104 65 2 307 -620 65 2 -3.67 22.08 10 13.7 0.005 35.0 1489 121 2014-04-13T05:19:36.070Z,1397366376.070 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 3 of 46 2014-04-13T05:19:36.070Z,1397366376.070 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X01 1 19.0 16.4 13.8 15.3 -281.8 43.1 336.3 4.9 -476 20 382 -67 4 3 2 2 -824.9 51.0 27.6 1 411.2 -641.6 321.1 1 -1145 116 -38 2 604 -979 -38 2 -4.21 21.27 127.5 13.8 13.7 0.005 35.0 1489 109 2014-04-13T05:19:37.415Z,1397366377.415 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:19:37.415Z,1397366377.415 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 20.0 17.0 14.2 15.7 -327.2 20.8 313.5 0.6 -436 37 307 -114 4 3 2 3 -855.1 27.0 2.0 1 457.6 -656.5 302.6 1 -991 201 -55 2 450 -906 -55 2 -5.51 20.78 127.9 14.2 05 35.0 1489 89 2014-04-13T05:19:42.066Z,1397366382.066 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 29 of 46 2014-04-13T05:19:42.070Z,1397366382.070 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 21.9 18.7 15.6 17.3 -315.5 57.5 379.4 26.1 -479 43 351 0 5 4 2 3 -927.4 41.9 39.8 1 493.2 -704.7 351.7 1 --22 2 655 -894 -22 2 -6.02 20.12 129.2 15.6 13.5 0.005 35.0 1489 124 2014-04-13T05:19:53.269Z,1397366393.269 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:73 Calculated:87 2014-04-13T05:19:53.269Z,1397366393.269 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 27.2 24.1 19.1 21.0 -316.2 -12.2 359.7 41.2 -445 -22 364 -63 7 5 4 4 -902.1 .5 1 554.6 -611.2 371.9 1 -1079 54 -44 2 640 -871 -44 2 -7.81 22.45 129.2 19.1 13.2 0.005 35.0 1489 73 2014-04-13T05:19:55.536Z,1397366395.536 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:19:55.536Z,1397366395.536 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 29.2 25.0 20.1 21.9 -301.5 53.6 375.3 35.3 -378 -9 355 -50 8 6 4 4 -903.3 24.4 43.8 1 465.6 -669.2 392.3 1 -978 54 -22 2 570 -796 -22 2 -8. 128.8 20.1 13.2 0.005 35.0 1489 65 2014-04-13T05:20:08.297Z,1397366408.297 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:116 Calculated:126 2014-04-13T05:20:08.297Z,1397366408.297 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 32.8 29.7 24.2 26.1 -355.1 -87.6 317.0 34.051 305 -33 9 7 5 6 -897.0 -162.3 -24.7 1 666.3 -550.7 290.3 1 -1057 -157 -98 2 809 -697 -98 2 -7.41 19.04 130.8 24.2 13.0 0.005 35.0 1489 116 2014-04-13T05:20:15.786Z,1397366415.786 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:20:15.787Z,1397366415.787 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 33.4 31.1 26.3 27.4 -159.5 33.5 495.1 279.9 -274 -62 423 61 9 8 5 6 -873.7 -328.9 175.0 1 669.9 -495 1 -930 -164 39 2 651 -683 39 2 -7.64 16.616.3 12.9 0.005 35.0 1489 84 2014-04-13T05:20:18.365Z,1397366418.365 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:20:18.365Z,1397366418.365 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 36.9 32.5 26.8 28.6 -595.5 -284.3 106.1 -192.9 -675 -302 162 -146 10 8 5 6 -936.4 -122.0 -260.6 1 676.2 -707.3 4117 -208 -259 2 819 -787 -259 2 -8.43 17.05 125.6 26.8 12.9 0.005 35.0 1489 84 2014-04-13T05:20:32.288Z,1397366432.288 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:20:32.290Z,1397366432.290 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 26.9 34.4 37.6 28.6 -344.6 -124.9 346.7 125.9 -331 -95 431 176 5 9 11 6 -922.6 -334.7 0.8 1 459.0 -820.7 -281.3 -361 48 2 476 -968 48 2 -10.56 -21.85 96.6 26.9 12.9 0.005 35.0 1489 117 2014-04-13T05:20:33.492Z,1397366433.492 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:20:33.492Z,1397366433.492 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 26.7 33.5 37.5 28.7 -339.3 -159.0 293.0 50.2 -388 -152 179 78 5 9 11 6 -843.9 -279.2 -41.9 1 357.7 -757.8 -299.5 1 -756 -307 -76 2 350 -737 -76 2 -11.07 -21.92 93.3.0 0.005 35.0 1489 102 2014-04-13T05:20:49.232Z,1397366449.232 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T05:20:49.232Z,1397366449.232 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T05:20:49.232Z,1397366449.232 [DVL_micro](ERROR): Communications Fault 2014-04-13T05:20:49.400Z,1397366449.400 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T05:20:49.932Z,1397366449.932 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T05:20:50.600Z,1397366450.600 [DVL_micro](FAULT): LCB fault: Software Overcurrent. 2014-04-13T05:20:50.600Z,1397366450.600 [DVL_micro] Hardware Fault, FailCount= 1 2014-04-13T05:20:50.600Z,1397366450.600 [DVL_micro](ERROR): Hardware Fault 2014-04-13T05:20:51.357Z,1397366451.357 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T05:20:51.358Z,1397366451.358 [DVL_micro] No Fault, FailCount= 1 2014-04-13T05:20:51.761Z,1397366451.761 [DVL_micro](INFO): Initializing 2014-04-13T05:20:59.470Z,1397366459.470 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:114 Calculated:127 2014-04-13T05:20:59.474Z,1397366459.474 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 20.0 23.0 25.1 21.4 -315.9 47.3 369.0 7.0 -251 116 388 74 4 4 6 4 -914.1 53.8 28.9 1 168.7-223.4 1 -852 56 88 2 150 -841 88 2 -4.61 -15.67 103.9 20.0 13.2 0.005 35.0 1489 114 2014-04-13T05:22:55.215Z,1397366575.215 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:113 Calculated:110 2014-04-13T05:22:55.215Z,1397366575.215 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 24.0 28.2 31.4 25.4 -447.0 -263.5 187.7 -94.7 -325 -139 219 36 4 6 8 5 -847.1 -225.3 -166.5 1 27.3 -393.4 1 -726 -233 -56 2 252 -719 -56 2 -6.92 -18.13 91.5 24.0 12.5 0.005 35.0 1489 113 2014-04-13T05:23:07.358Z,1397366587.358 [CTD_NeilBrown](ERROR): Bad response: 8.79 2014-04-13T05:25:55.985Z,1397366755.985 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-13T05:25:55.985Z,1397366755.985 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 12.8 12.0 11.9 11.5 -343.1 -31.0 262.6 -66.6 -434 45 1 1 1 1 -808.4 47.5 -48.0 1 354.7 -729.2 24.4 1 -964 -161 -50 2 611 -763 -50 2 -1 119.2 11.5 12.6 0.005 35.0 1489 105 2014-04-13T05:27:50.861Z,1397366870.861 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:77 Calculated:85 2014-04-13T05:27:50.861Z,1397366870.861 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 16.8 20.5 22.7 18.1 -401.8 -42.4 242.4 -103.5 -411 15 412 -50 3 4 5 3 -859.8 81.5 -82.1 -774.0 -364.0 1 -1098 86 -9 2 194 -1084 -9 2 -6.62 -18.81 104.7 16.8 12.7 0.005 35.0 1489 77 2014-04-13T05:31:32.867Z,1397367092.867 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:31:32.872Z,1397367092.872 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 29.1 33.2 33.4 29.2 -412.0 -149.2 224.3 -8.5 -442 -195 257 48 6 8 8 6 -849.2 -187.8 -93.1 1 483.7 -695.6 -217.4 1 -932 -324 -89 2 627 -762 -89 2 -9.01 -0.3 29.1 12.1 0.005 35.0 1489 76 2014-04-13T05:31:51.781Z,1397367111.781 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-13T05:31:51.790Z,1397367111.790 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 23.7 26.7 28.7 24.6 -335.3 -83.6 259.3 16.6 -358 -69 310 -5 4 6 7 5 -793.6 -133.7 -38.6 1 222.3 -743.8 -215.7 1 -891 -85 -32 2 178 -877 -32 2 -4.29 -13.73 9612.4 0.005 35.0 1489 65 2014-04-13T05:32:15.444Z,1397367135.444 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:32:15.444Z,1397367135.444 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 17.6 21.4 23.5 18.7 -375.0 -16.4 236.8 -81.9 -363 -4 421 5 3 -816.5 87.4 -63.8 1 92.2 -739.4 -351.1 1 -1046 14 10 2 201 -1026 10 2 -6.75 -20.16 101.9 17.6 12.6 0.005 35.0 1489 86 2014-04-13T05:32:48.754Z,1397367168.754 [CTD_NeilBrown](ERROR): Bad response: 16.44 2014-04-13T05:33:49.899Z,1397367229.899 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:33:49.899Z,1397367229.899 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 28.4 35.2 39.9 30.6 -238.8 -39.8 372.2 204.1 -283 -44 425 191 6 9 12 7 -815.5 -325.5 80.2 1 452.7 -737.3 -170.2 1 -944 -313 7-885 77 2 -9.46 -21.37 98.9 28.4 12.5 0.005 35.0 1489 124 2014-04-13T05:34:47.579Z,1397367287.579 [CTD_NeilBrown](ERROR): Bad response: ,33.8997 2014-04-13T05:35:13.356Z,1397367313.356 [CTD_NeilBrown](ERROR): Bad response: 13.46 2014-04-13T05:35:38.238Z,1397367338.238 [CTD_NeilBrown](ERROR): Bad response: *1B 2014-04-13T05:36:00.030Z,1397367360.030 [AHRS_sp3003D](ERROR): readAccelVecBin UART error: serial timeout 2014-04-13T05:36:00.030Z,1397367360.030 [AHRS_sp3003D](FAULT): Read Acceleration Vector Failure. 2014-04-13T05:36:00.031Z,1397367360.031 [AHRS_sp3003D] Communications Fault, FailCount= 1 2014-04-13T05:36:00.031Z,1397367360.031 [AHRS_sp3003D](ERROR): Communications Fault 2014-04-13T05:36:00.354Z,1397367360.354 [CBIT](ERROR): Communications Fault in component: AHRS_sp3003D 2014-04-13T05:36:00.390Z,1397367360.390 [AHRS_sp3003D](INFO): Powering down 2014-04-13T05:36:01.732Z,1397367361.732 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2014-04-13T05:36:01.732Z,1397367361.732 [AHRS_sp3003D] No Fault, FailCount= 1 2014-04-13T05:36:01.973Z,1397367361.973 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-13T05:36:05.476Z,1397367365.476 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:05.508Z,1397367365.508 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:36:05.509Z,1397367365.509 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 27.7 36.0 39.3 29.2 -550.0 -240.4 113.1 -147.7 -499 -227 280 -58 6 10 11 6 -885.0 -123.7 -222.5 1 207.2 -721.5 -533.5 1 -1039 -225 -135 2 241 -1036 -135 2 -10.44 -.9 27.7 12.4 0.005 35.0 1489 94 2014-04-13T05:36:07.871Z,1397367367.871 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:09.984Z,1397367369.984 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:12.256Z,1397367372.256 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:14.692Z,1397367374.692 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:17.185Z,1397367377.185 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:19.574Z,1397367379.574 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:22.323Z,1397367382.323 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:24.597Z,1397367384.597 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:27.150Z,1397367387.150 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:29.635Z,1397367389.635 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:31.829Z,1397367391.829 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:34.595Z,1397367394.595 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:36.885Z,1397367396.885 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:39.619Z,1397367399.619 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:41.877Z,1397367401.877 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:43.068Z,1397367403.068 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:90 Calculated:84 2014-04-13T05:36:43.068Z,1397367403.068 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 17.5 21.7 23.5 18.7 -296.8 55.5 324.2 -54.7 -403 103 402 62 3 4 5 3 -828.8 147.1 7.6 1 39.8 293.9 1 -1074 54 44 2 173 -1061 44 2 -7.56 -19.87 102.2 17.5 12.8 0.005 35.0 1489 90 2014-04-13T05:36:44.282Z,1397367404.282 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:46.599Z,1397367406.599 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:49.210Z,1397367409.210 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:51.577Z,1397367411.577 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:54.112Z,1397367414.112 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:56.313Z,1397367416.313 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:36:58.694Z,1397367418.694 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:01.319Z,1397367421.319 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:03.876Z,1397367423.876 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:06.330Z,1397367426.330 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:08.780Z,1397367428.780 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:11.074Z,1397367431.074 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:13.322Z,1397367433.322 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:16.201Z,1397367436.201 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:18.218Z,1397367438.218 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:21.007Z,1397367441.007 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:23.269Z,1397367443.269 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:25.585Z,1397367445.585 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:27.892Z,1397367447.892 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:30.493Z,1397367450.493 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:33.189Z,1397367453.189 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:35.237Z,1397367455.237 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:38.001Z,1397367458.001 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:40.389Z,1397367460.389 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:42.858Z,1397367462.858 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:45.197Z,1397367465.197 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:37:47.728Z,1397367467.728 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#9 STATUS: 65535 2014-04-13T05:38:03.180Z,1397367483.180 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T05:38:03.181Z,1397367483.181 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 .1 35.3 29.2 30.7 -439.9 -210.8 157.7 -57.9 -453 -238 208 -111 11 9 6 7 -797.6 -204.1 -148.6 1 580.9 -587.1 133.2 1 -882 -169 -160 2 591 -676 -160 2 -9.39 17.48 120.3 29.2 12.3 0.005 35.0 1489 96 2014-04-13T05:38:18.855Z,1397367498.855 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:38:18.855Z,1397367498.855 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 26.9 33.5 36.9 29.6 -362.1 -131.3 297.2 60.6 -370 -122 328 55 5 9 10 7 -879.9 -256.1 -36.6 1 244.6 -824.0 -319.8 236 -29 2 195 -941 -29 2 -7.51 -21.29 87.5 26.9 12.5 0.005 35.0 1489 84 2014-04-13T05:38:25.928Z,1397367505.928 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:81 Calculated:68 2014-04-13T05:38:25.929Z,1397367505.929 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 25.2 29.5 31.9 27.0 -369.2 -107.0 249.6 -48.0 -425 -127 236 -24 5 7 8 6 -825.9 -78.7 -74.1 1 146. -295.1 1 -882 -137 -91 2 192 -871 -91 2 -5.79 -16.34 93.6 25.2 12.6 0.005 35.0 1489 81 2014-04-13T05:39:04.812Z,1397367544.812 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 2 of 46 2014-04-13T05:39:04.812Z,1397367544.812 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0001 14.7 18.1 20.0 16.2 -318.4 73.9 327.6 -13.6 -353 19 391 47 2 4 4 3 -862.2 116.8 18.7 1 147.8 -803.4 -300.4 1 -993 -37 28 2 335 -935 28 2 -5.82 -20.78 107.6 14.7 12.8 0.005 35.0 1489 72 2014-04-13T05:39:19.260Z,1397367559.260 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 43 of 46 2014-04-13T05:39:19.260Z,1397367559.260 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 20.0 16.8 14.0 15.7 -274.4 61.6 309.3 -0.3 -369 -37 348 -50 -779.0 82.6 25.9 1 329.5 -644.5 300.4 1 -956 17 -29 2 530 -796 -29 2 -4.52 21.30 124.7 14.0 12.7 0.005 35.0 1489 98 2014-04-13T05:40:05.628Z,1397367605.628 [CTD_NeilBrown](ERROR): Bad response: 4.47 2014-04-13T05:40:34.060Z,1397367634.060 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:40:34.060Z,1397367634.060 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 26.5 30.9 33.4 28.7 -354.4 -73.2 288.1 70.4 -382 -147 273 100 5 7 9 6 -857.5 -191.7 -18.7 1 260.6 -802.6 -245.8 1 -874 -329 -42 2 392 -84-3.98 -16.34 94.2 26.5 12.5 0.005 35.0 1489 98 2014-04-13T05:41:16.156Z,1397367676.156 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 36 of 46 2014-04-13T05:41:16.156Z,1397367676.156 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 14.7 17.8 20.0 16.3 -323.2 13.4 305.6 -23.6 -315 135 384 -13 2 3 4 3 -839.2 49.4 -7.5 1 197.1 -758.1 -305.4 1 -932 197 51 2 83 -94489 80 2014-04-13T05:41:31.831Z,1397367691.831 [DVL_micro](ERROR): No DVL communication! Re-initializing 2014-04-13T05:41:31.831Z,1397367691.831 [DVL_micro] Communications Fault, FailCount= 1 2014-04-13T05:41:31.831Z,1397367691.831 [DVL_micro](ERROR): Communications Fault 2014-04-13T05:41:31.951Z,1397367691.951 [CBIT](ERROR): Communications Fault in component: DVL_micro 2014-04-13T05:41:32.402Z,1397367692.402 [DVL_micro](INFO): uninitialize:Powering down 2014-04-13T05:41:33.754Z,1397367693.754 [CBIT](INFO): Clearing failed state for component DVL_micro 2014-04-13T05:41:33.754Z,1397367693.754 [DVL_micro] No Fault, FailCount= 1 2014-04-13T05:41:34.156Z,1397367694.156 [DVL_micro](INFO): Initializing 2014-04-13T05:41:57.633Z,1397367717.633 [CTD_NeilBrown](ERROR): Bad response: 2.26926 2014-04-13T05:42:06.973Z,1397367726.973 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-13T05:42:06.973Z,1397367726.973 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 36.0 29.7 24.9 27.9 -353.6 -28.0 304.6 8.1 -417 -109 294 -50 10 7 5 6 -878.5 -48.2 -18.6 1 514.6 -640.7 314.7 1 -948 -7826 -717 -76 2 -5.29 21.89 126.4 24.9 12.3 0.005 35.0 1489 72 2014-04-13T05:42:40.182Z,1397367760.182 [AHRS_sp3003D](ERROR): readAccelVecBin UART error: serial timeout 2014-04-13T05:42:40.182Z,1397367760.182 [AHRS_sp3003D](ERROR): readAccelVecBin got 0xAEFFA0 2014-04-13T05:42:40.182Z,1397367760.182 [AHRS_sp3003D](FAULT): Read Acceleration Vector Failure. 2014-04-13T05:42:40.182Z,1397367760.182 [AHRS_sp3003D] Communications Fault, FailCount= 1 2014-04-13T05:42:40.182Z,1397367760.182 [AHRS_sp3003D](ERROR): Communications Fault 2014-04-13T05:42:40.330Z,1397367760.330 [CBIT](ERROR): Communications Fault in component: AHRS_sp3003D 2014-04-13T05:42:40.369Z,1397367760.369 [AHRS_sp3003D](INFO): Powering down 2014-04-13T05:42:41.750Z,1397367761.750 [CBIT](INFO): Clearing failed state for component AHRS_sp3003D 2014-04-13T05:42:41.750Z,1397367761.750 [AHRS_sp3003D] No Fault, FailCount= 1 2014-04-13T05:42:41.954Z,1397367761.954 [AHRS_sp3003D](DEBUG): Initializing AHRS_sp3003D. 2014-04-13T05:43:39.790Z,1397367819.790 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:68 Calculated:91 2014-04-13T05:43:39.791Z,1397367819.791 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 0 1 1 1 0 17.9 14.8 16.6 0 -26.3 300.7 -20.5 -322 7 318 -114 9 4 2 3 -865.1 -7.7 -25.2 1 477.5 -662 1 -854 161 -30 2 371 -786 -30 2 -4.59 20.96 126.0 14.8 12.6 0.005 35.0 1489 68 2014-04-13T05:46:28.601Z,1397367988.601 [CTD_NeilBrown](ERROR): Bad response: 6.03 2014-04-13T05:47:47.066Z,1397368067.066 [science_to:NeedComms] Running Loop=1 2014-04-13T05:47:47.066Z,1397368067.066 [science_to:NeedComms](INFO): Aggregate::initialize science_to:NeedComms 2014-04-13T05:47:47.068Z,1397368067.068 [science_to:NeedComms:A] Running Loop=1 2014-04-13T05:47:47.068Z,1397368067.068 [science_to:NeedComms:A](INFO): Aggregate::initialize science_to:NeedComms:A 2014-04-13T05:47:47.679Z,1397368067.679 [science_to:SURFACECOMMS] Running Loop=1 2014-04-13T05:47:47.679Z,1397368067.679 [science_to:SURFACECOMMS](INFO): Aggregate::initialize science_to:SURFACECOMMS 2014-04-13T05:47:47.689Z,1397368067.689 [science_to:SURFACECOMMS:A.GoToSurface] Running Loop=1 2014-04-13T05:47:47.689Z,1397368067.689 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T05:48:02.508Z,1397368082.508 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 45 of 46 2014-04-13T05:48:02.508Z,1397368082.508 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 24.4 21.8 18.4 20.3 -359.5 15.5 306.6 -26.8 -377 20 273 -95 6 4 3 4 -889.0 56.5 -17.3 1 468.2 -708.6 269.3 13 -48 2 417 -775 -48 2 -6.71 19.19 128.3 18.4 12.6 0.005 35.0 1489 98 2014-04-13T05:48:21.507Z,1397368101.507 [DVL_micro](ERROR): NQ1 string checksum mismatch. Reported:98 Calculated:105 2014-04-13T05:48:21.508Z,1397368101.508 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 31.8 29.1 23.6 25.2 -329.1 26.7 433.5 94.1 -439 -2 411 51 8 7 4 5 -1010 60.7 1 598.6 -732.9 390.2 1 -1134 -70 5 2 720 -878 5 2 -8.18 18.36 125.8 23.6 12.3 0.005 35.0 1489 98 2014-04-13T05:49:00.435Z,1397368140.435 [CTD_NeilBrown](ERROR): Salinity reading out of range: 4.524300 psu 2014-04-13T05:49:00.638Z,1397368140.638 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2.049700 psu 2014-04-13T05:49:00.846Z,1397368140.846 [CTD_NeilBrown](ERROR): Salinity reading out of range: 2.998400 psu 2014-04-13T05:49:01.056Z,1397368141.056 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:49:01.056Z,1397368141.056 [Radio_Freewave] Communications Fault, FailCount= 1 2014-04-13T05:49:01.056Z,1397368141.056 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T05:49:01.056Z,1397368141.056 [Radio_Freewave](INFO): Powering up 2014-04-13T05:49:01.088Z,1397368141.088 [science_to:SURFACECOMMS:B] Running Loop=1 2014-04-13T05:49:01.089Z,1397368141.089 [science_to:SURFACECOMMS:B](INFO): Aggregate::initialize science_to:SURFACECOMMS:B 2014-04-13T05:49:01.089Z,1397368141.089 [science_to:SURFACECOMMS:B:A] Running Loop=1 2014-04-13T05:49:01.261Z,1397368141.261 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T05:49:01.800Z,1397368141.800 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:49:01.800Z,1397368141.800 [Radio_Freewave](INFO): Powering down 2014-04-13T05:49:01.837Z,1397368141.837 [science_to:SURFACECOMMS:B] Stopped 2014-04-13T05:49:01.837Z,1397368141.837 [science_to:SURFACECOMMS:B](INFO): Aggregate::uninitialize science_to:SURFACECOMMS:B 2014-04-13T05:49:01.837Z,1397368141.837 [science_to:SURFACECOMMS:B:A] Stopped 2014-04-13T05:49:01.837Z,1397368141.837 [science_to:SURFACECOMMS:C] Running Loop=1 2014-04-13T05:49:01.837Z,1397368141.837 [science_to:SURFACECOMMS:C](INFO): Aggregate::initialize science_to:SURFACECOMMS:C 2014-04-13T05:49:01.838Z,1397368141.838 [science_to:SURFACECOMMS:C:A] Running Loop=1 2014-04-13T05:49:02.382Z,1397368142.382 [science_to:K.YoYo] Preempted 2014-04-13T05:49:02.382Z,1397368142.382 [science_to:J.DepthEnvelope] Preempted 2014-04-13T05:49:02.383Z,1397368142.383 [science_to:I.SetSpeed] Preempted 2014-04-13T05:49:02.383Z,1397368142.383 [science_to:H.Buoyancy] Preempted 2014-04-13T05:49:02.383Z,1397368142.383 [science_to:Science] Preempted 2014-04-13T05:49:02.383Z,1397368142.383 [science_to:Science:D] Preempted 2014-04-13T05:49:02.384Z,1397368142.384 [science_to:Science:G] Preempted 2014-04-13T05:49:02.384Z,1397368142.384 [science_to:Science:PeakDetectChl] Preempted 2014-04-13T05:49:02.548Z,1397368142.548 [WetLabsBB2FL](INFO): Powering down 2014-04-13T05:49:02.872Z,1397368142.872 [NAL9602](INFO): Powering up 2014-04-13T05:49:02.880Z,1397368142.880 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:49:02.880Z,1397368142.880 [Radio_Freewave](INFO): Powering up 2014-04-13T05:49:03.036Z,1397368143.036 [CBIT](INFO): Clearing failed state for component Radio_Freewave 2014-04-13T05:49:03.036Z,1397368143.036 [Radio_Freewave] No Fault, FailCount= 1 2014-04-13T05:49:04.108Z,1397368144.108 [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-13T05:49:04.109Z,1397368144.109 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T05:49:04.109Z,1397368144.109 [Radio_Freewave] Communications Fault, FailCount= 2 2014-04-13T05:49:04.109Z,1397368144.109 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T05:49:04.241Z,1397368144.241 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T05:49:04.242Z,1397368144.242 [CBIT](CRITICAL): Communications Fault in component: Radio_Freewave 2014-04-13T05:49:04.610Z,1397368144.610 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:49:04.610Z,1397368144.610 [Radio_Freewave](INFO): Powering down 2014-04-13T05:49:05.180Z,1397368145.180 [science_to] Stopped 2014-04-13T05:49:05.181Z,1397368145.181 [science_to](INFO): Aggregate::uninitialize science_to 2014-04-13T05:49:05.181Z,1397368145.181 [science_to:AltEnvWrapper] Stopped 2014-04-13T05:49:05.181Z,1397368145.181 [science_to:AltEnvWrapper](INFO): Aggregate::uninitialize science_to:AltEnvWrapper 2014-04-13T05:49:05.181Z,1397368145.181 [science_to:AltEnvWrapper:A.AltitudeEnvelope] Stopped 2014-04-13T05:49:05.181Z,1397368145.181 [science_to:AltEnvWrapper:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2014-04-13T05:49:05.181Z,1397368145.181 [science_to:B.DepthEnvelope] Stopped 2014-04-13T05:49:05.181Z,1397368145.181 [science_to:B.DepthEnvelope](DEBUG): Uninitialize. 2014-04-13T05:49:05.181Z,1397368145.181 [science_to:OffshoreWrapper] Stopped 2014-04-13T05:49:05.181Z,1397368145.181 [science_to:OffshoreWrapper](INFO): Aggregate::uninitialize science_to:OffshoreWrapper 2014-04-13T05:49:05.181Z,1397368145.181 [science_to:OffshoreWrapper:A.OffshoreEnvelope] Stopped 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:OffshoreWrapper:A.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:D.Pitch] Stopped 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:SURFACECOMMS] Stopped 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:SURFACECOMMS](INFO): Aggregate::uninitialize science_to:SURFACECOMMS 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:SURFACECOMMS:A.GoToSurface] Stopped 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:SURFACECOMMS:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:SURFACECOMMS:C] Stopped 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:SURFACECOMMS:C](INFO): Aggregate::uninitialize science_to:SURFACECOMMS:C 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:SURFACECOMMS:C:A] Stopped 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:NeedComms] Stopped 2014-04-13T05:49:05.182Z,1397368145.182 [science_to:NeedComms](INFO): Aggregate::uninitialize science_to:NeedComms 2014-04-13T05:49:05.183Z,1397368145.183 [science_to:NeedComms:A] Stopped 2014-04-13T05:49:05.183Z,1397368145.183 [science_to:NeedComms:A](INFO): Aggregate::uninitialize science_to:NeedComms:A 2014-04-13T05:49:05.183Z,1397368145.183 [science_to:Science] Stopped 2014-04-13T05:49:05.183Z,1397368145.183 [science_to:Science](INFO): Aggregate::uninitialize science_to:Science 2014-04-13T05:49:05.183Z,1397368145.183 [science_to:Science:D] Stopped 2014-04-13T05:49:05.183Z,1397368145.183 [science_to:Science:G] Stopped 2014-04-13T05:49:05.183Z,1397368145.183 [science_to:Science:PeakDetectChl] Stopped 2014-04-13T05:49:05.183Z,1397368145.183 [science_to:Science:PeakDetectChl](INFO): Aggregate::uninitialize science_to:Science:PeakDetectChl 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:Science:PeakDetectChl:A.PeakDetectVsDepth] Stopped 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:Science:PeakDetectChl:A.PeakDetectVsDepth](DEBUG): Uninitialize. 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:H.Buoyancy] Stopped 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:H.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:I.SetSpeed] Stopped 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:I.SetSpeed](DEBUG): Uninitialize. 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:J.DepthEnvelope] Stopped 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:J.DepthEnvelope](DEBUG): Uninitialize. 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:K.YoYo] Stopped 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:K.YoYo](DEBUG): Uninitialize YoYoComponent. 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:Wpt1] Stopped 2014-04-13T05:49:05.184Z,1397368145.184 [science_to:Wpt1](INFO): Aggregate::uninitialize science_to:Wpt1 2014-04-13T05:49:05.185Z,1397368145.185 [science_to:Wpt1:A.Waypoint] Stopped 2014-04-13T05:49:05.185Z,1397368145.185 [science_to:Wpt1:A.Waypoint](DEBUG): Uninitialize WaypointComponent. 2014-04-13T05:49:05.671Z,1397368145.671 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:49:05.671Z,1397368145.671 [Radio_Freewave](INFO): Powering up 2014-04-13T05:49:05.682Z,1397368145.682 [MissionManager](IMPORTANT): Started mission Default 2014-04-13T05:49:05.682Z,1397368145.682 [Default] Running Loop=1 2014-04-13T05:49:05.682Z,1397368145.682 [Default](INFO): Aggregate::initialize Default 2014-04-13T05:49:05.682Z,1397368145.682 [Default:Iridium] Running Loop=1 2014-04-13T05:49:05.682Z,1397368145.682 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T05:49:05.682Z,1397368145.682 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T05:49:05.683Z,1397368145.683 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T05:49:05.683Z,1397368145.683 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T05:49:05.683Z,1397368145.683 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T05:49:05.683Z,1397368145.683 [Default:CallIridium] Running Loop=1 2014-04-13T05:49:05.684Z,1397368145.684 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T05:49:05.684Z,1397368145.684 [Default:CallIridium:A] Running Loop=1 2014-04-13T05:49:05.686Z,1397368145.686 [Default:CallIridium:A] Stopped 2014-04-13T05:49:05.687Z,1397368145.687 [Default:CallIridium:B] Running Loop=1 2014-04-13T05:49:05.687Z,1397368145.687 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T05:49:05.692Z,1397368145.692 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T05:49:05.693Z,1397368145.693 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T05:49:05.693Z,1397368145.693 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T05:49:05.693Z,1397368145.693 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T05:49:05.698Z,1397368145.698 [Default:GPS] Running Loop=1 2014-04-13T05:49:05.698Z,1397368145.698 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T05:49:05.698Z,1397368145.698 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T05:49:05.698Z,1397368145.698 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T05:49:05.698Z,1397368145.698 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T05:49:05.699Z,1397368145.699 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T05:49:05.704Z,1397368145.704 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T05:49:05.704Z,1397368145.704 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T05:49:05.704Z,1397368145.704 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T05:49:05.704Z,1397368145.704 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T05:49:06.266Z,1397368146.266 [Default:Iridium:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2014-04-13T05:49:06.270Z,1397368146.270 [Default:GPS:Read_GPS](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2014-04-13T05:49:13.761Z,1397368153.761 [NAL9602](INFO): NAL9602 initialized 2014-04-13T05:49:39.177Z,1397368179.177 [NAL9602](INFO): SBD MO Status=1, MOMSN=25270, MT Status=0, MTMSN=0 2014-04-13T05:49:39.225Z,1397368179.225 [NAL9602](INFO): Sent 75 bytes from file Logs/20140413T051242/Courier0012.lzma 2014-04-13T05:49:39.225Z,1397368179.225 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:49:39.300Z,1397368179.300 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Courier0012.lzma.parts/0000.sbd 2014-04-13T05:49:39.300Z,1397368179.300 [NAL9602](INFO): Completed sending Logs/20140413T051242/Courier0012.lzma 2014-04-13T05:50:03.150Z,1397368203.150 [NAL9602](INFO): SBD MO Status=1, MOMSN=25271, MT Status=0, MTMSN=0 2014-04-13T05:50:03.198Z,1397368203.198 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Express0013.lzma 2014-04-13T05:50:03.198Z,1397368203.198 [NAL9602](INFO): Packets left to send: 3 2014-04-13T05:50:03.200Z,1397368203.200 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0013.lzma.parts/0003.sbd 2014-04-13T05:50:19.407Z,1397368219.407 [NAL9602](INFO): SBD MO Status=2, MOMSN=25272, MT Status=2, MTMSN=0 2014-04-13T05:50:19.407Z,1397368219.407 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T05:50:20.996Z,1397368220.996 [NAL9602](IMPORTANT): GPS fix at: 1397368185.00 2014-04-13T05:50:21.008Z,1397368221.008 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T05:50:21.009Z,1397368221.009 [DeadReckonUsingMultipleVelocitySources](DEBUG): horizontalPathLengthSinceLastFix_ = 1572.35, recording fix residuals... 2014-04-13T05:50:21.015Z,1397368221.015 [Default:GPS:Read_GPS] Stopped 2014-04-13T05:50:21.016Z,1397368221.016 [Default:GPS:D] Running Loop=1 2014-04-13T05:50:21.488Z,1397368221.488 [Default:GPS:D] Stopped 2014-04-13T05:50:21.489Z,1397368221.489 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T05:50:21.489Z,1397368221.489 [Default:GPS] Stopped 2014-04-13T05:50:21.489Z,1397368221.489 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T05:50:21.489Z,1397368221.489 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T05:50:21.489Z,1397368221.489 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T05:51:07.897Z,1397368267.897 [NAL9602](INFO): SBD MO Status=2, MOMSN=25272, MT Status=2, MTMSN=0 2014-04-13T05:51:07.897Z,1397368267.897 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T05:51:26.333Z,1397368286.333 [NAL9602](INFO): SBD MO Status=1, MOMSN=25272, MT Status=0, MTMSN=0 2014-04-13T05:51:26.383Z,1397368286.383 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Express0013.lzma 2014-04-13T05:51:26.383Z,1397368286.383 [NAL9602](INFO): Packets left to send: 2 2014-04-13T05:51:26.384Z,1397368286.384 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0013.lzma.parts/0002.sbd 2014-04-13T05:51:34.440Z,1397368294.440 [CBIT](INFO): Clearing failed count for component Radio_Freewave 2014-04-13T05:51:34.440Z,1397368294.440 [Radio_Freewave] No Fault, FailCount= 2 2014-04-13T05:51:34.875Z,1397368294.875 [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-13T05:51:34.877Z,1397368294.877 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T05:51:34.877Z,1397368294.877 [Radio_Freewave] Communications Fault, FailCount= 1 2014-04-13T05:51:34.877Z,1397368294.877 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T05:51:34.932Z,1397368294.932 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T05:51:35.310Z,1397368295.310 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:51:35.310Z,1397368295.310 [Radio_Freewave](INFO): Powering down 2014-04-13T05:51:36.243Z,1397368296.243 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:51:36.243Z,1397368296.243 [Radio_Freewave](INFO): Powering up 2014-04-13T05:51:36.310Z,1397368296.310 [CBIT](INFO): Clearing failed state for component Radio_Freewave 2014-04-13T05:51:36.310Z,1397368296.310 [Radio_Freewave] No Fault, FailCount= 1 2014-04-13T05:51:37.685Z,1397368297.685 [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-13T05:51:37.686Z,1397368297.686 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T05:51:37.686Z,1397368297.686 [Radio_Freewave] Communications Fault, FailCount= 2 2014-04-13T05:51:37.686Z,1397368297.686 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T05:51:37.745Z,1397368297.745 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T05:51:37.745Z,1397368297.745 [CBIT](CRITICAL): Communications Fault in component: Radio_Freewave 2014-04-13T05:51:38.108Z,1397368298.108 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:51:38.109Z,1397368298.109 [Radio_Freewave](INFO): Powering down 2014-04-13T05:51:39.076Z,1397368299.076 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:51:39.076Z,1397368299.076 [Radio_Freewave](INFO): Powering up 2014-04-13T05:52:25.875Z,1397368345.875 [NAL9602](INFO): SBD MO Status=2, MOMSN=25273, MT Status=2, MTMSN=0 2014-04-13T05:52:25.875Z,1397368345.875 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2014-04-13T05:52:47.214Z,1397368367.214 [NAL9602](INFO): SBD MO Status=1, MOMSN=25273, MT Status=0, MTMSN=0 2014-04-13T05:52:47.264Z,1397368367.264 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Express0013.lzma 2014-04-13T05:52:47.265Z,1397368367.265 [NAL9602](INFO): Packets left to send: 1 2014-04-13T05:52:47.266Z,1397368367.266 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0013.lzma.parts/0001.sbd 2014-04-13T05:52:49.232Z,1397368369.232 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:52:51.873Z,1397368371.873 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:52:53.178Z,1397368373.178 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:52:55.814Z,1397368375.814 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:52:57.961Z,1397368377.961 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:52:57.998Z,1397368377.998 [NAL9602](INFO): SBD MO Status=1, MOMSN=25274, MT Status=0, MTMSN=0 2014-04-13T05:52:58.049Z,1397368378.049 [NAL9602](INFO): Sent 269 bytes from file Logs/20140413T051242/Express0013.lzma 2014-04-13T05:52:58.049Z,1397368378.049 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:52:58.050Z,1397368378.050 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0013.lzma.parts/0000.sbd 2014-04-13T05:52:58.051Z,1397368378.051 [NAL9602](INFO): Completed sending Logs/20140413T051242/Express0013.lzma 2014-04-13T05:53:00.575Z,1397368380.575 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:02.865Z,1397368382.865 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:05.483Z,1397368385.483 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:07.740Z,1397368387.740 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:07.800Z,1397368387.800 [NAL9602](INFO): SBD MO Status=0, MOMSN=25275, MT Status=0, MTMSN=0 2014-04-13T05:53:07.886Z,1397368387.886 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T05:53:07.887Z,1397368387.887 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T05:53:07.887Z,1397368387.887 [Default:Iridium] Stopped 2014-04-13T05:53:07.887Z,1397368387.887 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T05:53:07.887Z,1397368387.887 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T05:53:07.888Z,1397368387.888 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T05:53:07.888Z,1397368387.888 [Default:WaitAtTheSurface] Running Loop=1 2014-04-13T05:53:07.888Z,1397368387.888 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2014-04-13T05:53:07.888Z,1397368387.888 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-13T05:53:07.888Z,1397368387.888 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed](DEBUG): Initialize. 2014-04-13T05:53:07.888Z,1397368387.888 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-13T05:53:07.888Z,1397368387.888 [Default:WaitAtTheSurface:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T05:53:08.288Z,1397368388.288 [Default:WaitAtTheSurface:B.GoToSurface] Running Loop=1 2014-04-13T05:53:08.294Z,1397368388.294 [Default:WaitAtTheSurface:RunAtLowSpeed.SetSpeed] Running Loop=1 2014-04-13T05:53:08.299Z,1397368388.299 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T05:53:08.299Z,1397368388.299 [Default:CallIridium:B] Stopped 2014-04-13T05:53:08.299Z,1397368388.299 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T05:53:08.299Z,1397368388.299 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T05:53:08.299Z,1397368388.299 [Default:CallIridium] Stopped 2014-04-13T05:53:08.300Z,1397368388.300 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T05:53:13.514Z,1397368393.514 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:18.493Z,1397368398.493 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:18.512Z,1397368398.512 [NAL9602](INFO): Powering down 2014-04-13T05:53:23.511Z,1397368403.511 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:28.498Z,1397368408.498 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:33.508Z,1397368413.508 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:38.506Z,1397368418.506 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:43.491Z,1397368423.491 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:48.500Z,1397368428.500 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:53:58.469Z,1397368438.469 [Batt_Ocean_Server](INFO): Bus busy reported for battery bank#8 STATUS: 65535 2014-04-13T05:54:08.621Z,1397368448.621 [CBIT](INFO): Clearing failed count for component Radio_Freewave 2014-04-13T05:54:08.621Z,1397368448.621 [Radio_Freewave] No Fault, FailCount= 2 2014-04-13T05:54:13.524Z,1397368453.524 [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-13T05:54:13.525Z,1397368453.525 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T05:54:13.525Z,1397368453.525 [Radio_Freewave] Communications Fault, FailCount= 1 2014-04-13T05:54:13.538Z,1397368453.538 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T05:54:13.578Z,1397368453.578 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T05:54:18.480Z,1397368458.480 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:54:18.481Z,1397368458.481 [Radio_Freewave](INFO): Powering down 2014-04-13T05:54:28.468Z,1397368468.468 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:54:28.468Z,1397368468.468 [Radio_Freewave](INFO): Powering up 2014-04-13T05:54:28.497Z,1397368468.497 [CBIT](INFO): Clearing failed state for component Radio_Freewave 2014-04-13T05:54:28.497Z,1397368468.497 [Radio_Freewave] No Fault, FailCount= 1 2014-04-13T05:54:33.484Z,1397368473.484 [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-13T05:54:33.485Z,1397368473.485 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T05:54:33.486Z,1397368473.486 [Radio_Freewave] Communications Fault, FailCount= 2 2014-04-13T05:54:33.486Z,1397368473.486 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T05:54:33.506Z,1397368473.506 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T05:54:33.506Z,1397368473.506 [CBIT](CRITICAL): Communications Fault in component: Radio_Freewave 2014-04-13T05:54:38.501Z,1397368478.501 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:54:38.501Z,1397368478.501 [Radio_Freewave](INFO): Powering down 2014-04-13T05:54:48.517Z,1397368488.517 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:54:48.518Z,1397368488.518 [Radio_Freewave](INFO): Powering up 2014-04-13T05:57:03.546Z,1397368623.546 [CBIT](INFO): Clearing failed count for component Radio_Freewave 2014-04-13T05:57:03.546Z,1397368623.546 [Radio_Freewave] No Fault, FailCount= 2 2014-04-13T05:57:08.539Z,1397368628.539 [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-13T05:57:08.541Z,1397368628.541 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T05:57:08.541Z,1397368628.541 [Radio_Freewave] Communications Fault, FailCount= 1 2014-04-13T05:57:08.541Z,1397368628.541 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T05:57:08.561Z,1397368628.561 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T05:57:13.553Z,1397368633.553 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:57:13.554Z,1397368633.554 [Radio_Freewave](INFO): Powering down 2014-04-13T05:57:23.560Z,1397368643.560 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:57:23.560Z,1397368643.560 [Radio_Freewave](INFO): Powering up 2014-04-13T05:57:23.582Z,1397368643.582 [CBIT](INFO): Clearing failed state for component Radio_Freewave 2014-04-13T05:57:23.582Z,1397368643.582 [Radio_Freewave] No Fault, FailCount= 1 2014-04-13T05:57:28.557Z,1397368648.557 [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-13T05:57:28.558Z,1397368648.558 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T05:57:28.558Z,1397368648.558 [Radio_Freewave] Communications Fault, FailCount= 2 2014-04-13T05:57:28.558Z,1397368648.558 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T05:57:28.578Z,1397368648.578 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T05:57:28.579Z,1397368648.579 [CBIT](CRITICAL): Communications Fault in component: Radio_Freewave 2014-04-13T05:57:33.550Z,1397368653.550 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:57:33.551Z,1397368653.551 [Radio_Freewave](INFO): Powering down 2014-04-13T05:57:43.544Z,1397368663.544 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T05:57:43.545Z,1397368663.545 [Radio_Freewave](INFO): Powering up 2014-04-13T05:58:08.484Z,1397368688.484 [Default:CallIridium] Running Loop=1 2014-04-13T05:58:08.484Z,1397368688.484 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T05:58:08.485Z,1397368688.485 [Default:CallIridium:A] Running Loop=1 2014-04-13T05:58:08.485Z,1397368688.485 [Default:CallIridium:A] Stopped 2014-04-13T05:58:08.485Z,1397368688.485 [Default:CallIridium:B] Running Loop=1 2014-04-13T05:58:08.485Z,1397368688.485 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T05:58:13.603Z,1397368693.603 [Default:Iridium] Running Loop=1 2014-04-13T05:58:13.603Z,1397368693.603 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T05:58:13.603Z,1397368693.603 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T05:58:13.603Z,1397368693.603 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T05:58:13.604Z,1397368693.604 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T05:58:13.604Z,1397368693.604 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T05:58:13.604Z,1397368693.604 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T05:58:13.605Z,1397368693.605 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T05:58:13.605Z,1397368693.605 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T05:58:13.605Z,1397368693.605 [Default:GPS] Running Loop=1 2014-04-13T05:58:13.605Z,1397368693.605 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T05:58:13.605Z,1397368693.605 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T05:58:13.605Z,1397368693.605 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T05:58:13.605Z,1397368693.605 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T05:58:13.606Z,1397368693.606 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T05:58:13.615Z,1397368693.615 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T05:58:13.615Z,1397368693.615 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T05:58:13.615Z,1397368693.615 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T05:58:16.226Z,1397368696.226 [NAL9602](INFO): Powering up 2014-04-13T05:58:27.056Z,1397368707.056 [NAL9602](INFO): NAL9602 initialized 2014-04-13T05:58:52.426Z,1397368732.426 [NAL9602](INFO): SBD MO Status=1, MOMSN=25276, MT Status=0, MTMSN=0 2014-04-13T05:58:52.475Z,1397368732.475 [NAL9602](INFO): Sent 45 bytes from file Logs/20140413T051242/Courier0016.lzma 2014-04-13T05:58:52.475Z,1397368732.475 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:58:52.477Z,1397368732.477 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Courier0016.lzma.parts/0000.sbd 2014-04-13T05:58:52.477Z,1397368732.477 [NAL9602](INFO): Completed sending Logs/20140413T051242/Courier0016.lzma 2014-04-13T05:59:10.975Z,1397368750.975 [NAL9602](INFO): SBD MO Status=1, MOMSN=25277, MT Status=0, MTMSN=0 2014-04-13T05:59:11.031Z,1397368751.031 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Express0017.lzma 2014-04-13T05:59:11.031Z,1397368751.031 [NAL9602](INFO): Packets left to send: 1 2014-04-13T05:59:11.033Z,1397368751.033 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0017.lzma.parts/0001.sbd 2014-04-13T05:59:19.604Z,1397368759.604 [NAL9602](INFO): SBD MO Status=1, MOMSN=25278, MT Status=0, MTMSN=0 2014-04-13T05:59:19.653Z,1397368759.653 [NAL9602](INFO): Sent 111 bytes from file Logs/20140413T051242/Express0017.lzma 2014-04-13T05:59:19.653Z,1397368759.653 [NAL9602](INFO): Packets left to send: 0 2014-04-13T05:59:19.655Z,1397368759.655 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0017.lzma.parts/0000.sbd 2014-04-13T05:59:19.655Z,1397368759.655 [NAL9602](INFO): Completed sending Logs/20140413T051242/Express0017.lzma 2014-04-13T05:59:30.150Z,1397368770.150 [NAL9602](INFO): SBD MO Status=0, MOMSN=25279, MT Status=0, MTMSN=0 2014-04-13T05:59:30.249Z,1397368770.249 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T05:59:30.252Z,1397368770.252 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T05:59:30.252Z,1397368770.252 [Default:Iridium] Stopped 2014-04-13T05:59:30.252Z,1397368770.252 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T05:59:30.252Z,1397368770.252 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T05:59:30.252Z,1397368770.252 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T05:59:30.659Z,1397368770.659 [Default:CallIridium:B](INFO): Completed Default:CallIridium:B 2014-04-13T05:59:30.659Z,1397368770.659 [Default:CallIridium:B] Stopped 2014-04-13T05:59:30.660Z,1397368770.660 [Default:CallIridium:B](INFO): Aggregate::uninitialize Default:CallIridium:B 2014-04-13T05:59:30.660Z,1397368770.660 [Default:CallIridium](INFO): Completed Default:CallIridium 2014-04-13T05:59:30.660Z,1397368770.660 [Default:CallIridium] Stopped 2014-04-13T05:59:30.660Z,1397368770.660 [Default:CallIridium](INFO): Aggregate::uninitialize Default:CallIridium 2014-04-13T05:59:31.497Z,1397368771.497 [NAL9602](IMPORTANT): GPS fix at: 1397368737.00 2014-04-13T05:59:31.547Z,1397368771.547 [DeadReckonUsingMultipleVelocitySources](DEBUG): Got GPS fix: latitudeAccuracy_ = 1.74533e-07, longitudeAccuracy = 1.74533e-07 2014-04-13T05:59:31.552Z,1397368771.552 [Default:GPS:Read_GPS] Stopped 2014-04-13T05:59:31.552Z,1397368771.552 [Default:GPS:D] Running Loop=1 2014-04-13T05:59:32.033Z,1397368772.033 [Default:GPS:D] Stopped 2014-04-13T05:59:32.034Z,1397368772.034 [Default:GPS](INFO): Completed Default:GPS 2014-04-13T05:59:32.034Z,1397368772.034 [Default:GPS] Stopped 2014-04-13T05:59:32.034Z,1397368772.034 [Default:GPS](INFO): Aggregate::uninitialize Default:GPS 2014-04-13T05:59:32.034Z,1397368772.034 [Default:GPS:A.SetSpeed] Stopped 2014-04-13T05:59:32.034Z,1397368772.034 [Default:GPS:A.SetSpeed](DEBUG): Uninitialize. 2014-04-13T05:59:52.667Z,1397368792.667 [NAL9602](INFO): Powering down 2014-04-13T06:00:02.711Z,1397368802.711 [CBIT](INFO): Clearing failed count for component Radio_Freewave 2014-04-13T06:00:02.711Z,1397368802.711 [Radio_Freewave] No Fault, FailCount= 2 2014-04-13T06:00:07.675Z,1397368807.675 [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-13T06:00:07.676Z,1397368807.676 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T06:00:07.676Z,1397368807.676 [Radio_Freewave] Communications Fault, FailCount= 1 2014-04-13T06:00:07.677Z,1397368807.677 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T06:00:07.737Z,1397368807.737 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T06:00:12.656Z,1397368812.656 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:00:12.656Z,1397368812.656 [Radio_Freewave](INFO): Powering down 2014-04-13T06:00:22.651Z,1397368822.651 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:00:22.651Z,1397368822.651 [Radio_Freewave](INFO): Powering up 2014-04-13T06:00:22.673Z,1397368822.673 [CBIT](INFO): Clearing failed state for component Radio_Freewave 2014-04-13T06:00:22.673Z,1397368822.673 [Radio_Freewave] No Fault, FailCount= 1 2014-04-13T06:00:27.703Z,1397368827.703 [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-13T06:00:27.704Z,1397368827.704 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T06:00:27.704Z,1397368827.704 [Radio_Freewave] Communications Fault, FailCount= 2 2014-04-13T06:00:27.704Z,1397368827.704 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T06:00:27.740Z,1397368827.740 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T06:00:27.740Z,1397368827.740 [CBIT](CRITICAL): Communications Fault in component: Radio_Freewave 2014-04-13T06:00:32.659Z,1397368832.659 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:00:32.659Z,1397368832.659 [Radio_Freewave](INFO): Powering down 2014-04-13T06:00:42.654Z,1397368842.654 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:00:42.655Z,1397368842.655 [Radio_Freewave](INFO): Powering up 2014-04-13T06:02:57.727Z,1397368977.727 [CBIT](INFO): Clearing failed count for component Radio_Freewave 2014-04-13T06:02:57.727Z,1397368977.727 [Radio_Freewave] No Fault, FailCount= 2 2014-04-13T06:03:02.668Z,1397368982.668 [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-13T06:03:02.669Z,1397368982.669 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T06:03:02.669Z,1397368982.669 [Radio_Freewave] Communications Fault, FailCount= 1 2014-04-13T06:03:02.669Z,1397368982.669 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T06:03:02.703Z,1397368982.703 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T06:03:07.668Z,1397368987.668 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:03:07.668Z,1397368987.668 [Radio_Freewave](INFO): Powering down 2014-04-13T06:03:17.698Z,1397368997.698 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:03:17.699Z,1397368997.699 [Radio_Freewave](INFO): Powering up 2014-04-13T06:03:17.747Z,1397368997.747 [CBIT](INFO): Clearing failed state for component Radio_Freewave 2014-04-13T06:03:17.747Z,1397368997.747 [Radio_Freewave] No Fault, FailCount= 1 2014-04-13T06:03:22.614Z,1397369002.614 [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-13T06:03:22.619Z,1397369002.619 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T06:03:22.619Z,1397369002.619 [Radio_Freewave] Communications Fault, FailCount= 2 2014-04-13T06:03:22.620Z,1397369002.620 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T06:03:22.655Z,1397369002.655 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T06:03:22.655Z,1397369002.655 [CBIT](CRITICAL): Communications Fault in component: Radio_Freewave 2014-04-13T06:03:27.719Z,1397369007.719 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:03:27.719Z,1397369007.719 [Radio_Freewave](INFO): Powering down 2014-04-13T06:03:37.744Z,1397369017.744 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:03:37.744Z,1397369017.744 [Radio_Freewave](INFO): Powering up 2014-04-13T06:04:32.744Z,1397369072.744 [Default:CallIridium] Running Loop=1 2014-04-13T06:04:32.744Z,1397369072.744 [Default:CallIridium](INFO): Aggregate::initialize Default:CallIridium 2014-04-13T06:04:32.756Z,1397369072.756 [Default:CallIridium:A] Running Loop=1 2014-04-13T06:04:32.764Z,1397369072.764 [Default:CallIridium:A] Stopped 2014-04-13T06:04:32.764Z,1397369072.764 [Default:CallIridium:B] Running Loop=1 2014-04-13T06:04:32.764Z,1397369072.764 [Default:CallIridium:B](INFO): Aggregate::initialize Default:CallIridium:B 2014-04-13T06:04:37.692Z,1397369077.692 [Default:Iridium] Running Loop=1 2014-04-13T06:04:37.692Z,1397369077.692 [Default:Iridium](INFO): Aggregate::initialize Default:Iridium 2014-04-13T06:04:37.692Z,1397369077.692 [Default:Iridium:A.SetSpeed] Running Loop=1 2014-04-13T06:04:37.692Z,1397369077.692 [Default:Iridium:A.SetSpeed](DEBUG): Initialize. 2014-04-13T06:04:37.698Z,1397369077.698 [Default:Iridium:B.GoToSurface] Running Loop=1 2014-04-13T06:04:37.698Z,1397369077.698 [Default:Iridium:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T06:04:37.699Z,1397369077.699 [Default:Iridium:B.GoToSurface] Stopped 2014-04-13T06:04:37.700Z,1397369077.700 [Default:Iridium:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T06:04:37.700Z,1397369077.700 [Default:Iridium:Read_Iridium] Running Loop=1 2014-04-13T06:04:37.700Z,1397369077.700 [Default:GPS] Running Loop=1 2014-04-13T06:04:37.700Z,1397369077.700 [Default:GPS](INFO): Aggregate::initialize Default:GPS 2014-04-13T06:04:37.700Z,1397369077.700 [Default:GPS:A.SetSpeed] Running Loop=1 2014-04-13T06:04:37.700Z,1397369077.700 [Default:GPS:A.SetSpeed](DEBUG): Initialize. 2014-04-13T06:04:37.701Z,1397369077.701 [Default:GPS:B.GoToSurface] Running Loop=1 2014-04-13T06:04:37.701Z,1397369077.701 [Default:GPS:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2014-04-13T06:04:37.702Z,1397369077.702 [Default:GPS:B.GoToSurface] Stopped 2014-04-13T06:04:37.702Z,1397369077.702 [Default:GPS:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2014-04-13T06:04:37.702Z,1397369077.702 [Default:GPS:Read_GPS] Running Loop=1 2014-04-13T06:04:40.584Z,1397369080.584 [NAL9602](INFO): Powering up 2014-04-13T06:04:51.375Z,1397369091.375 [NAL9602](INFO): NAL9602 initialized 2014-04-13T06:05:20.091Z,1397369120.091 [NAL9602](INFO): SBD MO Status=1, MOMSN=25280, MT Status=0, MTMSN=0 2014-04-13T06:05:20.140Z,1397369120.140 [NAL9602](INFO): Sent 102 bytes from file Logs/20140413T051242/Courier0020.lzma 2014-04-13T06:05:20.140Z,1397369120.140 [NAL9602](INFO): Packets left to send: 0 2014-04-13T06:05:20.142Z,1397369120.142 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Courier0020.lzma.parts/0000.sbd 2014-04-13T06:05:20.142Z,1397369120.142 [NAL9602](INFO): Completed sending Logs/20140413T051242/Courier0020.lzma 2014-04-13T06:05:32.074Z,1397369132.074 [NAL9602](INFO): SBD MO Status=1, MOMSN=25281, MT Status=0, MTMSN=0 2014-04-13T06:05:32.125Z,1397369132.125 [NAL9602](INFO): Sent 332 bytes from file Logs/20140413T051242/Express0021.lzma 2014-04-13T06:05:32.125Z,1397369132.125 [NAL9602](INFO): Packets left to send: 1 2014-04-13T06:05:32.127Z,1397369132.127 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0021.lzma.parts/0001.sbd 2014-04-13T06:05:43.809Z,1397369143.809 [NAL9602](INFO): SBD MO Status=1, MOMSN=25282, MT Status=0, MTMSN=0 2014-04-13T06:05:43.860Z,1397369143.860 [NAL9602](INFO): Sent 123 bytes from file Logs/20140413T051242/Express0021.lzma 2014-04-13T06:05:43.861Z,1397369143.861 [NAL9602](INFO): Packets left to send: 0 2014-04-13T06:05:43.862Z,1397369143.862 [NAL9602](INFO): Stored copy of sent data in Logs/20140413T051242/Express0021.lzma.parts/0000.sbd 2014-04-13T06:05:43.862Z,1397369143.862 [NAL9602](INFO): Completed sending Logs/20140413T051242/Express0021.lzma 2014-04-13T06:05:52.710Z,1397369152.710 [CBIT](INFO): Clearing failed count for component Radio_Freewave 2014-04-13T06:05:52.710Z,1397369152.710 [Radio_Freewave] No Fault, FailCount= 2 2014-04-13T06:05:53.110Z,1397369153.110 [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-13T06:05:53.115Z,1397369153.115 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T06:05:53.115Z,1397369153.115 [Radio_Freewave] Communications Fault, FailCount= 1 2014-04-13T06:05:53.115Z,1397369153.115 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T06:05:53.140Z,1397369153.140 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T06:05:53.594Z,1397369153.594 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:05:53.594Z,1397369153.594 [Radio_Freewave](INFO): Powering down 2014-04-13T06:05:54.447Z,1397369154.447 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:05:54.447Z,1397369154.447 [Radio_Freewave](INFO): Powering up 2014-04-13T06:05:54.530Z,1397369154.530 [CBIT](INFO): Clearing failed state for component Radio_Freewave 2014-04-13T06:05:54.531Z,1397369154.531 [Radio_Freewave] No Fault, FailCount= 1 2014-04-13T06:05:55.820Z,1397369155.820 [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-13T06:05:55.821Z,1397369155.821 [Radio_Freewave](FAULT): Cannot start PPPD: /sbin/pppd nocrtscts /dev/ttyS1 noauth 115200 10.1.1.2:10.1.1.1 persist maxfail 0 2014-04-13T06:05:55.821Z,1397369155.821 [Radio_Freewave] Communications Fault, FailCount= 2 2014-04-13T06:05:55.821Z,1397369155.821 [Radio_Freewave](ERROR): Communications Fault 2014-04-13T06:05:55.842Z,1397369155.842 [CBIT](ERROR): Communications Fault in component: Radio_Freewave 2014-04-13T06:05:55.842Z,1397369155.842 [CBIT](CRITICAL): Communications Fault in component: Radio_Freewave 2014-04-13T06:05:56.312Z,1397369156.312 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:05:56.312Z,1397369156.312 [Radio_Freewave](INFO): Powering down 2014-04-13T06:05:57.209Z,1397369157.209 [Radio_Freewave](FAULT): Cannot stop PPPD. 2014-04-13T06:05:57.210Z,1397369157.210 [Radio_Freewave](INFO): Powering up 2014-04-13T06:06:50.102Z,1397369210.102 [NAL9602](FAULT): Verify xmit timeout failure. 2014-04-13T06:06:50.107Z,1397369210.107 [NAL9602] Data Fault, FailCount= 1 2014-04-13T06:06:50.107Z,1397369210.107 [NAL9602](ERROR): Data Fault 2014-04-13T06:06:50.135Z,1397369210.135 [CBIT](ERROR): Data Fault in component: NAL9602 2014-04-13T06:06:50.510Z,1397369210.510 [NAL9602](INFO): Powering down 2014-04-13T06:06:51.426Z,1397369211.426 [CBIT](INFO): Clearing failed state for component NAL9602 2014-04-13T06:06:51.426Z,1397369211.426 [NAL9602] No Fault, FailCount= 1 2014-04-13T06:06:55.717Z,1397369215.717 [NAL9602](INFO): Powering up NAL9602 2014-04-13T06:07:06.364Z,1397369226.364 [NAL9602](INFO): NAL9602 initialized 2014-04-13T06:07:14.593Z,1397369234.593 [DVL_micro](ERROR): DVL Failure: Failed to read in all data items. Got 44 of 46 2014-04-13T06:07:14.593Z,1397369234.593 [DVL_micro](ERROR): Failed to parse DVL response:$#NQ.RES 0X0000 1 1 1 1 37.1 37.5 38.1 37.2 -227.8 -42.3 1.3 -167 28 153 -17 9 9 9 9 -496.9 -14.7 -42.3 1 440.5 226.5 -59.9 1 -427 60 0 2 412 2.81 -1.96 205.8 37.1 14.7 0.005 35.0 1489 122 2014-04-13T06:07:19.906Z,1397369239.906 [NAL9602](INFO): SBD MO Status=0, MOMSN=25283, MT Status=0, MTMSN=0 2014-04-13T06:07:20.017Z,1397369240.017 [Default:Iridium:Read_Iridium] Stopped 2014-04-13T06:07:20.040Z,1397369240.040 [Default:Iridium](INFO): Completed Default:Iridium 2014-04-13T06:07:20.040Z,1397369240.040 [Default:Iridium] Stopped 2014-04-13T06:07:20.040Z,1397369240.040 [Default:Iridium](INFO): Aggregate::uninitialize Default:Iridium 2014-04-13T06:07:20.040Z,1397369240.040 [Default:Iridium:A.SetSpeed] Stopped 2014-04-13T06:07:20.040Z,1397369240.040 [Default:Iridium:A.SetSpeed](DEBUG): Uninitialize.