2017-05-11T17:04:49.956Z,1494522289.956 [Supervisor](DEBUG): Initializing supervisor. 2017-05-11T17:04:49.958Z,1494522289.958 [SyncHandler](DEBUG): Created PCaller Thread at 4051A4E0 2017-05-11T17:04:49.959Z,1494522289.959 [SyncHandler](INFO): Protected caller Thread ID is 771 2017-05-11T17:04:49.959Z,1494522289.959 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2017-05-11T17:04:49.960Z,1494522289.960 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 4054A4E0 2017-05-11T17:04:49.961Z,1494522289.961 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 772 2017-05-11T17:04:49.964Z,1494522289.964 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2017-05-11T17:04:49.976Z,1494522289.976 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2017-05-11T17:04:49.977Z,1494522289.977 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 4057A4E0 2017-05-11T17:04:49.978Z,1494522289.977 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 773 2017-05-11T17:04:49.978Z,1494522289.978 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2017-05-11T17:04:49.979Z,1494522289.979 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405AA4E0 2017-05-11T17:04:49.980Z,1494522289.980 [logger ThreadHandler](INFO): Protected caller Thread ID is 774 2017-05-11T17:04:49.982Z,1494522289.982 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2017-05-11T17:04:49.982Z,1494522289.982 [Supervisor](INFO): Looking for Config files in directory: Config/ 2017-05-11T17:04:49.986Z,1494522289.986 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2017-05-11T17:04:50.073Z,1494522290.073 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2017-05-11T17:04:50.403Z,1494522290.404 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2017-05-11T17:04:50.404Z,1494522290.404 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2017-05-11T17:04:50.539Z,1494522290.539 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2017-05-11T17:04:50.540Z,1494522290.540 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2017-05-11T17:04:50.740Z,1494522290.740 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2017-05-11T17:04:50.741Z,1494522290.741 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2017-05-11T17:04:50.842Z,1494522290.842 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2017-05-11T17:04:50.843Z,1494522290.843 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2017-05-11T17:04:51.039Z,1494522291.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2017-05-11T17:04:51.041Z,1494522291.041 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2017-05-11T17:04:51.510Z,1494522291.510 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2017-05-11T17:04:51.511Z,1494522291.511 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2017-05-11T17:04:51.799Z,1494522291.799 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2017-05-11T17:04:51.800Z,1494522291.800 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2017-05-11T17:04:51.887Z,1494522291.887 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2017-05-11T17:04:51.888Z,1494522291.888 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2017-05-11T17:04:52.030Z,1494522292.030 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2017-05-11T17:04:52.031Z,1494522292.031 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2017-05-11T17:04:52.230Z,1494522292.230 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2017-05-11T17:04:52.231Z,1494522292.231 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2017-05-11T17:04:52.689Z,1494522292.689 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2017-05-11T17:04:52.690Z,1494522292.690 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2017-05-11T17:04:57.523Z,1494522297.523 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2017-05-11T17:04:57.524Z,1494522297.523 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2017-05-11T17:04:58.078Z,1494522298.078 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2017-05-11T17:04:58.078Z,1494522298.078 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2017-05-11T17:04:58.193Z,1494522298.193 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2017-05-11T17:04:58.195Z,1494522298.195 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2017-05-11T17:04:58.199Z,1494522298.199 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2017-05-11T17:04:58.305Z,1494522298.305 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2017-05-11T17:04:58.399Z,1494522298.399 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2017-05-11T17:04:58.488Z,1494522298.488 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2017-05-11T17:04:58.593Z,1494522298.593 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2017-05-11T17:04:58.684Z,1494522298.684 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2017-05-11T17:04:58.814Z,1494522298.814 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2017-05-11T17:04:58.911Z,1494522298.911 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2017-05-11T17:04:59.090Z,1494522299.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2017-05-11T17:04:59.328Z,1494522299.328 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2017-05-11T17:04:59.328Z,1494522299.328 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2017-05-11T17:04:59.484Z,1494522299.484 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2017-05-11T17:04:59.586Z,1494522299.586 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2017-05-11T17:04:59.666Z,1494522299.667 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2017-05-11T17:04:59.670Z,1494522299.670 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2017-05-11T17:04:59.743Z,1494522299.743 [VerticalControl](DEBUG): Construct VerticalControl. 2017-05-11T17:04:59.862Z,1494522299.862 [VerticalControl] Loaded 2017-05-11T17:04:59.863Z,1494522299.863 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2017-05-11T17:04:59.863Z,1494522299.863 [HorizontalControl](DEBUG): Construct HorizontalControl. 2017-05-11T17:04:59.934Z,1494522299.934 [HorizontalControl] Loaded 2017-05-11T17:04:59.934Z,1494522299.934 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2017-05-11T17:04:59.935Z,1494522299.935 [SpeedControl](DEBUG): Construct SpeedControl. 2017-05-11T17:04:59.941Z,1494522299.941 [SpeedControl] Loaded 2017-05-11T17:04:59.941Z,1494522299.941 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2017-05-11T17:04:59.942Z,1494522299.942 [LoopControl](DEBUG): Construct LoopControl. 2017-05-11T17:04:59.942Z,1494522299.942 [LoopControl] Loaded 2017-05-11T17:04:59.942Z,1494522299.943 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2017-05-11T17:04:59.943Z,1494522299.943 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2017-05-11T17:04:59.944Z,1494522299.944 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2017-05-11T17:05:00.105Z,1494522300.105 [SBIT](DEBUG): Construct Startup Built In Test. 2017-05-11T17:05:00.117Z,1494522300.117 [SBIT] Loaded 2017-05-11T17:05:00.117Z,1494522300.117 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2017-05-11T17:05:00.118Z,1494522300.118 [IBIT](DEBUG): Construct Initiated Built In Test. 2017-05-11T17:05:00.147Z,1494522300.147 [IBIT] Loaded 2017-05-11T17:05:00.147Z,1494522300.147 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2017-05-11T17:05:00.150Z,1494522300.150 [CBIT](DEBUG): Construct Continuous Built In Test. 2017-05-11T17:05:00.300Z,1494522300.300 [CBIT] Loaded 2017-05-11T17:05:00.301Z,1494522300.301 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2017-05-11T17:05:00.301Z,1494522300.301 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2017-05-11T17:05:00.303Z,1494522300.303 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2017-05-11T17:05:00.345Z,1494522300.345 [DepthRateCalculator] Loaded 2017-05-11T17:05:00.345Z,1494522300.345 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2017-05-11T17:05:00.351Z,1494522300.351 [PitchRateCalculator] Loaded 2017-05-11T17:05:00.351Z,1494522300.351 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2017-05-11T17:05:00.363Z,1494522300.363 [SpeedCalculator] Loaded 2017-05-11T17:05:00.363Z,1494522300.363 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2017-05-11T17:05:00.385Z,1494522300.385 [TempGradientCalculator] Loaded 2017-05-11T17:05:00.386Z,1494522300.385 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2017-05-11T17:05:00.401Z,1494522300.401 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2017-05-11T17:05:00.402Z,1494522300.402 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2017-05-11T17:05:00.407Z,1494522300.407 [YawRateCalculator] Loaded 2017-05-11T17:05:00.407Z,1494522300.407 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2017-05-11T17:05:00.408Z,1494522300.408 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2017-05-11T17:05:00.408Z,1494522300.408 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2017-05-11T17:05:00.531Z,1494522300.532 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2017-05-11T17:05:00.532Z,1494522300.532 [StratificationFrontDetector](DEBUG): (re)initializing 2017-05-11T17:05:00.532Z,1494522300.532 [StratificationFrontDetector] Loaded 2017-05-11T17:05:00.532Z,1494522300.532 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2017-05-11T17:05:00.556Z,1494522300.556 [DepAvgTempFrontDetector] Loaded 2017-05-11T17:05:00.556Z,1494522300.556 [ComponentRegistry](DEBUG): SyncComponent "DepAvgTempFrontDetector" handled in the control thread. 2017-05-11T17:05:00.557Z,1494522300.557 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2017-05-11T17:05:00.558Z,1494522300.558 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2017-05-11T17:05:00.846Z,1494522300.846 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2017-05-11T17:05:00.846Z,1494522300.846 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2017-05-11T17:05:00.974Z,1494522300.974 [DeadReckonUsingMultipleVelocitySources] Loaded 2017-05-11T17:05:00.974Z,1494522300.974 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2017-05-11T17:05:01.030Z,1494522301.030 [DeadReckonUsingSpeedCalculator] Loaded 2017-05-11T17:05:01.030Z,1494522301.030 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2017-05-11T17:05:01.047Z,1494522301.047 [NavChart] Loaded 2017-05-11T17:05:01.048Z,1494522301.048 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2017-05-11T17:05:01.052Z,1494522301.052 [UniversalFixResidualReporter] Loaded 2017-05-11T17:05:01.052Z,1494522301.052 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2017-05-11T17:05:01.053Z,1494522301.053 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2017-05-11T17:05:01.054Z,1494522301.053 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2017-05-11T17:05:01.063Z,1494522301.063 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2017-05-11T17:05:01.064Z,1494522301.064 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2017-05-11T17:05:01.259Z,1494522301.259 [Aanderaa_O2] Loaded 2017-05-11T17:05:01.260Z,1494522301.260 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2017-05-11T17:05:01.341Z,1494522301.341 [CTD_NeilBrown] Loaded 2017-05-11T17:05:01.341Z,1494522301.341 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2017-05-11T17:05:01.342Z,1494522301.342 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 407734E0 2017-05-11T17:05:01.343Z,1494522301.343 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 856 2017-05-11T17:05:01.675Z,1494522301.675 [CTD_Seabird] Loaded 2017-05-11T17:05:01.675Z,1494522301.675 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2017-05-11T17:05:01.676Z,1494522301.676 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 407A34E0 2017-05-11T17:05:01.677Z,1494522301.677 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 857 2017-05-11T17:05:01.692Z,1494522301.692 [PAR_Licor] Loaded 2017-05-11T17:05:01.692Z,1494522301.693 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2017-05-11T17:05:01.743Z,1494522301.743 [WetLabsBB2FL] Loaded 2017-05-11T17:05:01.743Z,1494522301.743 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2017-05-11T17:05:01.744Z,1494522301.744 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 407D34E0 2017-05-11T17:05:01.745Z,1494522301.745 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 858 2017-05-11T17:05:01.745Z,1494522301.745 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2017-05-11T17:05:01.746Z,1494522301.746 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2017-05-11T17:05:02.370Z,1494522302.370 [DataOverHttps] Loaded 2017-05-11T17:05:02.370Z,1494522302.371 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2017-05-11T17:05:02.384Z,1494522302.384 [Depth_Keller] Loaded 2017-05-11T17:05:02.385Z,1494522302.385 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2017-05-11T17:05:02.390Z,1494522302.390 [DropWeight] Loaded 2017-05-11T17:05:02.390Z,1494522302.390 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2017-05-11T17:05:02.483Z,1494522302.483 [NAL9602] Loaded 2017-05-11T17:05:02.483Z,1494522302.483 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2017-05-11T17:05:02.493Z,1494522302.493 [Onboard] Loaded 2017-05-11T17:05:02.493Z,1494522302.493 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2017-05-11T17:05:02.500Z,1494522302.500 [Radio_Surface] Loaded 2017-05-11T17:05:02.501Z,1494522302.500 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2017-05-11T17:05:02.502Z,1494522302.502 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A1E4E0 2017-05-11T17:05:02.502Z,1494522302.502 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 859 2017-05-11T17:05:02.697Z,1494522302.697 [PNI_TCM] Loaded 2017-05-11T17:05:02.697Z,1494522302.697 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2017-05-11T17:05:02.762Z,1494522302.762 [Rowe_600LCM] Loaded 2017-05-11T17:05:02.762Z,1494522302.762 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2017-05-11T17:05:02.763Z,1494522302.763 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 40A4E4E0 2017-05-11T17:05:02.764Z,1494522302.764 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 860 2017-05-11T17:05:04.687Z,1494522304.687 [BPC1] Loaded 2017-05-11T17:05:04.687Z,1494522304.687 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2017-05-11T17:05:04.687Z,1494522304.687 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2017-05-11T17:05:04.688Z,1494522304.688 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2017-05-11T17:05:06.676Z,1494522306.676 [BuoyancyServo] Loaded 2017-05-11T17:05:06.676Z,1494522306.676 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2017-05-11T17:05:06.688Z,1494522306.688 [ElevatorServo] Loaded 2017-05-11T17:05:06.689Z,1494522306.689 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2017-05-11T17:05:06.701Z,1494522306.701 [MassServo] Loaded 2017-05-11T17:05:06.701Z,1494522306.701 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2017-05-11T17:05:06.713Z,1494522306.713 [RudderServo] Loaded 2017-05-11T17:05:06.714Z,1494522306.714 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2017-05-11T17:05:06.725Z,1494522306.725 [ThrusterServo] Loaded 2017-05-11T17:05:06.725Z,1494522306.725 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2017-05-11T17:05:06.726Z,1494522306.726 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2017-05-11T17:05:06.726Z,1494522306.726 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2017-05-11T17:05:06.863Z,1494522306.863 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2017-05-11T17:05:06.864Z,1494522306.864 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2017-05-11T17:05:06.905Z,1494522306.905 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2017-05-11T17:05:06.909Z,1494522306.909 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2017-05-11T17:05:06.910Z,1494522306.910 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2017-05-11T17:05:06.917Z,1494522306.917 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2017-05-11T17:05:06.918Z,1494522306.918 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFC4E0 2017-05-11T17:05:06.919Z,1494522306.918 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 862 2017-05-11T17:05:06.923Z,1494522306.923 [Supervisor](INFO): Main Thread ID is 766 2017-05-11T17:05:06.923Z,1494522306.923 [Supervisor](DEBUG): Running supervisor. 2017-05-11T17:05:06.924Z,1494522306.924 [CommandLine ThreadHandler](INFO): Handler Thread ID is 863 2017-05-11T17:05:06.927Z,1494522306.927 [controlThread ThreadHandler](INFO): Handler Thread ID is 864 2017-05-11T17:05:06.927Z,1494522306.927 [controlThread](DEBUG): Initializing ControlThread 2017-05-11T17:05:06.928Z,1494522306.928 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2017-05-11T17:05:06.930Z,1494522306.930 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2017-05-11T17:05:06.931Z,1494522306.931 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2017-05-11T17:05:06.932Z,1494522306.932 [LoopControl](DEBUG): Initialize LoopControlComponent. 2017-05-11T17:05:06.932Z,1494522306.932 [SBIT](INFO): Initialize SBIT Component. 2017-05-11T17:05:06.933Z,1494522306.932 [SBIT](IMPORTANT): git: 2017-04-19-5-g443ab08 2017-05-11T17:05:06.933Z,1494522306.933 [SBIT](INFO): git hash: 443ab0852958b11c27b2467e632b948d2f0b0b23 2017-05-11T17:05:06.934Z,1494522306.934 [SBIT](INFO): Kernel Reporting Different Release From Configuration. Kernel Expected: 2.6.27.8 Kernel Reported: 2.6.27.8-00011-g2bc81df-dirty 2017-05-11T17:05:06.935Z,1494522306.935 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #646 PREEMPT Thu Feb 11 17:01:12 PST 2016 2017-05-11T17:05:06.936Z,1494522306.936 [SBIT](INFO): Beginning SBIT in 32.000000 seconds. 2017-05-11T17:05:06.936Z,1494522306.936 [IBIT](INFO): Initialize IBIT Component. 2017-05-11T17:05:06.937Z,1494522306.937 [CBIT](DEBUG): Initialize CBIT Component. 2017-05-11T17:05:06.938Z,1494522306.938 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2017-05-11T17:05:06.938Z,1494522306.938 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2017-05-11T17:05:06.939Z,1494522306.939 [logger ThreadHandler](INFO): Handler Thread ID is 865 2017-05-11T17:05:06.964Z,1494522306.964 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 866 2017-05-11T17:05:06.965Z,1494522306.965 [CTD_NeilBrown](INFO): Powering down 2017-05-11T17:05:06.996Z,1494522306.996 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 867 2017-05-11T17:05:07.004Z,1494522307.004 [CTD_Seabird](INFO): Initializing 2017-05-11T17:05:07.030Z,1494522307.030 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2017-05-11T17:05:07.030Z,1494522307.030 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2017-05-11T17:05:07.031Z,1494522307.030 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2017-05-11T17:05:07.031Z,1494522307.031 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2017-05-11T17:05:07.032Z,1494522307.032 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2017-05-11T17:05:07.033Z,1494522307.033 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2017-05-11T17:05:07.034Z,1494522307.034 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-05-11T17:05:07.035Z,1494522307.035 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-05-11T17:05:07.035Z,1494522307.035 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-05-11T17:05:07.036Z,1494522307.036 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-05-11T17:05:07.036Z,1494522307.036 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-05-11T17:05:07.037Z,1494522307.037 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-05-11T17:05:07.037Z,1494522307.037 [NavChart](DEBUG): Initialize NavChart Navigation. 2017-05-11T17:05:07.038Z,1494522307.038 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2017-05-11T17:05:07.046Z,1494522307.046 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 869 2017-05-11T17:05:07.047Z,1494522307.047 [WetLabsBB2FL](INFO): Powering down 2017-05-11T17:05:07.075Z,1494522307.075 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2017-05-11T17:05:07.087Z,1494522307.087 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 870 2017-05-11T17:05:07.095Z,1494522307.095 [Radio_Surface](INFO): Powering up 2017-05-11T17:05:07.116Z,1494522307.116 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 871 2017-05-11T17:05:07.120Z,1494522307.120 [Rowe_600LCM](INFO): Initializing 2017-05-11T17:05:07.121Z,1494522307.121 [Rowe_600LCM](INFO): Checking LCM 2017-05-11T17:05:07.122Z,1494522307.122 [Rowe_600LCM](INFO): LCM OK 2017-05-11T17:05:07.122Z,1494522307.122 [Rowe_600LCM](INFO): Powering up 2017-05-11T17:05:07.124Z,1494522307.124 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2017-05-11T17:05:07.132Z,1494522307.132 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 872 2017-05-11T17:05:07.142Z,1494522307.142 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2017-05-11T17:05:07.142Z,1494522307.142 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2017-05-11T17:05:07.142Z,1494522307.142 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2017-05-11T17:05:07.142Z,1494522307.142 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2017-05-11T17:05:07.143Z,1494522307.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2017-05-11T17:05:07.143Z,1494522307.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2017-05-11T17:05:07.143Z,1494522307.143 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2017-05-11T17:05:07.143Z,1494522307.143 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2017-05-11T17:05:07.144Z,1494522307.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2017-05-11T17:05:07.144Z,1494522307.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2017-05-11T17:05:07.144Z,1494522307.144 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2017-05-11T17:05:07.144Z,1494522307.144 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2017-05-11T17:05:07.145Z,1494522307.145 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2017-05-11T17:05:07.145Z,1494522307.145 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2017-05-11T17:05:07.145Z,1494522307.145 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2017-05-11T17:05:07.145Z,1494522307.145 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2017-05-11T17:05:07.182Z,1494522307.182 [MissionManager](DEBUG): 2017-05-11T17:05:07.183Z,1494522307.183 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2017-05-11T17:05:07.310Z,1494522307.310 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2017-05-11T17:05:07.312Z,1494522307.312 [Default:A.Wait](DEBUG): Construct Wait. 2017-05-11T17:05:07.313Z,1494522307.313 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2017-05-11T17:05:07.320Z,1494522307.320 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2017-05-11T17:05:07.320Z,1494522307.320 [CTD_Seabird](INFO): Powering down 2017-05-11T17:05:07.371Z,1494522307.371 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2017-05-11T17:05:07.382Z,1494522307.382 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2017-05-11T17:05:07.411Z,1494522307.411 [Default:E.Execute](DEBUG): Construct Execute. 2017-05-11T17:05:07.415Z,1494522307.415 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn 300 Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2017-05-11T17:05:07.425Z,1494522307.425 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,PAR_Licor,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,StratificationFrontDetector,DepAvgTempFrontDetector,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2017-05-11T17:05:07.508Z,1494522307.508 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2017-05-11T17:05:07.519Z,1494522307.519 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2017-05-11T17:05:07.568Z,1494522307.568 [NAL9602](INFO): Powering up NAL9602 2017-05-11T17:05:07.776Z,1494522307.776 [DepthRateCalculator](ERROR): Depth measurement is not active 2017-05-11T17:05:07.870Z,1494522307.870 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:08.124Z,1494522308.124 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:08.224Z,1494522308.224 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:05:08.232Z,1494522308.232 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2017-05-11T17:05:08.254Z,1494522308.254 [ElevatorServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:05:08.260Z,1494522308.260 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2017-05-11T17:05:08.274Z,1494522308.274 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:05:08.276Z,1494522308.276 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:05:08.304Z,1494522308.304 [RudderServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:05:08.312Z,1494522308.312 [RudderServo](DEBUG): Initializing RudderServo. 2017-05-11T17:05:08.326Z,1494522308.326 [ThrusterServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:05:08.332Z,1494522308.332 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2017-05-11T17:05:08.582Z,1494522308.582 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2017-05-11T17:05:08.582Z,1494522308.582 [DropWeight] Hardware Fault, FailCount= 1 2017-05-11T17:05:08.582Z,1494522308.582 [DropWeight](ERROR): Hardware Fault 2017-05-11T17:05:08.655Z,1494522308.655 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:08.664Z,1494522308.664 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:08.689Z,1494522308.689 [CommandLine](FAULT): Scheduling is paused 2017-05-11T17:05:08.689Z,1494522308.689 [CBIT](INFO): Critical error at 20170511T170508 2017-05-11T17:05:08.690Z,1494522308.690 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2017-05-11T17:05:08.692Z,1494522308.692 [CBIT](ERROR): Hardware Fault in component: DropWeight 2017-05-11T17:05:08.692Z,1494522308.693 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2017-05-11T17:05:08.888Z,1494522308.888 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:08.890Z,1494522308.889 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:09.354Z,1494522309.353 [CBIT](INFO): Critical error at 20170511T170508 2017-05-11T17:05:09.425Z,1494522309.425 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:09.426Z,1494522309.426 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:09.820Z,1494522309.820 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:09.821Z,1494522309.821 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:10.216Z,1494522310.216 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:10.217Z,1494522310.217 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:10.684Z,1494522310.684 [Aanderaa_O2](INFO): Powering down 2017-05-11T17:05:10.836Z,1494522310.836 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:10.837Z,1494522310.837 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:11.038Z,1494522311.038 [DeadReckonUsingMultipleVelocitySources](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:11.039Z,1494522311.039 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2017-05-11T17:05:11.369Z,1494522311.369 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2017-05-11T17:05:11.518Z,1494522311.518 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null & 2017-05-11T17:05:12.372Z,1494522312.372 [MassServo](FAULT): Overload Error 2017-05-11T17:05:12.372Z,1494522312.372 [MassServo] Hardware Fault, FailCount= 1 2017-05-11T17:05:12.372Z,1494522312.372 [MassServo](ERROR): Hardware Fault 2017-05-11T17:05:12.504Z,1494522312.504 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:05:12.518Z,1494522312.518 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2017-05-11T17:05:12.519Z,1494522312.519 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2017-05-11T17:05:12.520Z,1494522312.520 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2017-05-11T17:05:12.672Z,1494522312.672 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:05:12.672Z,1494522312.672 [MassServo](INFO): Powering down 2017-05-11T17:05:13.477Z,1494522313.477 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:05:13.478Z,1494522313.478 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:05:13.490Z,1494522313.490 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:05:13.490Z,1494522313.490 [MassServo] No Fault, FailCount= 1 2017-05-11T17:05:17.408Z,1494522317.408 [MassServo](FAULT): Overload Error 2017-05-11T17:05:17.408Z,1494522317.408 [MassServo] Hardware Fault, FailCount= 2 2017-05-11T17:05:17.408Z,1494522317.408 [MassServo](ERROR): Hardware Fault 2017-05-11T17:05:17.413Z,1494522317.413 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:05:17.818Z,1494522317.818 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:05:17.818Z,1494522317.818 [MassServo](INFO): Powering down 2017-05-11T17:05:18.535Z,1494522318.535 [NAL9602](INFO): NAL9602 initialized 2017-05-11T17:05:18.643Z,1494522318.643 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:05:18.652Z,1494522318.652 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:05:18.667Z,1494522318.667 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:05:18.667Z,1494522318.667 [MassServo] No Fault, FailCount= 2 2017-05-11T17:05:22.308Z,1494522322.308 [MassServo](FAULT): Overload Error 2017-05-11T17:05:22.308Z,1494522322.308 [MassServo] Hardware Fault, FailCount= 3 2017-05-11T17:05:22.308Z,1494522322.308 [MassServo](ERROR): Hardware Fault 2017-05-11T17:05:22.385Z,1494522322.385 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:05:22.688Z,1494522322.688 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:05:22.688Z,1494522322.688 [MassServo](INFO): Powering down 2017-05-11T17:05:23.406Z,1494522323.406 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:05:23.406Z,1494522323.406 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:05:23.419Z,1494522323.419 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:05:23.424Z,1494522323.424 [MassServo] No Fault, FailCount= 3 2017-05-11T17:05:27.836Z,1494522327.836 [MassServo](FAULT): Overload Error 2017-05-11T17:05:27.836Z,1494522327.836 [MassServo] Hardware Fault, FailCount= 4 2017-05-11T17:05:27.836Z,1494522327.836 [MassServo](ERROR): Hardware Fault 2017-05-11T17:05:27.842Z,1494522327.842 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:05:28.203Z,1494522328.203 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:05:28.203Z,1494522328.203 [MassServo](INFO): Powering down 2017-05-11T17:05:29.055Z,1494522329.055 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:05:29.068Z,1494522329.068 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:05:29.087Z,1494522329.087 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:05:29.087Z,1494522329.087 [MassServo] No Fault, FailCount= 4 2017-05-11T17:05:33.064Z,1494522333.064 [MassServo](FAULT): Overload Error 2017-05-11T17:05:33.064Z,1494522333.064 [MassServo] Hardware Fault, FailCount= 5 2017-05-11T17:05:33.064Z,1494522333.064 [MassServo](ERROR): Hardware Fault 2017-05-11T17:05:33.141Z,1494522333.141 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:05:33.141Z,1494522333.141 [CBIT](CRITICAL): Hardware Fault in component: MassServo 2017-05-11T17:05:33.414Z,1494522333.414 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:05:33.414Z,1494522333.414 [MassServo](INFO): Powering down 2017-05-11T17:05:33.434Z,1494522333.434 [CBIT](INFO): Critical error at 20170511T170533 2017-05-11T17:05:34.186Z,1494522334.186 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:05:34.187Z,1494522334.187 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:05:39.379Z,1494522339.378 [SBIT](IMPORTANT): Beginning Startup BIT 2017-05-11T17:05:39.383Z,1494522339.383 [CBIT](IMPORTANT): Beginning ground fault scan 2017-05-11T17:05:49.864Z,1494522349.865 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 4.657929 CHAN A1 (24V): 0.026879 CHAN A2 (12V): -0.005937 CHAN A3 (5V): -0.000979 CHAN B0 (3.3V): -0.001461 CHAN B1 (3.15aV): -0.001079 CHAN B2 (3.15bV): -0.000984 CHAN B3 (GND): 0.000923 OPEN: -0.000956 Full Scale Calc: 4.765 mA, -1.589 mA 2017-05-11T17:05:52.676Z,1494522352.676 [SBIT](ERROR): Could not read massPosReader_. 2017-05-11T17:06:19.022Z,1494522379.022 [SBIT](ERROR): Could not read massPosReader_. 2017-05-11T17:06:19.022Z,1494522379.022 [SBIT](FAULT): Control surface position failure. 2017-05-11T17:06:32.562Z,1494522392.562 [PNI_TCM](ERROR): CRC does not match. Expected:0x1512 got:0x6592 2017-05-11T17:06:32.619Z,1494522392.619 [SBIT](ERROR): Could not read massPosReader_. 2017-05-11T17:06:32.619Z,1494522392.619 [SBIT](FAULT): Control surface position failure. 2017-05-11T17:06:33.019Z,1494522393.019 [SBIT](CRITICAL): SBIT FAILED 2017-05-11T17:06:33.020Z,1494522393.020 [CBIT](INFO): Critical error at 20170511T170633 2017-05-11T17:06:33.382Z,1494522393.382 [MissionManager](IMPORTANT): Started mission Startup 2017-05-11T17:06:33.382Z,1494522393.382 [Startup] Running Loop=1 2017-05-11T17:06:33.382Z,1494522393.382 [Startup](DEBUG): Aggregate::initialize Startup 2017-05-11T17:06:33.382Z,1494522393.382 [Startup:A.GoToSurface] Running Loop=1 2017-05-11T17:06:33.382Z,1494522393.382 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2017-05-11T17:06:33.383Z,1494522393.383 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2017-05-11T17:06:33.383Z,1494522393.383 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2017-05-11T17:06:33.384Z,1494522393.384 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2017-05-11T17:06:33.384Z,1494522393.384 [Startup:A.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2017-05-11T17:06:33.384Z,1494522393.384 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2017-05-11T17:06:33.390Z,1494522393.390 [Startup:StartupSatComms] Running Loop=1 2017-05-11T17:06:33.390Z,1494522393.390 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2017-05-11T17:06:33.391Z,1494522393.391 [Startup:StartupSatComms:A] Running Loop=1 2017-05-11T17:06:33.788Z,1494522393.788 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2017-05-11T17:06:47.754Z,1494522407.754 [PNI_TCM](ERROR): CRC does not match. Expected:0x20787 got:0x15961 2017-05-11T17:06:56.865Z,1494522416.865 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003900 2017-05-11T17:07:07.780Z,1494522427.780 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2017-05-11T17:07:07.780Z,1494522427.780 [Rowe_600LCM] Communications Fault, FailCount= 1 2017-05-11T17:07:07.780Z,1494522427.780 [Rowe_600LCM](ERROR): Communications Fault 2017-05-11T17:07:08.121Z,1494522428.121 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.4 s old, using for 20.0 s. 2017-05-11T17:07:08.135Z,1494522428.135 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2017-05-11T17:07:08.184Z,1494522428.184 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2017-05-11T17:07:08.286Z,1494522428.286 [Rowe_600LCM](INFO): Powering down 2017-05-11T17:07:08.526Z,1494522428.526 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.8 s old, using for 20.0 s. 2017-05-11T17:07:08.917Z,1494522428.917 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s. 2017-05-11T17:07:09.316Z,1494522429.316 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s. 2017-05-11T17:07:09.728Z,1494522429.728 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s. 2017-05-11T17:07:09.764Z,1494522429.764 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2017-05-11T17:07:09.764Z,1494522429.764 [Rowe_600LCM] No Fault, FailCount= 1 2017-05-11T17:07:09.900Z,1494522429.901 [Rowe_600LCM](INFO): Initializing 2017-05-11T17:07:09.901Z,1494522429.901 [Rowe_600LCM](INFO): Checking LCM 2017-05-11T17:07:09.901Z,1494522429.901 [Rowe_600LCM](INFO): LCM OK 2017-05-11T17:07:09.901Z,1494522429.901 [Rowe_600LCM](INFO): Powering up 2017-05-11T17:07:10.116Z,1494522430.116 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s. 2017-05-11T17:07:10.518Z,1494522430.518 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s. 2017-05-11T17:07:10.924Z,1494522430.924 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s. 2017-05-11T17:07:11.336Z,1494522431.336 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s. 2017-05-11T17:07:11.733Z,1494522431.733 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s. 2017-05-11T17:07:12.138Z,1494522432.138 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s. 2017-05-11T17:07:12.587Z,1494522432.587 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.9 s old, using for 20.0 s. 2017-05-11T17:07:12.934Z,1494522432.934 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s. 2017-05-11T17:07:13.301Z,1494522433.301 [PNI_TCM](ERROR): CRC does not match. Expected:0x61067 got:0x14418 2017-05-11T17:07:13.334Z,1494522433.334 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s. 2017-05-11T17:07:13.750Z,1494522433.750 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s. 2017-05-11T17:07:14.026Z,1494522434.026 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2017-05-11T17:07:14.153Z,1494522434.153 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s. 2017-05-11T17:07:14.163Z,1494522434.163 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null & 2017-05-11T17:07:14.169Z,1494522434.169 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2017-05-11T17:07:14.170Z,1494522434.170 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2017-05-11T17:07:14.171Z,1494522434.171 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2017-05-11T17:07:14.535Z,1494522434.535 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s. 2017-05-11T17:07:16.513Z,1494522436.513 [PNI_TCM](ERROR): CRC does not match. Expected:0x10239 got:0x32768 2017-05-11T17:07:33.757Z,1494522453.757 [Startup:StartupSatComms:A](INFO): Timed out from 2017-05-11T17:06:33.4Z 2017-05-11T17:07:33.757Z,1494522453.757 [Startup:StartupSatComms:A] Stopped 2017-05-11T17:07:33.757Z,1494522453.757 [Startup:StartupSatComms:B] Running Loop=1 2017-05-11T17:07:34.121Z,1494522454.121 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2017-05-11T17:07:38.725Z,1494522458.725 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170511T164856/Courier0008.lzma 2017-05-11T17:07:39.474Z,1494522459.474 [DataOverHttps](INFO): Moved sent file to Logs/20170511T164856/Courier0008.lzma.bak 2017-05-11T17:07:39.474Z,1494522459.474 [DataOverHttps](INFO): SBD MOMSN=5021953 2017-05-11T17:07:49.046Z,1494522469.046 [DataOverHttps](INFO): Sending 174 bytes from file Logs/20170511T170449/Courier0000.lzma 2017-05-11T17:07:49.814Z,1494522469.814 [DataOverHttps](INFO): Moved sent file to Logs/20170511T170449/Courier0000.lzma.bak 2017-05-11T17:07:49.814Z,1494522469.814 [DataOverHttps](INFO): SBD MOMSN=5021955 2017-05-11T17:08:06.896Z,1494522486.896 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170505T154608/Express0009.lzma 2017-05-11T17:08:06.997Z,1494522486.997 [BPC1](ERROR): Failed to receive battery data 2017-05-11T17:08:06.997Z,1494522486.997 [BPC1] Communications Fault, FailCount= 1 2017-05-11T17:08:06.997Z,1494522486.997 [BPC1](ERROR): Communications Fault 2017-05-11T17:08:07.108Z,1494522487.108 [CBIT](ERROR): Communications Fault in component: BPC1 2017-05-11T17:08:07.223Z,1494522487.223 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-05-11T17:08:07.223Z,1494522487.223 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2017-05-11T17:08:07.223Z,1494522487.223 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2017-05-11T17:08:07.230Z,1494522487.230 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-05-11T17:08:07.230Z,1494522487.230 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2017-05-11T17:08:07.230Z,1494522487.230 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2017-05-11T17:08:07.267Z,1494522487.267 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2017-05-11T17:08:07.268Z,1494522487.268 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2017-05-11T17:08:07.522Z,1494522487.522 [DataOverHttps](INFO): Moved sent file to Logs/20170505T154608/Express0009.lzma.bak 2017-05-11T17:08:07.522Z,1494522487.522 [DataOverHttps](INFO): SBD MOMSN=5021951 2017-05-11T17:08:07.603Z,1494522487.603 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2017-05-11T17:08:07.603Z,1494522487.603 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2017-05-11T17:08:07.604Z,1494522487.604 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2017-05-11T17:08:07.604Z,1494522487.605 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2017-05-11T17:08:08.315Z,1494522488.315 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-05-11T17:08:08.315Z,1494522488.315 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-05-11T17:08:08.320Z,1494522488.320 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-05-11T17:08:08.321Z,1494522488.321 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-05-11T17:08:08.321Z,1494522488.321 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-05-11T17:08:08.321Z,1494522488.321 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-05-11T17:08:08.362Z,1494522488.362 [CBIT](INFO): Clearing failed state for component BPC1 2017-05-11T17:08:08.362Z,1494522488.362 [BPC1] No Fault, FailCount= 1 2017-05-11T17:08:17.033Z,1494522497.033 [DataOverHttps](INFO): Sending 766 bytes from file Logs/20170505T155642/Express0001.lzma 2017-05-11T17:08:17.810Z,1494522497.810 [DataOverHttps](INFO): Moved sent file to Logs/20170505T155642/Express0001.lzma.bak 2017-05-11T17:08:17.810Z,1494522497.810 [DataOverHttps](INFO): SBD MOMSN=5021963 2017-05-11T17:08:27.295Z,1494522507.295 [DataOverHttps](INFO): Sending 179 bytes from file Logs/20170505T155642/Express0005.lzma 2017-05-11T17:08:28.026Z,1494522508.026 [DataOverHttps](INFO): Moved sent file to Logs/20170505T155642/Express0005.lzma.bak 2017-05-11T17:08:28.026Z,1494522508.026 [DataOverHttps](INFO): SBD MOMSN=5021976 2017-05-11T17:08:33.802Z,1494522513.802 [Startup:StartupSatComms:B](INFO): Timed out from 2017-05-11T17:07:33.8Z 2017-05-11T17:08:33.802Z,1494522513.802 [Startup:StartupSatComms:B] Stopped 2017-05-11T17:08:33.802Z,1494522513.802 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2017-05-11T17:08:33.802Z,1494522513.802 [Startup:StartupSatComms] Stopped 2017-05-11T17:08:33.802Z,1494522513.802 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2017-05-11T17:08:33.803Z,1494522513.803 [Startup](INFO): Completed Startup 2017-05-11T17:08:33.803Z,1494522513.803 [MissionManager](INFO): Startup is completed. 2017-05-11T17:08:33.803Z,1494522513.803 [MissionManager](INFO): Uninitializing Mission Startup 2017-05-11T17:08:33.803Z,1494522513.803 [Startup] Stopped 2017-05-11T17:08:33.803Z,1494522513.803 [Startup](DEBUG): Aggregate::uninitialize Startup 2017-05-11T17:08:33.804Z,1494522513.804 [Startup:A.GoToSurface] Stopped 2017-05-11T17:08:33.804Z,1494522513.804 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2017-05-11T17:08:34.272Z,1494522514.272 [MissionManager](IMPORTANT): Started mission Default 2017-05-11T17:08:34.273Z,1494522514.273 [Default] Running Loop=1 2017-05-11T17:08:34.273Z,1494522514.273 [Default](DEBUG): Aggregate::initialize Default 2017-05-11T17:08:34.273Z,1494522514.273 [Default:B.GoToSurface] Running Loop=1 2017-05-11T17:08:34.273Z,1494522514.273 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2017-05-11T17:08:34.273Z,1494522514.273 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2017-05-11T17:08:34.273Z,1494522514.273 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2017-05-11T17:08:34.274Z,1494522514.274 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2017-05-11T17:08:34.274Z,1494522514.274 [Default:B.GoToSurface](DEBUG): No pitch timeout specified. Using default value of 20.000000 seconds. 2017-05-11T17:08:34.274Z,1494522514.274 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2017-05-11T17:08:34.275Z,1494522514.275 [Default:A.Wait] Running Loop=1 2017-05-11T17:08:34.275Z,1494522514.275 [Default:A.Wait](DEBUG): Initialize Wait Component. 2017-05-11T17:08:37.696Z,1494522517.696 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170505T155642/Express0009.lzma 2017-05-11T17:08:38.502Z,1494522518.502 [DataOverHttps](INFO): Moved sent file to Logs/20170505T155642/Express0009.lzma.bak 2017-05-11T17:08:38.502Z,1494522518.502 [DataOverHttps](INFO): SBD MOMSN=5021980 2017-05-11T17:08:47.373Z,1494522527.373 [Default:A.Wait](INFO): Done Waiting. 2017-05-11T17:08:47.373Z,1494522527.373 [Default:A.Wait] Stopped 2017-05-11T17:08:47.373Z,1494522527.373 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2017-05-11T17:08:47.757Z,1494522527.757 [Default:CheckIn] Running Loop=1 2017-05-11T17:08:47.757Z,1494522527.757 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2017-05-11T17:08:47.757Z,1494522527.757 [Default:CheckIn:Read_GPS] Running Loop=1 2017-05-11T17:08:48.206Z,1494522528.206 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2017-05-11T17:09:40.928Z,1494522580.928 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2017-05-11T17:09:40.928Z,1494522580.928 [Rowe_600LCM] Communications Fault, FailCount= 2 2017-05-11T17:09:40.928Z,1494522580.928 [Rowe_600LCM](ERROR): Communications Fault 2017-05-11T17:09:41.226Z,1494522581.226 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.4 s old, using for 20.0 s. 2017-05-11T17:09:41.252Z,1494522581.252 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2017-05-11T17:09:41.332Z,1494522581.332 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2017-05-11T17:09:41.423Z,1494522581.423 [Rowe_600LCM](INFO): Powering down 2017-05-11T17:09:41.632Z,1494522581.632 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.8 s old, using for 20.0 s. 2017-05-11T17:09:42.031Z,1494522582.030 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s. 2017-05-11T17:09:42.499Z,1494522582.499 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.7 s old, using for 20.0 s. 2017-05-11T17:09:42.871Z,1494522582.871 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s. 2017-05-11T17:09:42.902Z,1494522582.902 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2017-05-11T17:09:42.902Z,1494522582.902 [Rowe_600LCM] No Fault, FailCount= 2 2017-05-11T17:09:43.040Z,1494522583.040 [Rowe_600LCM](INFO): Initializing 2017-05-11T17:09:43.041Z,1494522583.040 [Rowe_600LCM](INFO): Checking LCM 2017-05-11T17:09:43.041Z,1494522583.041 [Rowe_600LCM](INFO): LCM OK 2017-05-11T17:09:43.041Z,1494522583.041 [Rowe_600LCM](INFO): Powering up 2017-05-11T17:09:43.237Z,1494522583.237 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s. 2017-05-11T17:09:43.651Z,1494522583.651 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s. 2017-05-11T17:09:44.055Z,1494522584.055 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s. 2017-05-11T17:09:44.439Z,1494522584.439 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s. 2017-05-11T17:09:44.843Z,1494522584.843 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s. 2017-05-11T17:09:45.254Z,1494522585.254 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s. 2017-05-11T17:09:45.614Z,1494522585.614 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s. 2017-05-11T17:09:46.037Z,1494522586.037 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s. 2017-05-11T17:09:46.442Z,1494522586.442 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s. 2017-05-11T17:09:46.842Z,1494522586.842 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s. 2017-05-11T17:09:47.164Z,1494522587.164 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2017-05-11T17:09:47.299Z,1494522587.299 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null & 2017-05-11T17:09:47.301Z,1494522587.301 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2017-05-11T17:09:47.302Z,1494522587.302 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2017-05-11T17:09:47.303Z,1494522587.303 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2017-05-11T17:09:47.307Z,1494522587.307 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.5 s old, using for 20.0 s. 2017-05-11T17:09:47.660Z,1494522587.661 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.8 s old, using for 20.0 s. 2017-05-11T17:10:22.377Z,1494522622.377 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2017-05-11T17:10:33.255Z,1494522633.255 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:10:33.260Z,1494522633.260 [MassServo] No Fault, FailCount= 5 2017-05-11T17:10:40.036Z,1494522640.036 [MassServo](FAULT): Overload Error 2017-05-11T17:10:40.036Z,1494522640.036 [MassServo] Hardware Fault, FailCount= 1 2017-05-11T17:10:40.036Z,1494522640.036 [MassServo](ERROR): Hardware Fault 2017-05-11T17:10:40.041Z,1494522640.041 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:10:40.404Z,1494522640.404 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:10:40.404Z,1494522640.404 [MassServo](INFO): Powering down 2017-05-11T17:10:41.191Z,1494522641.191 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:10:41.191Z,1494522641.191 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:10:41.196Z,1494522641.196 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:10:41.196Z,1494522641.196 [MassServo] No Fault, FailCount= 1 2017-05-11T17:10:45.212Z,1494522645.212 [MassServo](FAULT): Overload Error 2017-05-11T17:10:45.212Z,1494522645.212 [MassServo] Hardware Fault, FailCount= 2 2017-05-11T17:10:45.212Z,1494522645.212 [MassServo](ERROR): Hardware Fault 2017-05-11T17:10:45.300Z,1494522645.300 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:10:45.623Z,1494522645.622 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:10:45.623Z,1494522645.623 [MassServo](INFO): Powering down 2017-05-11T17:10:46.376Z,1494522646.376 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:10:46.376Z,1494522646.376 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:10:46.381Z,1494522646.381 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:10:46.381Z,1494522646.381 [MassServo] No Fault, FailCount= 2 2017-05-11T17:10:50.824Z,1494522650.824 [MassServo](FAULT): Overload Error 2017-05-11T17:10:50.824Z,1494522650.824 [MassServo] Hardware Fault, FailCount= 3 2017-05-11T17:10:50.824Z,1494522650.824 [MassServo](ERROR): Hardware Fault 2017-05-11T17:10:50.829Z,1494522650.829 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:10:51.188Z,1494522651.188 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:10:51.188Z,1494522651.188 [MassServo](INFO): Powering down 2017-05-11T17:10:51.981Z,1494522651.981 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:10:51.982Z,1494522651.981 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:10:51.991Z,1494522651.991 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:10:51.991Z,1494522651.991 [MassServo] No Fault, FailCount= 3 2017-05-11T17:10:56.016Z,1494522656.016 [MassServo](FAULT): Overload Error 2017-05-11T17:10:56.016Z,1494522656.016 [MassServo] Hardware Fault, FailCount= 4 2017-05-11T17:10:56.016Z,1494522656.016 [MassServo](ERROR): Hardware Fault 2017-05-11T17:10:56.105Z,1494522656.105 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:10:56.412Z,1494522656.412 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:10:56.412Z,1494522656.412 [MassServo](INFO): Powering down 2017-05-11T17:10:57.240Z,1494522657.240 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:10:57.240Z,1494522657.240 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:10:57.257Z,1494522657.257 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:10:57.257Z,1494522657.257 [MassServo] No Fault, FailCount= 4 2017-05-11T17:11:01.620Z,1494522661.620 [MassServo](FAULT): Overload Error 2017-05-11T17:11:01.620Z,1494522661.620 [MassServo] Hardware Fault, FailCount= 5 2017-05-11T17:11:01.620Z,1494522661.620 [MassServo](ERROR): Hardware Fault 2017-05-11T17:11:01.625Z,1494522661.625 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:11:01.625Z,1494522661.625 [CBIT](CRITICAL): Hardware Fault in component: MassServo 2017-05-11T17:11:01.987Z,1494522661.987 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:11:01.987Z,1494522661.987 [MassServo](INFO): Powering down 2017-05-11T17:11:01.990Z,1494522661.990 [CBIT](INFO): Critical error at 20170511T171101 2017-05-11T17:11:02.790Z,1494522662.790 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:11:02.790Z,1494522662.790 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:11:08.359Z,1494522668.359 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-05-11T17:11:08.360Z,1494522668.360 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2017-05-11T17:11:08.360Z,1494522668.360 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2017-05-11T17:11:08.362Z,1494522668.362 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-05-11T17:11:08.362Z,1494522668.362 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2017-05-11T17:11:08.362Z,1494522668.362 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2017-05-11T17:11:08.375Z,1494522668.375 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2017-05-11T17:11:08.375Z,1494522668.375 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2017-05-11T17:11:08.825Z,1494522668.825 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2017-05-11T17:11:08.825Z,1494522668.825 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2017-05-11T17:11:08.825Z,1494522668.825 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2017-05-11T17:11:08.825Z,1494522668.825 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2017-05-11T17:11:09.173Z,1494522669.173 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-05-11T17:11:09.174Z,1494522669.174 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-05-11T17:11:09.174Z,1494522669.174 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-05-11T17:11:09.174Z,1494522669.174 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-05-11T17:11:09.175Z,1494522669.175 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-05-11T17:11:09.175Z,1494522669.175 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-05-11T17:11:43.100Z,1494522703.100 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2017-05-11T17:11:43.100Z,1494522703.100 [Rowe_600LCM] Communications Fault, FailCount= 3 2017-05-11T17:11:43.100Z,1494522703.100 [Rowe_600LCM](ERROR): Communications Fault 2017-05-11T17:11:43.504Z,1494522703.504 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2017-05-11T17:11:43.537Z,1494522703.537 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.4 s old, using for 20.0 s. 2017-05-11T17:11:43.602Z,1494522703.602 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2017-05-11T17:11:43.694Z,1494522703.694 [Rowe_600LCM](INFO): Powering down 2017-05-11T17:11:43.899Z,1494522703.899 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 0.8 s old, using for 20.0 s. 2017-05-11T17:11:44.279Z,1494522704.279 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.2 s old, using for 20.0 s. 2017-05-11T17:11:44.709Z,1494522704.709 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 1.6 s old, using for 20.0 s. 2017-05-11T17:11:45.090Z,1494522705.090 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.0 s old, using for 20.0 s. 2017-05-11T17:11:45.132Z,1494522705.132 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2017-05-11T17:11:45.132Z,1494522705.132 [Rowe_600LCM] No Fault, FailCount= 3 2017-05-11T17:11:45.308Z,1494522705.308 [Rowe_600LCM](INFO): Initializing 2017-05-11T17:11:45.308Z,1494522705.308 [Rowe_600LCM](INFO): Checking LCM 2017-05-11T17:11:45.308Z,1494522705.309 [Rowe_600LCM](INFO): LCM OK 2017-05-11T17:11:45.309Z,1494522705.309 [Rowe_600LCM](INFO): Powering up 2017-05-11T17:11:45.485Z,1494522705.485 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.4 s old, using for 20.0 s. 2017-05-11T17:11:45.879Z,1494522705.879 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 2.8 s old, using for 20.0 s. 2017-05-11T17:11:46.274Z,1494522706.274 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.2 s old, using for 20.0 s. 2017-05-11T17:11:46.675Z,1494522706.675 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s. 2017-05-11T17:11:47.082Z,1494522707.082 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s. 2017-05-11T17:11:47.482Z,1494522707.483 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s. 2017-05-11T17:11:47.886Z,1494522707.885 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s. 2017-05-11T17:11:48.288Z,1494522708.288 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s. 2017-05-11T17:11:48.684Z,1494522708.684 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.6 s old, using for 20.0 s. 2017-05-11T17:11:49.076Z,1494522709.076 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.0 s old, using for 20.0 s. 2017-05-11T17:11:49.494Z,1494522709.494 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.4 s old, using for 20.0 s. 2017-05-11T17:11:49.524Z,1494522709.524 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2017-05-11T17:11:49.631Z,1494522709.631 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null & 2017-05-11T17:11:49.633Z,1494522709.633 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2017-05-11T17:11:49.634Z,1494522709.634 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2017-05-11T17:11:49.635Z,1494522709.635 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2017-05-11T17:11:49.941Z,1494522709.941 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 6.9 s old, using for 20.0 s. 2017-05-11T17:11:56.268Z,1494522716.268 [BPC1](ERROR): Failed to receive battery data 2017-05-11T17:11:56.268Z,1494522716.268 [BPC1] Communications Fault, FailCount= 1 2017-05-11T17:11:56.268Z,1494522716.268 [BPC1](ERROR): Communications Fault 2017-05-11T17:11:56.316Z,1494522716.316 [CBIT](ERROR): Communications Fault in component: BPC1 2017-05-11T17:11:57.510Z,1494522717.510 [CBIT](INFO): Clearing failed state for component BPC1 2017-05-11T17:11:57.510Z,1494522717.510 [BPC1] No Fault, FailCount= 1 2017-05-11T17:13:48.006Z,1494522828.006 [Default:CheckIn:Read_GPS](INFO): Timed out from 2017-05-11T17:08:47.8Z 2017-05-11T17:13:48.006Z,1494522828.006 [Default:CheckIn:Read_GPS] Stopped 2017-05-11T17:13:48.006Z,1494522828.006 [Default:CheckIn:Read_Iridium] Running Loop=1 2017-05-11T17:13:48.423Z,1494522828.423 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2017-05-11T17:13:52.000Z,1494522833.000 [DataOverHttps](INFO): Sending 240 bytes from file Logs/20170511T170449/Courier0004.lzma 2017-05-11T17:13:53.762Z,1494522833.762 [DataOverHttps](INFO): Moved sent file to Logs/20170511T170449/Courier0004.lzma.bak 2017-05-11T17:13:53.762Z,1494522833.762 [DataOverHttps](INFO): SBD MOMSN=5021982 2017-05-11T17:14:03.347Z,1494522843.347 [DataOverHttps](INFO): Sending 644 bytes from file Logs/20170505T161046/Express0001.lzma 2017-05-11T17:14:04.134Z,1494522844.134 [DataOverHttps](INFO): Moved sent file to Logs/20170505T161046/Express0001.lzma.bak 2017-05-11T17:14:04.134Z,1494522844.134 [DataOverHttps](INFO): SBD MOMSN=5021985 2017-05-11T17:14:09.286Z,1494522849.286 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-05-11T17:14:09.286Z,1494522849.286 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2017-05-11T17:14:09.286Z,1494522849.286 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2017-05-11T17:14:09.288Z,1494522849.288 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-05-11T17:14:09.288Z,1494522849.288 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2017-05-11T17:14:09.288Z,1494522849.288 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2017-05-11T17:14:09.336Z,1494522849.336 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2017-05-11T17:14:09.336Z,1494522849.336 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2017-05-11T17:14:09.701Z,1494522849.701 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2017-05-11T17:14:09.701Z,1494522849.701 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2017-05-11T17:14:09.701Z,1494522849.701 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2017-05-11T17:14:09.701Z,1494522849.701 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2017-05-11T17:14:10.098Z,1494522850.098 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-05-11T17:14:10.098Z,1494522850.098 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-05-11T17:14:10.098Z,1494522850.099 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-05-11T17:14:10.099Z,1494522850.099 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-05-11T17:14:10.099Z,1494522850.099 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-05-11T17:14:10.104Z,1494522850.104 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-05-11T17:14:13.634Z,1494522853.634 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20170505T161046/Express0005.lzma 2017-05-11T17:14:14.386Z,1494522854.386 [DataOverHttps](INFO): Moved sent file to Logs/20170505T161046/Express0005.lzma.bak 2017-05-11T17:14:14.386Z,1494522854.386 [DataOverHttps](INFO): SBD MOMSN=5021995 2017-05-11T17:14:23.861Z,1494522863.861 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170505T161046/Express0009.lzma 2017-05-11T17:14:24.627Z,1494522864.627 [DataOverHttps](INFO): Moved sent file to Logs/20170505T161046/Express0009.lzma.bak 2017-05-11T17:14:24.627Z,1494522864.627 [DataOverHttps](INFO): SBD MOMSN=5022000 2017-05-11T17:14:34.163Z,1494522874.163 [DataOverHttps](INFO): Sending 759 bytes from file Logs/20170505T163101/Express0001.lzma 2017-05-11T17:14:34.926Z,1494522874.926 [DataOverHttps](INFO): Moved sent file to Logs/20170505T163101/Express0001.lzma.bak 2017-05-11T17:14:34.926Z,1494522874.926 [DataOverHttps](INFO): SBD MOMSN=5022002 2017-05-11T17:14:34.981Z,1494522874.981 [PNI_TCM](ERROR): CRC does not match. Expected:0x30129 got:0x39626 2017-05-11T17:14:44.414Z,1494522884.414 [DataOverHttps](INFO): Sending 108 bytes from file Logs/20170505T163101/Express0005.lzma 2017-05-11T17:14:45.182Z,1494522885.182 [DataOverHttps](INFO): Moved sent file to Logs/20170505T163101/Express0005.lzma.bak 2017-05-11T17:14:45.182Z,1494522885.182 [DataOverHttps](INFO): SBD MOMSN=5022014 2017-05-11T17:14:55.486Z,1494522895.486 [DataOverHttps](INFO): Sending 304 bytes from file Logs/20170505T163101/Express0009.lzma 2017-05-11T17:14:56.238Z,1494522896.238 [DataOverHttps](INFO): Moved sent file to Logs/20170505T163101/Express0009.lzma.bak 2017-05-11T17:14:56.238Z,1494522896.238 [DataOverHttps](INFO): SBD MOMSN=5022017 2017-05-11T17:15:05.888Z,1494522905.888 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170505T163101/Express0013.lzma 2017-05-11T17:15:06.649Z,1494522906.649 [DataOverHttps](INFO): Moved sent file to Logs/20170505T163101/Express0013.lzma.bak 2017-05-11T17:15:06.650Z,1494522906.650 [DataOverHttps](INFO): SBD MOMSN=5022025 2017-05-11T17:15:16.388Z,1494522916.388 [DataOverHttps](INFO): Sending 673 bytes from file Logs/20170505T165456/Express0001.lzma 2017-05-11T17:15:17.130Z,1494522917.130 [DataOverHttps](INFO): Moved sent file to Logs/20170505T165456/Express0001.lzma.bak 2017-05-11T17:15:17.130Z,1494522917.130 [DataOverHttps](INFO): SBD MOMSN=5022027 2017-05-11T17:15:21.889Z,1494522921.889 [NAL9602](FAULT): GPS failed to acquire within timeout. 2017-05-11T17:15:21.889Z,1494522921.889 [NAL9602] Data Fault, FailCount= 1 2017-05-11T17:15:21.889Z,1494522921.889 [NAL9602](ERROR): Data Fault 2017-05-11T17:15:22.017Z,1494522922.017 [CBIT](ERROR): Data Fault in component: NAL9602 2017-05-11T17:15:22.329Z,1494522922.329 [NAL9602](INFO): Powering down 2017-05-11T17:15:23.223Z,1494522923.223 [CBIT](INFO): Clearing failed state for component NAL9602 2017-05-11T17:15:23.228Z,1494522923.228 [NAL9602] No Fault, FailCount= 1 2017-05-11T17:15:26.902Z,1494522926.902 [DataOverHttps](INFO): Sending 280 bytes from file Logs/20170505T165456/Express0005.lzma 2017-05-11T17:15:27.673Z,1494522927.673 [DataOverHttps](INFO): Moved sent file to Logs/20170505T165456/Express0005.lzma.bak 2017-05-11T17:15:27.674Z,1494522927.674 [DataOverHttps](INFO): SBD MOMSN=5022039 2017-05-11T17:15:27.716Z,1494522927.716 [NAL9602](INFO): Powering up NAL9602 2017-05-11T17:15:37.082Z,1494522937.082 [DataOverHttps](INFO): Sending 297 bytes from file Logs/20170505T165456/Express0009.lzma 2017-05-11T17:15:37.810Z,1494522937.810 [DataOverHttps](INFO): Moved sent file to Logs/20170505T165456/Express0009.lzma.bak 2017-05-11T17:15:37.810Z,1494522937.810 [DataOverHttps](INFO): SBD MOMSN=5022043 2017-05-11T17:15:42.028Z,1494522942.028 [NAL9602](INFO): NAL9602 initialized 2017-05-11T17:15:45.392Z,1494522945.392 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2017-05-11T17:15:45.392Z,1494522945.392 [Rowe_600LCM] Communications Fault, FailCount= 4 2017-05-11T17:15:45.392Z,1494522945.392 [Rowe_600LCM](ERROR): Communications Fault 2017-05-11T17:15:45.796Z,1494522945.796 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2017-05-11T17:15:45.969Z,1494522945.969 [Rowe_600LCM](INFO): Powering down 2017-05-11T17:15:47.272Z,1494522947.272 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.5 s old, using for 20.0 s. 2017-05-11T17:15:47.319Z,1494522947.319 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2017-05-11T17:15:47.320Z,1494522947.320 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2017-05-11T17:15:47.321Z,1494522947.321 [Rowe_600LCM] No Fault, FailCount= 4 2017-05-11T17:15:47.357Z,1494522947.358 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170505T165456/Express0013.lzma 2017-05-11T17:15:47.418Z,1494522947.418 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s. 2017-05-11T17:15:47.585Z,1494522947.585 [Rowe_600LCM](INFO): Initializing 2017-05-11T17:15:47.586Z,1494522947.586 [Rowe_600LCM](INFO): Checking LCM 2017-05-11T17:15:47.586Z,1494522947.586 [Rowe_600LCM](INFO): LCM OK 2017-05-11T17:15:47.586Z,1494522947.586 [Rowe_600LCM](INFO): Powering up 2017-05-11T17:15:47.800Z,1494522947.800 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.0 s old, using for 20.0 s. 2017-05-11T17:15:48.134Z,1494522948.134 [DataOverHttps](INFO): Moved sent file to Logs/20170505T165456/Express0013.lzma.bak 2017-05-11T17:15:48.134Z,1494522948.134 [DataOverHttps](INFO): SBD MOMSN=5022050 2017-05-11T17:15:48.213Z,1494522948.213 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s. 2017-05-11T17:15:48.918Z,1494522948.918 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.1 s old, using for 20.0 s. 2017-05-11T17:15:49.061Z,1494522949.061 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 5.2 s old, using for 20.0 s. 2017-05-11T17:15:51.796Z,1494522951.796 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2017-05-11T17:15:51.911Z,1494522951.911 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 38400 >& /dev/null & 2017-05-11T17:15:51.912Z,1494522951.912 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2017-05-11T17:15:51.914Z,1494522951.914 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2017-05-11T17:15:51.915Z,1494522951.915 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2017-05-11T17:15:57.971Z,1494522957.971 [DataOverHttps](INFO): Sending 664 bytes from file Logs/20170505T171645/Express0001.lzma 2017-05-11T17:15:58.714Z,1494522958.714 [DataOverHttps](INFO): Moved sent file to Logs/20170505T171645/Express0001.lzma.bak 2017-05-11T17:15:58.714Z,1494522958.714 [DataOverHttps](INFO): SBD MOMSN=5022052 2017-05-11T17:16:03.075Z,1494522963.075 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:16:03.075Z,1494522963.075 [MassServo] No Fault, FailCount= 5 2017-05-11T17:16:08.482Z,1494522968.482 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20170505T171645/Express0005.lzma 2017-05-11T17:16:08.596Z,1494522968.596 [MassServo](FAULT): Overload Error 2017-05-11T17:16:08.596Z,1494522968.596 [MassServo] Hardware Fault, FailCount= 1 2017-05-11T17:16:08.596Z,1494522968.596 [MassServo](ERROR): Hardware Fault 2017-05-11T17:16:08.684Z,1494522968.684 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:16:08.936Z,1494522968.936 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:16:08.936Z,1494522968.936 [MassServo](INFO): Powering down 2017-05-11T17:16:09.266Z,1494522969.266 [DataOverHttps](INFO): Moved sent file to Logs/20170505T171645/Express0005.lzma.bak 2017-05-11T17:16:09.266Z,1494522969.266 [DataOverHttps](INFO): SBD MOMSN=5022063 2017-05-11T17:16:09.919Z,1494522969.919 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:16:09.919Z,1494522969.919 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:16:09.933Z,1494522969.933 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:16:09.933Z,1494522969.933 [MassServo] No Fault, FailCount= 1 2017-05-11T17:16:18.905Z,1494522978.905 [DataOverHttps](INFO): Sending 301 bytes from file Logs/20170505T171645/Express0009.lzma 2017-05-11T17:16:19.012Z,1494522979.012 [MassServo](FAULT): Overload Error 2017-05-11T17:16:19.012Z,1494522979.012 [MassServo] Hardware Fault, FailCount= 2 2017-05-11T17:16:19.012Z,1494522979.012 [MassServo](ERROR): Hardware Fault 2017-05-11T17:16:19.017Z,1494522979.017 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:16:19.329Z,1494522979.329 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:16:19.329Z,1494522979.329 [MassServo](INFO): Powering down 2017-05-11T17:16:19.661Z,1494522979.661 [DataOverHttps](INFO): Moved sent file to Logs/20170505T171645/Express0009.lzma.bak 2017-05-11T17:16:19.661Z,1494522979.661 [DataOverHttps](INFO): SBD MOMSN=5022067 2017-05-11T17:16:20.305Z,1494522980.305 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:16:20.305Z,1494522980.305 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:16:20.310Z,1494522980.310 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:16:20.310Z,1494522980.310 [MassServo] No Fault, FailCount= 2 2017-05-11T17:16:29.277Z,1494522989.277 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170505T171645/Express0013.lzma 2017-05-11T17:16:29.460Z,1494522989.460 [MassServo](FAULT): Overload Error 2017-05-11T17:16:29.460Z,1494522989.460 [MassServo] Hardware Fault, FailCount= 3 2017-05-11T17:16:29.460Z,1494522989.460 [MassServo](ERROR): Hardware Fault 2017-05-11T17:16:29.549Z,1494522989.549 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:16:29.737Z,1494522989.737 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:16:29.737Z,1494522989.737 [MassServo](INFO): Powering down 2017-05-11T17:16:30.050Z,1494522990.050 [DataOverHttps](INFO): Moved sent file to Logs/20170505T171645/Express0013.lzma.bak 2017-05-11T17:16:30.050Z,1494522990.050 [DataOverHttps](INFO): SBD MOMSN=5022075 2017-05-11T17:16:30.850Z,1494522990.850 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:16:30.851Z,1494522990.851 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:16:30.856Z,1494522990.856 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:16:30.856Z,1494522990.856 [MassServo] No Fault, FailCount= 3 2017-05-11T17:16:39.616Z,1494522999.616 [DataOverHttps](INFO): Sending 670 bytes from file Logs/20170505T173358/Express0001.lzma 2017-05-11T17:16:39.708Z,1494522999.708 [MassServo](FAULT): Overload Error 2017-05-11T17:16:39.708Z,1494522999.708 [MassServo] Hardware Fault, FailCount= 4 2017-05-11T17:16:39.708Z,1494522999.708 [MassServo](ERROR): Hardware Fault 2017-05-11T17:16:39.713Z,1494522999.713 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:16:40.096Z,1494523000.096 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:16:40.096Z,1494523000.096 [MassServo](INFO): Powering down 2017-05-11T17:16:40.410Z,1494523000.410 [DataOverHttps](INFO): Moved sent file to Logs/20170505T173358/Express0001.lzma.bak 2017-05-11T17:16:40.410Z,1494523000.410 [DataOverHttps](INFO): SBD MOMSN=5022077 2017-05-11T17:16:41.203Z,1494523001.203 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:16:41.203Z,1494523001.203 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:16:41.228Z,1494523001.228 [CBIT](INFO): Clearing failed state for component MassServo 2017-05-11T17:16:41.228Z,1494523001.228 [MassServo] No Fault, FailCount= 4 2017-05-11T17:16:49.946Z,1494523009.946 [DataOverHttps](INFO): Sending 227 bytes from file Logs/20170505T173358/Express0005.lzma 2017-05-11T17:16:50.096Z,1494523010.096 [MassServo](FAULT): Overload Error 2017-05-11T17:16:50.096Z,1494523010.096 [MassServo] Hardware Fault, FailCount= 5 2017-05-11T17:16:50.096Z,1494523010.096 [MassServo](ERROR): Hardware Fault 2017-05-11T17:16:50.184Z,1494523010.184 [CBIT](ERROR): Hardware Fault in component: MassServo 2017-05-11T17:16:50.185Z,1494523010.185 [CBIT](CRITICAL): Hardware Fault in component: MassServo 2017-05-11T17:16:50.346Z,1494523010.346 [MassServo](DEBUG): Uninitialize Mass Servo. 2017-05-11T17:16:50.346Z,1494523010.346 [MassServo](INFO): Powering down 2017-05-11T17:16:50.350Z,1494523010.349 [CBIT](INFO): Critical error at 20170511T171650 2017-05-11T17:16:50.658Z,1494523010.658 [DataOverHttps](INFO): Moved sent file to Logs/20170505T173358/Express0005.lzma.bak 2017-05-11T17:16:50.658Z,1494523010.658 [DataOverHttps](INFO): SBD MOMSN=5022089 2017-05-11T17:16:51.356Z,1494523011.356 [MassServo](DEBUG): Initializing EZServoServo. 2017-05-11T17:16:51.357Z,1494523011.357 [MassServo](DEBUG): Initializing MassServo. 2017-05-11T17:17:00.245Z,1494523020.245 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170505T173358/Express0009.lzma 2017-05-11T17:17:01.030Z,1494523021.030 [DataOverHttps](INFO): Moved sent file to Logs/20170505T173358/Express0009.lzma.bak 2017-05-11T17:17:01.030Z,1494523021.030 [DataOverHttps](INFO): SBD MOMSN=5022092 2017-05-11T17:17:10.451Z,1494523030.451 [DeadReckonUsingMultipleVelocitySources](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-05-11T17:17:10.452Z,1494523030.452 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2017-05-11T17:17:10.452Z,1494523030.452 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2017-05-11T17:17:10.454Z,1494523030.454 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan 2017-05-11T17:17:10.454Z,1494523030.454 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4 2017-05-11T17:17:10.454Z,1494523030.454 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2017-05-11T17:17:10.499Z,1494523030.499 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2017-05-11T17:17:10.499Z,1494523030.499 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2017-05-11T17:17:10.548Z,1494523030.547 [DataOverHttps](INFO): Sending 758 bytes from file Logs/20170505T174408/Express0001.lzma 2017-05-11T17:17:10.642Z,1494523030.642 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2017-05-11T17:17:10.642Z,1494523030.642 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2017-05-11T17:17:10.642Z,1494523030.642 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2017-05-11T17:17:10.642Z,1494523030.642 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4 2017-05-11T17:17:10.977Z,1494523030.977 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component. 2017-05-11T17:17:10.978Z,1494523030.978 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s. 2017-05-11T17:17:10.978Z,1494523030.978 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s. 2017-05-11T17:17:10.978Z,1494523030.978 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2017-05-11T17:17:10.979Z,1494523030.979 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2017-05-11T17:17:10.979Z,1494523030.979 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2017-05-11T17:17:11.328Z,1494523031.328 [DataOverHttps](INFO): Moved sent file to Logs/20170505T174408/Express0001.lzma.bak 2017-05-11T17:17:11.329Z,1494523031.329 [DataOverHttps](INFO): SBD MOMSN=5022094 2017-05-11T17:17:21.042Z,1494523041.042 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20170505T174408/Express0005.lzma 2017-05-11T17:17:21.778Z,1494523041.778 [DataOverHttps](INFO): Moved sent file to Logs/20170505T174408/Express0005.lzma.bak 2017-05-11T17:17:21.778Z,1494523041.778 [DataOverHttps](INFO): SBD MOMSN=5022106 2017-05-11T17:17:34.800Z,1494523054.800 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20170505T174408/Express0009.lzma 2017-05-11T17:17:35.590Z,1494523055.590 [DataOverHttps](INFO): Moved sent file to Logs/20170505T174408/Express0009.lzma.bak 2017-05-11T17:17:35.590Z,1494523055.590 [DataOverHttps](INFO): SBD MOMSN=5022110 2017-05-11T17:17:45.187Z,1494523065.187 [DataOverHttps](INFO): Sending 672 bytes from file Logs/20170505T175749/Express0001.lzma 2017-05-11T17:17:45.950Z,1494523065.950 [DataOverHttps](INFO): Moved sent file to Logs/20170505T175749/Express0001.lzma.bak 2017-05-11T17:17:45.950Z,1494523065.950 [DataOverHttps](INFO): SBD MOMSN=5022112 2017-05-11T17:17:47.861Z,1494523067.861 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2017-05-11T17:17:47.862Z,1494523067.862 [Rowe_600LCM] Communications Fault, FailCount= 5 2017-05-11T17:17:47.862Z,1494523067.862 [Rowe_600LCM](ERROR): Communications Fault 2017-05-11T17:17:48.264Z,1494523068.264 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2017-05-11T17:17:48.437Z,1494523068.437 [Rowe_600LCM](INFO): Powering down 2017-05-11T17:17:50.317Z,1494523070.318 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.5 s old, using for 20.0 s. 2017-05-11T17:17:50.333Z,1494523070.333 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2017-05-11T17:17:50.333Z,1494523070.333 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM 2017-05-11T17:17:50.456Z,1494523070.456 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 3.6 s old, using for 20.0 s. 2017-05-11T17:17:50.860Z,1494523070.861 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.1 s old, using for 20.0 s. 2017-05-11T17:17:51.218Z,1494523071.218 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.4 s old, using for 20.0 s. 2017-05-11T17:17:51.638Z,1494523071.638 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom track data is 4.8 s old, using for 20.0 s. 2017-05-11T17:17:52.022Z,1494523072.022 [DeadReckonUsingMultipleVelocitySources](DEBUG): Bottom