2018-07-11T15:19:14.390Z,1531322354.390 [Supervisor](DEBUG): Initializing supervisor. 2018-07-11T15:19:14.392Z,1531322354.392 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2018-07-11T15:19:14.393Z,1531322354.393 [SyncHandler](INFO): Protected caller Thread ID is 797 2018-07-11T15:19:14.393Z,1531322354.393 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2018-07-11T15:19:14.394Z,1531322354.394 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2018-07-11T15:19:14.395Z,1531322354.395 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 798 2018-07-11T15:19:14.397Z,1531322354.397 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2018-07-11T15:19:14.409Z,1531322354.409 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2018-07-11T15:19:14.410Z,1531322354.410 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2018-07-11T15:19:14.410Z,1531322354.410 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 799 2018-07-11T15:19:14.411Z,1531322354.411 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2018-07-11T15:19:14.412Z,1531322354.412 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2018-07-11T15:19:14.412Z,1531322354.412 [logger ThreadHandler](INFO): Protected caller Thread ID is 800 2018-07-11T15:19:14.414Z,1531322354.414 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2018-07-11T15:19:14.415Z,1531322354.415 [Supervisor](INFO): Looking for Config files in directory: Config/ 2018-07-11T15:19:14.419Z,1531322354.419 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2018-07-11T15:19:14.768Z,1531322354.768 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2018-07-11T15:19:14.770Z,1531322354.770 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2018-07-11T15:19:14.996Z,1531322354.996 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2018-07-11T15:19:14.997Z,1531322354.997 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2018-07-11T15:19:15.326Z,1531322355.326 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2018-07-11T15:19:15.328Z,1531322355.328 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2018-07-11T15:19:15.471Z,1531322355.471 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2018-07-11T15:19:15.472Z,1531322355.472 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2018-07-11T15:19:15.572Z,1531322355.572 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2018-07-11T15:19:15.573Z,1531322355.573 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2018-07-11T15:19:16.061Z,1531322356.061 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2018-07-11T15:19:16.063Z,1531322356.063 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2018-07-11T15:19:16.467Z,1531322356.467 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2018-07-11T15:19:16.469Z,1531322356.469 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2018-07-11T15:19:16.935Z,1531322356.935 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2018-07-11T15:19:16.936Z,1531322356.936 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2018-07-11T15:19:17.044Z,1531322357.044 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2018-07-11T15:19:17.044Z,1531322357.044 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2018-07-11T15:19:17.144Z,1531322357.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2018-07-11T15:19:17.145Z,1531322357.145 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2018-07-11T15:19:17.365Z,1531322357.365 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2018-07-11T15:19:17.366Z,1531322357.366 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2018-07-11T15:19:17.582Z,1531322357.582 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2018-07-11T15:19:17.582Z,1531322357.582 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2018-07-11T15:19:17.946Z,1531322357.946 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2018-07-11T15:19:17.947Z,1531322357.947 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2018-07-11T15:19:18.094Z,1531322358.094 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2018-07-11T15:19:18.095Z,1531322358.095 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2018-07-11T15:19:19.008Z,1531322359.008 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2018-07-11T15:19:19.011Z,1531322359.011 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2018-07-11T15:19:19.118Z,1531322359.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2018-07-11T15:19:19.240Z,1531322359.240 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2018-07-11T15:19:19.337Z,1531322359.337 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2018-07-11T15:19:19.423Z,1531322359.423 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2018-07-11T15:19:19.580Z,1531322359.580 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2018-07-11T15:19:19.764Z,1531322359.764 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2018-07-11T15:19:19.842Z,1531322359.842 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2018-07-11T15:19:20.076Z,1531322360.076 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2018-07-11T15:19:20.077Z,1531322360.077 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2018-07-11T15:19:20.161Z,1531322360.161 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2018-07-11T15:19:20.253Z,1531322360.253 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2018-07-11T15:19:20.356Z,1531322360.356 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2018-07-11T15:19:20.485Z,1531322360.485 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2018-07-11T15:19:20.498Z,1531322360.498 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2018-07-11T15:19:20.777Z,1531322360.777 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2018-07-11T15:19:20.779Z,1531322360.779 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2018-07-11T15:19:20.835Z,1531322360.835 [DepthRateCalculator] Loaded 2018-07-11T15:19:20.836Z,1531322360.836 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2018-07-11T15:19:20.842Z,1531322360.842 [PitchRateCalculator] Loaded 2018-07-11T15:19:20.842Z,1531322360.842 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2018-07-11T15:19:20.859Z,1531322360.859 [SpeedCalculator] Loaded 2018-07-11T15:19:20.859Z,1531322360.859 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2018-07-11T15:19:20.880Z,1531322360.880 [TempGradientCalculator] Loaded 2018-07-11T15:19:20.880Z,1531322360.880 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2018-07-11T15:19:20.896Z,1531322360.896 [VerticalTemperatureHomogeneityIndexCalculator] Loaded 2018-07-11T15:19:20.896Z,1531322360.896 [ComponentRegistry](DEBUG): SyncComponent "VerticalTemperatureHomogeneityIndexCalculator" handled in the control thread. 2018-07-11T15:19:20.902Z,1531322360.902 [YawRateCalculator] Loaded 2018-07-11T15:19:20.902Z,1531322360.902 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2018-07-11T15:19:20.942Z,1531322360.942 [ElevatorOffsetCalculator] Loaded 2018-07-11T15:19:20.943Z,1531322360.943 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2018-07-11T15:19:20.943Z,1531322360.943 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2018-07-11T15:19:20.944Z,1531322360.944 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2018-07-11T15:19:21.064Z,1531322361.064 [StratificationFrontDetector](INFO): threshold set to: 0.399988 degC 2018-07-11T15:19:21.064Z,1531322361.064 [StratificationFrontDetector](DEBUG): (re)initializing 2018-07-11T15:19:21.064Z,1531322361.064 [StratificationFrontDetector] Loaded 2018-07-11T15:19:21.065Z,1531322361.065 [ComponentRegistry](DEBUG): SyncComponent "StratificationFrontDetector" handled in the control thread. 2018-07-11T15:19:21.065Z,1531322361.065 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2018-07-11T15:19:21.066Z,1531322361.066 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2018-07-11T15:19:21.202Z,1531322361.202 [BuoyancyServo] Loaded 2018-07-11T15:19:21.203Z,1531322361.203 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2018-07-11T15:19:21.218Z,1531322361.218 [ElevatorServo] Loaded 2018-07-11T15:19:21.218Z,1531322361.218 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2018-07-11T15:19:21.232Z,1531322361.232 [MassServo] Loaded 2018-07-11T15:19:21.233Z,1531322361.233 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2018-07-11T15:19:21.248Z,1531322361.248 [RudderServo] Loaded 2018-07-11T15:19:21.248Z,1531322361.248 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2018-07-11T15:19:21.263Z,1531322361.263 [ThrusterServo] Loaded 2018-07-11T15:19:21.263Z,1531322361.263 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2018-07-11T15:19:21.264Z,1531322361.264 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2018-07-11T15:19:21.264Z,1531322361.264 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2018-07-11T15:19:21.288Z,1531322361.288 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2018-07-11T15:19:21.289Z,1531322361.289 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2018-07-11T15:19:21.414Z,1531322361.414 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2018-07-11T15:19:21.415Z,1531322361.415 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2018-07-11T15:19:21.976Z,1531322361.976 [DataOverHttps] Loaded 2018-07-11T15:19:21.976Z,1531322361.976 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread. 2018-07-11T15:19:21.990Z,1531322361.990 [Depth_Keller] Loaded 2018-07-11T15:19:21.990Z,1531322361.990 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2018-07-11T15:19:21.995Z,1531322361.995 [DropWeight] Loaded 2018-07-11T15:19:21.996Z,1531322361.996 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2018-07-11T15:19:22.094Z,1531322362.094 [NAL9602] Loaded 2018-07-11T15:19:22.095Z,1531322362.095 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2018-07-11T15:19:22.111Z,1531322362.111 [Onboard] Loaded 2018-07-11T15:19:22.111Z,1531322362.111 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2018-07-11T15:19:22.121Z,1531322362.121 [Radio_Surface] Loaded 2018-07-11T15:19:22.122Z,1531322362.122 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2018-07-11T15:19:22.123Z,1531322362.123 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408844E0 2018-07-11T15:19:22.123Z,1531322362.123 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 883 2018-07-11T15:19:22.417Z,1531322362.417 [PNI_TCM] Loaded 2018-07-11T15:19:22.417Z,1531322362.417 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2018-07-11T15:19:22.550Z,1531322362.550 [Rowe_600LCM] Loaded 2018-07-11T15:19:22.550Z,1531322362.550 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2018-07-11T15:19:22.551Z,1531322362.551 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408B44E0 2018-07-11T15:19:22.551Z,1531322362.551 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 884 2018-07-11T15:19:24.931Z,1531322364.931 [BPC1] Loaded 2018-07-11T15:19:24.932Z,1531322364.932 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2018-07-11T15:19:24.932Z,1531322364.932 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2018-07-11T15:19:24.933Z,1531322364.933 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2018-07-11T15:19:25.086Z,1531322365.086 [SBIT](DEBUG): Construct Startup Built In Test. 2018-07-11T15:19:25.109Z,1531322365.109 [SBIT] Loaded 2018-07-11T15:19:25.109Z,1531322365.109 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2018-07-11T15:19:25.110Z,1531322365.110 [IBIT](DEBUG): Construct Initiated Built In Test. 2018-07-11T15:19:25.121Z,1531322365.121 [IBIT] Loaded 2018-07-11T15:19:25.122Z,1531322365.122 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2018-07-11T15:19:25.125Z,1531322365.125 [CBIT](DEBUG): Construct Continuous Built In Test. 2018-07-11T15:19:25.277Z,1531322365.277 [CBIT] Loaded 2018-07-11T15:19:25.277Z,1531322365.277 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2018-07-11T15:19:25.277Z,1531322365.277 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2018-07-11T15:19:25.278Z,1531322365.278 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2018-07-11T15:19:25.466Z,1531322365.466 [Aanderaa_O2] Loaded 2018-07-11T15:19:25.467Z,1531322365.467 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2018-07-11T15:19:25.545Z,1531322365.545 [CTD_NeilBrown] Loaded 2018-07-11T15:19:25.545Z,1531322365.545 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2018-07-11T15:19:25.547Z,1531322365.547 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409754E0 2018-07-11T15:19:25.547Z,1531322365.547 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 885 2018-07-11T15:19:25.594Z,1531322365.594 [CTD_Seabird] Loaded 2018-07-11T15:19:25.594Z,1531322365.594 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2018-07-11T15:19:25.595Z,1531322365.595 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409A54E0 2018-07-11T15:19:25.595Z,1531322365.595 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 886 2018-07-11T15:19:25.610Z,1531322365.610 [PAR_Licor] Loaded 2018-07-11T15:19:25.610Z,1531322365.610 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2018-07-11T15:19:25.660Z,1531322365.660 [WetLabsBB2FL] Loaded 2018-07-11T15:19:25.661Z,1531322365.661 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2018-07-11T15:19:25.662Z,1531322365.662 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409D54E0 2018-07-11T15:19:25.662Z,1531322365.662 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 887 2018-07-11T15:19:25.663Z,1531322365.663 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2018-07-11T15:19:25.663Z,1531322365.663 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2018-07-11T15:19:25.751Z,1531322365.751 [VerticalControl](DEBUG): Construct VerticalControl. 2018-07-11T15:19:25.837Z,1531322365.837 [VerticalControl] Loaded 2018-07-11T15:19:25.837Z,1531322365.837 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2018-07-11T15:19:25.838Z,1531322365.838 [HorizontalControl](DEBUG): Construct HorizontalControl. 2018-07-11T15:19:25.896Z,1531322365.896 [HorizontalControl] Loaded 2018-07-11T15:19:25.896Z,1531322365.896 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2018-07-11T15:19:25.897Z,1531322365.897 [SpeedControl](DEBUG): Construct SpeedControl. 2018-07-11T15:19:25.899Z,1531322365.899 [SpeedControl] Loaded 2018-07-11T15:19:25.899Z,1531322365.899 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2018-07-11T15:19:25.900Z,1531322365.900 [LoopControl](DEBUG): Construct LoopControl. 2018-07-11T15:19:25.900Z,1531322365.900 [LoopControl] Loaded 2018-07-11T15:19:25.901Z,1531322365.901 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2018-07-11T15:19:25.901Z,1531322365.901 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2018-07-11T15:19:25.902Z,1531322365.902 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2018-07-11T15:19:25.939Z,1531322365.939 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2018-07-11T15:19:25.940Z,1531322365.940 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2018-07-11T15:19:26.048Z,1531322366.048 [DeadReckonUsingSpeedCalculator] Loaded 2018-07-11T15:19:26.048Z,1531322366.048 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2018-07-11T15:19:26.065Z,1531322366.065 [NavChart] Loaded 2018-07-11T15:19:26.065Z,1531322366.065 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2018-07-11T15:19:26.069Z,1531322366.069 [UniversalFixResidualReporter] Loaded 2018-07-11T15:19:26.070Z,1531322366.070 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2018-07-11T15:19:26.070Z,1531322366.070 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2018-07-11T15:19:26.074Z,1531322366.074 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2018-07-11T15:19:26.074Z,1531322366.074 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2018-07-11T15:19:26.081Z,1531322366.081 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2018-07-11T15:19:26.082Z,1531322366.082 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40A614E0 2018-07-11T15:19:26.083Z,1531322366.083 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 888 2018-07-11T15:19:26.087Z,1531322366.087 [Supervisor](INFO): Main Thread ID is 796 2018-07-11T15:19:26.087Z,1531322366.087 [Supervisor](DEBUG): Running supervisor. 2018-07-11T15:19:26.088Z,1531322366.088 [CommandLine ThreadHandler](INFO): Handler Thread ID is 889 2018-07-11T15:19:26.090Z,1531322366.090 [controlThread ThreadHandler](INFO): Handler Thread ID is 890 2018-07-11T15:19:26.091Z,1531322366.091 [controlThread](DEBUG): Initializing ControlThread 2018-07-11T15:19:26.092Z,1531322366.092 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2018-07-11T15:19:26.092Z,1531322366.092 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2018-07-11T15:19:26.092Z,1531322366.092 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2018-07-11T15:19:26.093Z,1531322366.093 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2018-07-11T15:19:26.093Z,1531322366.093 [VerticalTemperatureHomogeneityIndexCalculator](DEBUG): (re)initializing 2018-07-11T15:19:26.094Z,1531322366.094 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2018-07-11T15:19:26.095Z,1531322366.095 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2018-07-11T15:19:26.104Z,1531322366.104 [SBIT](INFO): Initialize SBIT Component. 2018-07-11T15:19:26.104Z,1531322366.104 [SBIT](IMPORTANT): git: 2018-06-03 2018-07-11T15:19:26.104Z,1531322366.104 [SBIT](INFO): git hash: e89e4219fcae2edd415aee450018ea5d8b44159b 2018-07-11T15:19:26.105Z,1531322366.105 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2018-07-11T15:19:26.106Z,1531322366.106 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #639 PREEMPT Wed Mar 12 12:53:33 PDT 2014 Kernel Reported: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 2018-07-11T15:19:26.107Z,1531322366.107 [SBIT](INFO): Beginning SBIT in 41.000000 seconds. 2018-07-11T15:19:26.108Z,1531322366.108 [IBIT](INFO): Initialize IBIT Component. 2018-07-11T15:19:26.109Z,1531322366.109 [CBIT](DEBUG): Initialize CBIT Component. 2018-07-11T15:19:26.109Z,1531322366.109 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2018-07-11T15:19:26.110Z,1531322366.110 [logger ThreadHandler](INFO): Handler Thread ID is 891 2018-07-11T15:19:26.129Z,1531322366.129 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 892 2018-07-11T15:19:26.135Z,1531322366.135 [Radio_Surface](INFO): Powering up 2018-07-11T15:19:26.141Z,1531322366.141 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 893 2018-07-11T15:19:26.142Z,1531322366.142 [Rowe_600LCM](INFO): Initializing 2018-07-11T15:19:26.142Z,1531322366.142 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T15:19:26.221Z,1531322366.221 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2018-07-11T15:19:26.223Z,1531322366.223 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2018-07-11T15:19:26.224Z,1531322366.224 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2018-07-11T15:19:26.224Z,1531322366.224 [LoopControl](DEBUG): Initialize LoopControlComponent. 2018-07-11T15:19:26.225Z,1531322366.225 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2018-07-11T15:19:26.226Z,1531322366.226 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s. 2018-07-11T15:19:26.226Z,1531322366.226 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s. 2018-07-11T15:19:26.226Z,1531322366.226 [NavChart](DEBUG): Initialize NavChart Navigation. 2018-07-11T15:19:26.227Z,1531322366.227 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2018-07-11T15:19:26.260Z,1531322366.260 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2018-07-11T15:19:26.271Z,1531322366.271 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 894 2018-07-11T15:19:26.272Z,1531322366.272 [CTD_NeilBrown](INFO): Powering down 2018-07-11T15:19:26.287Z,1531322366.287 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 895 2018-07-11T15:19:26.287Z,1531322366.287 [CTD_Seabird](INFO): Initializing 2018-07-11T15:19:26.290Z,1531322366.290 [CTD_Seabird](INFO): Checking LCM 2018-07-11T15:19:26.417Z,1531322366.417 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 896 2018-07-11T15:19:26.418Z,1531322366.418 [WetLabsBB2FL](INFO): Powering down 2018-07-11T15:19:26.438Z,1531322366.438 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 897 2018-07-11T15:19:26.450Z,1531322366.450 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2018-07-11T15:19:26.451Z,1531322366.451 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2018-07-11T15:19:26.451Z,1531322366.451 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2018-07-11T15:19:26.451Z,1531322366.451 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2018-07-11T15:19:26.451Z,1531322366.451 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2018-07-11T15:19:26.451Z,1531322366.451 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2018-07-11T15:19:26.452Z,1531322366.452 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2018-07-11T15:19:26.452Z,1531322366.452 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2018-07-11T15:19:26.452Z,1531322366.452 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2018-07-11T15:19:26.452Z,1531322366.452 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2018-07-11T15:19:26.453Z,1531322366.453 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2018-07-11T15:19:26.453Z,1531322366.453 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2018-07-11T15:19:26.453Z,1531322366.453 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2018-07-11T15:19:26.453Z,1531322366.453 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2018-07-11T15:19:26.454Z,1531322366.454 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2018-07-11T15:19:26.454Z,1531322366.454 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2018-07-11T15:19:26.545Z,1531322366.545 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2018-07-11T15:19:26.642Z,1531322366.642 [MissionManager](DEBUG): 2018-07-11T15:19:26.642Z,1531322366.642 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2018-07-11T15:19:26.676Z,1531322366.676 [CTD_Seabird](INFO): LCM OK 2018-07-11T15:19:26.676Z,1531322366.676 [CTD_Seabird](INFO): Powering up 2018-07-11T15:19:26.676Z,1531322366.676 [Rowe_600LCM](INFO): LCM OK 2018-07-11T15:19:26.676Z,1531322366.676 [Rowe_600LCM](INFO): Powering up 2018-07-11T15:19:26.736Z,1531322366.736 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2018-07-11T15:19:26.737Z,1531322366.737 [Default:A.Wait](DEBUG): Construct Wait. 2018-07-11T15:19:26.739Z,1531322366.739 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2018-07-11T15:19:26.794Z,1531322366.794 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2018-07-11T15:19:26.797Z,1531322366.797 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2018-07-11T15:19:26.823Z,1531322366.823 [Default:E.Execute](DEBUG): Construct Execute. 2018-07-11T15:19:26.826Z,1531322366.826 [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 2018-07-11T15:19:26.847Z,1531322366.847 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,VerticalTemperatureHomogeneityIndexCalculator,YawRateCalculator,ElevatorOffsetCalculator,StratificationFrontDetector,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2018-07-11T15:19:26.873Z,1531322366.873 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2018-07-11T15:19:26.914Z,1531322366.914 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar 2018-07-11T15:19:27.264Z,1531322367.264 [DepthRateCalculator](ERROR): Depth measurement is not active 2018-07-11T15:19:27.385Z,1531322367.385 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-11T15:19:27.586Z,1531322367.586 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-07-11T15:19:27.593Z,1531322367.593 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-07-11T15:19:27.600Z,1531322367.600 [ElevatorServo](DEBUG): Initializing EZServoServo. 2018-07-11T15:19:27.609Z,1531322367.609 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2018-07-11T15:19:27.635Z,1531322367.635 [MassServo](DEBUG): Initializing EZServoServo. 2018-07-11T15:19:27.641Z,1531322367.641 [MassServo](DEBUG): Initializing MassServo. 2018-07-11T15:19:27.656Z,1531322367.656 [RudderServo](DEBUG): Initializing EZServoServo. 2018-07-11T15:19:27.657Z,1531322367.657 [RudderServo](DEBUG): Initializing RudderServo. 2018-07-11T15:19:27.679Z,1531322367.679 [ThrusterServo](DEBUG): Initializing EZServoServo. 2018-07-11T15:19:27.689Z,1531322367.689 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2018-07-11T15:19:28.006Z,1531322368.006 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-11T15:19:28.247Z,1531322368.247 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-11T15:19:28.585Z,1531322368.585 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2018-07-11T15:19:28.585Z,1531322368.585 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2018-07-11T15:19:28.585Z,1531322368.585 [BuoyancyServo] Communications Fault, FailCount= 1 2018-07-11T15:19:28.585Z,1531322368.585 [BuoyancyServo](ERROR): Communications Fault 2018-07-11T15:19:28.789Z,1531322368.789 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2018-07-11T15:19:28.839Z,1531322368.839 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-11T15:19:28.853Z,1531322368.853 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2018-07-11T15:19:28.854Z,1531322368.854 [BuoyancyServo](INFO): Powering down 2018-07-11T15:19:29.253Z,1531322369.253 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-11T15:19:29.669Z,1531322369.669 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-11T15:19:30.073Z,1531322370.073 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-11T15:19:30.443Z,1531322370.443 [Aanderaa_O2](INFO): Powering down 2018-07-11T15:19:30.536Z,1531322370.536 [DeadReckonUsingSpeedCalculator](DEBUG): Starting up and don't have orientation data yet. 2018-07-11T15:19:30.773Z,1531322370.773 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T15:19:30.908Z,1531322370.908 [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 9600 >& /dev/null & 2018-07-11T15:19:31.054Z,1531322371.054 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T15:19:31.055Z,1531322371.055 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T15:19:31.056Z,1531322371.056 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T15:19:31.090Z,1531322371.090 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2018-07-11T15:19:31.090Z,1531322371.090 [BuoyancyServo] No Fault, FailCount= 1 2018-07-11T15:19:31.342Z,1531322371.342 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2018-07-11T15:19:31.342Z,1531322371.342 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2018-07-11T15:19:32.035Z,1531322372.035 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-07-11T15:19:32.285Z,1531322372.285 [CTD_Seabird](INFO): Started Seabird LCM interface with command:nohup ./lrauv-framework/onboard/bin/gpctd -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyC6 -b 9600 >& /dev/null & 2018-07-11T15:19:32.287Z,1531322372.287 [CTD_Seabird](INFO): LCM subscribed to channel:ctd_t.seabird-gpctd 2018-07-11T15:19:33.029Z,1531322373.029 [CTD_Seabird](INFO): Stopping potential previous instance(s) of CTD_Seabird LCM interface 2018-07-11T15:19:33.038Z,1531322373.038 [CTD_Seabird](INFO): Powering down 2018-07-11T15:19:52.115Z,1531322392.115 [NAL9602](INFO): Powering up NAL9602 2018-07-11T15:20:02.915Z,1531322402.915 [NAL9602](INFO): NAL9602 initialized 2018-07-11T15:20:07.832Z,1531322407.832 [SBIT](IMPORTANT): Beginning Startup BIT 2018-07-11T15:20:07.837Z,1531322407.837 [CBIT](IMPORTANT): Beginning ground fault scan 2018-07-11T15:20:18.790Z,1531322418.790 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.010698 CHAN A1 (24V): -0.013153 CHAN A2 (12V): 4.697929 CHAN A3 (5V): -0.001581 CHAN B0 (3.3V): -0.000411 CHAN B1 (3.15aV): 0.000039 CHAN B2 (3.15bV): -0.000591 CHAN B3 (GND): 0.000118 OPEN: -0.000145 Full Scale Calc: 4.765 mA, -1.589 mA 2018-07-11T15:20:37.288Z,1531322437.288 [NAL9602](INFO): SBD MO Status=2, MOMSN=7224, MT Status=2, MTMSN=0 2018-07-11T15:20:37.288Z,1531322437.288 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-11T15:20:51.864Z,1531322451.864 [NAL9602](INFO): SBD MO Status=2, MOMSN=7224, MT Status=2, MTMSN=0 2018-07-11T15:20:51.865Z,1531322451.865 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-11T15:20:59.502Z,1531322459.502 [BPC1](ERROR): Failed to parse Bank B battery data 2018-07-11T15:21:02.040Z,1531322462.040 [SBIT](IMPORTANT): SBIT PASSED 2018-07-11T15:21:02.142Z,1531322462.142 [CommandLine](IMPORTANT): got command configSet list 2018-07-11T15:21:02.142Z,1531322462.142 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2018-07-11T15:21:02.143Z,1531322462.143 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool; 2018-07-11T15:21:02.143Z,1531322462.143 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=0 bool; 2018-07-11T15:21:02.143Z,1531322462.143 [CommandLine](IMPORTANT): ESPComponent.sampleTimeout=5 minute; 2018-07-11T15:21:02.143Z,1531322462.143 [CommandLine](IMPORTANT): ESPComponent.simulateHardware=0 bool; 2018-07-11T15:21:02.143Z,1531322462.143 [CommandLine](IMPORTANT): Express none Rowe_600LCM.height_above_sea_floor; 2018-07-11T15:21:02.144Z,1531322462.144 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=132 cubic_centimeter; 2018-07-11T15:21:02.144Z,1531322462.144 [CommandLine](IMPORTANT): VerticalControl.massDefault=5.3 millimeter; 2018-07-11T15:21:02.316Z,1531322462.316 [MissionManager](IMPORTANT): Started mission Startup 2018-07-11T15:21:02.316Z,1531322462.316 [Startup] Running Loop=1 2018-07-11T15:21:02.317Z,1531322462.317 [Startup](DEBUG): Aggregate::initialize Startup 2018-07-11T15:21:02.317Z,1531322462.317 [Startup:A.GoToSurface] Running Loop=1 2018-07-11T15:21:02.317Z,1531322462.317 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-07-11T15:21:02.318Z,1531322462.318 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-07-11T15:21:02.318Z,1531322462.318 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-07-11T15:21:02.318Z,1531322462.318 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-07-11T15:21:02.319Z,1531322462.319 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-07-11T15:21:02.319Z,1531322462.319 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-07-11T15:21:02.325Z,1531322462.325 [Startup:StartupSatComms] Running Loop=1 2018-07-11T15:21:02.326Z,1531322462.326 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2018-07-11T15:21:02.326Z,1531322462.326 [Startup:StartupSatComms:A] Running Loop=1 2018-07-11T15:21:02.704Z,1531322462.704 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2018-07-11T15:21:07.456Z,1531322467.456 [NAL9602](INFO): SBD MO Status=2, MOMSN=7224, MT Status=2, MTMSN=0 2018-07-11T15:21:07.456Z,1531322467.456 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-11T15:21:10.730Z,1531322470.730 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:21:11.526Z,1531322471.526 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:21:31.056Z,1531322491.056 [NAL9602](INFO): SBD MO Status=2, MOMSN=7224, MT Status=2, MTMSN=0 2018-07-11T15:21:31.057Z,1531322491.057 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-11T15:21:40.660Z,1531322500.660 [NAL9602](INFO): SBD MO Status=0, MOMSN=7224, MT Status=0, MTMSN=0 2018-07-11T15:21:40.660Z,1531322500.660 [NAL9602](INFO): No messages in MT queue 2018-07-11T15:21:41.860Z,1531322501.860 [NAL9602](INFO): GPS fix at 20180711T152133: (36.802447, -121.787084) 2018-07-11T15:21:41.934Z,1531322501.934 [Startup:StartupSatComms:A] Stopped 2018-07-11T15:21:41.934Z,1531322501.934 [Startup:StartupSatComms:B] Running Loop=1 2018-07-11T15:21:42.319Z,1531322502.319 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-07-11T15:21:51.055Z,1531322511.055 [NAL9602](INFO): SBD MO Status=1, MOMSN=7225, MT Status=0, MTMSN=0 2018-07-11T15:21:51.113Z,1531322511.113 [NAL9602](INFO): Sent 25 bytes from file Logs/20180710T235445/Courier0277.lzma 2018-07-11T15:21:51.113Z,1531322511.113 [NAL9602](INFO): Packets left to send: 0 2018-07-11T15:21:51.115Z,1531322511.115 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180710T235445/Courier0277.lzma.parts/0000.sbd 2018-07-11T15:21:51.115Z,1531322511.115 [NAL9602](DEBUG): Completed sending Logs/20180710T235445/Courier0277.lzma 2018-07-11T15:22:01.584Z,1531322521.584 [NAL9602](INFO): SBD MO Status=1, MOMSN=7226, MT Status=0, MTMSN=0 2018-07-11T15:22:01.633Z,1531322521.633 [NAL9602](INFO): Sent 25 bytes from file Logs/20180710T235445/Courier0280.lzma 2018-07-11T15:22:01.633Z,1531322521.633 [NAL9602](INFO): Packets left to send: 0 2018-07-11T15:22:01.635Z,1531322521.635 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180710T235445/Courier0280.lzma.parts/0000.sbd 2018-07-11T15:22:01.635Z,1531322521.635 [NAL9602](DEBUG): Completed sending Logs/20180710T235445/Courier0280.lzma 2018-07-11T15:22:21.016Z,1531322541.016 [NAL9602](INFO): SBD MO Status=1, MOMSN=7227, MT Status=0, MTMSN=0 2018-07-11T15:22:21.069Z,1531322541.069 [NAL9602](INFO): Sent 212 bytes from file Logs/20180711T151914/Courier0000.lzma 2018-07-11T15:22:21.069Z,1531322541.069 [NAL9602](INFO): Packets left to send: 0 2018-07-11T15:22:21.071Z,1531322541.071 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180711T151914/Courier0000.lzma.parts/0000.sbd 2018-07-11T15:22:21.071Z,1531322541.071 [NAL9602](DEBUG): Completed sending Logs/20180711T151914/Courier0000.lzma 2018-07-11T15:22:33.160Z,1531322553.160 [NAL9602](INFO): SBD MO Status=1, MOMSN=7228, MT Status=0, MTMSN=0 2018-07-11T15:22:33.213Z,1531322553.213 [NAL9602](INFO): Sent 203 bytes from file Logs/20180710T235445/Express0275.lzma 2018-07-11T15:22:33.213Z,1531322553.213 [NAL9602](INFO): Packets left to send: 0 2018-07-11T15:22:33.215Z,1531322553.215 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180710T235445/Express0275.lzma.parts/0000.sbd 2018-07-11T15:22:33.215Z,1531322553.215 [NAL9602](DEBUG): Completed sending Logs/20180710T235445/Express0275.lzma 2018-07-11T15:22:42.153Z,1531322562.153 [Startup:StartupSatComms:B](INFO): Timed out from 2018-07-11T15:21:41.9Z 2018-07-11T15:22:42.153Z,1531322562.153 [Startup:StartupSatComms:B] Stopped 2018-07-11T15:22:42.153Z,1531322562.153 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2018-07-11T15:22:42.153Z,1531322562.153 [Startup:StartupSatComms] Stopped 2018-07-11T15:22:42.153Z,1531322562.153 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2018-07-11T15:22:42.154Z,1531322562.154 [Startup](INFO): Completed Startup 2018-07-11T15:22:42.155Z,1531322562.155 [MissionManager](INFO): Startup is completed. 2018-07-11T15:22:42.155Z,1531322562.155 [MissionManager](INFO): Uninitializing Mission Startup 2018-07-11T15:22:42.155Z,1531322562.155 [Startup] Stopped 2018-07-11T15:22:42.155Z,1531322562.155 [Startup](DEBUG): Aggregate::uninitialize Startup 2018-07-11T15:22:42.155Z,1531322562.155 [Startup:A.GoToSurface] Stopped 2018-07-11T15:22:42.155Z,1531322562.155 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2018-07-11T15:22:42.536Z,1531322562.536 [MissionManager](IMPORTANT): Started mission Default 2018-07-11T15:22:42.536Z,1531322562.536 [Default] Running Loop=1 2018-07-11T15:22:42.541Z,1531322562.541 [Default](DEBUG): Aggregate::initialize Default 2018-07-11T15:22:42.541Z,1531322562.541 [Default:B.GoToSurface] Running Loop=1 2018-07-11T15:22:42.541Z,1531322562.541 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2018-07-11T15:22:42.541Z,1531322562.541 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2018-07-11T15:22:42.542Z,1531322562.542 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2018-07-11T15:22:42.542Z,1531322562.542 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2018-07-11T15:22:42.542Z,1531322562.542 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2018-07-11T15:22:42.543Z,1531322562.543 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2018-07-11T15:22:42.543Z,1531322562.543 [Default:A.Wait] Running Loop=1 2018-07-11T15:22:42.543Z,1531322562.543 [Default:A.Wait](DEBUG): Initialize Wait Component. 2018-07-11T15:22:44.069Z,1531322564.069 [NAL9602](INFO): SBD MO Status=1, MOMSN=7229, MT Status=0, MTMSN=0 2018-07-11T15:22:44.121Z,1531322564.121 [NAL9602](INFO): Sent 170 bytes from file Logs/20180710T235445/Express0278.lzma 2018-07-11T15:22:44.122Z,1531322564.122 [NAL9602](INFO): Packets left to send: 0 2018-07-11T15:22:44.124Z,1531322564.124 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180710T235445/Express0278.lzma.parts/0000.sbd 2018-07-11T15:22:44.124Z,1531322564.124 [NAL9602](DEBUG): Completed sending Logs/20180710T235445/Express0278.lzma 2018-07-11T15:22:55.746Z,1531322575.746 [Default:A.Wait](INFO): Done Waiting. 2018-07-11T15:22:55.746Z,1531322575.746 [Default:A.Wait] Stopped 2018-07-11T15:22:55.747Z,1531322575.747 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T15:22:56.151Z,1531322576.151 [Default:CheckIn] Running Loop=1 2018-07-11T15:22:56.152Z,1531322576.152 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T15:22:56.152Z,1531322576.152 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T15:22:56.525Z,1531322576.525 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2018-07-11T15:22:58.075Z,1531322578.075 [NAL9602](INFO): GPS fix at 20180711T152249: (36.802374, -121.787116) 2018-07-11T15:22:58.171Z,1531322578.171 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T15:22:58.171Z,1531322578.171 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T15:22:58.533Z,1531322578.533 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2018-07-11T15:23:02.734Z,1531322582.734 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:23:03.529Z,1531322583.529 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:23:06.316Z,1531322586.316 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004638 2018-07-11T15:23:10.848Z,1531322590.848 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20180711T151914/Courier0004.lzma 2018-07-11T15:23:11.636Z,1531322591.636 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0004.lzma.bak 2018-07-11T15:23:11.636Z,1531322591.636 [DataOverHttps](INFO): SBD MOMSN=8362306 2018-07-11T15:23:21.444Z,1531322601.444 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20180710T235445/Express0281.lzma 2018-07-11T15:23:22.236Z,1531322602.236 [DataOverHttps](INFO): Moved sent file to Logs/20180710T235445/Express0281.lzma.bak 2018-07-11T15:23:22.237Z,1531322602.237 [DataOverHttps](INFO): SBD MOMSN=8362311 2018-07-11T15:23:22.865Z,1531322602.865 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T15:23:22.865Z,1531322602.865 [Rowe_600LCM] Communications Fault, FailCount= 1 2018-07-11T15:23:22.865Z,1531322602.865 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T15:23:23.141Z,1531322603.141 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T15:23:23.269Z,1531322603.269 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T15:23:23.375Z,1531322603.375 [Rowe_600LCM](INFO): Powering down 2018-07-11T15:23:26.283Z,1531322606.283 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T15:23:26.284Z,1531322606.284 [Rowe_600LCM] No Fault, FailCount= 1 2018-07-11T15:23:26.605Z,1531322606.605 [Rowe_600LCM](INFO): Initializing 2018-07-11T15:23:26.605Z,1531322606.605 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T15:23:26.606Z,1531322606.606 [Rowe_600LCM](INFO): LCM OK 2018-07-11T15:23:26.606Z,1531322606.606 [Rowe_600LCM](INFO): Powering up 2018-07-11T15:23:30.799Z,1531322610.799 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T15:23:30.932Z,1531322610.932 [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 9600 >& /dev/null & 2018-07-11T15:23:30.933Z,1531322610.933 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T15:23:30.934Z,1531322610.934 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T15:23:30.935Z,1531322610.935 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T15:23:31.508Z,1531322611.508 [DataOverHttps](INFO): Sending 854 bytes from file Logs/20180711T151914/Express0001.lzma 2018-07-11T15:23:32.281Z,1531322612.281 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0001.lzma.bak 2018-07-11T15:23:32.281Z,1531322612.281 [DataOverHttps](INFO): SBD MOMSN=8362313 2018-07-11T15:23:41.480Z,1531322621.480 [NAL9602](INFO): Powering down 2018-07-11T15:23:41.593Z,1531322621.593 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20180711T151914/Express0005.lzma 2018-07-11T15:23:42.391Z,1531322622.391 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0005.lzma.bak 2018-07-11T15:23:42.392Z,1531322622.392 [DataOverHttps](INFO): SBD MOMSN=8362333 2018-07-11T15:23:42.912Z,1531322622.912 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T15:23:42.912Z,1531322622.912 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T15:23:42.912Z,1531322622.912 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T15:24:42.742Z,1531322682.742 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:24:43.538Z,1531322683.538 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:25:26.614Z,1531322726.614 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T15:25:26.615Z,1531322726.615 [Rowe_600LCM] Communications Fault, FailCount= 2 2018-07-11T15:25:26.615Z,1531322726.615 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T15:25:26.781Z,1531322726.781 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T15:25:27.017Z,1531322727.017 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T15:25:27.215Z,1531322727.215 [Rowe_600LCM](INFO): Powering down 2018-07-11T15:25:28.776Z,1531322728.776 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T15:25:28.776Z,1531322728.776 [Rowe_600LCM] No Fault, FailCount= 2 2018-07-11T15:25:28.829Z,1531322728.829 [Rowe_600LCM](INFO): Initializing 2018-07-11T15:25:28.829Z,1531322728.829 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T15:25:28.830Z,1531322728.830 [Rowe_600LCM](INFO): LCM OK 2018-07-11T15:25:28.830Z,1531322728.830 [Rowe_600LCM](INFO): Powering up 2018-07-11T15:25:32.953Z,1531322732.953 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T15:25:33.023Z,1531322733.023 [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 9600 >& /dev/null & 2018-07-11T15:25:33.026Z,1531322733.026 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T15:25:33.027Z,1531322733.027 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T15:25:33.027Z,1531322733.027 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T15:26:43.334Z,1531322803.334 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:44.130Z,1531322804.130 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:44.729Z,1531322804.729 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:45.526Z,1531322805.526 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:46.321Z,1531322806.321 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:47.021Z,1531322807.021 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:47.817Z,1531322807.817 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:48.614Z,1531322808.614 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:49.033Z,1531322809.033 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:49.830Z,1531322809.830 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:50.477Z,1531322810.477 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:51.274Z,1531322811.274 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:52.070Z,1531322812.070 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:52.477Z,1531322812.477 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:53.274Z,1531322813.274 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:54.071Z,1531322814.071 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:54.478Z,1531322814.478 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:55.273Z,1531322815.273 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:56.075Z,1531322816.075 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:56.529Z,1531322816.529 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:57.328Z,1531322817.328 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:58.123Z,1531322818.123 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:58.717Z,1531322818.717 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:26:59.513Z,1531322819.513 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:00.309Z,1531322820.309 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:01.022Z,1531322821.022 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:01.817Z,1531322821.817 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:02.614Z,1531322822.614 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:03.017Z,1531322823.017 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:03.816Z,1531322823.816 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:04.465Z,1531322824.465 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:05.261Z,1531322825.261 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:06.058Z,1531322826.058 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:06.473Z,1531322826.473 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:07.270Z,1531322827.270 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:08.070Z,1531322828.070 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:08.477Z,1531322828.477 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:09.273Z,1531322829.273 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:10.070Z,1531322830.070 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:10.529Z,1531322830.529 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:11.325Z,1531322831.325 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:12.122Z,1531322832.122 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:12.717Z,1531322832.717 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:13.513Z,1531322833.513 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:14.309Z,1531322834.309 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:15.012Z,1531322835.012 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:15.805Z,1531322835.805 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:16.602Z,1531322836.602 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:17.023Z,1531322837.023 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:17.820Z,1531322837.820 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:18.465Z,1531322838.465 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:19.261Z,1531322839.261 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:20.058Z,1531322840.058 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:20.469Z,1531322840.469 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:21.265Z,1531322841.265 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:22.062Z,1531322842.062 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:22.481Z,1531322842.481 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:23.278Z,1531322843.278 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:24.074Z,1531322844.074 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:24.533Z,1531322844.533 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:25.329Z,1531322845.329 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:26.126Z,1531322846.126 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:26.721Z,1531322846.721 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:27.518Z,1531322847.518 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:28.313Z,1531322848.313 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:29.022Z,1531322849.022 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:27:29.413Z,1531322849.413 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T15:27:29.413Z,1531322849.413 [Rowe_600LCM] Communications Fault, FailCount= 3 2018-07-11T15:27:29.413Z,1531322849.413 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T15:27:29.485Z,1531322849.485 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T15:27:29.819Z,1531322849.819 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T15:27:30.027Z,1531322850.027 [Rowe_600LCM](INFO): Powering down 2018-07-11T15:27:30.833Z,1531322850.833 [Rowe_600LCM](FAULT): LCB fault: Software Overcurrent. 2018-07-11T15:27:30.833Z,1531322850.833 [Rowe_600LCM] Hardware Fault, FailCount= 3 2018-07-11T15:27:30.833Z,1531322850.833 [Rowe_600LCM](ERROR): Hardware Fault 2018-07-11T15:27:31.461Z,1531322851.461 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T15:27:31.461Z,1531322851.461 [Rowe_600LCM] No Fault, FailCount= 3 2018-07-11T15:27:31.641Z,1531322851.641 [Rowe_600LCM](INFO): Initializing 2018-07-11T15:27:31.641Z,1531322851.641 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T15:27:31.642Z,1531322851.642 [Rowe_600LCM](INFO): LCM OK 2018-07-11T15:27:31.642Z,1531322851.642 [Rowe_600LCM](INFO): Powering up 2018-07-11T15:27:35.772Z,1531322855.772 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T15:27:35.944Z,1531322855.944 [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 9600 >& /dev/null & 2018-07-11T15:27:35.946Z,1531322855.946 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T15:27:35.946Z,1531322855.946 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T15:27:35.947Z,1531322855.947 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T15:28:33.762Z,1531322913.762 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:28:34.558Z,1531322914.558 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:28:43.356Z,1531322923.356 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T15:28:43.356Z,1531322923.356 [Default:CheckIn:C.Wait] Stopped 2018-07-11T15:28:43.356Z,1531322923.356 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T15:28:43.356Z,1531322923.356 [Default:CheckIn:D] Running Loop=1 2018-07-11T15:28:43.777Z,1531322923.777 [Default:CheckIn:D] Stopped 2018-07-11T15:28:43.777Z,1531322923.777 [Default:CheckIn:E] Running Loop=1 2018-07-11T15:28:44.156Z,1531322924.156 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.020563 min 2018-07-11T15:28:44.158Z,1531322924.158 [Default:CheckIn:E] Stopped 2018-07-11T15:28:44.158Z,1531322924.158 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T15:28:44.158Z,1531322924.158 [Default:CheckIn] Stopped 2018-07-11T15:28:44.158Z,1531322924.158 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T15:28:44.159Z,1531322924.159 [Default:CheckIn](INFO): Running loop #2 2018-07-11T15:28:44.159Z,1531322924.159 [Default:CheckIn] Running Loop=2 2018-07-11T15:28:44.159Z,1531322924.159 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T15:28:44.159Z,1531322924.159 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T15:28:44.931Z,1531322924.931 [NAL9602](INFO): Powering up 2018-07-11T15:28:55.958Z,1531322935.958 [NAL9602](INFO): NAL9602 initialized 2018-07-11T15:29:20.352Z,1531322960.352 [NAL9602](INFO): SBD MO Status=0, MOMSN=7230, MT Status=0, MTMSN=0 2018-07-11T15:29:20.352Z,1531322960.352 [NAL9602](INFO): No messages in MT queue 2018-07-11T15:29:32.421Z,1531322972.421 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T15:29:32.421Z,1531322972.421 [Rowe_600LCM] Communications Fault, FailCount= 4 2018-07-11T15:29:32.421Z,1531322972.421 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T15:29:32.441Z,1531322972.441 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T15:29:32.825Z,1531322972.825 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T15:29:32.995Z,1531322972.995 [Rowe_600LCM](INFO): Powering down 2018-07-11T15:29:34.430Z,1531322974.430 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T15:29:34.431Z,1531322974.431 [Rowe_600LCM] No Fault, FailCount= 4 2018-07-11T15:29:34.609Z,1531322974.609 [Rowe_600LCM](INFO): Initializing 2018-07-11T15:29:34.609Z,1531322974.609 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T15:29:34.610Z,1531322974.610 [Rowe_600LCM](INFO): LCM OK 2018-07-11T15:29:34.610Z,1531322974.610 [Rowe_600LCM](INFO): Powering up 2018-07-11T15:29:38.732Z,1531322978.732 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T15:29:38.896Z,1531322978.896 [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 9600 >& /dev/null & 2018-07-11T15:29:38.898Z,1531322978.898 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T15:29:38.899Z,1531322978.899 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T15:29:38.899Z,1531322978.899 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T15:29:39.160Z,1531322979.160 [NAL9602](INFO): GPS fix at 20180711T152930: (36.802400, -121.787143) 2018-07-11T15:29:39.253Z,1531322979.253 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T15:29:39.253Z,1531322979.253 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T15:29:43.736Z,1531322983.736 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180711T151914/Courier0007.lzma 2018-07-11T15:29:44.536Z,1531322984.536 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0007.lzma.bak 2018-07-11T15:29:44.536Z,1531322984.536 [DataOverHttps](INFO): SBD MOMSN=8362365 2018-07-11T15:29:54.880Z,1531322994.880 [DataOverHttps](INFO): Sending 290 bytes from file Logs/20180711T151914/Express0008.lzma 2018-07-11T15:29:55.676Z,1531322995.676 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0008.lzma.bak 2018-07-11T15:29:55.676Z,1531322995.676 [DataOverHttps](INFO): SBD MOMSN=8362368 2018-07-11T15:29:56.229Z,1531322996.229 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T15:29:56.229Z,1531322996.229 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T15:29:56.229Z,1531322996.229 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T15:30:14.114Z,1531323014.114 [NAL9602](INFO): Powering down 2018-07-11T15:30:22.726Z,1531323022.726 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:30:23.521Z,1531323023.521 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:32:14.722Z,1531323134.722 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:32:15.517Z,1531323135.517 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:32:28.722Z,1531323148.722 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:32:29.517Z,1531323149.517 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:34:01.703Z,1531323241.703 [DataOverHttps](IMPORTANT): SBD MTMSN=20180711T153353 2018-07-11T15:34:05.950Z,1531323245.950 [DataOverHttps](INFO): Received command:ibit 2018-07-11T15:34:05.962Z,1531323245.962 [CommandLine](IMPORTANT): got command ibit 2018-07-11T15:34:06.046Z,1531323246.046 [IBIT](IMPORTANT): Beginning Initiated BIT 2018-07-11T15:34:06.046Z,1531323246.046 [IBIT](IMPORTANT): Beginning control surface checks. 2018-07-11T15:34:06.054Z,1531323246.054 [CBIT](IMPORTANT): Beginning ground fault scan 2018-07-11T15:34:06.336Z,1531323246.336 [NAL9602](INFO): Powering up 2018-07-11T15:34:16.787Z,1531323256.787 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010213 CHAN A1 (24V): -0.013431 CHAN A2 (12V): -0.002310 CHAN A3 (5V): -0.001188 CHAN B0 (3.3V): 0.000617 CHAN B1 (3.15aV): -0.000113 CHAN B2 (3.15bV): 0.000249 CHAN B3 (GND): 0.000414 OPEN: -0.000650 Full Scale Calc: 4.765 mA, -1.589 mA 2018-07-11T15:34:17.522Z,1531323257.522 [NAL9602](INFO): NAL9602 initialized 2018-07-11T15:34:20.730Z,1531323260.730 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:34:21.526Z,1531323261.526 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:34:32.744Z,1531323272.744 [NAL9602](INFO): SBD MO Status=0, MOMSN=7231, MT Status=0, MTMSN=0 2018-07-11T15:34:32.744Z,1531323272.744 [NAL9602](INFO): No messages in MT queue 2018-07-11T15:34:39.127Z,1531323279.127 [NAL9602](INFO): GPS fix at 20180711T153430: (36.802455, -121.787125) 2018-07-11T15:34:41.927Z,1531323281.927 [NAL9602](INFO): GPS fix at 20180711T153433: (36.802450, -121.787137) 2018-07-11T15:34:45.130Z,1531323285.130 [NAL9602](INFO): GPS fix at 20180711T153436: (36.802457, -121.787143) 2018-07-11T15:34:47.926Z,1531323287.926 [NAL9602](INFO): GPS fix at 20180711T153439: (36.802463, -121.787145) 2018-07-11T15:34:51.130Z,1531323291.130 [NAL9602](INFO): GPS fix at 20180711T153442: (36.802464, -121.787138) 2018-07-11T15:34:51.977Z,1531323291.977 [IBIT](IMPORTANT): Communications Status: Fix Status: 1 Iridium Signal Strength: 5 Latitude: 36.802464 Longitude: -121.787140 2018-07-11T15:34:52.448Z,1531323292.448 [IBIT](FAULT): Warning: Battery Data not active. Expected only when running primaries. Threshold checking not active. 2018-07-11T15:34:52.790Z,1531323292.790 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 % 2018-07-11T15:34:52.791Z,1531323292.791 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi 2018-07-11T15:34:52.791Z,1531323292.791 [IBIT](IMPORTANT): Pressure:9.454391 PSI 2018-07-11T15:34:52.791Z,1531323292.791 [IBIT](IMPORTANT): Humidity:16.054205 % 2018-07-11T15:34:53.189Z,1531323293.189 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m 2018-07-11T15:34:53.189Z,1531323293.189 [IBIT](IMPORTANT): buoyancyNeutral: 132.000000 cc 2018-07-11T15:34:53.189Z,1531323293.189 [IBIT](IMPORTANT): massDefault: 0.530000 cm 2018-07-11T15:34:53.190Z,1531323293.190 [IBIT](IMPORTANT): stopDepth: 205.000000 m 2018-07-11T15:34:53.190Z,1531323293.190 [IBIT](IMPORTANT): abortDepth: 250.000000 m 2018-07-11T15:34:53.190Z,1531323293.190 [IBIT](IMPORTANT): IBIT PASSED 2018-07-11T15:34:56.778Z,1531323296.778 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T15:34:56.778Z,1531323296.778 [Default:CheckIn:C.Wait] Stopped 2018-07-11T15:34:56.778Z,1531323296.778 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T15:34:56.778Z,1531323296.778 [Default:CheckIn:D] Running Loop=1 2018-07-11T15:34:57.179Z,1531323297.179 [Default:CheckIn:D] Stopped 2018-07-11T15:34:57.179Z,1531323297.179 [Default:CheckIn:E] Running Loop=1 2018-07-11T15:34:57.619Z,1531323297.619 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.244046 min 2018-07-11T15:34:57.619Z,1531323297.619 [Default:CheckIn:E] Stopped 2018-07-11T15:34:57.620Z,1531323297.620 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T15:34:57.620Z,1531323297.620 [Default:CheckIn] Stopped 2018-07-11T15:34:57.620Z,1531323297.620 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T15:34:57.620Z,1531323297.620 [Default:CheckIn](INFO): Running loop #3 2018-07-11T15:34:57.620Z,1531323297.620 [Default:CheckIn] Running Loop=3 2018-07-11T15:34:57.620Z,1531323297.620 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T15:34:57.620Z,1531323297.620 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T15:34:59.537Z,1531323299.537 [NAL9602](INFO): GPS fix at 20180711T153450: (36.802457, -121.787127) 2018-07-11T15:34:59.594Z,1531323299.594 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T15:34:59.594Z,1531323299.594 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T15:35:04.694Z,1531323304.694 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180711T151914/Courier0010.lzma 2018-07-11T15:35:05.491Z,1531323305.491 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0010.lzma.bak 2018-07-11T15:35:05.492Z,1531323305.492 [DataOverHttps](INFO): SBD MOMSN=8362380 2018-07-11T15:35:14.901Z,1531323314.901 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180711T151914/Courier0013.lzma 2018-07-11T15:35:15.688Z,1531323315.688 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0013.lzma.bak 2018-07-11T15:35:15.688Z,1531323315.688 [DataOverHttps](INFO): SBD MOMSN=8362384 2018-07-11T15:35:25.493Z,1531323325.493 [DataOverHttps](INFO): Sending 744 bytes from file Logs/20180711T151914/Express0011.lzma 2018-07-11T15:35:26.292Z,1531323326.292 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0011.lzma.bak 2018-07-11T15:35:26.292Z,1531323326.292 [DataOverHttps](INFO): SBD MOMSN=8362386 2018-07-11T15:35:31.034Z,1531323331.034 [NAL9602](INFO): Powering down 2018-07-11T15:35:35.883Z,1531323335.883 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20180711T151914/Express0014.lzma 2018-07-11T15:35:36.647Z,1531323336.647 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0014.lzma.bak 2018-07-11T15:35:36.648Z,1531323336.648 [DataOverHttps](INFO): SBD MOMSN=8362407 2018-07-11T15:35:37.169Z,1531323337.169 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T15:35:37.169Z,1531323337.169 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T15:35:37.169Z,1531323337.169 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T15:36:12.726Z,1531323372.726 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:36:13.533Z,1531323373.533 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:37:00.853Z,1531323420.853 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T15:37:00.853Z,1531323420.853 [Rowe_600LCM] Communications Fault, FailCount= 5 2018-07-11T15:37:00.853Z,1531323420.853 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T15:37:01.091Z,1531323421.091 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T15:37:01.092Z,1531323421.092 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM 2018-07-11T15:37:01.257Z,1531323421.257 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T15:37:01.348Z,1531323421.348 [Rowe_600LCM](INFO): Powering down 2018-07-11T15:38:28.559Z,1531323508.559 [CommandLine](IMPORTANT): got command failComponent 2018-07-11T15:38:28.559Z,1531323508.559 [CommandLine](IMPORTANT): Failed components: 2018-07-11T15:38:28.560Z,1531323508.560 [CommandLine](IMPORTANT): Rowe_600LCM: Communications Fault 2018-07-11T15:40:27.326Z,1531323627.326 [BPC1](FAULT): Failed to receive data from all sticks prior to timeout. Missing data from 14 sticks. 2018-07-11T15:40:27.327Z,1531323627.327 [BPC1] Data Fault, FailCount= 1 2018-07-11T15:40:27.327Z,1531323627.327 [BPC1](ERROR): Data Fault 2018-07-11T15:40:27.352Z,1531323627.352 [CBIT](ERROR): Data Fault in component: BPC1 2018-07-11T15:40:28.567Z,1531323628.567 [CBIT](INFO): Clearing failed state for component BPC1 2018-07-11T15:40:28.567Z,1531323628.567 [BPC1] No Fault, FailCount= 1 2018-07-11T15:40:37.749Z,1531323637.749 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T15:40:37.749Z,1531323637.749 [Default:CheckIn:C.Wait] Stopped 2018-07-11T15:40:37.749Z,1531323637.749 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T15:40:37.749Z,1531323637.749 [Default:CheckIn:D] Running Loop=1 2018-07-11T15:40:38.128Z,1531323638.128 [Default:CheckIn:D] Stopped 2018-07-11T15:40:38.128Z,1531323638.128 [Default:CheckIn:E] Running Loop=1 2018-07-11T15:40:38.568Z,1531323638.568 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.926516 min 2018-07-11T15:40:38.568Z,1531323638.568 [Default:CheckIn:E] Stopped 2018-07-11T15:40:38.568Z,1531323638.568 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T15:40:38.568Z,1531323638.568 [Default:CheckIn] Stopped 2018-07-11T15:40:38.569Z,1531323638.569 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T15:40:38.569Z,1531323638.569 [Default:CheckIn](INFO): Running loop #4 2018-07-11T15:40:38.569Z,1531323638.569 [Default:CheckIn] Running Loop=4 2018-07-11T15:40:38.569Z,1531323638.569 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T15:40:38.569Z,1531323638.569 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T15:40:41.760Z,1531323641.760 [NAL9602](INFO): Powering up 2018-07-11T15:40:52.926Z,1531323652.926 [NAL9602](INFO): NAL9602 initialized 2018-07-11T15:41:06.924Z,1531323666.924 [NAL9602](INFO): SBD MO Status=0, MOMSN=7232, MT Status=0, MTMSN=0 2018-07-11T15:41:06.924Z,1531323666.924 [NAL9602](INFO): No messages in MT queue 2018-07-11T15:41:28.930Z,1531323688.930 [NAL9602](INFO): GPS fix at 20180711T154120: (36.802623, -121.787445) 2018-07-11T15:41:28.990Z,1531323688.990 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T15:41:28.991Z,1531323688.991 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T15:41:33.398Z,1531323693.398 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20180711T151914/Courier0016.lzma 2018-07-11T15:41:34.188Z,1531323694.188 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0016.lzma.bak 2018-07-11T15:41:34.188Z,1531323694.188 [DataOverHttps](INFO): SBD MOMSN=8362429 2018-07-11T15:41:43.338Z,1531323703.338 [DataOverHttps](INFO): Sending 372 bytes from file Logs/20180711T151914/Express0017.lzma 2018-07-11T15:41:44.128Z,1531323704.128 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0017.lzma.bak 2018-07-11T15:41:44.128Z,1531323704.128 [DataOverHttps](INFO): SBD MOMSN=8362432 2018-07-11T15:41:44.649Z,1531323704.649 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T15:41:44.649Z,1531323704.649 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T15:41:44.649Z,1531323704.649 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T15:42:03.536Z,1531323723.536 [NAL9602](INFO): Powering down 2018-07-11T15:46:39.967Z,1531323999.967 [CommandLine](IMPORTANT): got command failComponent 2018-07-11T15:46:39.967Z,1531323999.967 [CommandLine](IMPORTANT): Failed components: 2018-07-11T15:46:39.968Z,1531323999.968 [CommandLine](IMPORTANT): Rowe_600LCM: Communications Fault 2018-07-11T15:46:45.362Z,1531324005.362 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T15:46:45.362Z,1531324005.362 [Default:CheckIn:C.Wait] Stopped 2018-07-11T15:46:45.362Z,1531324005.362 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T15:46:45.362Z,1531324005.362 [Default:CheckIn:D] Running Loop=1 2018-07-11T15:46:45.769Z,1531324005.769 [Default:CheckIn:D] Stopped 2018-07-11T15:46:45.769Z,1531324005.769 [Default:CheckIn:E] Running Loop=1 2018-07-11T15:46:48.919Z,1531324008.919 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 24.053880 min 2018-07-11T15:46:48.919Z,1531324008.919 [Default:CheckIn:E] Stopped 2018-07-11T15:46:48.919Z,1531324008.919 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T15:46:48.919Z,1531324008.919 [Default:CheckIn] Stopped 2018-07-11T15:46:48.919Z,1531324008.919 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T15:46:48.920Z,1531324008.920 [Default:CheckIn](INFO): Running loop #5 2018-07-11T15:46:48.920Z,1531324008.920 [Default:CheckIn] Running Loop=5 2018-07-11T15:46:48.920Z,1531324008.920 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T15:46:48.920Z,1531324008.920 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T15:46:49.362Z,1531324009.362 [NAL9602](INFO): Powering up 2018-07-11T15:47:00.567Z,1531324020.567 [NAL9602](INFO): NAL9602 initialized 2018-07-11T15:47:01.049Z,1531324021.049 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T15:47:01.050Z,1531324021.050 [Rowe_600LCM] No Fault, FailCount= 5 2018-07-11T15:47:01.289Z,1531324021.289 [Rowe_600LCM](INFO): Initializing 2018-07-11T15:47:01.290Z,1531324021.290 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T15:47:01.290Z,1531324021.290 [Rowe_600LCM](INFO): LCM OK 2018-07-11T15:47:01.290Z,1531324021.290 [Rowe_600LCM](INFO): Powering up 2018-07-11T15:47:05.563Z,1531324025.563 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T15:47:05.643Z,1531324025.643 [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 9600 >& /dev/null & 2018-07-11T15:47:05.646Z,1531324025.646 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T15:47:05.647Z,1531324025.647 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T15:47:05.648Z,1531324025.648 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T15:47:14.968Z,1531324034.968 [NAL9602](INFO): SBD MO Status=0, MOMSN=7233, MT Status=0, MTMSN=0 2018-07-11T15:47:14.968Z,1531324034.968 [NAL9602](INFO): No messages in MT queue 2018-07-11T15:47:16.775Z,1531324036.775 [CommandLine](IMPORTANT): got command failComponent none Rowe_600LCM 2018-07-11T15:47:16.775Z,1531324036.775 [CommandLine](IMPORTANT): Rowe_600LCM failureMode is No Fault 2018-07-11T15:47:34.176Z,1531324054.176 [NAL9602](INFO): GPS fix at 20180711T154725: (36.802457, -121.787081) 2018-07-11T15:47:34.342Z,1531324054.342 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T15:47:34.342Z,1531324054.342 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T15:47:38.974Z,1531324058.974 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180711T151914/Courier0019.lzma 2018-07-11T15:47:39.768Z,1531324059.768 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0019.lzma.bak 2018-07-11T15:47:39.768Z,1531324059.768 [DataOverHttps](INFO): SBD MOMSN=8362442 2018-07-11T15:47:49.159Z,1531324069.159 [DataOverHttps](INFO): Sending 242 bytes from file Logs/20180711T151914/Express0020.lzma 2018-07-11T15:47:49.960Z,1531324069.960 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0020.lzma.bak 2018-07-11T15:47:49.960Z,1531324069.960 [DataOverHttps](INFO): SBD MOMSN=8362446 2018-07-11T15:47:50.635Z,1531324070.635 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T15:47:50.635Z,1531324070.635 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T15:47:50.635Z,1531324070.635 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T15:48:09.279Z,1531324089.279 [NAL9602](INFO): Powering down 2018-07-11T15:48:30.702Z,1531324110.702 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:48:31.498Z,1531324111.498 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:49:32.097Z,1531324172.097 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T15:49:32.097Z,1531324172.097 [Rowe_600LCM] Communications Fault, FailCount= 1 2018-07-11T15:49:32.097Z,1531324172.097 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T15:49:32.156Z,1531324172.156 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T15:49:32.501Z,1531324172.501 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T15:49:32.678Z,1531324172.678 [Rowe_600LCM](INFO): Powering down 2018-07-11T15:49:33.485Z,1531324173.485 [Rowe_600LCM](FAULT): LCB fault: Software Overcurrent. 2018-07-11T15:49:33.485Z,1531324173.485 [Rowe_600LCM] Hardware Fault, FailCount= 1 2018-07-11T15:49:33.485Z,1531324173.485 [Rowe_600LCM](ERROR): Hardware Fault 2018-07-11T15:49:34.137Z,1531324174.137 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T15:49:34.137Z,1531324174.137 [Rowe_600LCM] No Fault, FailCount= 1 2018-07-11T15:49:34.293Z,1531324174.293 [Rowe_600LCM](INFO): Initializing 2018-07-11T15:49:34.293Z,1531324174.293 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T15:49:34.294Z,1531324174.294 [Rowe_600LCM](INFO): LCM OK 2018-07-11T15:49:34.294Z,1531324174.294 [Rowe_600LCM](INFO): Powering up 2018-07-11T15:49:38.418Z,1531324178.418 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T15:49:38.569Z,1531324178.569 [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 9600 >& /dev/null & 2018-07-11T15:49:38.571Z,1531324178.571 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T15:49:38.572Z,1531324178.572 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T15:49:38.573Z,1531324178.573 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T15:50:21.702Z,1531324221.702 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:50:22.497Z,1531324222.497 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:51:33.998Z,1531324293.998 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:51:34.793Z,1531324294.793 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:52:13.707Z,1531324333.707 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:52:14.502Z,1531324334.502 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:52:27.706Z,1531324347.706 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:52:28.509Z,1531324348.509 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:52:31.181Z,1531324351.181 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T15:52:31.181Z,1531324351.181 [Rowe_600LCM] Communications Fault, FailCount= 2 2018-07-11T15:52:31.181Z,1531324351.181 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T15:52:31.323Z,1531324351.323 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T15:52:31.585Z,1531324351.585 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T15:52:31.956Z,1531324351.956 [Rowe_600LCM](INFO): Powering down 2018-07-11T15:52:33.328Z,1531324353.328 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T15:52:33.329Z,1531324353.329 [Rowe_600LCM] No Fault, FailCount= 2 2018-07-11T15:52:33.573Z,1531324353.573 [Rowe_600LCM](INFO): Initializing 2018-07-11T15:52:33.573Z,1531324353.573 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T15:52:33.574Z,1531324353.574 [Rowe_600LCM](INFO): LCM OK 2018-07-11T15:52:33.574Z,1531324353.574 [Rowe_600LCM](INFO): Powering up 2018-07-11T15:52:37.836Z,1531324357.836 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T15:52:37.908Z,1531324357.908 [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 9600 >& /dev/null & 2018-07-11T15:52:37.910Z,1531324357.910 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T15:52:37.911Z,1531324357.911 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T15:52:37.912Z,1531324357.912 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T15:52:50.861Z,1531324370.861 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T15:52:50.862Z,1531324370.862 [Default:CheckIn:C.Wait] Stopped 2018-07-11T15:52:50.862Z,1531324370.862 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T15:52:50.862Z,1531324370.862 [Default:CheckIn:D] Running Loop=1 2018-07-11T15:52:51.268Z,1531324371.268 [Default:CheckIn:D] Stopped 2018-07-11T15:52:51.268Z,1531324371.268 [Default:CheckIn:E] Running Loop=1 2018-07-11T15:52:51.662Z,1531324371.662 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.145520 min 2018-07-11T15:52:51.663Z,1531324371.663 [Default:CheckIn:E] Stopped 2018-07-11T15:52:51.663Z,1531324371.663 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T15:52:51.663Z,1531324371.663 [Default:CheckIn] Stopped 2018-07-11T15:52:51.663Z,1531324371.663 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T15:52:51.663Z,1531324371.663 [Default:CheckIn](INFO): Running loop #6 2018-07-11T15:52:51.664Z,1531324371.664 [Default:CheckIn] Running Loop=6 2018-07-11T15:52:51.664Z,1531324371.664 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T15:52:51.664Z,1531324371.664 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T15:52:55.315Z,1531324375.315 [NAL9602](INFO): Powering up 2018-07-11T15:53:06.310Z,1531324386.310 [NAL9602](INFO): NAL9602 initialized 2018-07-11T15:53:23.112Z,1531324403.112 [NAL9602](INFO): SBD MO Status=0, MOMSN=7234, MT Status=0, MTMSN=0 2018-07-11T15:53:23.112Z,1531324403.112 [NAL9602](INFO): No messages in MT queue 2018-07-11T15:53:39.118Z,1531324419.118 [NAL9602](INFO): GPS fix at 20180711T155330: (36.802414, -121.787194) 2018-07-11T15:53:39.198Z,1531324419.198 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T15:53:39.198Z,1531324419.198 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T15:53:44.362Z,1531324424.362 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180711T151914/Courier0022.lzma 2018-07-11T15:53:45.160Z,1531324425.160 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0022.lzma.bak 2018-07-11T15:53:45.160Z,1531324425.160 [DataOverHttps](INFO): SBD MOMSN=8362469 2018-07-11T15:53:54.606Z,1531324434.606 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20180711T151914/Express0023.lzma 2018-07-11T15:53:55.392Z,1531324435.392 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0023.lzma.bak 2018-07-11T15:53:55.392Z,1531324435.392 [DataOverHttps](INFO): SBD MOMSN=8362472 2018-07-11T15:53:55.924Z,1531324435.924 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T15:53:55.924Z,1531324435.924 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T15:53:55.924Z,1531324435.924 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T15:54:03.702Z,1531324443.702 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:54:04.497Z,1531324444.497 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:54:14.166Z,1531324454.166 [NAL9602](INFO): Powering down 2018-07-11T15:54:49.185Z,1531324489.185 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T15:54:49.185Z,1531324489.185 [Rowe_600LCM] Communications Fault, FailCount= 3 2018-07-11T15:54:49.185Z,1531324489.185 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T15:54:49.517Z,1531324489.517 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T15:54:49.589Z,1531324489.589 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T15:54:49.726Z,1531324489.726 [Rowe_600LCM](INFO): Powering down 2018-07-11T15:54:51.024Z,1531324491.024 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T15:54:51.024Z,1531324491.024 [Rowe_600LCM] No Fault, FailCount= 3 2018-07-11T15:54:51.342Z,1531324491.342 [Rowe_600LCM](INFO): Initializing 2018-07-11T15:54:51.343Z,1531324491.343 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T15:54:51.343Z,1531324491.343 [Rowe_600LCM](INFO): LCM OK 2018-07-11T15:54:51.343Z,1531324491.343 [Rowe_600LCM](INFO): Powering up 2018-07-11T15:54:55.575Z,1531324495.575 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T15:54:55.651Z,1531324495.651 [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 9600 >& /dev/null & 2018-07-11T15:54:55.654Z,1531324495.654 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T15:54:55.655Z,1531324495.655 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T15:54:55.656Z,1531324495.656 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T15:55:13.990Z,1531324513.990 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:55:14.785Z,1531324514.785 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:55:53.702Z,1531324553.702 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:55:54.500Z,1531324554.500 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:56:51.591Z,1531324611.591 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T15:56:51.591Z,1531324611.591 [Rowe_600LCM] Communications Fault, FailCount= 4 2018-07-11T15:56:51.591Z,1531324611.591 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T15:56:51.844Z,1531324611.844 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T15:56:51.993Z,1531324611.993 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T15:56:52.102Z,1531324612.102 [Rowe_600LCM](INFO): Powering down 2018-07-11T15:56:53.424Z,1531324613.424 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T15:56:53.424Z,1531324613.424 [Rowe_600LCM] No Fault, FailCount= 4 2018-07-11T15:56:53.717Z,1531324613.717 [Rowe_600LCM](INFO): Initializing 2018-07-11T15:56:53.717Z,1531324613.717 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T15:56:53.718Z,1531324613.718 [Rowe_600LCM](INFO): LCM OK 2018-07-11T15:56:53.718Z,1531324613.718 [Rowe_600LCM](INFO): Powering up 2018-07-11T15:56:57.920Z,1531324617.920 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T15:56:58.060Z,1531324618.060 [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 9600 >& /dev/null & 2018-07-11T15:56:58.061Z,1531324618.061 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T15:56:58.062Z,1531324618.062 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T15:56:58.063Z,1531324618.063 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T15:57:40.694Z,1531324660.694 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:57:41.490Z,1531324661.490 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:58:56.496Z,1531324736.496 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T15:58:56.497Z,1531324736.497 [Default:CheckIn:C.Wait] Stopped 2018-07-11T15:58:56.497Z,1531324736.497 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T15:58:56.497Z,1531324736.497 [Default:CheckIn:D] Running Loop=1 2018-07-11T15:58:56.906Z,1531324736.906 [Default:CheckIn:D] Stopped 2018-07-11T15:58:56.906Z,1531324736.906 [Default:CheckIn:E] Running Loop=1 2018-07-11T15:58:57.300Z,1531324737.300 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.239494 min 2018-07-11T15:58:57.309Z,1531324737.309 [Default:CheckIn:E] Stopped 2018-07-11T15:58:57.309Z,1531324737.309 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T15:58:57.309Z,1531324737.309 [Default:CheckIn] Stopped 2018-07-11T15:58:57.309Z,1531324737.309 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T15:58:57.310Z,1531324737.310 [Default:CheckIn](INFO): Running loop #7 2018-07-11T15:58:57.310Z,1531324737.310 [Default:CheckIn] Running Loop=7 2018-07-11T15:58:57.310Z,1531324737.310 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T15:58:57.310Z,1531324737.310 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T15:59:00.866Z,1531324740.866 [NAL9602](INFO): Powering up 2018-07-11T15:59:12.056Z,1531324752.056 [NAL9602](INFO): NAL9602 initialized 2018-07-11T15:59:32.698Z,1531324772.698 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:59:33.493Z,1531324773.493 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T15:59:34.462Z,1531324774.462 [NAL9602](INFO): SBD MO Status=0, MOMSN=7235, MT Status=0, MTMSN=0 2018-07-11T15:59:34.462Z,1531324774.462 [NAL9602](INFO): No messages in MT queue 2018-07-11T15:59:38.089Z,1531324778.089 [NAL9602](INFO): GPS fix at 20180711T155929: (36.802407, -121.787156) 2018-07-11T15:59:38.177Z,1531324778.177 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T15:59:38.177Z,1531324778.177 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T15:59:43.096Z,1531324783.096 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180711T151914/Courier0025.lzma 2018-07-11T15:59:43.885Z,1531324783.885 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0025.lzma.bak 2018-07-11T15:59:43.885Z,1531324783.885 [DataOverHttps](INFO): SBD MOMSN=8362481 2018-07-11T15:59:53.271Z,1531324793.271 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20180711T151914/Express0026.lzma 2018-07-11T15:59:54.037Z,1531324794.037 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0026.lzma.bak 2018-07-11T15:59:54.037Z,1531324794.037 [DataOverHttps](INFO): SBD MOMSN=8362494 2018-07-11T15:59:54.560Z,1531324794.560 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T15:59:54.560Z,1531324794.560 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T15:59:54.560Z,1531324794.560 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T16:00:13.386Z,1531324813.386 [NAL9602](INFO): Powering down 2018-07-11T16:00:16.590Z,1531324816.590 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:00:16.590Z,1531324816.590 [Rowe_600LCM] Communications Fault, FailCount= 5 2018-07-11T16:00:16.590Z,1531324816.590 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:00:16.718Z,1531324816.718 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:00:16.718Z,1531324816.718 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM 2018-07-11T16:00:16.994Z,1531324816.994 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:00:17.246Z,1531324817.246 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:01:29.436Z,1531324889.436 [BPC1](FAULT): Failed to receive data from all sticks prior to timeout. Missing data from 14 sticks. 2018-07-11T16:01:29.436Z,1531324889.436 [BPC1] Data Fault, FailCount= 2 2018-07-11T16:01:29.441Z,1531324889.441 [BPC1](ERROR): Data Fault 2018-07-11T16:01:29.495Z,1531324889.495 [CBIT](ERROR): Data Fault in component: BPC1 2018-07-11T16:01:30.663Z,1531324890.663 [CBIT](INFO): Clearing failed state for component BPC1 2018-07-11T16:01:30.664Z,1531324890.664 [BPC1] No Fault, FailCount= 2 2018-07-11T16:04:55.052Z,1531325095.052 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T16:04:55.052Z,1531325095.052 [Default:CheckIn:C.Wait] Stopped 2018-07-11T16:04:55.057Z,1531325095.057 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T16:04:55.057Z,1531325095.057 [Default:CheckIn:D] Running Loop=1 2018-07-11T16:04:55.456Z,1531325095.456 [Default:CheckIn:D] Stopped 2018-07-11T16:04:55.456Z,1531325095.456 [Default:CheckIn:E] Running Loop=1 2018-07-11T16:04:58.567Z,1531325098.567 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.215320 min 2018-07-11T16:04:58.568Z,1531325098.568 [Default:CheckIn:E] Stopped 2018-07-11T16:04:58.568Z,1531325098.568 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T16:04:58.568Z,1531325098.568 [Default:CheckIn] Stopped 2018-07-11T16:04:58.568Z,1531325098.568 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T16:04:58.568Z,1531325098.568 [Default:CheckIn](INFO): Running loop #8 2018-07-11T16:04:58.568Z,1531325098.568 [Default:CheckIn] Running Loop=8 2018-07-11T16:04:58.569Z,1531325098.569 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T16:04:58.569Z,1531325098.569 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T16:04:59.050Z,1531325099.050 [NAL9602](INFO): Powering up 2018-07-11T16:05:10.250Z,1531325110.250 [NAL9602](INFO): NAL9602 initialized 2018-07-11T16:05:26.648Z,1531325126.648 [NAL9602](INFO): SBD MO Status=0, MOMSN=7236, MT Status=0, MTMSN=0 2018-07-11T16:05:26.648Z,1531325126.648 [NAL9602](INFO): No messages in MT queue 2018-07-11T16:05:39.854Z,1531325139.854 [NAL9602](INFO): GPS fix at 20180711T160531: (36.802385, -121.787250) 2018-07-11T16:05:39.937Z,1531325139.937 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T16:05:39.937Z,1531325139.937 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T16:05:44.377Z,1531325144.377 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180711T151914/Courier0028.lzma 2018-07-11T16:05:45.156Z,1531325145.156 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0028.lzma.bak 2018-07-11T16:05:45.156Z,1531325145.156 [DataOverHttps](INFO): SBD MOMSN=8362500 2018-07-11T16:05:54.495Z,1531325154.495 [DataOverHttps](INFO): Sending 300 bytes from file Logs/20180711T151914/Express0029.lzma 2018-07-11T16:05:55.280Z,1531325155.280 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0029.lzma.bak 2018-07-11T16:05:55.280Z,1531325155.280 [DataOverHttps](INFO): SBD MOMSN=8362503 2018-07-11T16:05:55.828Z,1531325155.828 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T16:05:55.828Z,1531325155.828 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T16:05:55.828Z,1531325155.828 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T16:06:14.662Z,1531325174.662 [NAL9602](INFO): Powering down 2018-07-11T16:10:16.985Z,1531325416.985 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:10:16.985Z,1531325416.985 [Rowe_600LCM] No Fault, FailCount= 5 2018-07-11T16:10:17.165Z,1531325417.165 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:10:17.165Z,1531325417.165 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:10:17.165Z,1531325417.165 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:10:17.165Z,1531325417.165 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:10:21.355Z,1531325421.355 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:10:21.512Z,1531325421.512 [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 9600 >& /dev/null & 2018-07-11T16:10:21.514Z,1531325421.514 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:10:21.515Z,1531325421.515 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:10:21.516Z,1531325421.516 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:10:56.568Z,1531325456.568 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T16:10:56.568Z,1531325456.568 [Default:CheckIn:C.Wait] Stopped 2018-07-11T16:10:56.574Z,1531325456.574 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T16:10:56.574Z,1531325456.574 [Default:CheckIn:D] Running Loop=1 2018-07-11T16:11:00.094Z,1531325460.094 [Default:CheckIn:D] Stopped 2018-07-11T16:11:00.094Z,1531325460.094 [Default:CheckIn:E] Running Loop=1 2018-07-11T16:11:00.230Z,1531325460.230 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.292631 min 2018-07-11T16:11:00.230Z,1531325460.230 [Default:CheckIn:E] Stopped 2018-07-11T16:11:00.230Z,1531325460.230 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T16:11:00.231Z,1531325460.231 [Default:CheckIn] Stopped 2018-07-11T16:11:00.231Z,1531325460.231 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T16:11:00.231Z,1531325460.231 [Default:CheckIn](INFO): Running loop #9 2018-07-11T16:11:00.231Z,1531325460.231 [Default:CheckIn] Running Loop=9 2018-07-11T16:11:00.231Z,1531325460.231 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T16:11:00.231Z,1531325460.231 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T16:11:00.950Z,1531325460.950 [NAL9602](INFO): Powering up 2018-07-11T16:11:12.146Z,1531325472.146 [NAL9602](INFO): NAL9602 initialized 2018-07-11T16:11:28.556Z,1531325488.556 [NAL9602](INFO): SBD MO Status=0, MOMSN=7237, MT Status=0, MTMSN=0 2018-07-11T16:11:28.556Z,1531325488.556 [NAL9602](INFO): No messages in MT queue 2018-07-11T16:11:39.355Z,1531325499.355 [NAL9602](INFO): GPS fix at 20180711T161130: (36.802262, -121.786938) 2018-07-11T16:11:39.424Z,1531325499.424 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T16:11:39.424Z,1531325499.424 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T16:11:44.348Z,1531325504.348 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180711T151914/Courier0031.lzma 2018-07-11T16:11:45.139Z,1531325505.139 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0031.lzma.bak 2018-07-11T16:11:45.140Z,1531325505.140 [DataOverHttps](INFO): SBD MOMSN=8362545 2018-07-11T16:11:54.543Z,1531325514.543 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20180711T151914/Express0032.lzma 2018-07-11T16:11:55.336Z,1531325515.336 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0032.lzma.bak 2018-07-11T16:11:55.336Z,1531325515.336 [DataOverHttps](INFO): SBD MOMSN=8362548 2018-07-11T16:11:56.077Z,1531325516.077 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T16:11:56.077Z,1531325516.077 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T16:11:56.078Z,1531325516.078 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T16:12:00.694Z,1531325520.694 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:12:01.489Z,1531325521.489 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:12:14.510Z,1531325534.510 [NAL9602](INFO): Powering down 2018-07-11T16:12:14.694Z,1531325534.694 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:12:15.489Z,1531325535.489 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:12:56.281Z,1531325576.281 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:12:56.281Z,1531325576.281 [Rowe_600LCM] Communications Fault, FailCount= 1 2018-07-11T16:12:56.281Z,1531325576.281 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:12:56.589Z,1531325576.589 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:12:56.685Z,1531325576.685 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:12:56.776Z,1531325576.776 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:12:59.725Z,1531325579.725 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:12:59.725Z,1531325579.725 [Rowe_600LCM] No Fault, FailCount= 1 2018-07-11T16:13:00.017Z,1531325580.017 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:13:00.018Z,1531325580.018 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:13:00.018Z,1531325580.018 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:13:00.018Z,1531325580.018 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:13:04.230Z,1531325584.230 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:13:04.360Z,1531325584.360 [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 9600 >& /dev/null & 2018-07-11T16:13:04.362Z,1531325584.362 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:13:04.362Z,1531325584.362 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:13:04.363Z,1531325584.363 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:13:33.690Z,1531325613.690 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:13:34.488Z,1531325614.488 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:15:00.373Z,1531325700.373 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:15:00.373Z,1531325700.373 [Rowe_600LCM] Communications Fault, FailCount= 2 2018-07-11T16:15:00.373Z,1531325700.373 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:15:00.517Z,1531325700.517 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:15:00.777Z,1531325700.777 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:15:00.991Z,1531325700.991 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:15:02.465Z,1531325702.465 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:15:02.465Z,1531325702.465 [Rowe_600LCM] No Fault, FailCount= 2 2018-07-11T16:15:02.605Z,1531325702.605 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:15:02.605Z,1531325702.605 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:15:02.606Z,1531325702.606 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:15:02.606Z,1531325702.606 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:15:06.738Z,1531325706.738 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:15:06.908Z,1531325706.908 [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 9600 >& /dev/null & 2018-07-11T16:15:06.910Z,1531325706.910 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:15:06.911Z,1531325706.911 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:15:06.911Z,1531325706.911 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:15:22.686Z,1531325722.686 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:15:23.481Z,1531325723.481 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:16:56.361Z,1531325816.361 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T16:16:56.361Z,1531325816.361 [Default:CheckIn:C.Wait] Stopped 2018-07-11T16:16:56.361Z,1531325816.361 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T16:16:56.361Z,1531325816.361 [Default:CheckIn:D] Running Loop=1 2018-07-11T16:16:56.745Z,1531325816.745 [Default:CheckIn:D] Stopped 2018-07-11T16:16:56.746Z,1531325816.746 [Default:CheckIn:E] Running Loop=1 2018-07-11T16:16:57.150Z,1531325817.150 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.236812 min 2018-07-11T16:16:57.150Z,1531325817.150 [Default:CheckIn:E] Stopped 2018-07-11T16:16:57.150Z,1531325817.150 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T16:16:57.151Z,1531325817.151 [Default:CheckIn] Stopped 2018-07-11T16:16:57.151Z,1531325817.151 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T16:16:57.151Z,1531325817.151 [Default:CheckIn](INFO): Running loop #10 2018-07-11T16:16:57.151Z,1531325817.151 [Default:CheckIn] Running Loop=10 2018-07-11T16:16:57.151Z,1531325817.151 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T16:16:57.151Z,1531325817.151 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T16:17:01.991Z,1531325821.991 [NAL9602](INFO): Powering up 2018-07-11T16:17:03.365Z,1531325823.365 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:17:03.365Z,1531325823.365 [Rowe_600LCM] Communications Fault, FailCount= 3 2018-07-11T16:17:03.365Z,1531325823.365 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:17:03.382Z,1531325823.382 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:17:03.769Z,1531325823.769 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:17:03.951Z,1531325823.951 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:17:05.398Z,1531325825.398 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:17:05.398Z,1531325825.398 [Rowe_600LCM] No Fault, FailCount= 3 2018-07-11T16:17:05.565Z,1531325825.565 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:17:05.565Z,1531325825.565 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:17:05.566Z,1531325825.566 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:17:05.566Z,1531325825.566 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:17:09.763Z,1531325829.763 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:17:09.885Z,1531325829.885 [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 9600 >& /dev/null & 2018-07-11T16:17:09.887Z,1531325829.887 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:17:09.888Z,1531325829.888 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:17:09.888Z,1531325829.888 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:17:12.915Z,1531325832.915 [NAL9602](INFO): NAL9602 initialized 2018-07-11T16:17:33.712Z,1531325853.712 [NAL9602](INFO): SBD MO Status=0, MOMSN=7238, MT Status=0, MTMSN=0 2018-07-11T16:17:33.712Z,1531325853.712 [NAL9602](INFO): No messages in MT queue 2018-07-11T16:18:10.962Z,1531325890.962 [NAL9602](INFO): GPS fix at 20180711T161802: (36.802310, -121.786826) 2018-07-11T16:18:11.031Z,1531325891.031 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T16:18:11.031Z,1531325891.031 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T16:18:15.867Z,1531325895.867 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180711T151914/Courier0034.lzma 2018-07-11T16:18:16.656Z,1531325896.656 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0034.lzma.bak 2018-07-11T16:18:16.656Z,1531325896.656 [DataOverHttps](INFO): SBD MOMSN=8362552 2018-07-11T16:18:26.020Z,1531325906.020 [DataOverHttps](INFO): Sending 207 bytes from file Logs/20180711T151914/Express0035.lzma 2018-07-11T16:18:26.821Z,1531325906.821 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0035.lzma.bak 2018-07-11T16:18:26.821Z,1531325906.821 [DataOverHttps](INFO): SBD MOMSN=8362555 2018-07-11T16:18:27.437Z,1531325907.437 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T16:18:27.438Z,1531325907.438 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T16:18:27.438Z,1531325907.438 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T16:18:45.922Z,1531325925.922 [NAL9602](INFO): Powering down 2018-07-11T16:19:03.690Z,1531325943.690 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:19:04.489Z,1531325944.489 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:20:55.686Z,1531326055.686 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:20:56.482Z,1531326056.482 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:20:59.158Z,1531326059.158 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:20:59.158Z,1531326059.158 [Rowe_600LCM] Communications Fault, FailCount= 4 2018-07-11T16:20:59.158Z,1531326059.158 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:20:59.248Z,1531326059.248 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:20:59.561Z,1531326059.561 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:20:59.780Z,1531326059.780 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:21:01.204Z,1531326061.204 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:21:01.204Z,1531326061.204 [Rowe_600LCM] No Fault, FailCount= 4 2018-07-11T16:21:01.397Z,1531326061.397 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:21:01.398Z,1531326061.398 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:21:01.398Z,1531326061.398 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:21:01.398Z,1531326061.398 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:21:05.525Z,1531326065.525 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:21:05.652Z,1531326065.652 [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 9600 >& /dev/null & 2018-07-11T16:21:05.654Z,1531326065.654 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:21:05.655Z,1531326065.655 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:21:05.656Z,1531326065.656 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:22:31.678Z,1531326151.678 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:22:32.476Z,1531326152.476 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:22:33.837Z,1531326153.837 [BPC1](FAULT): Failed to receive data from all sticks prior to timeout. Missing data from 13 sticks. 2018-07-11T16:22:33.837Z,1531326153.837 [BPC1] Data Fault, FailCount= 3 2018-07-11T16:22:33.837Z,1531326153.837 [BPC1](ERROR): Data Fault 2018-07-11T16:22:33.865Z,1531326153.865 [CBIT](ERROR): Data Fault in component: BPC1 2018-07-11T16:22:34.739Z,1531326154.739 [CBIT](INFO): Clearing failed state for component BPC1 2018-07-11T16:22:34.739Z,1531326154.739 [BPC1] No Fault, FailCount= 3 2018-07-11T16:22:45.686Z,1531326165.686 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:22:46.482Z,1531326166.482 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:23:01.568Z,1531326181.568 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:23:01.568Z,1531326181.568 [Rowe_600LCM] Communications Fault, FailCount= 5 2018-07-11T16:23:01.568Z,1531326181.568 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:23:01.624Z,1531326181.624 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:23:01.624Z,1531326181.624 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM 2018-07-11T16:23:01.973Z,1531326181.973 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:23:02.138Z,1531326182.138 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:23:27.928Z,1531326207.928 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T16:23:27.929Z,1531326207.929 [Default:CheckIn:C.Wait] Stopped 2018-07-11T16:23:27.929Z,1531326207.929 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T16:23:27.929Z,1531326207.929 [Default:CheckIn:D] Running Loop=1 2018-07-11T16:23:28.328Z,1531326208.328 [Default:CheckIn:D] Stopped 2018-07-11T16:23:28.329Z,1531326208.329 [Default:CheckIn:E] Running Loop=1 2018-07-11T16:23:28.732Z,1531326208.732 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.763196 min 2018-07-11T16:23:28.733Z,1531326208.733 [Default:CheckIn:E] Stopped 2018-07-11T16:23:28.733Z,1531326208.733 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T16:23:28.733Z,1531326208.733 [Default:CheckIn] Stopped 2018-07-11T16:23:28.733Z,1531326208.733 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T16:23:28.734Z,1531326208.734 [Default:CheckIn](INFO): Running loop #11 2018-07-11T16:23:28.734Z,1531326208.734 [Default:CheckIn] Running Loop=11 2018-07-11T16:23:28.734Z,1531326208.734 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T16:23:28.734Z,1531326208.734 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T16:23:31.938Z,1531326211.938 [NAL9602](INFO): Powering up 2018-07-11T16:23:43.090Z,1531326223.090 [NAL9602](INFO): NAL9602 initialized 2018-07-11T16:23:56.692Z,1531326236.692 [NAL9602](INFO): SBD MO Status=0, MOMSN=7239, MT Status=0, MTMSN=0 2018-07-11T16:23:56.692Z,1531326236.692 [NAL9602](INFO): No messages in MT queue 2018-07-11T16:24:35.346Z,1531326275.346 [NAL9602](INFO): GPS fix at 20180711T162426: (36.802438, -121.786774) 2018-07-11T16:24:35.431Z,1531326275.431 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T16:24:35.431Z,1531326275.431 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T16:24:41.481Z,1531326281.481 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180711T151914/Courier0037.lzma 2018-07-11T16:24:42.248Z,1531326282.248 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0037.lzma.bak 2018-07-11T16:24:42.248Z,1531326282.248 [DataOverHttps](INFO): SBD MOMSN=8362580 2018-07-11T16:24:51.123Z,1531326291.123 [DataOverHttps](INFO): Sending 301 bytes from file Logs/20180711T151914/Express0038.lzma 2018-07-11T16:24:51.924Z,1531326291.924 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0038.lzma.bak 2018-07-11T16:24:51.924Z,1531326291.924 [DataOverHttps](INFO): SBD MOMSN=8362583 2018-07-11T16:24:52.449Z,1531326292.450 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T16:24:52.450Z,1531326292.450 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T16:24:52.450Z,1531326292.450 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T16:25:11.582Z,1531326311.582 [NAL9602](INFO): Powering down 2018-07-11T16:29:52.829Z,1531326592.829 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T16:29:52.829Z,1531326592.829 [Default:CheckIn:C.Wait] Stopped 2018-07-11T16:29:52.830Z,1531326592.830 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T16:29:52.830Z,1531326592.830 [Default:CheckIn:D] Running Loop=1 2018-07-11T16:29:53.234Z,1531326593.234 [Default:CheckIn:D] Stopped 2018-07-11T16:29:53.234Z,1531326593.234 [Default:CheckIn:E] Running Loop=1 2018-07-11T16:29:53.639Z,1531326593.639 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.178292 min 2018-07-11T16:29:53.639Z,1531326593.639 [Default:CheckIn:E] Stopped 2018-07-11T16:29:53.639Z,1531326593.639 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T16:29:53.639Z,1531326593.639 [Default:CheckIn] Stopped 2018-07-11T16:29:53.640Z,1531326593.640 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T16:29:53.640Z,1531326593.640 [Default:CheckIn](INFO): Running loop #12 2018-07-11T16:29:53.640Z,1531326593.640 [Default:CheckIn] Running Loop=12 2018-07-11T16:29:53.640Z,1531326593.640 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T16:29:53.640Z,1531326593.640 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T16:29:56.870Z,1531326596.870 [NAL9602](INFO): Powering up 2018-07-11T16:30:08.018Z,1531326608.018 [NAL9602](INFO): NAL9602 initialized 2018-07-11T16:30:40.416Z,1531326640.416 [NAL9602](INFO): SBD MO Status=0, MOMSN=7240, MT Status=0, MTMSN=0 2018-07-11T16:30:40.416Z,1531326640.416 [NAL9602](INFO): No messages in MT queue 2018-07-11T16:30:58.929Z,1531326658.929 [NAL9602](INFO): GPS fix at 20180711T163050: (36.802301, -121.786757) 2018-07-11T16:30:59.002Z,1531326659.002 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T16:30:59.002Z,1531326659.002 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T16:31:03.413Z,1531326663.413 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180711T151914/Courier0040.lzma 2018-07-11T16:31:04.207Z,1531326664.207 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0040.lzma.bak 2018-07-11T16:31:04.208Z,1531326664.208 [DataOverHttps](INFO): SBD MOMSN=8362591 2018-07-11T16:31:13.102Z,1531326673.102 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20180711T151914/Express0041.lzma 2018-07-11T16:31:13.892Z,1531326673.892 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0041.lzma.bak 2018-07-11T16:31:13.892Z,1531326673.892 [DataOverHttps](INFO): SBD MOMSN=8362597 2018-07-11T16:31:14.410Z,1531326674.410 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T16:31:14.410Z,1531326674.410 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T16:31:14.410Z,1531326674.410 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T16:31:33.678Z,1531326693.678 [NAL9602](INFO): Powering down 2018-07-11T16:33:01.776Z,1531326781.776 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:33:01.776Z,1531326781.776 [Rowe_600LCM] No Fault, FailCount= 5 2018-07-11T16:33:01.977Z,1531326781.977 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:33:01.977Z,1531326781.977 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:33:01.978Z,1531326781.978 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:33:01.978Z,1531326781.978 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:33:06.110Z,1531326786.110 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:33:06.276Z,1531326786.276 [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 9600 >& /dev/null & 2018-07-11T16:33:06.278Z,1531326786.278 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:33:06.279Z,1531326786.279 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:33:06.280Z,1531326786.280 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:34:03.666Z,1531326843.666 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:34:04.461Z,1531326844.461 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:35:17.149Z,1531326917.149 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:35:17.149Z,1531326917.149 [Rowe_600LCM] Communications Fault, FailCount= 1 2018-07-11T16:35:17.149Z,1531326917.149 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:35:17.553Z,1531326917.553 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:35:17.746Z,1531326917.746 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:35:18.871Z,1531326918.871 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:35:19.031Z,1531326919.031 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:35:19.031Z,1531326919.031 [Rowe_600LCM] No Fault, FailCount= 1 2018-07-11T16:35:19.361Z,1531326919.361 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:35:19.361Z,1531326919.361 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:35:19.362Z,1531326919.362 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:35:19.362Z,1531326919.362 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:35:23.537Z,1531326923.537 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:35:23.609Z,1531326923.609 [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 9600 >& /dev/null & 2018-07-11T16:35:23.610Z,1531326923.610 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:35:23.611Z,1531326923.611 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:35:23.612Z,1531326923.612 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:35:40.466Z,1531326940.466 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:35:41.262Z,1531326941.262 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:36:15.023Z,1531326975.023 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T16:36:15.023Z,1531326975.023 [Default:CheckIn:C.Wait] Stopped 2018-07-11T16:36:15.023Z,1531326975.023 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T16:36:15.023Z,1531326975.023 [Default:CheckIn:D] Running Loop=1 2018-07-11T16:36:15.390Z,1531326975.390 [Default:CheckIn:D] Stopped 2018-07-11T16:36:15.390Z,1531326975.390 [Default:CheckIn:E] Running Loop=1 2018-07-11T16:36:18.683Z,1531326978.683 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.547550 min 2018-07-11T16:36:18.683Z,1531326978.683 [Default:CheckIn:E] Stopped 2018-07-11T16:36:18.683Z,1531326978.683 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T16:36:18.683Z,1531326978.683 [Default:CheckIn] Stopped 2018-07-11T16:36:18.684Z,1531326978.684 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T16:36:18.684Z,1531326978.684 [Default:CheckIn](INFO): Running loop #13 2018-07-11T16:36:18.684Z,1531326978.684 [Default:CheckIn] Running Loop=13 2018-07-11T16:36:18.684Z,1531326978.684 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T16:36:18.684Z,1531326978.684 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T16:36:19.130Z,1531326979.130 [NAL9602](INFO): Powering up 2018-07-11T16:36:29.930Z,1531326989.930 [NAL9602](INFO): NAL9602 initialized 2018-07-11T16:37:19.552Z,1531327039.552 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:37:19.552Z,1531327039.552 [Rowe_600LCM] Communications Fault, FailCount= 2 2018-07-11T16:37:19.552Z,1531327039.552 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:37:19.615Z,1531327039.615 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:37:19.957Z,1531327039.957 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:37:20.078Z,1531327040.078 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:37:21.529Z,1531327041.529 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:37:21.529Z,1531327041.529 [Rowe_600LCM] No Fault, FailCount= 2 2018-07-11T16:37:21.693Z,1531327041.693 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:37:21.693Z,1531327041.693 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:37:21.694Z,1531327041.694 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:37:21.694Z,1531327041.694 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:37:23.044Z,1531327043.044 [NAL9602](INFO): SBD MO Status=2, MOMSN=7241, MT Status=2, MTMSN=0 2018-07-11T16:37:23.044Z,1531327043.044 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-11T16:37:25.826Z,1531327045.826 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:37:25.983Z,1531327045.983 [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 9600 >& /dev/null & 2018-07-11T16:37:25.986Z,1531327045.986 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:37:25.986Z,1531327045.986 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:37:25.987Z,1531327045.987 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:37:42.649Z,1531327062.649 [NAL9602](INFO): SBD MO Status=2, MOMSN=7241, MT Status=2, MTMSN=0 2018-07-11T16:37:42.649Z,1531327062.649 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2018-07-11T16:37:57.452Z,1531327077.452 [NAL9602](INFO): SBD MO Status=0, MOMSN=7241, MT Status=0, MTMSN=0 2018-07-11T16:37:57.452Z,1531327077.452 [NAL9602](INFO): No messages in MT queue 2018-07-11T16:37:58.646Z,1531327078.646 [NAL9602](INFO): GPS fix at 20180711T163749: (36.802295, -121.786764) 2018-07-11T16:37:58.719Z,1531327078.719 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T16:37:58.719Z,1531327078.719 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T16:38:03.465Z,1531327083.465 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20180711T151914/Courier0043.lzma 2018-07-11T16:38:04.252Z,1531327084.252 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0043.lzma.bak 2018-07-11T16:38:04.252Z,1531327084.252 [DataOverHttps](INFO): SBD MOMSN=8362612 2018-07-11T16:38:09.662Z,1531327089.662 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:38:10.459Z,1531327090.459 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:38:13.680Z,1531327093.680 [DataOverHttps](INFO): Sending 200 bytes from file Logs/20180711T151914/Express0044.lzma 2018-07-11T16:38:14.472Z,1531327094.472 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0044.lzma.bak 2018-07-11T16:38:14.472Z,1531327094.472 [DataOverHttps](INFO): SBD MOMSN=8362615 2018-07-11T16:38:15.096Z,1531327095.096 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T16:38:15.096Z,1531327095.096 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T16:38:15.096Z,1531327095.096 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T16:38:30.122Z,1531327110.122 [NAL9602](INFO): Powering down 2018-07-11T16:39:22.345Z,1531327162.345 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:39:22.345Z,1531327162.345 [Rowe_600LCM] Communications Fault, FailCount= 3 2018-07-11T16:39:22.345Z,1531327162.345 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:39:22.488Z,1531327162.488 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:39:22.749Z,1531327162.749 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:39:22.974Z,1531327162.974 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:39:24.480Z,1531327164.480 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:39:24.480Z,1531327164.480 [Rowe_600LCM] No Fault, FailCount= 3 2018-07-11T16:39:24.589Z,1531327164.589 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:39:24.590Z,1531327164.590 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:39:24.590Z,1531327164.590 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:39:24.590Z,1531327164.590 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:39:28.752Z,1531327168.752 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:39:28.916Z,1531327168.916 [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 9600 >& /dev/null & 2018-07-11T16:39:28.918Z,1531327168.918 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:39:28.919Z,1531327168.919 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:39:28.920Z,1531327168.920 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:39:58.662Z,1531327198.662 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:39:59.457Z,1531327199.457 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:41:25.345Z,1531327285.345 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:41:25.345Z,1531327285.345 [Rowe_600LCM] Communications Fault, FailCount= 4 2018-07-11T16:41:25.345Z,1531327285.345 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:41:25.598Z,1531327285.598 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:41:25.749Z,1531327285.749 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:41:25.852Z,1531327285.852 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:41:27.221Z,1531327287.221 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:41:27.221Z,1531327287.221 [Rowe_600LCM] No Fault, FailCount= 4 2018-07-11T16:41:27.469Z,1531327287.469 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:41:27.469Z,1531327287.469 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:41:27.470Z,1531327287.470 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:41:27.470Z,1531327287.470 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:41:31.737Z,1531327291.737 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:41:31.812Z,1531327291.812 [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 9600 >& /dev/null & 2018-07-11T16:41:31.814Z,1531327291.814 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:41:31.815Z,1531327291.815 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:41:31.816Z,1531327291.816 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:43:15.700Z,1531327395.700 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T16:43:15.700Z,1531327395.700 [Default:CheckIn:C.Wait] Stopped 2018-07-11T16:43:15.700Z,1531327395.700 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T16:43:15.700Z,1531327395.700 [Default:CheckIn:D] Running Loop=1 2018-07-11T16:43:16.094Z,1531327396.094 [Default:CheckIn:D] Stopped 2018-07-11T16:43:16.094Z,1531327396.094 [Default:CheckIn:E] Running Loop=1 2018-07-11T16:43:16.489Z,1531327396.489 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 80.559294 min 2018-07-11T16:43:16.489Z,1531327396.489 [Default:CheckIn:E] Stopped 2018-07-11T16:43:16.490Z,1531327396.490 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T16:43:16.490Z,1531327396.490 [Default:CheckIn] Stopped 2018-07-11T16:43:16.490Z,1531327396.490 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T16:43:16.490Z,1531327396.490 [Default:CheckIn](INFO): Running loop #14 2018-07-11T16:43:16.490Z,1531327396.490 [Default:CheckIn] Running Loop=14 2018-07-11T16:43:16.490Z,1531327396.490 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T16:43:16.490Z,1531327396.490 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T16:43:20.159Z,1531327400.159 [NAL9602](INFO): Powering up 2018-07-11T16:43:25.662Z,1531327405.662 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:43:26.457Z,1531327406.457 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:43:27.587Z,1531327407.587 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:43:27.587Z,1531327407.587 [Rowe_600LCM] Communications Fault, FailCount= 5 2018-07-11T16:43:27.587Z,1531327407.587 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:43:27.655Z,1531327407.655 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:43:27.656Z,1531327407.656 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM 2018-07-11T16:43:27.989Z,1531327407.989 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:43:28.102Z,1531327408.102 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:43:31.095Z,1531327411.095 [NAL9602](INFO): NAL9602 initialized 2018-07-11T16:43:35.522Z,1531327415.522 [BPC1](FAULT): Failed to receive data from all sticks prior to timeout. Missing data from 13 sticks. 2018-07-11T16:43:35.522Z,1531327415.522 [BPC1] Data Fault, FailCount= 4 2018-07-11T16:43:35.522Z,1531327415.522 [BPC1](ERROR): Data Fault 2018-07-11T16:43:35.609Z,1531327415.609 [CBIT](ERROR): Data Fault in component: BPC1 2018-07-11T16:43:36.768Z,1531327416.768 [CBIT](INFO): Clearing failed state for component BPC1 2018-07-11T16:43:36.768Z,1531327416.768 [BPC1] No Fault, FailCount= 4 2018-07-11T16:43:53.484Z,1531327433.484 [NAL9602](INFO): SBD MO Status=0, MOMSN=7242, MT Status=0, MTMSN=0 2018-07-11T16:43:53.484Z,1531327433.484 [NAL9602](INFO): No messages in MT queue 2018-07-11T16:44:03.086Z,1531327443.086 [NAL9602](INFO): GPS fix at 20180711T164354: (36.808272, -121.785280) 2018-07-11T16:44:03.154Z,1531327443.154 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T16:44:03.154Z,1531327443.154 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T16:44:07.635Z,1531327447.635 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20180711T151914/Courier0046.lzma 2018-07-11T16:44:08.428Z,1531327448.428 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0046.lzma.bak 2018-07-11T16:44:08.428Z,1531327448.428 [DataOverHttps](INFO): SBD MOMSN=8362637 2018-07-11T16:44:17.814Z,1531327457.814 [DataOverHttps](INFO): Sending 318 bytes from file Logs/20180711T151914/Express0047.lzma 2018-07-11T16:44:18.612Z,1531327458.612 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0047.lzma.bak 2018-07-11T16:44:18.612Z,1531327458.612 [DataOverHttps](INFO): SBD MOMSN=8362640 2018-07-11T16:44:19.255Z,1531327459.255 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T16:44:19.255Z,1531327459.255 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T16:44:19.255Z,1531327459.255 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T16:44:37.990Z,1531327477.990 [NAL9602](INFO): Powering down 2018-07-11T16:49:19.500Z,1531327759.500 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T16:49:19.500Z,1531327759.500 [Default:CheckIn:C.Wait] Stopped 2018-07-11T16:49:19.500Z,1531327759.500 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T16:49:19.500Z,1531327759.500 [Default:CheckIn:D] Running Loop=1 2018-07-11T16:49:19.904Z,1531327759.904 [Default:CheckIn:D] Stopped 2018-07-11T16:49:19.904Z,1531327759.904 [Default:CheckIn:E] Running Loop=1 2018-07-11T16:49:20.296Z,1531327760.296 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 86.622795 min 2018-07-11T16:49:20.296Z,1531327760.296 [Default:CheckIn:E] Stopped 2018-07-11T16:49:20.297Z,1531327760.297 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T16:49:20.297Z,1531327760.297 [Default:CheckIn] Stopped 2018-07-11T16:49:20.297Z,1531327760.297 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T16:49:20.297Z,1531327760.297 [Default:CheckIn](INFO): Running loop #15 2018-07-11T16:49:20.297Z,1531327760.297 [Default:CheckIn] Running Loop=15 2018-07-11T16:49:20.297Z,1531327760.297 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T16:49:20.297Z,1531327760.297 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T16:49:21.046Z,1531327761.046 [NAL9602](INFO): Powering up 2018-07-11T16:49:31.882Z,1531327771.882 [NAL9602](INFO): NAL9602 initialized 2018-07-11T16:49:48.284Z,1531327788.284 [NAL9602](INFO): SBD MO Status=0, MOMSN=7243, MT Status=0, MTMSN=0 2018-07-11T16:49:48.284Z,1531327788.284 [NAL9602](INFO): No messages in MT queue 2018-07-11T16:50:40.746Z,1531327840.746 [NAL9602](INFO): GPS fix at 20180711T165032: (36.807755, -121.811447) 2018-07-11T16:50:40.829Z,1531327840.829 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T16:50:40.829Z,1531327840.829 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T16:50:45.316Z,1531327845.316 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20180711T151914/Courier0049.lzma 2018-07-11T16:50:46.116Z,1531327846.116 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Courier0049.lzma.bak 2018-07-11T16:50:46.116Z,1531327846.116 [DataOverHttps](INFO): SBD MOMSN=8362650 2018-07-11T16:50:55.009Z,1531327855.009 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20180711T151914/Express0050.lzma 2018-07-11T16:50:55.796Z,1531327855.796 [DataOverHttps](INFO): Moved sent file to Logs/20180711T151914/Express0050.lzma.bak 2018-07-11T16:50:55.796Z,1531327855.796 [DataOverHttps](INFO): SBD MOMSN=8362653 2018-07-11T16:50:56.338Z,1531327856.338 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T16:50:56.338Z,1531327856.338 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T16:50:56.338Z,1531327856.338 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T16:51:15.670Z,1531327875.670 [NAL9602](INFO): Powering down 2018-07-11T16:53:27.937Z,1531328007.937 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:53:27.937Z,1531328007.937 [Rowe_600LCM] No Fault, FailCount= 5 2018-07-11T16:53:28.333Z,1531328008.333 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:53:28.333Z,1531328008.333 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:53:28.333Z,1531328008.333 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:53:28.334Z,1531328008.334 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:53:32.462Z,1531328012.462 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:53:32.522Z,1531328012.522 [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 9600 >& /dev/null & 2018-07-11T16:53:32.523Z,1531328012.523 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:53:32.525Z,1531328012.525 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:53:32.525Z,1531328012.525 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:54:01.654Z,1531328041.654 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:54:02.450Z,1531328042.450 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:54:03.245Z,1531328043.245 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:54:03.941Z,1531328043.941 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:54:04.737Z,1531328044.737 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:54:05.534Z,1531328045.534 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:54:05.941Z,1531328045.941 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:54:57.654Z,1531328097.654 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:54:58.450Z,1531328098.450 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:08.218Z,1531328108.218 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:09.014Z,1531328109.014 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:09.461Z,1531328109.461 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:10.257Z,1531328110.257 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:11.054Z,1531328111.054 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:11.653Z,1531328111.653 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:12.449Z,1531328112.449 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:13.245Z,1531328113.245 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:13.941Z,1531328113.941 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:14.737Z,1531328114.737 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:15.534Z,1531328115.534 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:15.945Z,1531328115.945 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:16.741Z,1531328116.741 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:17.422Z,1531328117.422 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:18.217Z,1531328118.217 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:19.014Z,1531328119.014 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:19.421Z,1531328119.421 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:20.217Z,1531328120.217 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:21.014Z,1531328121.014 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:21.421Z,1531328121.421 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:22.217Z,1531328122.217 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:23.014Z,1531328123.014 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:23.465Z,1531328123.465 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:24.261Z,1531328124.261 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:25.058Z,1531328125.058 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:25.653Z,1531328125.653 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:26.449Z,1531328126.449 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:27.246Z,1531328127.246 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:27.945Z,1531328127.945 [Rowe_600LCM](DEBUG): LCB error: Software Overcurrent. 2018-07-11T16:55:28.337Z,1531328128.337 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2018-07-11T16:55:28.337Z,1531328128.337 [Rowe_600LCM] Communications Fault, FailCount= 1 2018-07-11T16:55:28.337Z,1531328128.337 [Rowe_600LCM](ERROR): Communications Fault 2018-07-11T16:55:28.573Z,1531328128.573 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2018-07-11T16:55:28.741Z,1531328128.741 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2018-07-11T16:55:28.843Z,1531328128.843 [Rowe_600LCM](INFO): Powering down 2018-07-11T16:55:29.653Z,1531328129.653 [Rowe_600LCM](FAULT): LCB fault: Software Overcurrent. 2018-07-11T16:55:29.653Z,1531328129.653 [Rowe_600LCM] Hardware Fault, FailCount= 1 2018-07-11T16:55:29.653Z,1531328129.653 [Rowe_600LCM](ERROR): Hardware Fault 2018-07-11T16:55:30.181Z,1531328130.181 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2018-07-11T16:55:30.181Z,1531328130.181 [Rowe_600LCM] No Fault, FailCount= 1 2018-07-11T16:55:30.461Z,1531328130.461 [Rowe_600LCM](INFO): Initializing 2018-07-11T16:55:30.461Z,1531328130.461 [Rowe_600LCM](INFO): Checking LCM 2018-07-11T16:55:30.462Z,1531328130.462 [Rowe_600LCM](INFO): LCM OK 2018-07-11T16:55:30.462Z,1531328130.462 [Rowe_600LCM](INFO): Powering up 2018-07-11T16:55:34.732Z,1531328134.732 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2018-07-11T16:55:34.808Z,1531328134.808 [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 9600 >& /dev/null & 2018-07-11T16:55:34.813Z,1531328134.813 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track 2018-07-11T16:55:34.814Z,1531328134.814 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity 2018-07-11T16:55:34.815Z,1531328134.815 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe 2018-07-11T16:55:56.957Z,1531328156.957 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2018-07-11T16:55:56.957Z,1531328156.957 [Default:CheckIn:C.Wait] Stopped 2018-07-11T16:55:56.957Z,1531328156.957 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2018-07-11T16:55:56.957Z,1531328156.957 [Default:CheckIn:D] Running Loop=1 2018-07-11T16:55:57.359Z,1531328157.359 [Default:CheckIn:D] Stopped 2018-07-11T16:55:57.360Z,1531328157.360 [Default:CheckIn:E] Running Loop=1 2018-07-11T16:56:00.861Z,1531328160.861 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.247046 min 2018-07-11T16:56:00.861Z,1531328160.861 [Default:CheckIn:E] Stopped 2018-07-11T16:56:00.861Z,1531328160.861 [Default:CheckIn](INFO): Completed Default:CheckIn 2018-07-11T16:56:00.861Z,1531328160.861 [Default:CheckIn] Stopped 2018-07-11T16:56:00.861Z,1531328160.861 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2018-07-11T16:56:00.862Z,1531328160.862 [Default:CheckIn](INFO): Running loop #16 2018-07-11T16:56:00.862Z,1531328160.862 [Default:CheckIn] Running Loop=16 2018-07-11T16:56:00.862Z,1531328160.862 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2018-07-11T16:56:00.862Z,1531328160.862 [Default:CheckIn:Read_GPS] Running Loop=1 2018-07-11T16:56:01.290Z,1531328161.290 [NAL9602](INFO): Powering up 2018-07-11T16:56:12.486Z,1531328172.486 [NAL9602](INFO): NAL9602 initialized 2018-07-11T16:56:13.042Z,1531328173.042 [Radio_Surface](INFO): Powering down 2018-07-11T16:56:13.342Z,1531328173.342 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -35.00 mm (1 active estimators). 2018-07-11T16:56:19.101Z,1531328179.101 [Radio_Surface](INFO): Powering up 2018-07-11T16:56:35.928Z,1531328195.928 [NAL9602](INFO): SBD MO Status=0, MOMSN=7244, MT Status=0, MTMSN=0 2018-07-11T16:56:35.928Z,1531328195.928 [NAL9602](INFO): No messages in MT queue 2018-07-11T16:57:11.930Z,1531328231.930 [NAL9602](INFO): GPS fix at 20180711T165703: (36.807040, -121.823364) 2018-07-11T16:57:11.998Z,1531328231.998 [Default:CheckIn:Read_GPS] Stopped 2018-07-11T16:57:11.998Z,1531328231.998 [Default:CheckIn:Read_Iridium] Running Loop=1 2018-07-11T16:57:27.116Z,1531328247.116 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2018-07-11T16:57:44.331Z,1531328264.331 [NAL9602](INFO): Powering down 2018-07-11T16:57:57.919Z,1531328277.919 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2018-07-11T16:58:28.324Z,1531328308.324 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2018-07-11T16:58:58.727Z,1531328338.727 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2018-07-11T16:59:02.318Z,1531328342.318 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.233093 2018-07-11T16:59:02.325Z,1531328342.325 [NAL9602](INFO): Powering up 2018-07-11T16:59:13.522Z,1531328353.522 [NAL9602](INFO): NAL9602 initialized 2018-07-11T16:59:27.624Z,1531328367.624 [NAL9602](INFO): SBD MO Status=1, MOMSN=7245, MT Status=0, MTMSN=0 2018-07-11T16:59:27.673Z,1531328367.673 [NAL9602](INFO): Sent 62 bytes from file Logs/20180711T151914/Courier0052.lzma 2018-07-11T16:59:27.673Z,1531328367.673 [NAL9602](INFO): Packets left to send: 0 2018-07-11T16:59:27.679Z,1531328367.679 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180711T151914/Courier0052.lzma.parts/0000.sbd 2018-07-11T16:59:27.679Z,1531328367.679 [NAL9602](DEBUG): Completed sending Logs/20180711T151914/Courier0052.lzma 2018-07-11T16:59:32.918Z,1531328372.918 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2018-07-11T16:59:35.324Z,1531328375.324 [NAL9602](INFO): SBD MO Status=1, MOMSN=7246, MT Status=0, MTMSN=0 2018-07-11T16:59:35.381Z,1531328375.381 [NAL9602](INFO): Sent 252 bytes from file Logs/20180711T151914/Express0053.lzma 2018-07-11T16:59:35.381Z,1531328375.381 [NAL9602](INFO): Packets left to send: 0 2018-07-11T16:59:35.383Z,1531328375.383 [NAL9602](DEBUG): Stored copy of sent data in Logs/20180711T151914/Express0053.lzma.parts/0000.sbd 2018-07-11T16:59:35.383Z,1531328375.383 [NAL9602](DEBUG): Completed sending Logs/20180711T151914/Express0053.lzma 2018-07-11T16:59:46.928Z,1531328386.928 [NAL9602](INFO): SBD MO Status=0, MOMSN=7247, MT Status=0, MTMSN=0 2018-07-11T16:59:47.049Z,1531328387.049 [Default:CheckIn:Read_Iridium] Stopped 2018-07-11T16:59:47.049Z,1531328387.049 [Default:CheckIn:C.Wait] Running Loop=1 2018-07-11T16:59:47.049Z,1531328387.049 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2018-07-11T17:00:07.939Z,1531328407.939 [DataOverHttps](IMPORTANT): SBD MTMSN=20180711T170000 2018-07-11T17:00:07.943Z,1531328407.943 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003517 2018-07-11T17:00:12.670Z,1531328412.670 [DataOverHttps](INFO): Received command:restart logs 2018-07-11T17:00:12.688Z,1531328412.688 [CommandLine](IMPORTANT): got command restart logs