2015-06-08T21:38:25.771Z,1433799505.771 [Supervisor](DEBUG): Initializing supervisor. 2015-06-08T21:38:25.774Z,1433799505.774 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2015-06-08T21:38:25.775Z,1433799505.775 [SyncHandler](INFO): Protected caller Thread ID is 765 2015-06-08T21:38:25.775Z,1433799505.775 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2015-06-08T21:38:25.778Z,1433799505.778 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2015-06-08T21:38:25.779Z,1433799505.779 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 766 2015-06-08T21:38:25.781Z,1433799505.781 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2015-06-08T21:38:25.794Z,1433799505.794 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2015-06-08T21:38:25.798Z,1433799505.798 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2015-06-08T21:38:25.799Z,1433799505.799 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 767 2015-06-08T21:38:25.800Z,1433799505.800 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2015-06-08T21:38:25.802Z,1433799505.802 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2015-06-08T21:38:25.803Z,1433799505.803 [logger ThreadHandler](INFO): Protected caller Thread ID is 768 2015-06-08T21:38:25.805Z,1433799505.805 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2015-06-08T21:38:25.805Z,1433799505.805 [Supervisor](INFO): Looking for Config files in directory: Config/ 2015-06-08T21:38:25.809Z,1433799505.809 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2015-06-08T21:38:26.200Z,1433799506.200 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2015-06-08T21:38:26.202Z,1433799506.202 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2015-06-08T21:38:26.391Z,1433799506.391 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2015-06-08T21:38:26.393Z,1433799506.393 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2015-06-08T21:38:26.511Z,1433799506.511 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2015-06-08T21:38:26.512Z,1433799506.512 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2015-06-08T21:38:26.652Z,1433799506.652 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2015-06-08T21:38:26.653Z,1433799506.653 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2015-06-08T21:38:26.748Z,1433799506.748 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2015-06-08T21:38:26.965Z,1433799506.965 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2015-06-08T21:38:26.966Z,1433799506.966 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2015-06-08T21:38:27.061Z,1433799507.061 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2015-06-08T21:38:27.062Z,1433799507.062 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2015-06-08T21:38:27.321Z,1433799507.321 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2015-06-08T21:38:27.322Z,1433799507.322 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2015-06-08T21:38:27.742Z,1433799507.742 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2015-06-08T21:38:27.743Z,1433799507.743 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2015-06-08T21:38:28.095Z,1433799508.095 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2015-06-08T21:38:28.096Z,1433799508.096 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2015-06-08T21:38:28.668Z,1433799508.668 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2015-06-08T21:38:28.669Z,1433799508.669 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2015-06-08T21:38:28.896Z,1433799508.896 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2015-06-08T21:38:28.897Z,1433799508.897 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2015-06-08T21:38:29.009Z,1433799509.009 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2015-06-08T21:38:29.009Z,1433799509.009 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2015-06-08T21:38:29.500Z,1433799509.500 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2015-06-08T21:38:29.501Z,1433799509.501 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2015-06-08T21:38:29.680Z,1433799509.680 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2015-06-08T21:38:29.682Z,1433799509.682 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2015-06-08T21:38:29.685Z,1433799509.685 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2015-06-08T21:38:29.954Z,1433799509.954 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2015-06-08T21:38:29.955Z,1433799509.955 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2015-06-08T21:38:30.090Z,1433799510.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg 2015-06-08T21:38:30.198Z,1433799510.198 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2015-06-08T21:38:30.307Z,1433799510.307 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2015-06-08T21:38:30.416Z,1433799510.416 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2015-06-08T21:38:30.583Z,1433799510.583 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2015-06-08T21:38:30.771Z,1433799510.771 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2015-06-08T21:38:30.886Z,1433799510.886 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2015-06-08T21:38:30.988Z,1433799510.988 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2015-06-08T21:38:31.082Z,1433799511.082 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2015-06-08T21:38:31.192Z,1433799511.192 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2015-06-08T21:38:31.396Z,1433799511.396 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2015-06-08T21:38:31.400Z,1433799511.400 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2015-06-08T21:38:31.474Z,1433799511.474 [VerticalControl](DEBUG): Construct VerticalControl. 2015-06-08T21:38:31.607Z,1433799511.607 [VerticalControl] Loaded 2015-06-08T21:38:31.607Z,1433799511.607 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2015-06-08T21:38:31.608Z,1433799511.608 [HorizontalControl](DEBUG): Construct HorizontalControl. 2015-06-08T21:38:31.687Z,1433799511.687 [HorizontalControl] Loaded 2015-06-08T21:38:31.688Z,1433799511.688 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2015-06-08T21:38:31.688Z,1433799511.688 [SpeedControl](DEBUG): Construct SpeedControl. 2015-06-08T21:38:31.694Z,1433799511.694 [SpeedControl] Loaded 2015-06-08T21:38:31.694Z,1433799511.694 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2015-06-08T21:38:31.695Z,1433799511.695 [LoopControl](DEBUG): Construct LoopControl. 2015-06-08T21:38:31.696Z,1433799511.696 [LoopControl] Loaded 2015-06-08T21:38:31.696Z,1433799511.696 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2015-06-08T21:38:31.696Z,1433799511.696 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2015-06-08T21:38:31.697Z,1433799511.697 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2015-06-08T21:38:31.859Z,1433799511.859 [SBIT](DEBUG): Construct Startup Built In Test. 2015-06-08T21:38:31.871Z,1433799511.871 [SBIT] Loaded 2015-06-08T21:38:31.871Z,1433799511.871 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2015-06-08T21:38:31.872Z,1433799511.872 [IBIT](DEBUG): Construct Initiated Built In Test. 2015-06-08T21:38:31.905Z,1433799511.905 [IBIT] Loaded 2015-06-08T21:38:31.906Z,1433799511.906 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2015-06-08T21:38:31.908Z,1433799511.908 [CBIT](DEBUG): Construct Continuous Built In Test. 2015-06-08T21:38:32.059Z,1433799512.059 [CBIT] Loaded 2015-06-08T21:38:32.059Z,1433799512.059 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2015-06-08T21:38:32.059Z,1433799512.059 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2015-06-08T21:38:32.060Z,1433799512.060 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2015-06-08T21:38:32.088Z,1433799512.088 [DepthRateCalculator] Loaded 2015-06-08T21:38:32.088Z,1433799512.088 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2015-06-08T21:38:32.099Z,1433799512.099 [PitchRateCalculator] Loaded 2015-06-08T21:38:32.099Z,1433799512.099 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2015-06-08T21:38:32.110Z,1433799512.110 [SpeedCalculator] Loaded 2015-06-08T21:38:32.111Z,1433799512.111 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2015-06-08T21:38:32.127Z,1433799512.127 [TempGradientCalculator] Loaded 2015-06-08T21:38:32.128Z,1433799512.128 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2015-06-08T21:38:32.133Z,1433799512.133 [YawRateCalculator] Loaded 2015-06-08T21:38:32.133Z,1433799512.133 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2015-06-08T21:38:32.134Z,1433799512.134 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2015-06-08T21:38:32.134Z,1433799512.134 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2015-06-08T21:38:36.577Z,1433799516.577 [HFRadarCompactModelForecaster] Loaded 2015-06-08T21:38:36.577Z,1433799516.577 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread. 2015-06-08T21:38:37.654Z,1433799517.654 [HFRCMSpaceInterpolator] Loaded 2015-06-08T21:38:37.655Z,1433799517.655 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread. 2015-06-08T21:38:37.657Z,1433799517.657 [HFRCMTimeInterpolator] Loaded 2015-06-08T21:38:37.657Z,1433799517.657 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread. 2015-06-08T21:38:38.817Z,1433799518.817 [HFRCMReconstructedInterpolator] Loaded 2015-06-08T21:38:38.818Z,1433799518.818 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread. 2015-06-08T21:38:38.830Z,1433799518.830 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded 2015-06-08T21:38:38.830Z,1433799518.830 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread. 2015-06-08T21:38:38.862Z,1433799518.862 [HFRCMVirtualSurfaceDrifter] Loaded 2015-06-08T21:38:38.867Z,1433799518.867 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread. 2015-06-08T21:38:38.867Z,1433799518.867 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2015-06-08T21:38:38.868Z,1433799518.868 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2015-06-08T21:38:39.164Z,1433799519.164 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2015-06-08T21:38:39.165Z,1433799519.165 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2015-06-08T21:38:39.291Z,1433799519.291 [DeadReckonUsingMultipleVelocitySources] Loaded 2015-06-08T21:38:39.291Z,1433799519.291 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2015-06-08T21:38:39.356Z,1433799519.356 [DeadReckonUsingSpeedCalculator] Loaded 2015-06-08T21:38:39.356Z,1433799519.356 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2015-06-08T21:38:39.373Z,1433799519.373 [NavChart] Loaded 2015-06-08T21:38:39.374Z,1433799519.374 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2015-06-08T21:38:39.378Z,1433799519.378 [UniversalFixResidualReporter] Loaded 2015-06-08T21:38:39.378Z,1433799519.378 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2015-06-08T21:38:39.379Z,1433799519.379 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2015-06-08T21:38:39.384Z,1433799519.384 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2015-06-08T21:38:39.392Z,1433799519.392 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2015-06-08T21:38:39.393Z,1433799519.393 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2015-06-08T21:38:39.611Z,1433799519.611 [Aanderaa_O2] Loaded 2015-06-08T21:38:39.612Z,1433799519.612 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2015-06-08T21:38:39.623Z,1433799519.623 [CANONSampler] Loaded 2015-06-08T21:38:39.623Z,1433799519.623 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2015-06-08T21:38:39.708Z,1433799519.708 [CTD_NeilBrown] Loaded 2015-06-08T21:38:39.708Z,1433799519.708 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2015-06-08T21:38:39.712Z,1433799519.712 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406EF4E0 2015-06-08T21:38:39.712Z,1433799519.712 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 850 2015-06-08T21:38:39.728Z,1433799519.728 [PAR_Licor] Loaded 2015-06-08T21:38:39.728Z,1433799519.728 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2015-06-08T21:38:39.784Z,1433799519.784 [WetLabsBB2FL] Loaded 2015-06-08T21:38:39.785Z,1433799519.785 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2015-06-08T21:38:39.788Z,1433799519.788 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4071F4E0 2015-06-08T21:38:39.789Z,1433799519.789 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 851 2015-06-08T21:38:39.789Z,1433799519.789 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2015-06-08T21:38:39.790Z,1433799519.790 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2015-06-08T21:38:40.366Z,1433799520.366 [AcousticModem_Benthos_ATM900] Loaded 2015-06-08T21:38:40.366Z,1433799520.366 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2015-06-08T21:38:40.560Z,1433799520.560 [DataOverHttps] Loaded 2015-06-08T21:38:40.561Z,1433799520.561 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2015-06-08T21:38:40.575Z,1433799520.575 [Depth_Keller] Loaded 2015-06-08T21:38:40.575Z,1433799520.575 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2015-06-08T21:38:40.584Z,1433799520.584 [DropWeight] Loaded 2015-06-08T21:38:40.584Z,1433799520.584 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2015-06-08T21:38:40.686Z,1433799520.686 [NAL9602] Loaded 2015-06-08T21:38:40.687Z,1433799520.687 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2015-06-08T21:38:40.734Z,1433799520.734 [Onboard] Loaded 2015-06-08T21:38:40.735Z,1433799520.735 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2015-06-08T21:38:40.742Z,1433799520.742 [Radio_Surface] Loaded 2015-06-08T21:38:40.742Z,1433799520.742 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2015-06-08T21:38:40.746Z,1433799520.746 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409634E0 2015-06-08T21:38:40.746Z,1433799520.746 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 853 2015-06-08T21:38:40.962Z,1433799520.962 [PNI_TCM] Loaded 2015-06-08T21:38:40.962Z,1433799520.962 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2015-06-08T21:38:43.029Z,1433799523.029 [BPC1] Loaded 2015-06-08T21:38:43.029Z,1433799523.029 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2015-06-08T21:38:43.030Z,1433799523.030 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2015-06-08T21:38:43.031Z,1433799523.031 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2015-06-08T21:38:43.162Z,1433799523.162 [BuoyancyServo] Loaded 2015-06-08T21:38:43.162Z,1433799523.162 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2015-06-08T21:38:43.175Z,1433799523.175 [ElevatorServo] Loaded 2015-06-08T21:38:43.175Z,1433799523.175 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2015-06-08T21:38:43.187Z,1433799523.187 [MassServo] Loaded 2015-06-08T21:38:43.187Z,1433799523.187 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2015-06-08T21:38:43.200Z,1433799523.200 [RudderServo] Loaded 2015-06-08T21:38:43.200Z,1433799523.200 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2015-06-08T21:38:43.212Z,1433799523.212 [ThrusterServo] Loaded 2015-06-08T21:38:43.212Z,1433799523.212 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2015-06-08T21:38:43.213Z,1433799523.213 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2015-06-08T21:38:43.214Z,1433799523.214 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2015-06-08T21:38:43.355Z,1433799523.355 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2015-06-08T21:38:43.356Z,1433799523.356 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2015-06-08T21:38:43.398Z,1433799523.398 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2015-06-08T21:38:43.402Z,1433799523.402 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2015-06-08T21:38:43.403Z,1433799523.403 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2015-06-08T21:38:43.410Z,1433799523.410 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2015-06-08T21:38:43.414Z,1433799523.414 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A114E0 2015-06-08T21:38:43.414Z,1433799523.414 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 854 2015-06-08T21:38:43.419Z,1433799523.419 [Supervisor](INFO): Main Thread ID is 764 2015-06-08T21:38:43.419Z,1433799523.419 [Supervisor](DEBUG): Running supervisor. 2015-06-08T21:38:43.420Z,1433799523.420 [CommandLine ThreadHandler](INFO): Handler Thread ID is 855 2015-06-08T21:38:43.426Z,1433799523.426 [controlThread ThreadHandler](INFO): Handler Thread ID is 856 2015-06-08T21:38:43.427Z,1433799523.427 [controlThread](DEBUG): Initializing ControlThread 2015-06-08T21:38:43.428Z,1433799523.428 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2015-06-08T21:38:43.429Z,1433799523.429 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2015-06-08T21:38:43.430Z,1433799523.430 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2015-06-08T21:38:43.431Z,1433799523.431 [LoopControl](DEBUG): Initialize LoopControlComponent. 2015-06-08T21:38:43.431Z,1433799523.431 [SBIT](INFO): Initialize SBIT Component. 2015-06-08T21:38:43.432Z,1433799523.432 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12296 2015-06-08T21:38:43.432Z,1433799523.432 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2015-06-08T21:38:43.432Z,1433799523.432 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2015-06-08T21:38:43.433Z,1433799523.433 [IBIT](INFO): Initialize IBIT Component. 2015-06-08T21:38:43.434Z,1433799523.434 [CBIT](DEBUG): Initialize CBIT Component. 2015-06-08T21:38:43.434Z,1433799523.434 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2015-06-08T21:38:43.434Z,1433799523.434 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2015-06-08T21:38:43.438Z,1433799523.438 [logger ThreadHandler](INFO): Handler Thread ID is 857 2015-06-08T21:38:43.458Z,1433799523.458 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-06-08T21:38:43.458Z,1433799523.458 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2015-06-08T21:38:43.459Z,1433799523.459 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2015-06-08T21:38:43.459Z,1433799523.459 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2015-06-08T21:38:43.460Z,1433799523.460 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2015-06-08T21:38:43.495Z,1433799523.495 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 858 2015-06-08T21:38:43.495Z,1433799523.495 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2015-06-08T21:38:43.501Z,1433799523.501 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 860 2015-06-08T21:38:43.503Z,1433799523.503 [WetLabsBB2FL](INFO): Powering down 2015-06-08T21:38:43.523Z,1433799523.523 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2015-06-08T21:38:43.543Z,1433799523.543 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 861 2015-06-08T21:38:43.549Z,1433799523.549 [Radio_Surface](INFO): Powering up 2015-06-08T21:38:43.556Z,1433799523.556 [HFRadarCompactModelForecaster](DEBUG): Found new ECs! 2015-06-08T21:38:43.556Z,1433799523.556 [HFRadarCompactModelForecaster](ERROR): Most recent ECs are more than six hours old. 2015-06-08T21:38:43.560Z,1433799523.560 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 862 2015-06-08T21:38:43.567Z,1433799523.567 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2015-06-08T21:38:43.568Z,1433799523.568 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2015-06-08T21:38:43.568Z,1433799523.568 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2015-06-08T21:38:43.569Z,1433799523.569 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2015-06-08T21:38:43.569Z,1433799523.569 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2015-06-08T21:38:43.569Z,1433799523.569 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2015-06-08T21:38:43.569Z,1433799523.569 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2015-06-08T21:38:43.570Z,1433799523.570 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2015-06-08T21:38:43.570Z,1433799523.570 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2015-06-08T21:38:43.947Z,1433799523.947 [CTD_NeilBrown](DEBUG): CTD uart timeout: serial timeout 2015-06-08T21:38:43.947Z,1433799523.947 [CTD_NeilBrown](ERROR): Could not get real or simulated CTD data. startTime.elapsed() = 0.423760 2015-06-08T21:38:52.812Z,1433799532.812 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201505192300 published 2015-06-08T21:38:52.816Z,1433799532.816 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0. 2015-06-08T21:38:52.829Z,1433799532.829 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component. 2015-06-08T21:38:52.830Z,1433799532.830 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s. 2015-06-08T21:38:52.832Z,1433799532.832 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component. 2015-06-08T21:38:52.832Z,1433799532.832 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component. 2015-06-08T21:38:52.837Z,1433799532.837 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-06-08T21:38:52.837Z,1433799532.837 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-06-08T21:38:52.838Z,1433799532.838 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-06-08T21:38:52.838Z,1433799532.838 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-06-08T21:38:52.839Z,1433799532.839 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-06-08T21:38:52.839Z,1433799532.839 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-06-08T21:38:52.839Z,1433799532.839 [NavChart](DEBUG): Initialize NavChart Navigation. 2015-06-08T21:38:52.840Z,1433799532.840 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2015-06-08T21:38:52.844Z,1433799532.844 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2015-06-08T21:38:52.844Z,1433799532.844 [DropWeight] Hardware Fault, FailCount= 1 2015-06-08T21:38:52.844Z,1433799532.844 [DropWeight](ERROR): Hardware Fault 2015-06-08T21:38:52.856Z,1433799532.856 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2015-06-08T21:38:52.899Z,1433799532.899 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-06-08T21:38:52.938Z,1433799532.938 [MissionManager](DEBUG): 2015-06-08T21:38:52.938Z,1433799532.938 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2015-06-08T21:38:53.022Z,1433799533.022 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2015-06-08T21:38:53.023Z,1433799533.023 [Default:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-06-08T21:38:53.073Z,1433799533.073 [Default:CheckIn:A.SetSpeed](DEBUG): Construct. 2015-06-08T21:38:53.099Z,1433799533.099 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2015-06-08T21:38:53.119Z,1433799533.119 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct. 2015-06-08T21:38:53.153Z,1433799533.153 [MissionManager](DEBUG): 0 5.0 1.0 400 10 500 Default mission has been running for Burn 300 Dropped weight due to communications timeout. 5 2015-06-08T21:38:53.160Z,1433799533.160 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,CANONSampler,PAR_Licor,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,HFRCMReconstructedInterpolator,HFRCMSurfaceCurrentAtVehicleLocation,HFRCMVirtualSurfaceDrifter,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2015-06-08T21:38:53.208Z,1433799533.208 [CANONSampler](INFO): Powering down 2015-06-08T21:38:53.237Z,1433799533.237 [AcousticModem_Benthos_ATM900](INFO): Powering up 2015-06-08T21:38:53.238Z,1433799533.238 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2015-06-08T21:38:53.505Z,1433799533.505 [NAL9602](INFO): Powering up NAL9602 2015-06-08T21:39:03.396Z,1433799543.396 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:03.662Z,1433799543.662 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:03.778Z,1433799543.778 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2015-06-08T21:39:03.786Z,1433799543.786 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2015-06-08T21:39:03.804Z,1433799543.804 [ElevatorServo](DEBUG): Initializing EZServoServo. 2015-06-08T21:39:03.810Z,1433799543.810 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2015-06-08T21:39:03.826Z,1433799543.826 [MassServo](DEBUG): Initializing EZServoServo. 2015-06-08T21:39:03.838Z,1433799543.838 [MassServo](DEBUG): Initializing MassServo. 2015-06-08T21:39:03.843Z,1433799543.843 [RudderServo](DEBUG): Initializing EZServoServo. 2015-06-08T21:39:03.854Z,1433799543.854 [RudderServo](DEBUG): Initializing RudderServo. 2015-06-08T21:39:03.875Z,1433799543.875 [ThrusterServo](DEBUG): Initializing EZServoServo. 2015-06-08T21:39:03.886Z,1433799543.886 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2015-06-08T21:39:03.951Z,1433799543.951 [CommandLine](FAULT): Scheduling is paused 2015-06-08T21:39:03.953Z,1433799543.953 [CBIT](CRITICAL): Environmental Failure. Press:14.451184 PSI. Humidity:52%. Temp:21 C. ABORTING MISSION 2015-06-08T21:39:03.954Z,1433799543.954 [CBIT](ERROR): Hardware Fault in component: DropWeight 2015-06-08T21:39:03.954Z,1433799543.954 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2015-06-08T21:39:04.035Z,1433799544.035 [Aanderaa_O2](FAULT): Timed out starting 2015-06-08T21:39:04.035Z,1433799544.035 [Aanderaa_O2] Communications Fault, FailCount= 1 2015-06-08T21:39:04.035Z,1433799544.035 [Aanderaa_O2](ERROR): Communications Fault 2015-06-08T21:39:04.037Z,1433799544.037 [AcousticModem_Benthos_ATM900](DEBUG): 2015-06-08T21:39:04.054Z,1433799544.054 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire 2015-06-08T21:39:04.055Z,1433799544.055 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band 2015-06-08T21:39:04.059Z,1433799544.059 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3 2015-06-08T21:39:04.059Z,1433799544.059 [AcousticModem_Benthos_ATM900](DEBUG): Jun 8 2015 21:42:17 2015-06-08T21:39:04.161Z,1433799544.161 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:04.162Z,1433799544.162 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:04.187Z,1433799544.187 [SBIT](IMPORTANT): Beginning Startup BIT 2015-06-08T21:39:04.190Z,1433799544.190 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2 2015-06-08T21:39:04.190Z,1433799544.190 [CBIT](IMPORTANT): Beginning GF scan 2015-06-08T21:39:04.507Z,1433799544.507 [Aanderaa_O2](INFO): Powering down 2015-06-08T21:39:04.646Z,1433799544.646 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:04.656Z,1433799544.656 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:04.973Z,1433799544.973 [AcousticModem_Benthos_ATM900](INFO): entering command mode 2015-06-08T21:39:04.984Z,1433799544.984 [NAL9602](INFO): NAL9602 initialized 2015-06-08T21:39:05.027Z,1433799545.027 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:05.036Z,1433799545.036 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:05.377Z,1433799545.377 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment 2015-06-08T21:39:05.378Z,1433799545.378 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1> 2015-06-08T21:39:05.378Z,1433799545.378 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged 2015-06-08T21:39:05.430Z,1433799545.430 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:05.431Z,1433799545.431 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:05.458Z,1433799545.458 [CBIT](INFO): Clearing failed state for component Aanderaa_O2 2015-06-08T21:39:05.464Z,1433799545.464 [Aanderaa_O2] No Fault, FailCount= 1 2015-06-08T21:39:05.778Z,1433799545.778 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3 2015-06-08T21:39:05.858Z,1433799545.858 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:05.859Z,1433799545.859 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:06.178Z,1433799546.178 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment 2015-06-08T21:39:06.179Z,1433799546.179 [AcousticModem_Benthos_ATM900](INFO): set local address to 3 2015-06-08T21:39:06.276Z,1433799546.276 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:06.286Z,1433799546.286 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:06.579Z,1433799546.579 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2> 2015-06-08T21:39:06.727Z,1433799546.727 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:06.729Z,1433799546.729 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-06-08T21:39:12.769Z,1433799552.769 [PNI_TCM](ERROR): CRC does not match. Expected:0x37397 got:0x16888 2015-06-08T21:39:12.770Z,1433799552.770 [PNI_TCM](ERROR): CRC does not match. Expected:0x64439 got:0x16888 2015-06-08T21:39:13.157Z,1433799553.157 [PNI_TCM](ERROR): CRC does not match. Expected:0x54325 got:0x16888 2015-06-08T21:39:13.567Z,1433799553.567 [PNI_TCM](ERROR): CRC does not match. Expected:0x55951 got:0x16888 2015-06-08T21:39:13.956Z,1433799553.956 [PNI_TCM](ERROR): CRC does not match. Expected:0x21954 got:0x16888 2015-06-08T21:39:14.733Z,1433799554.733 [PNI_TCM](ERROR): CRC does not match. Expected:0x16492 got:0x16888 2015-06-08T21:39:14.734Z,1433799554.734 [PNI_TCM](ERROR): CRC does not match. Expected:0x15954 got:0x16888 2015-06-08T21:39:15.125Z,1433799555.125 [PNI_TCM](ERROR): CRC does not match. Expected:0x50686 got:0x16888 2015-06-08T21:39:15.868Z,1433799555.868 [Aanderaa_O2](FAULT): Timed out starting 2015-06-08T21:39:15.868Z,1433799555.868 [Aanderaa_O2] Communications Fault, FailCount= 2 2015-06-08T21:39:15.868Z,1433799555.868 [Aanderaa_O2](ERROR): Communications Fault 2015-06-08T21:39:15.945Z,1433799555.945 [PNI_TCM](ERROR): CRC does not match. Expected:0x61635 got:0x16888 2015-06-08T21:39:15.946Z,1433799555.946 [PNI_TCM](ERROR): CRC does not match. Expected:0x58430 got:0x16888 2015-06-08T21:39:16.104Z,1433799556.104 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2 2015-06-08T21:39:16.389Z,1433799556.389 [Aanderaa_O2](INFO): Powering down 2015-06-08T21:39:16.459Z,1433799556.459 [PNI_TCM](ERROR): CRC does not match. Expected:0x37241 got:0x16888 2015-06-08T21:39:16.757Z,1433799556.757 [PNI_TCM](ERROR): CRC does not match. Expected:0x16216 got:0x16888 2015-06-08T21:39:17.172Z,1433799557.172 [PNI_TCM](ERROR): CRC does not match. Expected:0x39633 got:0x16888 2015-06-08T21:39:17.316Z,1433799557.316 [SBIT](ERROR): Could not read massPosReader_. 2015-06-08T21:39:17.319Z,1433799557.319 [CBIT](INFO): Clearing failed state for component Aanderaa_O2 2015-06-08T21:39:17.319Z,1433799557.319 [Aanderaa_O2] No Fault, FailCount= 2 2015-06-08T21:39:17.553Z,1433799557.553 [PNI_TCM](ERROR): CRC does not match. Expected:0x62360 got:0x16888 2015-06-08T21:39:18.003Z,1433799558.003 [PNI_TCM](ERROR): CRC does not match. Expected:0x41675 got:0x16888 2015-06-08T21:39:18.375Z,1433799558.375 [PNI_TCM](ERROR): CRC does not match. Expected:0x53743 got:0x16888 2015-06-08T21:39:18.763Z,1433799558.763 [PNI_TCM](ERROR): CRC does not match. Expected:0x55959 got:0x16888 2015-06-08T21:39:19.166Z,1433799559.166 [PNI_TCM](ERROR): CRC does not match. Expected:0x15908 got:0x16888 2015-06-08T21:39:19.567Z,1433799559.567 [PNI_TCM](ERROR): CRC does not match. Expected:0x42200 got:0x16888 2015-06-08T21:39:19.961Z,1433799559.961 [PNI_TCM](ERROR): CRC does not match. Expected:0x52124 got:0x16888 2015-06-08T21:39:20.357Z,1433799560.357 [PNI_TCM](ERROR): CRC does not match. Expected:0x9967 got:0x16888 2015-06-08T21:39:20.770Z,1433799560.770 [PNI_TCM](ERROR): CRC does not match. Expected:0x42136 got:0x16888 2015-06-08T21:39:21.165Z,1433799561.165 [PNI_TCM](ERROR): CRC does not match. Expected:0x38033 got:0x16888 2015-06-08T21:39:21.532Z,1433799561.532 [PNI_TCM](ERROR): CRC does not match. Expected:0x32586 got:0x16888 2015-06-08T21:39:21.963Z,1433799561.963 [PNI_TCM](ERROR): CRC does not match. Expected:0x3207 got:0x16888 2015-06-08T21:39:22.360Z,1433799562.360 [PNI_TCM](ERROR): CRC does not match. Expected:0x34797 got:0x16888 2015-06-08T21:39:22.360Z,1433799562.360 [PNI_TCM](FAULT): Failed to acquire valid data within timeout. 2015-06-08T21:39:22.360Z,1433799562.360 [PNI_TCM] Data Fault, FailCount= 1 2015-06-08T21:39:22.360Z,1433799562.360 [PNI_TCM](ERROR): Data Fault 2015-06-08T21:39:22.374Z,1433799562.374 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.393411 seconds old. 2015-06-08T21:39:22.379Z,1433799562.379 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.398123 seconds old. 2015-06-08T21:39:22.503Z,1433799562.503 [CBIT](ERROR): Data Fault in component: PNI_TCM 2015-06-08T21:39:22.735Z,1433799562.735 [PNI_TCM](INFO): Powering down 2015-06-08T21:39:22.888Z,1433799562.888 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 0.908015 seconds old. 2015-06-08T21:39:22.889Z,1433799562.889 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 0.908415 seconds old. 2015-06-08T21:39:23.194Z,1433799563.194 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.214088 seconds old. 2015-06-08T21:39:23.216Z,1433799563.216 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.214388 seconds old. 2015-06-08T21:39:23.575Z,1433799563.575 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.595180 seconds old. 2015-06-08T21:39:23.577Z,1433799563.577 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.595687 seconds old. 2015-06-08T21:39:23.963Z,1433799563.963 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 1.983285 seconds old. 2015-06-08T21:39:23.969Z,1433799563.969 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 1.983585 seconds old. 2015-06-08T21:39:24.037Z,1433799564.037 [CBIT](INFO): Clearing failed state for component PNI_TCM 2015-06-08T21:39:24.037Z,1433799564.037 [PNI_TCM] No Fault, FailCount= 1 2015-06-08T21:39:24.373Z,1433799564.373 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.392720 seconds old. 2015-06-08T21:39:24.378Z,1433799564.378 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.397233 seconds old. 2015-06-08T21:39:24.726Z,1433799564.726 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 2.745569 seconds old. 2015-06-08T21:39:24.731Z,1433799564.731 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 2.750081 seconds old. 2015-06-08T21:39:25.189Z,1433799565.189 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 3.209192 seconds old. 2015-06-08T21:39:25.208Z,1433799565.208 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.209592 seconds old. 2015-06-08T21:39:25.567Z,1433799565.567 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 3.586678 seconds old. 2015-06-08T21:39:25.572Z,1433799565.572 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.591290 seconds old. 2015-06-08T21:39:25.944Z,1433799565.944 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 3.964270 seconds old. 2015-06-08T21:39:25.946Z,1433799565.946 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 3.964570 seconds old. 2015-06-08T21:39:26.388Z,1433799566.388 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 4.407855 seconds old. 2015-06-08T21:39:26.393Z,1433799566.393 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.412368 seconds old. 2015-06-08T21:39:26.745Z,1433799566.745 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 4.764510 seconds old. 2015-06-08T21:39:26.750Z,1433799566.750 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 4.769122 seconds old. 2015-06-08T21:39:27.129Z,1433799567.129 [DeadReckonUsingMultipleVelocitySources](DEBUG): Most recent orientation data is 5.149108 seconds old. 2015-06-08T21:39:27.158Z,1433799567.158 [DeadReckonUsingSpeedCalculator](DEBUG): Most recent orientation data is 5.177258 seconds old. 2015-06-08T21:39:27.890Z,1433799567.890 [Aanderaa_O2](FAULT): Timed out starting 2015-06-08T21:39:27.890Z,1433799567.890 [Aanderaa_O2] Communications Fault, FailCount= 3 2015-06-08T21:39:27.890Z,1433799567.890 [Aanderaa_O2](ERROR): Communications Fault 2015-06-08T21:39:28.071Z,1433799568.071 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2 2015-06-08T21:39:28.071Z,1433799568.071 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2 2015-06-08T21:39:28.408Z,1433799568.408 [Aanderaa_O2](INFO): Powering down 2015-06-08T21:39:30.481Z,1433799570.481 [CBIT](IMPORTANT): No ground fault detected 2015-06-08T21:39:58.121Z,1433799598.121 [SBIT](CRITICAL): SBIT FAILED 2015-06-08T21:39:58.499Z,1433799598.499 [MissionManager](IMPORTANT): Started mission Startup 2015-06-08T21:39:58.499Z,1433799598.499 [Startup] Running Loop=1 2015-06-08T21:39:58.499Z,1433799598.499 [Startup](INFO): Aggregate::initialize Startup 2015-06-08T21:39:58.499Z,1433799598.499 [Startup:A.GoToSurface] Running Loop=1 2015-06-08T21:39:58.499Z,1433799598.499 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2015-06-08T21:39:58.500Z,1433799598.500 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2015-06-08T21:39:58.500Z,1433799598.500 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2015-06-08T21:39:58.501Z,1433799598.501 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s. 2015-06-08T21:39:58.527Z,1433799598.527 [Startup:StartupSatComms] Running Loop=1 2015-06-08T21:39:58.527Z,1433799598.527 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2015-06-08T21:39:58.527Z,1433799598.527 [Startup:StartupSatComms:A] Running Loop=1 2015-06-08T21:39:58.962Z,1433799598.962 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2015-06-08T21:40:31.858Z,1433799631.858 [BPC1](ERROR): Failed to receive battery data 2015-06-08T21:40:31.858Z,1433799631.858 [BPC1] Communications Fault, FailCount= 1 2015-06-08T21:40:31.858Z,1433799631.858 [BPC1](ERROR): Communications Fault 2015-06-08T21:40:31.901Z,1433799631.901 [CBIT](ERROR): Communications Fault in component: BPC1 2015-06-08T21:40:32.718Z,1433799632.718 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003706 2015-06-08T21:40:32.812Z,1433799632.812 [CBIT](INFO): Clearing failed state for component BPC1 2015-06-08T21:40:32.812Z,1433799632.812 [BPC1] No Fault, FailCount= 1 2015-06-08T21:40:58.756Z,1433799658.756 [Startup:StartupSatComms:A](INFO): Timed out from 2015-06-08T21:39:58.5Z 2015-06-08T21:40:58.756Z,1433799658.756 [Startup:StartupSatComms:A] Stopped 2015-06-08T21:40:58.756Z,1433799658.756 [Startup:StartupSatComms:B] Running Loop=1 2015-06-08T21:40:59.153Z,1433799659.153 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2015-06-08T21:41:03.317Z,1433799663.317 [DataOverHttps](INFO): Sending 232 bytes from file Logs/20150608T213825/Courier0000.lzma 2015-06-08T21:41:04.099Z,1433799664.099 [DataOverHttps](INFO): Moved sent file to Logs/20150608T213825/Courier0000.lzma.bak 2015-06-08T21:41:04.099Z,1433799664.099 [DataOverHttps](INFO): SBD MOMSN=3549874 2015-06-08T21:41:16.158Z,1433799676.158 [DataOverHttps](INFO): Sending 798 bytes from file Logs/20150608T213825/Express0001.lzma 2015-06-08T21:41:16.908Z,1433799676.908 [DataOverHttps](INFO): Moved sent file to Logs/20150608T213825/Express0001.lzma.bak 2015-06-08T21:41:16.908Z,1433799676.908 [DataOverHttps](INFO): SBD MOMSN=3549881 2015-06-08T21:41:17.379Z,1433799677.379 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2015-06-08T21:41:17.386Z,1433799677.386 [Startup:StartupSatComms:B] Stopped 2015-06-08T21:41:17.386Z,1433799677.386 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2015-06-08T21:41:17.386Z,1433799677.386 [Startup:StartupSatComms] Stopped 2015-06-08T21:41:17.386Z,1433799677.386 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2015-06-08T21:41:17.387Z,1433799677.387 [Startup](INFO): Completed Startup 2015-06-08T21:41:17.387Z,1433799677.387 [Startup] Stopped 2015-06-08T21:41:17.388Z,1433799677.388 [Startup](INFO): Aggregate::uninitialize Startup 2015-06-08T21:41:17.388Z,1433799677.388 [Startup:A.GoToSurface] Stopped 2015-06-08T21:41:17.388Z,1433799677.388 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2015-06-08T21:41:17.746Z,1433799677.746 [MissionManager](IMPORTANT): Started mission Default 2015-06-08T21:41:17.746Z,1433799677.746 [Default] Running Loop=1 2015-06-08T21:41:17.746Z,1433799677.746 [Default](INFO): Aggregate::initialize Default 2015-06-08T21:41:17.746Z,1433799677.746 [Default:A.GoToSurface] Running Loop=1 2015-06-08T21:41:17.746Z,1433799677.746 [Default:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2015-06-08T21:41:17.747Z,1433799677.747 [Default:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2015-06-08T21:41:17.747Z,1433799677.747 [Default:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2015-06-08T21:41:17.747Z,1433799677.747 [Default:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s. 2015-06-08T21:41:17.753Z,1433799677.753 [Default:WaitAtTheSurface] Running Loop=1 2015-06-08T21:41:17.753Z,1433799677.753 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2015-06-08T21:41:17.754Z,1433799677.754 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1 2015-06-08T21:41:17.754Z,1433799677.754 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize. 2015-06-08T21:41:20.989Z,1433799680.989 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1 2015-06-08T21:41:43.207Z,1433799703.207 [CBIT](CRITICAL): Environmental Failure. Press:14.451184 PSI. Humidity:51%. Temp:21 C. ABORTING MISSION 2015-06-08T21:41:53.192Z,1433799713.192 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-06-08T21:41:53.192Z,1433799713.192 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2015-06-08T21:41:53.193Z,1433799713.193 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-06-08T21:41:53.195Z,1433799713.195 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-06-08T21:41:53.195Z,1433799713.195 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2015-06-08T21:41:53.195Z,1433799713.195 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-06-08T21:41:53.207Z,1433799713.207 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-06-08T21:41:53.208Z,1433799713.208 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-06-08T21:41:58.199Z,1433799718.199 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-06-08T21:41:58.199Z,1433799718.199 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2015-06-08T21:41:58.200Z,1433799718.200 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-06-08T21:41:58.200Z,1433799718.200 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2015-06-08T21:41:58.200Z,1433799718.200 [CBIT](INFO): Clearing failed count for component Aanderaa_O2 2015-06-08T21:41:58.200Z,1433799718.200 [Aanderaa_O2] No Fault, FailCount= 3 2015-06-08T21:42:03.154Z,1433799723.154 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-06-08T21:42:03.155Z,1433799723.155 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-06-08T21:42:03.155Z,1433799723.155 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-06-08T21:42:03.156Z,1433799723.156 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-06-08T21:42:03.156Z,1433799723.156 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-06-08T21:42:03.156Z,1433799723.156 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-06-08T21:42:08.153Z,1433799728.153 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 14.961277 seconds since last successful read, accepting data for 20.000000 seconds. 2015-06-08T21:42:13.184Z,1433799733.184 [BPC1](ERROR): Failed to receive battery data 2015-06-08T21:42:13.184Z,1433799733.184 [BPC1] Communications Fault, FailCount= 1 2015-06-08T21:42:13.184Z,1433799733.184 [BPC1](ERROR): Communications Fault 2015-06-08T21:42:13.250Z,1433799733.250 [CBIT](ERROR): Communications Fault in component: BPC1 2015-06-08T21:42:18.099Z,1433799738.099 [Aanderaa_O2](FAULT): Timed out starting 2015-06-08T21:42:18.099Z,1433799738.099 [Aanderaa_O2] Communications Fault, FailCount= 1 2015-06-08T21:42:18.099Z,1433799738.099 [Aanderaa_O2](ERROR): Communications Fault 2015-06-08T21:42:18.209Z,1433799738.209 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2 2015-06-08T21:42:23.216Z,1433799743.216 [Aanderaa_O2](INFO): Powering down 2015-06-08T21:42:31.013Z,1433799751.013 [CBIT](INFO): Clearing failed state for component BPC1 2015-06-08T21:42:31.013Z,1433799751.013 [BPC1] No Fault, FailCount= 1 2015-06-08T21:42:33.250Z,1433799753.250 [CBIT](INFO): Clearing failed state for component Aanderaa_O2 2015-06-08T21:42:33.250Z,1433799753.250 [Aanderaa_O2] No Fault, FailCount= 1 2015-06-08T21:42:53.097Z,1433799773.097 [Aanderaa_O2](FAULT): Timed out starting 2015-06-08T21:42:53.098Z,1433799773.098 [Aanderaa_O2] Communications Fault, FailCount= 2 2015-06-08T21:42:53.098Z,1433799773.098 [Aanderaa_O2](ERROR): Communications Fault 2015-06-08T21:42:53.271Z,1433799773.271 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2 2015-06-08T21:42:58.210Z,1433799778.210 [Aanderaa_O2](INFO): Powering down 2015-06-08T21:43:08.177Z,1433799788.177 [CBIT](INFO): Clearing failed state for component Aanderaa_O2 2015-06-08T21:43:08.177Z,1433799788.177 [Aanderaa_O2] No Fault, FailCount= 2 2015-06-08T21:43:18.212Z,1433799798.212 [CBIT](CRITICAL): Environmental Failure. Press:14.982194 PSI. Humidity:52%. Temp:20 C. ABORTING MISSION 2015-06-08T21:43:28.100Z,1433799808.100 [Aanderaa_O2](FAULT): Timed out starting 2015-06-08T21:43:28.100Z,1433799808.100 [Aanderaa_O2] Communications Fault, FailCount= 3 2015-06-08T21:43:28.100Z,1433799808.100 [Aanderaa_O2](ERROR): Communications Fault 2015-06-08T21:43:31.086Z,1433799811.086 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2 2015-06-08T21:43:31.086Z,1433799811.086 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2 2015-06-08T21:43:33.217Z,1433799813.217 [Aanderaa_O2](INFO): Powering down 2015-06-08T21:43:33.273Z,1433799813.273 [BPC1](ERROR): Failed to receive battery data 2015-06-08T21:43:33.273Z,1433799813.273 [BPC1] Communications Fault, FailCount= 1 2015-06-08T21:43:33.273Z,1433799813.273 [BPC1](ERROR): Communications Fault 2015-06-08T21:43:33.320Z,1433799813.320 [CBIT](ERROR): Communications Fault in component: BPC1 2015-06-08T21:43:43.181Z,1433799823.181 [CBIT](CRITICAL): Environmental Failure. Press:14.451184 PSI. Humidity:51%. Temp:21 C. ABORTING MISSION 2015-06-08T21:43:48.179Z,1433799828.179 [CBIT](INFO): Clearing failed state for component BPC1 2015-06-08T21:43:48.180Z,1433799828.180 [BPC1] No Fault, FailCount= 1 2015-06-08T21:43:58.201Z,1433799838.201 [CBIT](CRITICAL): Environmental Failure. Press:14.451184 PSI. Humidity:53%. Temp:20 C. ABORTING MISSION 2015-06-08T21:44:08.112Z,1433799848.112 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2015-06-08T21:44:36.038Z,1433799876.038 [CBIT](CRITICAL): Environmental Failure. Press:14.982194 PSI. Humidity:53%. Temp:21 C. ABORTING MISSION 2015-06-08T21:44:53.237Z,1433799893.237 [CBIT](CRITICAL): Environmental Failure. Press:14.982194 PSI. Humidity:53%. Temp:20 C. ABORTING MISSION 2015-06-08T21:45:03.180Z,1433799903.180 [DeadReckonUsingMultipleVelocitySources](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-06-08T21:45:03.180Z,1433799903.180 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2015-06-08T21:45:03.180Z,1433799903.180 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2015-06-08T21:45:03.182Z,1433799903.182 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-06-08T21:45:03.182Z,1433799903.182 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2015-06-08T21:45:03.182Z,1433799903.182 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-06-08T21:45:03.199Z,1433799903.199 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2015-06-08T21:45:03.199Z,1433799903.199 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-06-08T21:45:08.170Z,1433799908.170 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2015-06-08T21:45:08.170Z,1433799908.170 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2015-06-08T21:45:08.170Z,1433799908.170 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-06-08T21:45:08.170Z,1433799908.170 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2015-06-08T21:45:13.204Z,1433799913.204 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2015-06-08T21:45:13.204Z,1433799913.204 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-06-08T21:45:13.204Z,1433799913.204 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-06-08T21:45:13.205Z,1433799913.205 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-06-08T21:45:13.205Z,1433799913.205 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-06-08T21:45:13.206Z,1433799913.206 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-06-08T21:45:18.192Z,1433799918.192 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 15.012651 seconds since last successful read, accepting data for 20.000000 seconds. 2015-06-08T21:45:18.205Z,1433799918.205 [CBIT](CRITICAL): Environmental Failure. Press:14.982194 PSI. Humidity:52%. Temp:20 C. ABORTING MISSION 2015-06-08T21:45:23.153Z,1433799923.153 [DeadReckonUsingMultipleVelocitySources](DEBUG): No bottom track data -- 19.973573 seconds since last successful read, accepting data for 20.000000 seconds. 2015-06-08T21:45:35.996Z,1433799935.996 [BPC1](ERROR): Failed to receive battery data 2015-06-08T21:45:35.996Z,1433799935.996 [BPC1] Communications Fault, FailCount= 1 2015-06-08T21:45:35.996Z,1433799935.996 [BPC1](ERROR): Communications Fault 2015-06-08T21:45:36.024Z,1433799936.024 [CBIT](ERROR): Communications Fault in component: BPC1 2015-06-08T21:45:48.170Z,1433799948.170 [CBIT](CRITICAL): Environmental Failure. P