2015-05-29T02:52:32.863Z,1432867952.863 [Supervisor](DEBUG): Initializing supervisor. 2015-05-29T02:52:32.867Z,1432867952.867 [SyncHandler](DEBUG): Created PCaller Thread at 4034C4E0 2015-05-29T02:52:32.867Z,1432867952.867 [SyncHandler](INFO): Protected caller Thread ID is 765 2015-05-29T02:52:32.868Z,1432867952.868 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2015-05-29T02:52:32.871Z,1432867952.871 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4037C4E0 2015-05-29T02:52:32.871Z,1432867952.871 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 766 2015-05-29T02:52:32.874Z,1432867952.874 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2015-05-29T02:52:32.886Z,1432867952.886 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2015-05-29T02:52:32.891Z,1432867952.891 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 403AC4E0 2015-05-29T02:52:32.891Z,1432867952.891 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 767 2015-05-29T02:52:32.892Z,1432867952.892 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2015-05-29T02:52:32.895Z,1432867952.895 [logger ThreadHandler](DEBUG): Created PCaller Thread at 403DC4E0 2015-05-29T02:52:32.895Z,1432867952.895 [logger ThreadHandler](INFO): Protected caller Thread ID is 768 2015-05-29T02:52:32.897Z,1432867952.897 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2015-05-29T02:52:32.898Z,1432867952.898 [Supervisor](INFO): Looking for Config files in directory: Config/ 2015-05-29T02:52:32.901Z,1432867952.901 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2015-05-29T02:52:33.289Z,1432867953.289 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2015-05-29T02:52:33.290Z,1432867953.290 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2015-05-29T02:52:33.480Z,1432867953.480 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2015-05-29T02:52:33.481Z,1432867953.481 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2015-05-29T02:52:33.604Z,1432867953.604 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2015-05-29T02:52:33.605Z,1432867953.605 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2015-05-29T02:52:33.745Z,1432867953.745 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2015-05-29T02:52:33.746Z,1432867953.746 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2015-05-29T02:52:33.844Z,1432867953.844 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2015-05-29T02:52:34.064Z,1432867954.064 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2015-05-29T02:52:34.065Z,1432867954.065 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2015-05-29T02:52:34.160Z,1432867954.160 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2015-05-29T02:52:34.161Z,1432867954.161 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2015-05-29T02:52:34.418Z,1432867954.418 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2015-05-29T02:52:34.419Z,1432867954.419 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2015-05-29T02:52:34.833Z,1432867954.833 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2015-05-29T02:52:34.834Z,1432867954.834 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2015-05-29T02:52:35.187Z,1432867955.187 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2015-05-29T02:52:35.188Z,1432867955.188 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2015-05-29T02:52:35.765Z,1432867955.765 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2015-05-29T02:52:35.766Z,1432867955.766 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2015-05-29T02:52:35.989Z,1432867955.989 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2015-05-29T02:52:35.990Z,1432867955.990 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2015-05-29T02:52:36.105Z,1432867956.105 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2015-05-29T02:52:36.105Z,1432867956.105 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2015-05-29T02:52:36.597Z,1432867956.597 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2015-05-29T02:52:36.597Z,1432867956.597 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2015-05-29T02:52:36.766Z,1432867956.766 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2015-05-29T02:52:36.768Z,1432867956.768 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2015-05-29T02:52:36.772Z,1432867956.772 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2015-05-29T02:52:37.042Z,1432867957.042 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2015-05-29T02:52:37.043Z,1432867957.043 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2015-05-29T02:52:37.180Z,1432867957.180 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Estimation.cfg 2015-05-29T02:52:37.287Z,1432867957.287 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2015-05-29T02:52:37.395Z,1432867957.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2015-05-29T02:52:37.503Z,1432867957.503 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2015-05-29T02:52:37.671Z,1432867957.671 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2015-05-29T02:52:37.864Z,1432867957.864 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2015-05-29T02:52:37.979Z,1432867957.979 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2015-05-29T02:52:38.080Z,1432867958.080 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2015-05-29T02:52:38.175Z,1432867958.175 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2015-05-29T02:52:38.285Z,1432867958.285 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2015-05-29T02:52:38.485Z,1432867958.485 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2015-05-29T02:52:38.500Z,1432867958.500 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2015-05-29T02:52:38.573Z,1432867958.573 [VerticalControl](DEBUG): Construct VerticalControl. 2015-05-29T02:52:38.706Z,1432867958.706 [VerticalControl] Loaded 2015-05-29T02:52:38.706Z,1432867958.706 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2015-05-29T02:52:38.707Z,1432867958.707 [HorizontalControl](DEBUG): Construct HorizontalControl. 2015-05-29T02:52:38.791Z,1432867958.791 [HorizontalControl] Loaded 2015-05-29T02:52:38.792Z,1432867958.792 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2015-05-29T02:52:38.792Z,1432867958.792 [SpeedControl](DEBUG): Construct SpeedControl. 2015-05-29T02:52:38.798Z,1432867958.798 [SpeedControl] Loaded 2015-05-29T02:52:38.798Z,1432867958.798 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2015-05-29T02:52:38.799Z,1432867958.799 [LoopControl](DEBUG): Construct LoopControl. 2015-05-29T02:52:38.800Z,1432867958.800 [LoopControl] Loaded 2015-05-29T02:52:38.800Z,1432867958.800 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2015-05-29T02:52:38.801Z,1432867958.801 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2015-05-29T02:52:38.803Z,1432867958.803 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2015-05-29T02:52:38.966Z,1432867958.966 [SBIT](DEBUG): Construct Startup Built In Test. 2015-05-29T02:52:38.978Z,1432867958.978 [SBIT] Loaded 2015-05-29T02:52:38.979Z,1432867958.979 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2015-05-29T02:52:38.979Z,1432867958.979 [IBIT](DEBUG): Construct Initiated Built In Test. 2015-05-29T02:52:39.013Z,1432867959.013 [IBIT] Loaded 2015-05-29T02:52:39.013Z,1432867959.013 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2015-05-29T02:52:39.016Z,1432867959.016 [CBIT](DEBUG): Construct Continuous Built In Test. 2015-05-29T02:52:39.171Z,1432867959.171 [CBIT] Loaded 2015-05-29T02:52:39.171Z,1432867959.171 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2015-05-29T02:52:39.172Z,1432867959.172 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2015-05-29T02:52:39.172Z,1432867959.172 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2015-05-29T02:52:39.205Z,1432867959.205 [DepthRateCalculator] Loaded 2015-05-29T02:52:39.205Z,1432867959.205 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2015-05-29T02:52:39.210Z,1432867959.210 [PitchRateCalculator] Loaded 2015-05-29T02:52:39.211Z,1432867959.211 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2015-05-29T02:52:39.226Z,1432867959.226 [SpeedCalculator] Loaded 2015-05-29T02:52:39.226Z,1432867959.226 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2015-05-29T02:52:39.243Z,1432867959.243 [TempGradientCalculator] Loaded 2015-05-29T02:52:39.244Z,1432867959.244 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2015-05-29T02:52:39.249Z,1432867959.249 [YawRateCalculator] Loaded 2015-05-29T02:52:39.249Z,1432867959.249 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2015-05-29T02:52:39.250Z,1432867959.250 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2015-05-29T02:52:39.250Z,1432867959.250 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2015-05-29T02:52:44.012Z,1432867964.012 [HFRadarCompactModelForecaster] Loaded 2015-05-29T02:52:44.012Z,1432867964.012 [ComponentRegistry](DEBUG): SyncComponent "HFRadarCompactModelForecaster" handled in the control thread. 2015-05-29T02:52:45.102Z,1432867965.102 [HFRCMSpaceInterpolator] Loaded 2015-05-29T02:52:45.102Z,1432867965.102 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSpaceInterpolator" handled in the control thread. 2015-05-29T02:52:45.105Z,1432867965.105 [HFRCMTimeInterpolator] Loaded 2015-05-29T02:52:45.105Z,1432867965.105 [ComponentRegistry](DEBUG): SyncComponent "HFRCMTimeInterpolator" handled in the control thread. 2015-05-29T02:52:46.349Z,1432867966.349 [HFRCMReconstructedInterpolator] Loaded 2015-05-29T02:52:46.349Z,1432867966.349 [ComponentRegistry](DEBUG): SyncComponent "HFRCMReconstructedInterpolator" handled in the control thread. 2015-05-29T02:52:46.361Z,1432867966.361 [HFRCMSurfaceCurrentAtVehicleLocation] Loaded 2015-05-29T02:52:46.362Z,1432867966.362 [ComponentRegistry](DEBUG): SyncComponent "HFRCMSurfaceCurrentAtVehicleLocation" handled in the control thread. 2015-05-29T02:52:46.394Z,1432867966.394 [HFRCMVirtualSurfaceDrifter] Loaded 2015-05-29T02:52:46.394Z,1432867966.394 [ComponentRegistry](DEBUG): SyncComponent "HFRCMVirtualSurfaceDrifter" handled in the control thread. 2015-05-29T02:52:46.395Z,1432867966.395 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2015-05-29T02:52:46.395Z,1432867966.395 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2015-05-29T02:52:46.696Z,1432867966.696 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2015-05-29T02:52:46.697Z,1432867966.697 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2015-05-29T02:52:46.821Z,1432867966.821 [DeadReckonUsingSpeedCalculator] Loaded 2015-05-29T02:52:46.821Z,1432867966.821 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2015-05-29T02:52:46.838Z,1432867966.838 [NavChart] Loaded 2015-05-29T02:52:46.839Z,1432867966.839 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2015-05-29T02:52:46.843Z,1432867966.843 [UniversalFixResidualReporter] Loaded 2015-05-29T02:52:46.843Z,1432867966.843 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2015-05-29T02:52:46.844Z,1432867966.844 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2015-05-29T02:52:46.849Z,1432867966.849 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2015-05-29T02:52:46.861Z,1432867966.861 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2015-05-29T02:52:46.862Z,1432867966.862 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2015-05-29T02:52:47.084Z,1432867967.084 [Aanderaa_O2] Loaded 2015-05-29T02:52:47.085Z,1432867967.085 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2015-05-29T02:52:47.096Z,1432867967.096 [CANONSampler] Loaded 2015-05-29T02:52:47.096Z,1432867967.096 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread. 2015-05-29T02:52:47.181Z,1432867967.181 [CTD_NeilBrown] Loaded 2015-05-29T02:52:47.181Z,1432867967.181 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2015-05-29T02:52:47.185Z,1432867967.185 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 406EC4E0 2015-05-29T02:52:47.185Z,1432867967.185 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 850 2015-05-29T02:52:47.201Z,1432867967.201 [PAR_Licor] Loaded 2015-05-29T02:52:47.201Z,1432867967.201 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2015-05-29T02:52:47.257Z,1432867967.257 [WetLabsBB2FL] Loaded 2015-05-29T02:52:47.257Z,1432867967.257 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2015-05-29T02:52:47.261Z,1432867967.261 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4071C4E0 2015-05-29T02:52:47.262Z,1432867967.262 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 851 2015-05-29T02:52:47.262Z,1432867967.262 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2015-05-29T02:52:47.263Z,1432867967.263 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2015-05-29T02:52:47.790Z,1432867967.790 [AcousticModem_Benthos_ATM900] Loaded 2015-05-29T02:52:47.790Z,1432867967.790 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2015-05-29T02:52:47.969Z,1432867967.969 [DataOverHttps] Loaded 2015-05-29T02:52:47.970Z,1432867967.970 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2015-05-29T02:52:47.988Z,1432867967.988 [Depth_Keller] Loaded 2015-05-29T02:52:47.988Z,1432867967.988 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2015-05-29T02:52:48.095Z,1432867968.095 [NAL9602] Loaded 2015-05-29T02:52:48.096Z,1432867968.096 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2015-05-29T02:52:48.142Z,1432867968.142 [Onboard] Loaded 2015-05-29T02:52:48.142Z,1432867968.142 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2015-05-29T02:52:48.149Z,1432867968.149 [Radio_Surface] Loaded 2015-05-29T02:52:48.149Z,1432867968.149 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2015-05-29T02:52:48.151Z,1432867968.151 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409604E0 2015-05-29T02:52:48.151Z,1432867968.151 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 852 2015-05-29T02:52:48.364Z,1432867968.364 [PNI_TCM] Loaded 2015-05-29T02:52:48.365Z,1432867968.365 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2015-05-29T02:52:50.491Z,1432867970.491 [BPC1] Loaded 2015-05-29T02:52:50.491Z,1432867970.491 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2015-05-29T02:52:50.492Z,1432867970.492 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2015-05-29T02:52:50.492Z,1432867970.492 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2015-05-29T02:52:50.630Z,1432867970.630 [BuoyancyServo] Loaded 2015-05-29T02:52:50.630Z,1432867970.630 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2015-05-29T02:52:50.643Z,1432867970.643 [ElevatorServo] Loaded 2015-05-29T02:52:50.644Z,1432867970.644 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2015-05-29T02:52:50.656Z,1432867970.656 [MassServo] Loaded 2015-05-29T02:52:50.656Z,1432867970.656 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2015-05-29T02:52:50.672Z,1432867970.672 [RudderServo] Loaded 2015-05-29T02:52:50.673Z,1432867970.673 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2015-05-29T02:52:50.685Z,1432867970.685 [ThrusterServo] Loaded 2015-05-29T02:52:50.685Z,1432867970.685 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2015-05-29T02:52:50.686Z,1432867970.686 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2015-05-29T02:52:50.686Z,1432867970.686 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2015-05-29T02:52:50.832Z,1432867970.832 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2015-05-29T02:52:50.832Z,1432867970.832 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2015-05-29T02:52:50.876Z,1432867970.876 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2015-05-29T02:52:50.880Z,1432867970.880 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2015-05-29T02:52:50.881Z,1432867970.881 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2015-05-29T02:52:50.888Z,1432867970.888 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2015-05-29T02:52:50.891Z,1432867970.891 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A0E4E0 2015-05-29T02:52:50.891Z,1432867970.891 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 854 2015-05-29T02:52:50.896Z,1432867970.896 [Supervisor](INFO): Main Thread ID is 764 2015-05-29T02:52:50.896Z,1432867970.896 [Supervisor](DEBUG): Running supervisor. 2015-05-29T02:52:50.897Z,1432867970.897 [CommandLine ThreadHandler](INFO): Handler Thread ID is 855 2015-05-29T02:52:50.903Z,1432867970.903 [controlThread ThreadHandler](INFO): Handler Thread ID is 856 2015-05-29T02:52:50.904Z,1432867970.904 [controlThread](DEBUG): Initializing ControlThread 2015-05-29T02:52:50.905Z,1432867970.905 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2015-05-29T02:52:50.907Z,1432867970.907 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2015-05-29T02:52:50.907Z,1432867970.907 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2015-05-29T02:52:50.908Z,1432867970.908 [LoopControl](DEBUG): Initialize LoopControlComponent. 2015-05-29T02:52:50.908Z,1432867970.908 [SBIT](INFO): Initialize SBIT Component. 2015-05-29T02:52:50.909Z,1432867970.909 [SBIT](IMPORTANT): Tethys CM Info: SVN revision:12250 2015-05-29T02:52:50.909Z,1432867970.909 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2015-05-29T02:52:50.909Z,1432867970.909 [SBIT](IMPORTANT): Kernel Version:#639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 2015-05-29T02:52:50.910Z,1432867970.910 [IBIT](INFO): Initialize IBIT Component. 2015-05-29T02:52:50.911Z,1432867970.911 [CBIT](DEBUG): Initialize CBIT Component. 2015-05-29T02:52:50.911Z,1432867970.911 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2015-05-29T02:52:50.915Z,1432867970.915 [logger ThreadHandler](INFO): Handler Thread ID is 857 2015-05-29T02:52:50.935Z,1432867970.935 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-05-29T02:52:50.935Z,1432867970.935 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2015-05-29T02:52:50.936Z,1432867970.936 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2015-05-29T02:52:50.936Z,1432867970.936 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2015-05-29T02:52:50.937Z,1432867970.937 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2015-05-29T02:52:50.974Z,1432867970.974 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 858 2015-05-29T02:52:50.974Z,1432867970.974 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown. 2015-05-29T02:52:50.976Z,1432867970.976 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4 2015-05-29T02:52:50.996Z,1432867970.996 [HFRadarCompactModelForecaster](DEBUG): Found new ECs! 2015-05-29T02:52:50.996Z,1432867970.996 [HFRadarCompactModelForecaster](ERROR): Most recent ECs are more than six hours old. 2015-05-29T02:52:50.999Z,1432867970.999 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 860 2015-05-29T02:52:51.008Z,1432867971.008 [WetLabsBB2FL](INFO): Powering down 2015-05-29T02:52:51.036Z,1432867971.036 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 861 2015-05-29T02:52:51.042Z,1432867971.042 [Radio_Surface](INFO): Powering up 2015-05-29T02:52:51.064Z,1432867971.064 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 862 2015-05-29T02:52:51.069Z,1432867971.069 [NavChartDb](INFO): Looking for Electronic Nav Chart files in directory: Resources 2015-05-29T02:52:51.069Z,1432867971.069 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2015-05-29T02:52:51.070Z,1432867971.070 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2015-05-29T02:52:51.070Z,1432867971.070 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2015-05-29T02:52:51.070Z,1432867971.070 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2015-05-29T02:52:51.070Z,1432867971.070 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2015-05-29T02:52:51.071Z,1432867971.071 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2015-05-29T02:52:51.071Z,1432867971.071 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2015-05-29T02:52:51.071Z,1432867971.071 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2015-05-29T02:52:51.127Z,1432867971.127 [CTD_NeilBrown](DEBUG): CTD uart timeout: serial timeout 2015-05-29T02:52:51.128Z,1432867971.128 [CTD_NeilBrown](ERROR): Could not get real or simulated CTD data. startTime.elapsed() = 0.151137 2015-05-29T02:53:00.167Z,1432867980.167 [HFRadarCompactModelForecaster](IMPORTANT): forecast time 201505192300 published 2015-05-29T02:53:00.186Z,1432867980.186 [HFRCMSpaceInterpolator](DEBUG): Initializing HFRCMSpaceInterpolator component with verbosity level 0. 2015-05-29T02:53:00.187Z,1432867980.187 [HFRCMTimeInterpolator](DEBUG): Initializing HFRCMTimeInterpolator component. 2015-05-29T02:53:00.188Z,1432867980.188 [HFRCMReconstructedInterpolator](INFO): Initializing HFRCMReconstructedInterpolator component with velocityAccuracy_ = 0.300000 m/s. 2015-05-29T02:53:00.205Z,1432867980.205 [HFRCMSurfaceCurrentAtVehicleLocation](DEBUG): Initializing HFRCMSurfaceCurrentAtVehicleLocation component. 2015-05-29T02:53:00.206Z,1432867980.206 [HFRCMVirtualSurfaceDrifter](DEBUG): Initializing HFRCMVirtualSurfaceDrifter component. 2015-05-29T02:53:00.206Z,1432867980.206 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-05-29T02:53:00.207Z,1432867980.207 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-05-29T02:53:00.207Z,1432867980.207 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-05-29T02:53:00.208Z,1432867980.208 [NavChart](DEBUG): Initialize NavChart Navigation. 2015-05-29T02:53:00.208Z,1432867980.208 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2015-05-29T02:53:00.218Z,1432867980.218 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2015-05-29T02:53:00.259Z,1432867980.259 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-05-29T02:53:00.284Z,1432867980.284 [MissionManager](DEBUG): 2015-05-29T02:53:00.285Z,1432867980.285 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2015-05-29T02:53:00.386Z,1432867980.386 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2015-05-29T02:53:00.387Z,1432867980.387 [Default:A.GoToSurface](DEBUG): Construct GoToSurface. 2015-05-29T02:53:00.416Z,1432867980.416 [Default:CheckIn:A.SetSpeed](DEBUG): Construct. 2015-05-29T02:53:00.452Z,1432867980.452 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2015-05-29T02:53:00.456Z,1432867980.456 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Construct. 2015-05-29T02:53:00.479Z,1432867980.479 [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-05-29T02:53:00.495Z,1432867980.495 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,CANONSampler,PAR_Licor,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,HFRadarCompactModelForecaster,HFRCMSpaceInterpolator,HFRCMTimeInterpolator,HFRCMReconstructedInterpolator,HFRCMSurfaceCurrentAtVehicleLocation,HFRCMVirtualSurfaceDrifter,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2015-05-29T02:53:00.541Z,1432867980.541 [CANONSampler](INFO): Powering down 2015-05-29T02:53:00.582Z,1432867980.582 [AcousticModem_Benthos_ATM900](INFO): Powering up 2015-05-29T02:53:00.582Z,1432867980.582 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2015-05-29T02:53:00.957Z,1432867980.957 [NAL9602](INFO): Powering up NAL9602 2015-05-29T02:53:10.909Z,1432867990.909 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-05-29T02:53:11.054Z,1432867991.054 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2015-05-29T02:53:11.067Z,1432867991.067 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2015-05-29T02:53:11.093Z,1432867991.093 [ElevatorServo](DEBUG): Initializing EZServoServo. 2015-05-29T02:53:11.099Z,1432867991.099 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2015-05-29T02:53:11.112Z,1432867991.112 [MassServo](DEBUG): Initializing EZServoServo. 2015-05-29T02:53:11.119Z,1432867991.119 [MassServo](DEBUG): Initializing MassServo. 2015-05-29T02:53:11.131Z,1432867991.131 [RudderServo](DEBUG): Initializing EZServoServo. 2015-05-29T02:53:11.139Z,1432867991.139 [RudderServo](DEBUG): Initializing RudderServo. 2015-05-29T02:53:11.160Z,1432867991.160 [ThrusterServo](DEBUG): Initializing EZServoServo. 2015-05-29T02:53:11.167Z,1432867991.167 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2015-05-29T02:53:11.304Z,1432867991.304 [AcousticModem_Benthos_ATM900](DEBUG): 2015-05-29T02:53:11.305Z,1432867991.305 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire 2015-05-29T02:53:11.306Z,1432867991.306 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band 2015-05-29T02:53:11.306Z,1432867991.306 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3 2015-05-29T02:53:11.307Z,1432867991.307 [AcousticModem_Benthos_ATM900](DEBUG): May 29 2015 02:55:56 2015-05-29T02:53:11.390Z,1432867991.390 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-05-29T02:53:11.424Z,1432867991.424 [SBIT](IMPORTANT): Beginning Startup BIT 2015-05-29T02:53:11.426Z,1432867991.426 [CBIT](IMPORTANT): Beginning GF scan 2015-05-29T02:53:11.747Z,1432867991.747 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-05-29T02:53:12.316Z,1432867992.316 [Aanderaa_O2](INFO): Powering down 2015-05-29T02:53:12.392Z,1432867992.392 [AcousticModem_Benthos_ATM900](INFO): entering command mode 2015-05-29T02:53:12.423Z,1432867992.423 [NAL9602](INFO): NAL9602 initialized 2015-05-29T02:53:12.536Z,1432867992.536 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-05-29T02:53:12.598Z,1432867992.598 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment 2015-05-29T02:53:12.599Z,1432867992.599 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1> 2015-05-29T02:53:12.599Z,1432867992.599 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged 2015-05-29T02:53:12.655Z,1432867992.655 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-05-29T02:53:12.998Z,1432867992.998 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3 2015-05-29T02:53:13.086Z,1432867993.086 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-05-29T02:53:13.399Z,1432867993.399 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment 2015-05-29T02:53:13.400Z,1432867993.400 [AcousticModem_Benthos_ATM900](INFO): set local address to 3 2015-05-29T02:53:13.485Z,1432867993.485 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-05-29T02:53:13.796Z,1432867993.796 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2> 2015-05-29T02:53:13.845Z,1432867993.845 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2015-05-29T02:53:22.736Z,1432868002.736 [BPC1](ERROR): Failed to parse bank A battery data 2015-05-29T02:53:22.740Z,1432868002.740 [BPC1] Data Fault, FailCount= 1 2015-05-29T02:53:22.740Z,1432868002.740 [BPC1](ERROR): Data Fault 2015-05-29T02:53:22.896Z,1432868002.896 [CBIT](ERROR): Data Fault in component: BPC1 2015-05-29T02:53:24.098Z,1432868004.098 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T02:53:24.098Z,1432868004.098 [BPC1] No Fault, FailCount= 1 2015-05-29T02:53:24.593Z,1432868004.593 [SBIT](ERROR): Could not read massPosReader_. 2015-05-29T02:53:37.729Z,1432868017.729 [CBIT](IMPORTANT): No ground fault detected 2015-05-29T02:54:04.995Z,1432868044.995 [SBIT](CRITICAL): SBIT FAILED 2015-05-29T02:54:04.997Z,1432868044.997 [CommandLine](FAULT): Scheduling is paused 2015-05-29T02:54:05.320Z,1432868045.320 [MissionManager](IMPORTANT): Started mission Startup 2015-05-29T02:54:05.321Z,1432868045.321 [Startup] Running Loop=1 2015-05-29T02:54:05.321Z,1432868045.321 [Startup](INFO): Aggregate::initialize Startup 2015-05-29T02:54:05.321Z,1432868045.321 [Startup:A.GoToSurface] Running Loop=1 2015-05-29T02:54:05.321Z,1432868045.321 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2015-05-29T02:54:05.322Z,1432868045.322 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2015-05-29T02:54:05.322Z,1432868045.322 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2015-05-29T02:54:05.323Z,1432868045.323 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s. 2015-05-29T02:54:05.328Z,1432868045.328 [Startup:StartupSatComms] Running Loop=1 2015-05-29T02:54:05.328Z,1432868045.328 [Startup:StartupSatComms](INFO): Aggregate::initialize Startup:StartupSatComms 2015-05-29T02:54:05.328Z,1432868045.328 [Startup:StartupSatComms:A] Running Loop=1 2015-05-29T02:54:05.765Z,1432868045.765 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2015-05-29T02:54:38.625Z,1432868078.625 [BPC1](ERROR): Failed to receive battery data 2015-05-29T02:54:38.625Z,1432868078.625 [BPC1] Communications Fault, FailCount= 1 2015-05-29T02:54:38.625Z,1432868078.625 [BPC1](ERROR): Communications Fault 2015-05-29T02:54:38.738Z,1432868078.738 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T02:54:42.539Z,1432868082.539 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T02:54:42.539Z,1432868082.539 [BPC1] No Fault, FailCount= 1 2015-05-29T02:54:42.815Z,1432868082.815 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003607 2015-05-29T02:55:05.672Z,1432868105.672 [Startup:StartupSatComms:A](INFO): Timed out from 2015-05-29T02:54:05.3Z 2015-05-29T02:55:05.672Z,1432868105.672 [Startup:StartupSatComms:A] Stopped 2015-05-29T02:55:05.672Z,1432868105.672 [Startup:StartupSatComms:B] Running Loop=1 2015-05-29T02:55:06.072Z,1432868106.072 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2015-05-29T02:55:10.460Z,1432868110.460 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20150529T023849/Courier0004.lzma 2015-05-29T02:55:11.292Z,1432868111.292 [DataOverHttps](INFO): Moved sent file to Logs/20150529T023849/Courier0004.lzma.bak 2015-05-29T02:55:11.292Z,1432868111.292 [DataOverHttps](INFO): SBD MOMSN=3530095 2015-05-29T02:55:20.475Z,1432868120.475 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20150529T023849/Courier0008.lzma 2015-05-29T02:55:21.280Z,1432868121.280 [DataOverHttps](INFO): Moved sent file to Logs/20150529T023849/Courier0008.lzma.bak 2015-05-29T02:55:21.280Z,1432868121.280 [DataOverHttps](INFO): SBD MOMSN=3530097 2015-05-29T02:55:30.493Z,1432868130.493 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20150529T025232/Courier0000.lzma 2015-05-29T02:55:31.291Z,1432868131.291 [DataOverHttps](INFO): Moved sent file to Logs/20150529T025232/Courier0000.lzma.bak 2015-05-29T02:55:31.291Z,1432868131.291 [DataOverHttps](INFO): SBD MOMSN=3530099 2015-05-29T02:55:40.704Z,1432868140.704 [DataOverHttps](INFO): Sending 710 bytes from file Logs/20150529T023248/Express0001.lzma 2015-05-29T02:55:41.511Z,1432868141.511 [DataOverHttps](INFO): Moved sent file to Logs/20150529T023248/Express0001.lzma.bak 2015-05-29T02:55:41.511Z,1432868141.511 [DataOverHttps](INFO): SBD MOMSN=3530103 2015-05-29T02:55:50.861Z,1432868150.861 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20150529T023248/Express0005.lzma 2015-05-29T02:55:51.307Z,1432868151.307 [BPC1](ERROR): Failed to receive battery data 2015-05-29T02:55:51.307Z,1432868151.307 [BPC1] Communications Fault, FailCount= 1 2015-05-29T02:55:51.307Z,1432868151.307 [BPC1](ERROR): Communications Fault 2015-05-29T02:55:51.395Z,1432868151.395 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T02:55:51.663Z,1432868151.663 [DataOverHttps](INFO): Moved sent file to Logs/20150529T023248/Express0005.lzma.bak 2015-05-29T02:55:51.663Z,1432868151.663 [DataOverHttps](INFO): SBD MOMSN=3530117 2015-05-29T02:55:52.729Z,1432868152.729 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T02:55:52.729Z,1432868152.729 [BPC1] No Fault, FailCount= 1 2015-05-29T02:56:00.926Z,1432868160.926 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-05-29T02:56:00.927Z,1432868160.927 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2015-05-29T02:56:00.927Z,1432868160.927 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-05-29T02:56:01.037Z,1432868161.037 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-05-29T02:56:01.055Z,1432868161.055 [DataOverHttps](INFO): Sending 713 bytes from file Logs/20150529T023849/Express0001.lzma 2015-05-29T02:56:01.190Z,1432868161.190 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-05-29T02:56:01.190Z,1432868161.190 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2015-05-29T02:56:01.509Z,1432868161.509 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-05-29T02:56:01.510Z,1432868161.510 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-05-29T02:56:01.510Z,1432868161.510 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-05-29T02:56:01.851Z,1432868161.851 [DataOverHttps](INFO): Moved sent file to Logs/20150529T023849/Express0001.lzma.bak 2015-05-29T02:56:01.851Z,1432868161.851 [DataOverHttps](INFO): SBD MOMSN=3530119 2015-05-29T02:56:06.106Z,1432868166.106 [Startup:StartupSatComms:B](INFO): Timed out from 2015-05-29T02:55:05.7Z 2015-05-29T02:56:06.107Z,1432868166.107 [Startup:StartupSatComms:B] Stopped 2015-05-29T02:56:06.107Z,1432868166.107 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2015-05-29T02:56:06.107Z,1432868166.107 [Startup:StartupSatComms] Stopped 2015-05-29T02:56:06.107Z,1432868166.107 [Startup:StartupSatComms](INFO): Aggregate::uninitialize Startup:StartupSatComms 2015-05-29T02:56:06.108Z,1432868166.108 [Startup](INFO): Completed Startup 2015-05-29T02:56:06.108Z,1432868166.108 [Startup] Stopped 2015-05-29T02:56:06.108Z,1432868166.108 [Startup](INFO): Aggregate::uninitialize Startup 2015-05-29T02:56:06.108Z,1432868166.108 [Startup:A.GoToSurface] Stopped 2015-05-29T02:56:06.108Z,1432868166.108 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2015-05-29T02:56:06.253Z,1432868166.253 [MissionManager](IMPORTANT): Started mission Default 2015-05-29T02:56:06.253Z,1432868166.253 [Default] Running Loop=1 2015-05-29T02:56:06.254Z,1432868166.254 [Default](INFO): Aggregate::initialize Default 2015-05-29T02:56:06.254Z,1432868166.254 [Default:A.GoToSurface] Running Loop=1 2015-05-29T02:56:06.254Z,1432868166.254 [Default:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2015-05-29T02:56:06.254Z,1432868166.254 [Default:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2015-05-29T02:56:06.254Z,1432868166.254 [Default:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2015-05-29T02:56:06.259Z,1432868166.259 [Default:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 0.500000 m/s. 2015-05-29T02:56:06.259Z,1432868166.259 [Default:CheckIn] Running Loop=1 2015-05-29T02:56:06.260Z,1432868166.260 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn 2015-05-29T02:56:06.260Z,1432868166.260 [Default:CheckIn:A.SetSpeed] Running Loop=1 2015-05-29T02:56:06.260Z,1432868166.260 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize. 2015-05-29T02:56:06.260Z,1432868166.260 [Default:CheckIn:Read_GPS] Running Loop=1 2015-05-29T02:56:06.261Z,1432868166.261 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2015-05-29T02:56:06.263Z,1432868166.263 [Default:CheckIn:A.SetSpeed] Running Loop=1 2015-05-29T02:56:06.287Z,1432868166.287 [Default:WaitAtTheSurface] Running Loop=1 2015-05-29T02:56:06.288Z,1432868166.288 [Default:WaitAtTheSurface](INFO): Aggregate::initialize Default:WaitAtTheSurface 2015-05-29T02:56:06.288Z,1432868166.288 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1 2015-05-29T02:56:06.288Z,1432868166.288 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Initialize. 2015-05-29T02:56:06.669Z,1432868166.669 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Running Loop=1 2015-05-29T02:56:11.270Z,1432868171.270 [DataOverHttps](INFO): Sending 461 bytes from file Logs/20150529T023849/Express0005.lzma 2015-05-29T02:56:12.075Z,1432868172.075 [DataOverHttps](INFO): Moved sent file to Logs/20150529T023849/Express0005.lzma.bak 2015-05-29T02:56:12.075Z,1432868172.075 [DataOverHttps](INFO): SBD MOMSN=3530133 2015-05-29T02:56:24.890Z,1432868184.890 [BPC1](ERROR): Failed to parse bank A battery data 2015-05-29T02:56:24.890Z,1432868184.890 [BPC1] Data Fault, FailCount= 1 2015-05-29T02:56:24.890Z,1432868184.890 [BPC1](ERROR): Data Fault 2015-05-29T02:56:25.003Z,1432868185.003 [CBIT](ERROR): Data Fault in component: BPC1 2015-05-29T02:56:26.201Z,1432868186.201 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T02:56:26.201Z,1432868186.201 [BPC1] No Fault, FailCount= 1 2015-05-29T02:57:14.767Z,1432868234.767 [BPC1](ERROR): Failed to receive battery data 2015-05-29T02:57:14.767Z,1432868234.767 [BPC1] Communications Fault, FailCount= 1 2015-05-29T02:57:14.767Z,1432868234.767 [BPC1](ERROR): Communications Fault 2015-05-29T02:57:14.917Z,1432868234.917 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T02:57:15.940Z,1432868235.940 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T02:57:15.940Z,1432868235.940 [BPC1] No Fault, FailCount= 1 2015-05-29T02:58:15.199Z,1432868295.199 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2015-05-29T02:59:01.665Z,1432868341.665 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-05-29T02:59:01.665Z,1432868341.665 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2015-05-29T02:59:01.665Z,1432868341.665 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-05-29T02:59:01.775Z,1432868341.775 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-05-29T02:59:02.187Z,1432868342.187 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-05-29T02:59:02.188Z,1432868342.188 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2015-05-29T02:59:02.454Z,1432868342.454 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-05-29T02:59:02.455Z,1432868342.455 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-05-29T02:59:02.455Z,1432868342.455 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-05-29T03:00:47.417Z,1432868447.417 [BPC1](DEBUG): Received data from all battery sticks 2015-05-29T03:01:06.655Z,1432868466.655 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-05-29T02:56:06.3Z 2015-05-29T03:01:06.655Z,1432868466.655 [Default:CheckIn:Read_GPS] Stopped 2015-05-29T03:01:06.655Z,1432868466.655 [Default:CheckIn:Read_Iridium] Running Loop=1 2015-05-29T03:01:07.092Z,1432868467.092 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2015-05-29T03:01:15.458Z,1432868475.458 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20150529T025232/Courier0004.lzma 2015-05-29T03:01:16.257Z,1432868476.257 [DataOverHttps](INFO): Moved sent file to Logs/20150529T025232/Courier0004.lzma.bak 2015-05-29T03:01:16.257Z,1432868476.257 [DataOverHttps](INFO): SBD MOMSN=3530142 2015-05-29T03:01:17.503Z,1432868477.503 [BPC1](ERROR): Failed to receive battery data 2015-05-29T03:01:17.503Z,1432868477.503 [BPC1] Communications Fault, FailCount= 1 2015-05-29T03:01:17.503Z,1432868477.503 [BPC1](ERROR): Communications Fault 2015-05-29T03:01:17.630Z,1432868477.630 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T03:01:24.914Z,1432868484.914 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:01:24.914Z,1432868484.914 [BPC1] No Fault, FailCount= 1 2015-05-29T03:01:33.491Z,1432868493.491 [DataOverHttps](INFO): Sending 214 bytes from file Logs/20150529T023849/Express0009.lzma 2015-05-29T03:01:34.296Z,1432868494.296 [DataOverHttps](INFO): Moved sent file to Logs/20150529T023849/Express0009.lzma.bak 2015-05-29T03:01:34.296Z,1432868494.296 [DataOverHttps](INFO): SBD MOMSN=3530144 2015-05-29T03:01:42.850Z,1432868502.850 [BPC1](ERROR): Failed to receive battery data 2015-05-29T03:01:42.851Z,1432868502.851 [BPC1] Communications Fault, FailCount= 2 2015-05-29T03:01:42.851Z,1432868502.851 [BPC1](ERROR): Communications Fault 2015-05-29T03:01:43.019Z,1432868503.019 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T03:01:44.023Z,1432868504.023 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:01:44.023Z,1432868504.023 [BPC1] No Fault, FailCount= 2 2015-05-29T03:01:51.789Z,1432868511.789 [DataOverHttps](INFO): Sending 638 bytes from file Logs/20150529T025232/Express0001.lzma 2015-05-29T03:01:52.564Z,1432868512.564 [DataOverHttps](INFO): Moved sent file to Logs/20150529T025232/Express0001.lzma.bak 2015-05-29T03:01:52.564Z,1432868512.564 [DataOverHttps](INFO): SBD MOMSN=3530150 2015-05-29T03:02:02.818Z,1432868522.818 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-05-29T03:02:02.819Z,1432868522.819 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2015-05-29T03:02:02.819Z,1432868522.819 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-05-29T03:02:02.909Z,1432868522.909 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-05-29T03:02:09.767Z,1432868529.767 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-05-29T03:02:09.767Z,1432868529.767 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2015-05-29T03:02:09.790Z,1432868529.790 [DataOverHttps](INFO): Sending 385 bytes from file Logs/20150529T025232/Express0005.lzma 2015-05-29T03:02:09.885Z,1432868529.885 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-05-29T03:02:09.885Z,1432868529.885 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-05-29T03:02:09.886Z,1432868529.886 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-05-29T03:02:10.592Z,1432868530.592 [DataOverHttps](INFO): Moved sent file to Logs/20150529T025232/Express0005.lzma.bak 2015-05-29T03:02:10.592Z,1432868530.592 [DataOverHttps](INFO): SBD MOMSN=3530162 2015-05-29T03:02:12.006Z,1432868532.006 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2015-05-29T03:02:12.030Z,1432868532.030 [Default:CheckIn:Read_Iridium] Stopped 2015-05-29T03:02:12.030Z,1432868532.030 [Default:CheckIn](INFO): Completed Default:CheckIn 2015-05-29T03:02:12.031Z,1432868532.031 [Default:CheckIn] Stopped 2015-05-29T03:02:12.031Z,1432868532.031 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn 2015-05-29T03:02:12.031Z,1432868532.031 [Default:CheckIn:A.SetSpeed] Stopped 2015-05-29T03:02:12.031Z,1432868532.031 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize. 2015-05-29T03:02:54.029Z,1432868574.029 [CBIT](DEBUG): EFC running - data check-sum false 2015-05-29T03:03:18.845Z,1432868598.845 [NAL9602](FAULT): GPS failed to acquire within timeout. 2015-05-29T03:03:18.845Z,1432868598.845 [NAL9602] Data Fault, FailCount= 1 2015-05-29T03:03:18.845Z,1432868598.845 [NAL9602](ERROR): Data Fault 2015-05-29T03:03:18.928Z,1432868598.928 [BPC1](ERROR): Failed to receive battery data 2015-05-29T03:03:18.928Z,1432868598.928 [BPC1] Communications Fault, FailCount= 1 2015-05-29T03:03:18.928Z,1432868598.928 [BPC1](ERROR): Communications Fault 2015-05-29T03:03:19.095Z,1432868599.095 [CBIT](ERROR): Data Fault in component: NAL9602 2015-05-29T03:03:19.096Z,1432868599.096 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T03:03:30.312Z,1432868610.312 [NAL9602](INFO): Powering down 2015-05-29T03:03:35.669Z,1432868615.669 [CBIT](INFO): Clearing failed state for component NAL9602 2015-05-29T03:03:35.669Z,1432868615.669 [NAL9602] No Fault, FailCount= 1 2015-05-29T03:03:35.669Z,1432868615.669 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:03:35.670Z,1432868615.670 [BPC1] No Fault, FailCount= 1 2015-05-29T03:03:40.507Z,1432868620.507 [NAL9602](INFO): Powering up NAL9602 2015-05-29T03:04:05.506Z,1432868645.506 [NAL9602](INFO): NAL9602 initialized 2015-05-29T03:05:12.293Z,1432868712.293 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-05-29T03:05:12.293Z,1432868712.293 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4 2015-05-29T03:05:12.294Z,1432868712.294 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-05-29T03:05:12.392Z,1432868712.392 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-05-29T03:05:17.327Z,1432868717.327 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-05-29T03:05:17.327Z,1432868717.327 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4 2015-05-29T03:05:22.292Z,1432868722.292 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-05-29T03:05:22.293Z,1432868722.293 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-05-29T03:05:22.293Z,1432868722.293 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-05-29T03:05:33.716Z,1432868733.716 [BPC1](ERROR): Failed to receive battery data 2015-05-29T03:05:33.716Z,1432868733.716 [BPC1] Communications Fault, FailCount= 1 2015-05-29T03:05:33.717Z,1432868733.717 [BPC1](ERROR): Communications Fault 2015-05-29T03:05:33.857Z,1432868733.857 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T03:05:44.081Z,1432868744.081 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:05:44.081Z,1432868744.081 [BPC1] No Fault, FailCount= 1 2015-05-29T03:07:15.726Z,1432868835.726 [Default:CheckIn] Running Loop=1 2015-05-29T03:07:15.727Z,1432868835.727 [Default:CheckIn](INFO): Aggregate::initialize Default:CheckIn 2015-05-29T03:07:15.727Z,1432868835.727 [Default:CheckIn:A.SetSpeed] Running Loop=1 2015-05-29T03:07:15.727Z,1432868835.727 [Default:CheckIn:A.SetSpeed](DEBUG): Initialize. 2015-05-29T03:07:15.727Z,1432868835.727 [Default:CheckIn:Read_GPS] Running Loop=1 2015-05-29T03:08:00.698Z,1432868880.698 [BPC1](ERROR): Failed to receive battery data 2015-05-29T03:08:00.702Z,1432868880.702 [BPC1] Communications Fault, FailCount= 1 2015-05-29T03:08:00.702Z,1432868880.702 [BPC1](ERROR): Communications Fault 2015-05-29T03:08:00.854Z,1432868880.854 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T03:08:02.023Z,1432868882.023 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:08:02.023Z,1432868882.023 [BPC1] No Fault, FailCount= 1 2015-05-29T03:08:17.530Z,1432868897.530 [BPC1](DEBUG): Received data from all battery sticks 2015-05-29T03:08:26.828Z,1432868906.828 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-05-29T03:08:26.828Z,1432868906.828 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5 2015-05-29T03:08:26.828Z,1432868906.828 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-05-29T03:08:26.958Z,1432868906.958 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-05-29T03:08:27.170Z,1432868907.170 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-05-29T03:08:27.170Z,1432868907.170 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5 2015-05-29T03:08:27.496Z,1432868907.496 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-05-29T03:08:27.496Z,1432868907.496 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-05-29T03:08:27.497Z,1432868907.497 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-05-29T03:08:43.388Z,1432868923.388 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:43.808Z,1432868923.808 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:44.209Z,1432868924.209 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:45.821Z,1432868925.821 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:46.217Z,1432868926.217 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:46.617Z,1432868926.617 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:47.017Z,1432868927.017 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:47.402Z,1432868927.402 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:47.810Z,1432868927.810 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:48.208Z,1432868928.208 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:48.628Z,1432868928.628 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:49.009Z,1432868929.009 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:49.394Z,1432868929.394 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:49.795Z,1432868929.795 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:50.211Z,1432868930.211 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:50.607Z,1432868930.607 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:51.012Z,1432868931.012 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:51.413Z,1432868931.413 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:53.008Z,1432868933.008 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:53.411Z,1432868933.411 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:53.812Z,1432868933.812 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:54.204Z,1432868934.204 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:54.605Z,1432868934.605 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:55.010Z,1432868935.010 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:55.402Z,1432868935.402 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:55.799Z,1432868935.799 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:08:56.208Z,1432868936.208 [PNI_TCM](DEBUG): LCB error: Software Overcurrent. 2015-05-29T03:10:15.328Z,1432869015.328 [BPC1](ERROR): Failed to receive battery data 2015-05-29T03:10:15.328Z,1432869015.328 [BPC1] Communications Fault, FailCount= 1 2015-05-29T03:10:15.328Z,1432869015.328 [BPC1](ERROR): Communications Fault 2015-05-29T03:10:15.456Z,1432869015.456 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T03:10:16.633Z,1432869016.633 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:10:16.633Z,1432869016.633 [BPC1] No Fault, FailCount= 1 2015-05-29T03:10:28.478Z,1432869028.478 [BPC1](ERROR): Failed to parse bank A battery data 2015-05-29T03:10:28.478Z,1432869028.478 [BPC1] Data Fault, FailCount= 2 2015-05-29T03:10:28.478Z,1432869028.478 [BPC1](ERROR): Data Fault 2015-05-29T03:10:28.611Z,1432869028.611 [CBIT](ERROR): Data Fault in component: BPC1 2015-05-29T03:10:29.782Z,1432869029.782 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:10:29.782Z,1432869029.782 [BPC1] No Fault, FailCount= 2 2015-05-29T03:10:42.505Z,1432869042.505 [BPC1](ERROR): Failed to parse bank B battery data 2015-05-29T03:10:42.505Z,1432869042.505 [BPC1] Data Fault, FailCount= 3 2015-05-29T03:10:42.505Z,1432869042.505 [BPC1](ERROR): Data Fault 2015-05-29T03:10:42.658Z,1432869042.658 [CBIT](ERROR): Data Fault in component: BPC1 2015-05-29T03:10:43.807Z,1432869043.807 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:10:43.807Z,1432869043.807 [BPC1] No Fault, FailCount= 3 2015-05-29T03:11:27.879Z,1432869087.879 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-05-29T03:11:27.879Z,1432869087.879 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 6 2015-05-29T03:11:27.879Z,1432869087.879 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-05-29T03:11:27.968Z,1432869087.968 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-05-29T03:11:28.196Z,1432869088.196 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-05-29T03:11:28.196Z,1432869088.196 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 6 2015-05-29T03:11:28.525Z,1432869088.525 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-05-29T03:11:28.526Z,1432869088.526 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-05-29T03:11:28.526Z,1432869088.526 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-05-29T03:11:44.827Z,1432869104.827 [BPC1](ERROR): Failed to receive battery data 2015-05-29T03:11:44.827Z,1432869104.827 [BPC1] Communications Fault, FailCount= 1 2015-05-29T03:11:44.827Z,1432869104.827 [BPC1](ERROR): Communications Fault 2015-05-29T03:11:44.954Z,1432869104.954 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T03:11:46.156Z,1432869106.156 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:11:46.156Z,1432869106.156 [BPC1] No Fault, FailCount= 1 2015-05-29T03:12:16.096Z,1432869136.096 [Default:CheckIn:Read_GPS](INFO): Timed out from 2015-05-29T03:07:15.7Z 2015-05-29T03:12:16.096Z,1432869136.096 [Default:CheckIn:Read_GPS] Stopped 2015-05-29T03:12:16.096Z,1432869136.096 [Default:CheckIn:Read_Iridium] Running Loop=1 2015-05-29T03:12:25.058Z,1432869145.058 [DataOverHttps](INFO): Sending 45 bytes from file Logs/20150529T025232/Courier0008.lzma 2015-05-29T03:12:25.866Z,1432869145.866 [DataOverHttps](INFO): Moved sent file to Logs/20150529T025232/Courier0008.lzma.bak 2015-05-29T03:12:25.866Z,1432869145.866 [DataOverHttps](INFO): SBD MOMSN=3530182 2015-05-29T03:12:43.169Z,1432869163.169 [DataOverHttps](INFO): Sending 188 bytes from file Logs/20150529T025232/Express0009.lzma 2015-05-29T03:12:43.978Z,1432869163.978 [DataOverHttps](INFO): Moved sent file to Logs/20150529T025232/Express0009.lzma.bak 2015-05-29T03:12:43.978Z,1432869163.978 [DataOverHttps](INFO): SBD MOMSN=3530184 2015-05-29T03:12:45.363Z,1432869165.363 [HFRadarCompactModelForecaster](DEBUG): Did not find new historical expansion coefficients. 2015-05-29T03:12:45.377Z,1432869165.377 [Default:CheckIn:Read_Iridium] Stopped 2015-05-29T03:12:45.378Z,1432869165.378 [Default:CheckIn](INFO): Completed Default:CheckIn 2015-05-29T03:12:45.378Z,1432869165.378 [Default:CheckIn] Stopped 2015-05-29T03:12:45.378Z,1432869165.378 [Default:CheckIn](INFO): Aggregate::uninitialize Default:CheckIn 2015-05-29T03:12:45.378Z,1432869165.378 [Default:CheckIn:A.SetSpeed] Stopped 2015-05-29T03:12:45.378Z,1432869165.378 [Default:CheckIn:A.SetSpeed](DEBUG): Uninitialize. 2015-05-29T03:12:57.031Z,1432869177.031 [BPC1](ERROR): Failed to receive battery data 2015-05-29T03:12:57.032Z,1432869177.032 [BPC1] Communications Fault, FailCount= 1 2015-05-29T03:12:57.032Z,1432869177.032 [BPC1](ERROR): Communications Fault 2015-05-29T03:12:57.183Z,1432869177.183 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T03:12:57.183Z,1432869177.183 [CBIT](DEBUG): EFC running - data check-sum false 2015-05-29T03:13:07.370Z,1432869187.370 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:13:07.370Z,1432869187.370 [BPC1] No Fault, FailCount= 1 2015-05-29T03:14:28.938Z,1432869268.938 [DeadReckonUsingSpeedCalculator](FAULT): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2015-05-29T03:14:28.938Z,1432869268.938 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 7 2015-05-29T03:14:28.938Z,1432869268.938 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2015-05-29T03:14:29.045Z,1432869269.045 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2015-05-29T03:14:33.851Z,1432869273.851 [NAL9602](FAULT): GPS failed to acquire within timeout. 2015-05-29T03:14:33.851Z,1432869273.851 [NAL9602] Data Fault, FailCount= 2 2015-05-29T03:14:33.851Z,1432869273.851 [NAL9602](ERROR): Data Fault 2015-05-29T03:14:34.049Z,1432869274.049 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2015-05-29T03:14:34.049Z,1432869274.049 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 7 2015-05-29T03:14:34.050Z,1432869274.050 [CBIT](ERROR): Data Fault in component: NAL9602 2015-05-29T03:14:38.851Z,1432869278.851 [NAL9602](INFO): Powering down 2015-05-29T03:14:38.928Z,1432869278.928 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2015-05-29T03:14:38.928Z,1432869278.928 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after this many seconds: 120.000000 2015-05-29T03:14:38.928Z,1432869278.928 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after this many seconds: 20.000000 2015-05-29T03:14:49.024Z,1432869289.024 [CBIT](INFO): Clearing failed state for component NAL9602 2015-05-29T03:14:49.025Z,1432869289.025 [NAL9602] No Fault, FailCount= 2 2015-05-29T03:14:53.858Z,1432869293.858 [NAL9602](INFO): Powering up NAL9602 2015-05-29T03:15:05.509Z,1432869305.509 [BPC1](ERROR): Failed to receive battery data 2015-05-29T03:15:05.509Z,1432869305.509 [BPC1] Communications Fault, FailCount= 1 2015-05-29T03:15:05.509Z,1432869305.509 [BPC1](ERROR): Communications Fault 2015-05-29T03:15:05.666Z,1432869305.666 [CBIT](ERROR): Communications Fault in component: BPC1 2015-05-29T03:15:10.689Z,1432869310.689 [NAL9602](INFO): NAL9602 initialized 2015-05-29T03:15:14.694Z,1432869314.694 [CommandLine](IMPORTANT): got command quit 2015-05-29T03:15:15.706Z,1432869315.706 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2015-05-29T03:15:15.706Z,1432869315.706 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:15.878Z,1432869315.878 [CBIT](INFO): Clearing failed state for component BPC1 2015-05-29T03:15:15.878Z,1432869315.878 [BPC1] No Fault, FailCount= 1 2015-05-29T03:15:15.899Z,1432869315.899 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2015-05-29T03:15:15.899Z,1432869315.899 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:15.900Z,1432869315.900 [CommandLine](INFO): Join timeout helper Thread ID is 900 2015-05-29T03:15:15.902Z,1432869315.902 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2015-05-29T03:15:15.902Z,1432869315.902 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:15.902Z,1432869315.902 [NavChartDb](INFO): Join timeout helper Thread ID is 901 2015-05-29T03:15:15.992Z,1432869315.992 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2015-05-29T03:15:15.992Z,1432869315.992 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.007Z,1432869316.007 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2015-05-29T03:15:16.008Z,1432869316.008 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.008Z,1432869316.008 [Radio_Surface](INFO): Join timeout helper Thread ID is 902 2015-05-29T03:15:16.360Z,1432869316.360 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2015-05-29T03:15:16.361Z,1432869316.361 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.376Z,1432869316.376 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2015-05-29T03:15:16.376Z,1432869316.376 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.377Z,1432869316.377 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 903 2015-05-29T03:15:16.429Z,1432869316.429 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2015-05-29T03:15:16.429Z,1432869316.429 [WetLabsBB2FL](INFO): Powering down 2015-05-29T03:15:16.430Z,1432869316.430 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.448Z,1432869316.448 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2015-05-29T03:15:16.448Z,1432869316.448 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.449Z,1432869316.449 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 904 2015-05-29T03:15:16.528Z,1432869316.528 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2015-05-29T03:15:16.529Z,1432869316.529 [CTD_NeilBrown](INFO): Powering down 2015-05-29T03:15:16.529Z,1432869316.529 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.541Z,1432869316.541 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2015-05-29T03:15:16.541Z,1432869316.541 [logger ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.542Z,1432869316.542 [logger](INFO): Join timeout helper Thread ID is 905 2015-05-29T03:15:16.568Z,1432869316.568 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2015-05-29T03:15:16.569Z,1432869316.569 [logger ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.585Z,1432869316.585 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2015-05-29T03:15:16.585Z,1432869316.585 [CommandLine ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.585Z,1432869316.585 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2015-05-29T03:15:16.585Z,1432869316.585 [controlThread ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:16.586Z,1432869316.586 [controlThread](INFO): Join timeout helper Thread ID is 906 2015-05-29T03:15:20.675Z,1432869320.675 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2015-05-29T03:15:20.675Z,1432869320.675 [controlThread](DEBUG): Uninitializing ControlThread 2015-05-29T03:15:20.675Z,1432869320.675 [Aanderaa_O2](INFO): Powering down 2015-05-29T03:15:20.677Z,1432869320.677 [AcousticModem_Benthos_ATM900](INFO): Powering down 2015-05-29T03:15:20.796Z,1432869320.796 [NAL9602](INFO): Powering down 2015-05-29T03:15:20.797Z,1432869320.797 [PNI_TCM](INFO): Powering down 2015-05-29T03:15:20.884Z,1432869320.884 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2015-05-29T03:15:20.886Z,1432869320.886 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2015-05-29T03:15:20.886Z,1432869320.886 [Default] Stopped 2015-05-29T03:15:20.887Z,1432869320.887 [Default](INFO): Aggregate::uninitialize Default 2015-05-29T03:15:20.887Z,1432869320.887 [Default:A.GoToSurface] Stopped 2015-05-29T03:15:20.887Z,1432869320.887 [Default:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2015-05-29T03:15:20.887Z,1432869320.887 [Default:WaitAtTheSurface] Stopped 2015-05-29T03:15:20.887Z,1432869320.887 [Default:WaitAtTheSurface](INFO): Aggregate::uninitialize Default:WaitAtTheSurface 2015-05-29T03:15:20.887Z,1432869320.887 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed] Stopped 2015-05-29T03:15:20.887Z,1432869320.887 [Default:WaitAtTheSurface:RunApplicationAtLowSpeed.SetSpeed](DEBUG): Uninitialize. 2015-05-29T03:15:20.890Z,1432869320.890 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2015-05-29T03:15:20.891Z,1432869320.891 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2015-05-29T03:15:20.891Z,1432869320.891 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2015-05-29T03:15:20.891Z,1432869320.891 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2015-05-29T03:15:20.892Z,1432869320.892 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2015-05-29T03:15:20.892Z,1432869320.892 [BuoyancyServo](INFO): Powering down 2015-05-29T03:15:20.907Z,1432869320.907 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2015-05-29T03:15:20.907Z,1432869320.907 [ElevatorServo](INFO): Powering down 2015-05-29T03:15:20.908Z,1432869320.908 [MassServo](DEBUG): Uninitialize Mass Servo. 2015-05-29T03:15:20.908Z,1432869320.908 [MassServo](INFO): Powering down 2015-05-29T03:15:20.909Z,1432869320.909 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2015-05-29T03:15:20.909Z,1432869320.909 [RudderServo](INFO): Powering down 2015-05-29T03:15:20.910Z,1432869320.910 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2015-05-29T03:15:20.910Z,1432869320.910 [ThrusterServo](INFO): Powering down 2015-05-29T03:15:20.911Z,1432869320.911 [SBIT](DEBUG): Uninitialize SBIT Component. 2015-05-29T03:15:20.911Z,1432869320.911 [IBIT](DEBUG): Uninitialize IBIT Component. 2015-05-29T03:15:20.912Z,1432869320.912 [CBIT](DEBUG): Uninitialize CBIT Component. 2015-05-29T03:15:20.948Z,1432869320.948 [controlThread ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:21.036Z,1432869321.036 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:21.051Z,1432869321.051 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:21.198Z,1432869321.198 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:21.394Z,1432869321.394 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2015-05-29T03:15:21.515Z,1432869321.515 [logger ThreadHandler](INFO): Thread cancelled.