2019-08-22T04:06:41.892Z,1566446801.892 [Supervisor](DEBUG): Initializing supervisor. 2019-08-22T04:06:41.895Z,1566446801.895 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-08-22T04:06:41.895Z,1566446801.895 [SyncHandler](INFO): Protected caller Thread ID is 3467 2019-08-22T04:06:41.896Z,1566446801.896 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-08-22T04:06:41.897Z,1566446801.897 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-08-22T04:06:41.897Z,1566446801.897 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3468 2019-08-22T04:06:41.900Z,1566446801.900 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-08-22T04:06:41.911Z,1566446801.911 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-08-22T04:06:41.912Z,1566446801.912 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-08-22T04:06:41.912Z,1566446801.912 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3469 2019-08-22T04:06:41.913Z,1566446801.913 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-08-22T04:06:41.914Z,1566446801.914 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-08-22T04:06:41.915Z,1566446801.915 [logger ThreadHandler](INFO): Protected caller Thread ID is 3470 2019-08-22T04:06:41.917Z,1566446801.917 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-08-22T04:06:41.917Z,1566446801.917 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-08-22T04:06:41.918Z,1566446801.918 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-08-22T04:06:42.017Z,1566446802.017 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-08-22T04:06:42.018Z,1566446802.018 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-08-22T04:06:42.563Z,1566446802.563 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-08-22T04:06:42.563Z,1566446802.563 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-08-22T04:06:42.664Z,1566446802.664 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-08-22T04:06:42.664Z,1566446802.664 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-08-22T04:06:42.768Z,1566446802.768 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-08-22T04:06:42.768Z,1566446802.768 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-08-22T04:06:42.850Z,1566446802.850 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-08-22T04:06:42.990Z,1566446802.990 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-08-22T04:06:42.990Z,1566446802.990 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-08-22T04:06:43.285Z,1566446803.285 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-08-22T04:06:43.286Z,1566446803.286 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-08-22T04:06:43.737Z,1566446803.737 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-08-22T04:06:43.738Z,1566446803.738 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-08-22T04:06:43.885Z,1566446803.885 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-08-22T04:06:43.886Z,1566446803.886 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-08-22T04:06:44.088Z,1566446804.088 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-08-22T04:06:44.089Z,1566446804.089 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-08-22T04:06:44.538Z,1566446804.538 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-08-22T04:06:44.539Z,1566446804.539 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-08-22T04:06:44.754Z,1566446804.754 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-08-22T04:06:44.755Z,1566446804.755 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-08-22T04:06:44.956Z,1566446804.956 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-08-22T04:06:44.957Z,1566446804.957 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-08-22T04:06:45.346Z,1566446805.346 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-08-22T04:06:45.347Z,1566446805.347 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-08-22T04:06:45.680Z,1566446805.680 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-08-22T04:06:45.682Z,1566446805.682 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2019-08-22T04:06:45.683Z,1566446805.683 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2019-08-22T04:06:45.768Z,1566446805.768 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2019-08-22T04:06:45.926Z,1566446805.926 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2019-08-22T04:06:46.071Z,1566446806.071 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2019-08-22T04:06:46.301Z,1566446806.301 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2019-08-22T04:06:46.421Z,1566446806.421 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2019-08-22T04:06:46.875Z,1566446806.875 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2019-08-22T04:06:47.323Z,1566446807.323 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-08-22T04:06:47.324Z,1566446807.324 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2019-08-22T04:06:47.419Z,1566446807.419 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2019-08-22T04:06:47.519Z,1566446807.519 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2019-08-22T04:06:47.641Z,1566446807.641 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2019-08-22T04:06:47.744Z,1566446807.744 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/ 2019-08-22T04:06:47.744Z,1566446807.744 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-08-22T04:06:47.751Z,1566446807.751 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-08-22T04:06:47.816Z,1566446807.816 [VerticalControl](DEBUG): Construct VerticalControl. 2019-08-22T04:06:47.925Z,1566446807.925 [VerticalControl] Loaded 2019-08-22T04:06:47.925Z,1566446807.925 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-08-22T04:06:47.926Z,1566446807.926 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-08-22T04:06:47.992Z,1566446807.992 [HorizontalControl] Loaded 2019-08-22T04:06:47.993Z,1566446807.993 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-08-22T04:06:47.993Z,1566446807.993 [SpeedControl](DEBUG): Construct SpeedControl. 2019-08-22T04:06:47.999Z,1566446807.999 [SpeedControl] Loaded 2019-08-22T04:06:47.999Z,1566446807.999 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-08-22T04:06:47.000Z,1566446808.000 [LoopControl](DEBUG): Construct LoopControl. 2019-08-22T04:06:48.000Z,1566446808.000 [LoopControl] Loaded 2019-08-22T04:06:48.001Z,1566446808.001 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-08-22T04:06:48.001Z,1566446808.001 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-08-22T04:06:48.002Z,1566446808.002 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-08-22T04:06:48.041Z,1566446808.041 [DepthRateCalculator] Loaded 2019-08-22T04:06:48.041Z,1566446808.041 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-08-22T04:06:48.046Z,1566446808.046 [PitchRateCalculator] Loaded 2019-08-22T04:06:48.046Z,1566446808.046 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-08-22T04:06:48.061Z,1566446808.061 [SpeedCalculator] Loaded 2019-08-22T04:06:48.061Z,1566446808.061 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-08-22T04:06:48.082Z,1566446808.082 [TempGradientCalculator] Loaded 2019-08-22T04:06:48.082Z,1566446808.082 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-08-22T04:06:48.087Z,1566446808.087 [YawRateCalculator] Loaded 2019-08-22T04:06:48.087Z,1566446808.087 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-08-22T04:06:48.115Z,1566446808.115 [ElevatorOffsetCalculator] Loaded 2019-08-22T04:06:48.115Z,1566446808.115 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-08-22T04:06:48.116Z,1566446808.116 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-08-22T04:06:48.116Z,1566446808.116 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-08-22T04:06:48.146Z,1566446808.146 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-08-22T04:06:48.147Z,1566446808.147 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-08-22T04:06:48.213Z,1566446808.213 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-08-22T04:06:48.213Z,1566446808.213 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-08-22T04:06:48.488Z,1566446808.488 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-08-22T04:06:48.489Z,1566446808.489 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-08-22T04:06:48.582Z,1566446808.582 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-08-22T04:06:48.582Z,1566446808.582 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-08-22T04:06:48.937Z,1566446808.937 [AHRS_M2] Loaded 2019-08-22T04:06:48.937Z,1566446808.937 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-08-22T04:06:49.013Z,1566446809.013 [DataOverHttps] Loaded 2019-08-22T04:06:49.013Z,1566446809.013 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-08-22T04:06:49.014Z,1566446809.014 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408CA4E0 2019-08-22T04:06:49.014Z,1566446809.014 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3549 2019-08-22T04:06:49.027Z,1566446809.027 [Depth_Keller] Loaded 2019-08-22T04:06:49.027Z,1566446809.027 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-08-22T04:06:49.032Z,1566446809.032 [DropWeight] Loaded 2019-08-22T04:06:49.032Z,1566446809.032 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-08-22T04:06:49.125Z,1566446809.125 [NAL9602] Loaded 2019-08-22T04:06:49.126Z,1566446809.126 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-08-22T04:06:49.141Z,1566446809.141 [Onboard] Loaded 2019-08-22T04:06:49.142Z,1566446809.142 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-08-22T04:06:49.145Z,1566446809.145 [Radio_Surface] Loaded 2019-08-22T04:06:49.145Z,1566446809.145 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-08-22T04:06:49.146Z,1566446809.146 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408FA4E0 2019-08-22T04:06:49.147Z,1566446809.147 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3550 2019-08-22T04:06:49.205Z,1566446809.205 [Rowe_600LCM] Loaded 2019-08-22T04:06:49.205Z,1566446809.205 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2019-08-22T04:06:49.206Z,1566446809.206 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 4092A4E0 2019-08-22T04:06:49.207Z,1566446809.207 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 3551 2019-08-22T04:06:50.649Z,1566446810.649 [BPC1] Loaded 2019-08-22T04:06:50.649Z,1566446810.649 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-08-22T04:06:50.650Z,1566446810.650 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-08-22T04:06:50.650Z,1566446810.650 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-08-22T04:06:50.749Z,1566446810.749 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-08-22T04:06:50.749Z,1566446810.749 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-08-22T04:06:50.769Z,1566446810.769 [NavChart] Loaded 2019-08-22T04:06:50.770Z,1566446810.770 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-08-22T04:06:50.774Z,1566446810.774 [UniversalFixResidualReporter] Loaded 2019-08-22T04:06:50.774Z,1566446810.774 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-08-22T04:06:50.774Z,1566446810.774 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-08-22T04:06:50.775Z,1566446810.775 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-08-22T04:06:50.899Z,1566446810.899 [SBIT](DEBUG): Construct Startup Built In Test. 2019-08-22T04:06:50.910Z,1566446810.910 [SBIT] Loaded 2019-08-22T04:06:50.910Z,1566446810.910 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-08-22T04:06:50.911Z,1566446810.911 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-08-22T04:06:50.922Z,1566446810.922 [IBIT] Loaded 2019-08-22T04:06:50.923Z,1566446810.923 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-08-22T04:06:50.926Z,1566446810.926 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-08-22T04:06:51.061Z,1566446811.061 [CBIT] Loaded 2019-08-22T04:06:51.061Z,1566446811.061 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-08-22T04:06:51.062Z,1566446811.062 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-08-22T04:06:51.062Z,1566446811.062 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-08-22T04:06:51.374Z,1566446811.374 [BuoyancyServo] Loaded 2019-08-22T04:06:51.374Z,1566446811.374 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-08-22T04:06:51.385Z,1566446811.385 [ElevatorServo] Loaded 2019-08-22T04:06:51.385Z,1566446811.385 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-08-22T04:06:51.396Z,1566446811.396 [MassServo] Loaded 2019-08-22T04:06:51.396Z,1566446811.396 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-08-22T04:06:51.442Z,1566446811.442 [RudderServo] Loaded 2019-08-22T04:06:51.442Z,1566446811.442 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-08-22T04:06:51.471Z,1566446811.471 [ThrusterServo] Loaded 2019-08-22T04:06:51.472Z,1566446811.472 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-08-22T04:06:51.472Z,1566446811.472 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-08-22T04:06:51.473Z,1566446811.473 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-08-22T04:06:51.485Z,1566446811.485 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-08-22T04:06:51.486Z,1566446811.486 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-08-22T04:06:51.650Z,1566446811.650 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-08-22T04:06:51.656Z,1566446811.656 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-08-22T04:06:51.657Z,1566446811.657 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-08-22T04:06:51.662Z,1566446811.662 [CTD_Seabird](INFO): created writer for : depth 2019-08-22T04:06:51.662Z,1566446811.662 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-08-22T04:06:51.667Z,1566446811.667 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-08-22T04:06:51.668Z,1566446811.668 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-08-22T04:06:51.673Z,1566446811.673 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-08-22T04:06:51.673Z,1566446811.673 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-08-22T04:06:51.678Z,1566446811.678 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-08-22T04:06:51.679Z,1566446811.679 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-08-22T04:06:51.684Z,1566446811.684 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-08-22T04:06:51.685Z,1566446811.685 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-08-22T04:06:51.690Z,1566446811.690 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-08-22T04:06:51.716Z,1566446811.716 [CTD_Seabird] Loaded 2019-08-22T04:06:51.716Z,1566446811.716 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-08-22T04:06:51.717Z,1566446811.717 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AAE4E0 2019-08-22T04:06:51.718Z,1566446811.718 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3552 2019-08-22T04:06:51.765Z,1566446811.765 [WetLabsBB2FL] Loaded 2019-08-22T04:06:51.765Z,1566446811.765 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-08-22T04:06:51.766Z,1566446811.766 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40ADE4E0 2019-08-22T04:06:51.766Z,1566446811.766 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3553 2019-08-22T04:06:51.767Z,1566446811.767 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-08-22T04:06:51.770Z,1566446811.770 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-08-22T04:06:51.771Z,1566446811.771 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-08-22T04:06:51.778Z,1566446811.778 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-08-22T04:06:51.779Z,1566446811.779 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0E4E0 2019-08-22T04:06:51.779Z,1566446811.779 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3554 2019-08-22T04:06:51.784Z,1566446811.784 [Supervisor](INFO): Main Thread ID is 2500 2019-08-22T04:06:51.784Z,1566446811.784 [Supervisor](DEBUG): Running supervisor. 2019-08-22T04:06:51.785Z,1566446811.785 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3555 2019-08-22T04:06:51.787Z,1566446811.787 [controlThread ThreadHandler](INFO): Handler Thread ID is 3556 2019-08-22T04:06:51.787Z,1566446811.787 [controlThread](DEBUG): Initializing ControlThread 2019-08-22T04:06:51.788Z,1566446811.788 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-08-22T04:06:51.790Z,1566446811.790 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-08-22T04:06:51.790Z,1566446811.790 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-08-22T04:06:51.791Z,1566446811.791 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-08-22T04:06:51.791Z,1566446811.791 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-08-22T04:06:51.792Z,1566446811.792 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-08-22T04:06:51.792Z,1566446811.792 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-08-22T04:06:51.792Z,1566446811.792 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-08-22T04:06:51.793Z,1566446811.793 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-08-22T04:06:51.793Z,1566446811.793 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-08-22T04:06:51.798Z,1566446811.798 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-08-22T04:06:51.799Z,1566446811.799 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-08-22T04:06:51.799Z,1566446811.799 [SBIT](INFO): Initialize SBIT Component. 2019-08-22T04:06:51.799Z,1566446811.799 [SBIT](IMPORTANT): git: 2019-08-21 2019-08-22T04:06:51.800Z,1566446811.800 [SBIT](INFO): git hash: 91726968a91bb65c09438a13bfa0101a916cbc64 2019-08-22T04:06:51.800Z,1566446811.800 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-08-22T04:06:51.800Z,1566446811.800 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-08-22T04:06:51.801Z,1566446811.801 [SBIT](INFO): Beginning SBIT in 59.000000 seconds. 2019-08-22T04:06:51.802Z,1566446811.802 [IBIT](INFO): Initialize IBIT Component. 2019-08-22T04:06:51.803Z,1566446811.803 [CBIT](DEBUG): Initialize CBIT Component. 2019-08-22T04:06:51.804Z,1566446811.804 [logger ThreadHandler](INFO): Handler Thread ID is 3557 2019-08-22T04:06:51.816Z,1566446811.816 [CBIT](DEBUG): Initialized mux pins. 2019-08-22T04:06:51.816Z,1566446811.816 [CBIT](DEBUG): Initializing the watchdog timer. 2019-08-22T04:06:51.824Z,1566446811.824 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3558 2019-08-22T04:06:51.825Z,1566446811.825 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-08-22T04:06:51.836Z,1566446811.836 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3559 2019-08-22T04:06:51.840Z,1566446811.840 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-08-22T04:06:51.840Z,1566446811.840 [CBIT](DEBUG): Initializing heartbeat. 2019-08-22T04:06:51.848Z,1566446811.848 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 3560 2019-08-22T04:06:51.849Z,1566446811.849 [Rowe_600LCM](INFO): Initializing 2019-08-22T04:06:51.868Z,1566446811.868 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3561 2019-08-22T04:06:51.869Z,1566446811.869 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-08-22T04:06:51.872Z,1566446811.872 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-08-22T04:06:51.873Z,1566446811.873 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3563 2019-08-22T04:06:51.875Z,1566446811.875 [WetLabsBB2FL](INFO): Powering down 2019-08-22T04:06:51.904Z,1566446811.904 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3564 2019-08-22T04:06:51.907Z,1566446811.907 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-08-22T04:06:51.907Z,1566446811.907 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-08-22T04:06:51.908Z,1566446811.908 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-08-22T04:06:51.908Z,1566446811.908 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-08-22T04:06:51.908Z,1566446811.908 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-08-22T04:06:51.908Z,1566446811.908 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-08-22T04:06:51.908Z,1566446811.908 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-08-22T04:06:51.908Z,1566446811.908 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-08-22T04:06:51.909Z,1566446811.909 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-08-22T04:06:51.909Z,1566446811.909 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-08-22T04:06:51.909Z,1566446811.909 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-08-22T04:06:51.909Z,1566446811.909 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-08-22T04:06:51.909Z,1566446811.909 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-08-22T04:06:51.910Z,1566446811.910 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-08-22T04:06:51.910Z,1566446811.910 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-08-22T04:06:51.910Z,1566446811.910 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-08-22T04:06:51.912Z,1566446811.912 [CBIT](DEBUG): Deactivating GF circuits. 2019-08-22T04:06:51.912Z,1566446811.912 [CBIT](DEBUG): Deactivating emergency mode. 2019-08-22T04:06:51.948Z,1566446811.948 [CBIT](DEBUG): Backplane powered. 2019-08-22T04:06:51.949Z,1566446811.949 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-08-22T04:06:51.959Z,1566446811.959 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-08-22T04:06:51.970Z,1566446811.970 [MissionManager](DEBUG): 2019-08-22T04:06:51.971Z,1566446811.971 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-08-22T04:06:52.050Z,1566446812.050 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-08-22T04:06:52.051Z,1566446812.051 [Default:A.Wait](DEBUG): Construct Wait. 2019-08-22T04:06:52.053Z,1566446812.053 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-08-22T04:06:52.086Z,1566446812.086 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-08-22T04:06:52.089Z,1566446812.089 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-08-22T04:06:52.143Z,1566446812.143 [Default:E.Execute](DEBUG): Construct Execute. 2019-08-22T04:06:52.147Z,1566446812.147 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2019-08-22T04:06:52.163Z,1566446812.163 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-08-22T04:06:52.169Z,1566446812.169 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-08-22T04:06:52.206Z,1566446812.206 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar 2019-08-22T04:06:52.240Z,1566446812.240 [Radio_Surface](INFO): Powering up 2019-08-22T04:06:52.284Z,1566446812.284 [DepthRateCalculator](ERROR): Depth measurement is not active 2019-08-22T04:06:52.326Z,1566446812.326 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-08-22T04:06:52.332Z,1566446812.332 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-08-22T04:06:52.334Z,1566446812.334 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-08-22T04:06:52.344Z,1566446812.344 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-08-22T04:06:52.345Z,1566446812.345 [MassServo](DEBUG): Initializing EZServoServo. 2019-08-22T04:06:52.356Z,1566446812.356 [MassServo](DEBUG): Initializing MassServo. 2019-08-22T04:06:52.357Z,1566446812.357 [RudderServo](DEBUG): Initializing EZServoServo. 2019-08-22T04:06:52.368Z,1566446812.368 [RudderServo](DEBUG): Initializing RudderServo. 2019-08-22T04:06:52.369Z,1566446812.369 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-08-22T04:06:52.380Z,1566446812.380 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-08-22T04:06:52.530Z,1566446812.530 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-08-22T04:06:52.631Z,1566446812.631 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./auv-shared/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null & 2019-08-22T04:06:53.340Z,1566446813.340 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-08-22T04:06:53.340Z,1566446813.340 [RudderServo](FAULT): Rudder failed to initialize 2019-08-22T04:06:53.340Z,1566446813.340 [RudderServo] Communications Fault, FailCount= 1 2019-08-22T04:06:53.340Z,1566446813.340 [RudderServo](ERROR): Communications Fault 2019-08-22T04:06:53.451Z,1566446813.451 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-08-22T04:06:53.613Z,1566446813.613 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-08-22T04:06:53.613Z,1566446813.613 [RudderServo](INFO): Powering down 2019-08-22T04:06:54.303Z,1566446814.303 [RudderServo](DEBUG): Initializing EZServoServo. 2019-08-22T04:06:54.304Z,1566446814.304 [RudderServo](DEBUG): Initializing RudderServo. 2019-08-22T04:06:54.320Z,1566446814.320 [CBIT](INFO): Clearing failed state for component RudderServo 2019-08-22T04:06:54.320Z,1566446814.320 [RudderServo] No Fault, FailCount= 1 2019-08-22T04:07:19.318Z,1566446839.318 [NAL9602](INFO): Powering up NAL9602 2019-08-22T04:07:29.006Z,1566446849.006 [CommandLine](IMPORTANT): got command failComponent 2019-08-22T04:07:29.006Z,1566446849.006 [CommandLine](IMPORTANT): Failed components: 2019-08-22T04:07:29.006Z,1566446849.006 [CommandLine](IMPORTANT): No failed Components. 2019-08-22T04:07:30.233Z,1566446850.233 [NAL9602](INFO): NAL9602 initialized 2019-08-22T04:07:31.052Z,1566446851.052 [NAL9602](DEBUG): Fix Requested 2019-08-22T04:07:36.973Z,1566446856.973 [CommandLine](IMPORTANT): got command show best height_above_sea_floor 2019-08-22T04:07:36.973Z,1566446856.973 [CommandLine](IMPORTANT): height_above_sea_floor best is null 2019-08-22T04:07:51.316Z,1566446871.316 [SBIT](IMPORTANT): Beginning Startup BIT 2019-08-22T04:07:51.328Z,1566446871.328 [CBIT](IMPORTANT): Beginning ground fault scan 2019-08-22T04:08:02.376Z,1566446882.376 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): -0.008456 CHAN A1 (24V): 0.171524 CHAN A2 (12V): -0.006974 CHAN A3 (5V): -0.002351 CHAN B0 (3.3V): -0.000770 CHAN B1 (3.15aV): -0.000369 CHAN B2 (3.15bV): 0.000040 CHAN B3 (GND): 0.002274 OPEN: 0.006966 Full Scale Calc: 4.765 mA, -1.589 mA 2019-08-22T04:08:45.081Z,1566446925.081 [SBIT](IMPORTANT): SBIT PASSED 2019-08-22T04:08:45.128Z,1566446925.128 [CommandLine](IMPORTANT): got command configSet list 2019-08-22T04:08:45.128Z,1566446925.128 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-08-22T04:08:45.129Z,1566446925.129 [CommandLine](IMPORTANT): Micromodem.loadAtStartup=0 bool; 2019-08-22T04:08:45.129Z,1566446925.129 [CommandLine](IMPORTANT): Rowe_600.loadAtStartup=0 bool; 2019-08-22T04:08:45.129Z,1566446925.129 [CommandLine](IMPORTANT): Rowe_600LCM.baud=9600 bit_per_second; 2019-08-22T04:08:45.130Z,1566446925.130 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=1 bool; 2019-08-22T04:08:45.130Z,1566446925.130 [CommandLine](IMPORTANT): VerticalControl.massDefault=10 millimeter; 2019-08-22T04:08:45.477Z,1566446925.477 [MissionManager](IMPORTANT): Started mission Startup 2019-08-22T04:08:45.477Z,1566446925.477 [Startup] Running Loop=1 2019-08-22T04:08:45.477Z,1566446925.477 [Startup](DEBUG): Aggregate::initialize Startup 2019-08-22T04:08:45.477Z,1566446925.477 [Startup:A.GoToSurface] Running Loop=1 2019-08-22T04:08:45.477Z,1566446925.477 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-08-22T04:08:45.478Z,1566446925.478 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-08-22T04:08:45.479Z,1566446925.479 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-08-22T04:08:45.479Z,1566446925.479 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-08-22T04:08:45.479Z,1566446925.479 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-08-22T04:08:45.480Z,1566446925.480 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-08-22T04:08:45.481Z,1566446925.481 [Startup:StartupSatComms] Running Loop=1 2019-08-22T04:08:45.481Z,1566446925.481 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-08-22T04:08:45.481Z,1566446925.481 [Startup:StartupSatComms:A] Running Loop=1 2019-08-22T04:08:45.885Z,1566446925.885 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-08-22T04:08:51.996Z,1566446931.996 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-08-22T04:08:51.996Z,1566446931.996 [Rowe_600LCM] Communications Fault, FailCount= 1 2019-08-22T04:08:51.996Z,1566446931.996 [Rowe_600LCM](ERROR): Communications Fault 2019-08-22T04:08:52.353Z,1566446932.353 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-08-22T04:08:52.400Z,1566446932.400 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-08-22T04:08:53.962Z,1566446933.962 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2019-08-22T04:08:53.962Z,1566446933.962 [Rowe_600LCM] No Fault, FailCount= 1 2019-08-22T04:08:54.200Z,1566446934.200 [Rowe_600LCM](INFO): Initializing 2019-08-22T04:08:54.687Z,1566446934.687 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-08-22T04:08:54.819Z,1566446934.819 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./auv-shared/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null & 2019-08-22T04:09:14.700Z,1566446954.700 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T04:09:17.890Z,1566446957.890 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004947 2019-08-22T04:09:27.592Z,1566446967.592 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T04:09:40.929Z,1566446980.929 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T04:09:45.665Z,1566446985.665 [Startup:StartupSatComms:A](INFO): Timed out from 2019-08-22T04:08:45.5Z 2019-08-22T04:09:45.665Z,1566446985.665 [Startup:StartupSatComms:A] Stopped 2019-08-22T04:09:45.665Z,1566446985.665 [Startup:StartupSatComms:B] Running Loop=1 2019-08-22T04:09:46.065Z,1566446986.065 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-08-22T04:09:52.136Z,1566446992.136 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-08-22T04:09:52.136Z,1566446992.136 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-22T04:09:52.191Z,1566446992.191 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-22T04:09:52.541Z,1566446992.541 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-22T04:09:52.541Z,1566446992.541 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-08-22T04:09:56.343Z,1566446996.343 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190822T034835/Courier0013.lzma 2019-08-22T04:09:57.150Z,1566446997.150 [DataOverHttps](INFO): Moved sent file to Logs/20190822T034835/Courier0013.lzma.bak 2019-08-22T04:09:57.150Z,1566446997.150 [DataOverHttps](INFO): SBD MOMSN=11665613 2019-08-22T04:10:07.233Z,1566447007.233 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T04:10:18.149Z,1566447018.149 [DataOverHttps](INFO): Sending 258 bytes from file Logs/20190822T034835/Express0014.lzma 2019-08-22T04:10:18.954Z,1566447018.954 [DataOverHttps](INFO): Moved sent file to Logs/20190822T034835/Express0014.lzma.bak 2019-08-22T04:10:18.954Z,1566447018.954 [DataOverHttps](INFO): SBD MOMSN=11665615 2019-08-22T04:10:36.349Z,1566447036.349 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-08-22T04:10:40.665Z,1566447040.665 [DataOverHttps](INFO): Sending 913 bytes from file Logs/20190822T040641/Express0001.lzma 2019-08-22T04:10:41.469Z,1566447041.469 [DataOverHttps](INFO): Moved sent file to Logs/20190822T040641/Express0001.lzma.bak 2019-08-22T04:10:41.469Z,1566447041.469 [DataOverHttps](INFO): SBD MOMSN=11665621 2019-08-22T04:10:45.881Z,1566447045.881 [Startup:StartupSatComms:B](INFO): Timed out from 2019-08-22T04:09:45.7Z 2019-08-22T04:10:45.881Z,1566447045.881 [Startup:StartupSatComms:B] Stopped 2019-08-22T04:10:45.881Z,1566447045.881 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-08-22T04:10:45.881Z,1566447045.881 [Startup:StartupSatComms] Stopped 2019-08-22T04:10:45.882Z,1566447045.882 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-08-22T04:10:45.882Z,1566447045.882 [Startup](INFO): Completed Startup 2019-08-22T04:10:45.882Z,1566447045.882 [MissionManager](INFO): Startup is completed. 2019-08-22T04:10:45.883Z,1566447045.883 [MissionManager](INFO): Uninitializing Mission Startup 2019-08-22T04:10:45.883Z,1566447045.883 [Startup] Stopped 2019-08-22T04:10:45.883Z,1566447045.883 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-08-22T04:10:45.883Z,1566447045.883 [Startup:A.GoToSurface] Stopped 2019-08-22T04:10:45.883Z,1566447045.883 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-08-22T04:10:46.285Z,1566447046.285 [MissionManager](IMPORTANT): Started mission Default 2019-08-22T04:10:46.285Z,1566447046.285 [Default] Running Loop=1 2019-08-22T04:10:46.285Z,1566447046.285 [Default](DEBUG): Aggregate::initialize Default 2019-08-22T04:10:46.285Z,1566447046.285 [Default:B.GoToSurface] Running Loop=1 2019-08-22T04:10:46.285Z,1566447046.285 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-08-22T04:10:46.285Z,1566447046.285 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-08-22T04:10:46.286Z,1566447046.286 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-08-22T04:10:46.286Z,1566447046.286 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-08-22T04:10:46.286Z,1566447046.286 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-08-22T04:10:46.287Z,1566447046.287 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-08-22T04:10:46.287Z,1566447046.287 [Default:A.Wait] Running Loop=1 2019-08-22T04:10:46.287Z,1566447046.287 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-08-22T04:10:47.601Z,1566447047.601 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T04:10:53.947Z,1566447053.947 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T04:10:54.308Z,1566447054.308 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-08-22T04:10:54.308Z,1566447054.308 [Rowe_600LCM] Communications Fault, FailCount= 2 2019-08-22T04:10:54.308Z,1566447054.308 [Rowe_600LCM](ERROR): Communications Fault 2019-08-22T04:10:54.377Z,1566447054.377 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-08-22T04:10:54.722Z,1566447054.722 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-08-22T04:10:56.397Z,1566447056.397 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2019-08-22T04:10:56.397Z,1566447056.397 [Rowe_600LCM] No Fault, FailCount= 2 2019-08-22T04:10:56.632Z,1566447056.632 [Rowe_600LCM](INFO): Initializing 2019-08-22T04:10:57.116Z,1566447057.116 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-08-22T04:10:57.254Z,1566447057.254 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./auv-shared/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null & 2019-08-22T04:10:59.609Z,1566447059.609 [Default:A.Wait](INFO): Done Waiting. 2019-08-22T04:10:59.609Z,1566447059.609 [Default:A.Wait] Stopped 2019-08-22T04:10:59.609Z,1566447059.609 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-08-22T04:11:00.011Z,1566447060.011 [Default:CheckIn] Running Loop=1 2019-08-22T04:11:00.011Z,1566447060.011 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-22T04:11:00.011Z,1566447060.011 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-22T04:11:00.444Z,1566447060.444 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-08-22T04:11:05.707Z,1566447065.707 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T04:11:17.172Z,1566447077.172 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T04:12:33.705Z,1566447153.705 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-22T04:12:34.524Z,1566447154.524 [NAL9602](DEBUG): Fix Requested 2019-08-22T04:12:34.923Z,1566447154.923 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,041234.00,A,3648.16717,N,12147.28130,W,0.389,317.22,220819,,,A*7D 2019-08-22T04:12:34.926Z,1566447154.926 [NAL9602](INFO): GPS fix at 20190822T041234: (36.802786, -121.788022) 2019-08-22T04:12:34.995Z,1566447154.995 [Default:CheckIn:Read_GPS] Stopped 2019-08-22T04:12:34.995Z,1566447154.995 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-22T04:12:35.383Z,1566447155.383 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-08-22T04:12:48.796Z,1566447168.796 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20190822T040641/Courier0004.lzma 2019-08-22T04:12:49.601Z,1566447169.601 [DataOverHttps](INFO): Moved sent file to Logs/20190822T040641/Courier0004.lzma.bak 2019-08-22T04:12:49.602Z,1566447169.602 [DataOverHttps](INFO): SBD MOMSN=11665653 2019-08-22T04:12:57.440Z,1566447177.440 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-08-22T04:12:57.440Z,1566447177.440 [Rowe_600LCM] Communications Fault, FailCount= 3 2019-08-22T04:12:57.440Z,1566447177.440 [Rowe_600LCM](ERROR): Communications Fault 2019-08-22T04:12:57.537Z,1566447177.537 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-08-22T04:12:57.844Z,1566447177.844 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-08-22T04:12:59.500Z,1566447179.500 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2019-08-22T04:12:59.500Z,1566447179.500 [Rowe_600LCM] No Fault, FailCount= 3 2019-08-22T04:12:59.780Z,1566447179.780 [Rowe_600LCM](INFO): Initializing 2019-08-22T04:13:00.849Z,1566447180.849 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-08-22T04:13:01.047Z,1566447181.047 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./auv-shared/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null & 2019-08-22T04:13:07.141Z,1566447187.141 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-22T04:13:08.688Z,1566447188.688 [DataOverHttps](INFO): Sending 360 bytes from file Logs/20190822T040641/Express0005.lzma 2019-08-22T04:13:09.493Z,1566447189.493 [DataOverHttps](INFO): Moved sent file to Logs/20190822T040641/Express0005.lzma.bak 2019-08-22T04:13:09.493Z,1566447189.493 [DataOverHttps](INFO): SBD MOMSN=11665656 2019-08-22T04:13:12.019Z,1566447192.019 [Default:CheckIn:Read_Iridium] Stopped 2019-08-22T04:13:12.019Z,1566447192.019 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-22T04:13:12.019Z,1566447192.019 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-22T04:13:16.934Z,1566447196.934 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-08-22T04:14:02.632Z,1566447242.632 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T04:14:15.970Z,1566447255.970 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T04:15:00.268Z,1566447300.268 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-08-22T04:15:00.268Z,1566447300.268 [Rowe_600LCM] Communications Fault, FailCount= 4 2019-08-22T04:15:00.269Z,1566447300.269 [Rowe_600LCM](ERROR): Communications Fault 2019-08-22T04:15:00.304Z,1566447300.304 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-08-22T04:15:00.673Z,1566447300.673 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-08-22T04:15:02.319Z,1566447302.319 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2019-08-22T04:15:02.319Z,1566447302.319 [Rowe_600LCM] No Fault, FailCount= 4 2019-08-22T04:15:02.496Z,1566447302.496 [Rowe_600LCM](INFO): Initializing 2019-08-22T04:15:02.985Z,1566447302.985 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-08-22T04:15:03.054Z,1566447303.054 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./auv-shared/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null & 2019-08-22T04:15:21.702Z,1566447321.702 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-08-22T04:15:21.704Z,1566447321.704 [BPC1](INFO): Received data from all battery sticks. 2019-08-22T04:17:03.076Z,1566447423.076 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-08-22T04:17:03.076Z,1566447423.076 [Rowe_600LCM] Communications Fault, FailCount= 5 2019-08-22T04:17:03.076Z,1566447423.076 [Rowe_600LCM](ERROR): Communications Fault 2019-08-22T04:17:03.131Z,1566447423.131 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-08-22T04:17:03.131Z,1566447423.131 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM 2019-08-22T04:17:03.480Z,1566447423.480 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-08-22T04:18:12.607Z,1566447492.607 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-22T04:18:12.607Z,1566447492.607 [Default:CheckIn:C.Wait] Stopped 2019-08-22T04:18:12.607Z,1566447492.607 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-22T04:18:12.607Z,1566447492.607 [Default:CheckIn:D] Running Loop=1 2019-08-22T04:18:12.997Z,1566447492.997 [Default:CheckIn:D] Stopped 2019-08-22T04:18:12.997Z,1566447492.997 [Default:CheckIn:E] Running Loop=1 2019-08-22T04:18:13.406Z,1566447493.406 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.445199 min 2019-08-22T04:18:13.406Z,1566447493.406 [Default:CheckIn:E] Stopped 2019-08-22T04:18:13.406Z,1566447493.406 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-22T04:18:13.406Z,1566447493.406 [Default:CheckIn] Stopped 2019-08-22T04:18:13.406Z,1566447493.406 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-22T04:18:13.406Z,1566447493.406 [Default:CheckIn](INFO): Running loop #2 2019-08-22T04:18:13.406Z,1566447493.406 [Default:CheckIn] Running Loop=2 2019-08-22T04:18:13.407Z,1566447493.407 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-22T04:18:13.407Z,1566447493.407 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-22T04:18:15.016Z,1566447495.016 [NAL9602](DEBUG): Fix Requested 2019-08-22T04:18:15.406Z,1566447495.406 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,041815.00,A,3648.16472,N,12147.28019,W,0.369,317.22,220819,,,D*75 2019-08-22T04:18:15.419Z,1566447495.419 [NAL9602](INFO): GPS fix at 20190822T041815: (36.802745, -121.788003) 2019-08-22T04:18:15.447Z,1566447495.447 [Default:CheckIn:Read_GPS] Stopped 2019-08-22T04:18:15.447Z,1566447495.447 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-22T04:18:21.903Z,1566447501.903 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20190822T040641/Courier0007.lzma 2019-08-22T04:18:22.709Z,1566447502.709 [DataOverHttps](INFO): Moved sent file to Logs/20190822T040641/Courier0007.lzma.bak 2019-08-22T04:18:22.710Z,1566447502.710 [DataOverHttps](INFO): SBD MOMSN=11665679 2019-08-22T04:18:35.540Z,1566447515.540 [DataOverHttps](INFO): Sending 276 bytes from file Logs/20190822T040641/Express0008.lzma 2019-08-22T04:18:36.345Z,1566447516.345 [DataOverHttps](INFO): Moved sent file to Logs/20190822T040641/Express0008.lzma.bak 2019-08-22T04:18:36.345Z,1566447516.345 [DataOverHttps](INFO): SBD MOMSN=11665682 2019-08-22T04:18:38.869Z,1566447518.869 [Default:CheckIn:Read_Iridium] Stopped 2019-08-22T04:18:38.869Z,1566447518.869 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-22T04:18:38.869Z,1566447518.869 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-22T04:18:46.105Z,1566447526.105 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2019-08-22T04:18:46.180Z,1566447526.180 [NAL9602](FAULT): received: +CSQ:0 OK 2019-08-22T04:18:46.180Z,1566447526.180 [NAL9602] Data Fault, FailCount= 1 2019-08-22T04:18:46.180Z,1566447526.180 [NAL9602](ERROR): Data Fault 2019-08-22T04:18:46.213Z,1566447526.213 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-22T04:18:46.509Z,1566447526.509 [NAL9602](INFO): Powering down 2019-08-22T04:18:47.358Z,1566447527.358 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-22T04:18:47.358Z,1566447527.358 [NAL9602] No Fault, FailCount= 1 2019-08-22T04:19:16.806Z,1566447556.806 [NAL9602](INFO): Powering up NAL9602 2019-08-22T04:19:27.717Z,1566447567.717 [NAL9602](INFO): NAL9602 initialized 2019-08-22T04:19:58.825Z,1566447598.825 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-22T04:23:39.450Z,1566447819.450 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-22T04:23:39.450Z,1566447819.450 [Default:CheckIn:C.Wait] Stopped 2019-08-22T04:23:39.450Z,1566447819.450 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-22T04:23:39.450Z,1566447819.450 [Default:CheckIn:D] Running Loop=1 2019-08-22T04:23:39.853Z,1566447819.853 [Default:CheckIn:D] Stopped 2019-08-22T04:23:39.854Z,1566447819.854 [Default:CheckIn:E] Running Loop=1 2019-08-22T04:23:40.263Z,1566447820.263 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.892810 min 2019-08-22T04:23:40.263Z,1566447820.263 [Default:CheckIn:E] Stopped 2019-08-22T04:23:40.263Z,1566447820.263 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-22T04:23:40.263Z,1566447820.263 [Default:CheckIn] Stopped 2019-08-22T04:23:40.263Z,1566447820.263 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-22T04:23:40.264Z,1566447820.264 [Default:CheckIn](INFO): Running loop #3 2019-08-22T04:23:40.264Z,1566447820.264 [Default:CheckIn] Running Loop=3 2019-08-22T04:23:40.264Z,1566447820.264 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-22T04:23:40.264Z,1566447820.264 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-22T04:23:41.863Z,1566447821.863 [NAL9602](DEBUG): Fix Requested 2019-08-22T04:23:42.254Z,1566447822.254 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,042341.00,A,3648.16431,N,12147.28306,W,0.156,310.59,220819,,,A*76 2019-08-22T04:23:42.257Z,1566447822.257 [NAL9602](INFO): GPS fix at 20190822T042341: (36.802738, -121.788051) 2019-08-22T04:23:42.304Z,1566447822.304 [Default:CheckIn:Read_GPS] Stopped 2019-08-22T04:23:42.304Z,1566447822.304 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-22T04:23:44.683Z,1566447824.683 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-08-22T04:23:48.875Z,1566447828.875 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20190822T040641/Courier0010.lzma 2019-08-22T04:23:49.681Z,1566447829.681 [DataOverHttps](INFO): Moved sent file to Logs/20190822T040641/Courier0010.lzma.bak 2019-08-22T04:23:49.681Z,1566447829.681 [DataOverHttps](INFO): SBD MOMSN=11665703 2019-08-22T04:24:02.783Z,1566447842.783 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20190822T040641/Express0011.lzma 2019-08-22T04:24:03.589Z,1566447843.589 [DataOverHttps](INFO): Moved sent file to Logs/20190822T040641/Express0011.lzma.bak 2019-08-22T04:24:03.589Z,1566447843.589 [DataOverHttps](INFO): SBD MOMSN=11665706 2019-08-22T04:24:06.121Z,1566447846.121 [Default:CheckIn:Read_Iridium] Stopped 2019-08-22T04:24:06.121Z,1566447846.121 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-22T04:24:06.121Z,1566447846.121 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-22T04:24:15.381Z,1566447855.381 [NAL9602](INFO): Not Powering down - fast GPS 2019-08-22T04:24:58.781Z,1566447898.781 [CommandLine](IMPORTANT): got command failComponent 2019-08-22T04:24:58.781Z,1566447898.781 [CommandLine](IMPORTANT): Failed components: 2019-08-22T04:24:58.782Z,1566447898.782 [CommandLine](IMPORTANT): Rowe_600LCM: Communications Fault 2019-08-22T04:25:05.841Z,1566447905.841 [CommandLine](IMPORTANT): got command failComponent none Rowe_600LCM 2019-08-22T04:25:05.841Z,1566447905.841 [Rowe_600LCM] No Fault, FailCount= 5 2019-08-22T04:25:05.841Z,1566447905.841 [CommandLine](IMPORTANT): Rowe_600LCM failureMode is No Fault 2019-08-22T04:25:06.064Z,1566447906.064 [Rowe_600LCM](INFO): Initializing 2019-08-22T04:25:06.553Z,1566447906.553 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-08-22T04:25:06.607Z,1566447906.607 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./auv-shared/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null & 2019-08-22T04:25:43.820Z,1566447943.820 [CommandLine](IMPORTANT): got command failComponent 2019-08-22T04:25:43.821Z,1566447943.821 [CommandLine](IMPORTANT): Failed components: 2019-08-22T04:25:43.821Z,1566447943.821 [CommandLine](IMPORTANT): No failed Components. 2019-08-22T04:26:12.829Z,1566447972.829 [CommandLine](IMPORTANT): got command show best height_above_sea_floor 2019-08-22T04:26:12.829Z,1566447972.829 [CommandLine](IMPORTANT): height_above_sea_floor best is null 2019-08-22T04:26:15.833Z,1566447975.833 [CommandLine](IMPORTANT): got command show best height_above_sea_floor 2019-08-22T04:26:15.834Z,1566447975.834 [CommandLine](IMPORTANT): height_above_sea_floor best is null 2019-08-22T04:26:22.682Z,1566447982.682 [CommandLine](IMPORTANT): got command report touch height_above_sea_floor 2019-08-22T04:26:24.289Z,1566447984.289 [CommandLine](IMPORTANT): got command failComponent 2019-08-22T04:26:24.289Z,1566447984.289 [CommandLine](IMPORTANT): Failed components: 2019-08-22T04:26:24.289Z,1566447984.289 [CommandLine](IMPORTANT): No failed Components. 2019-08-22T04:26:27.792Z,1566447987.792 [CommandLine](IMPORTANT): got command ! ps -eaf 2019-08-22T04:26:28.213Z,1566447988.213 [CommandLine](IMPORTANT): UID PID PPID C STIME TTY TIME CMD root 1 0 0 Aug21 ? 00:00:03 init [3] root 2 0 0 Aug21 ? 00:00:00 [kthreadd] root 3 2 0 Aug21 ? 00:00:00 [ksoftirqd/0] root 4 2 0 Aug21 ? 00:00:13 [events/0] root 5 2 0 Aug21 ? 00:00:00 [khelper] root 51 2 0 Aug21 ? 00:00:00 [kblockd/0] root 53 2 0 Aug21 ? 00:00:00 [cqueue] root 65 2 0 Aug21 ? 00:00:00 [khubd] root 77 2 0 Aug21 ? 00:00:00 [kmmcd] root 99 2 0 Aug21 ? 00:00:00 [pdflush] root 100 2 0 Aug21 ? 00:00:01 [pdflush] root 101 2 0 Aug21 ? 00:00:00 [kswapd0] root 102 2 0 Aug21 ? 00:00:00 [aio/0] root 103 2 0 Aug21 ? 00:00:00 [nfsiod] root 220 2 0 Aug21 ? 00:00:00 [pegasus] root 225 2 0 Aug21 ? 00:00:00 [mtdblockd] root 243 2 0 Aug21 ? 00:00:00 [spi_lpc32xx.1] root 382 2 0 Aug21 ? 00:00:00 [rpciod/0] root 387 2 0 Aug21 ? 00:00:57 [mmcqd] root 403 1 0 Aug21 ? 00:00:01 udevd --daemon root 741 2 0 Aug21 ? 00:00:03 [jffs2_gcd_mtd3] root 754 1 0 Aug21 ? 00:00:00 /sbin/syslogd root 756 1 0 Aug21 ? 00:00:00 /sbin/klogd root 770 1 0 Aug21 ? 00:00:00 udhcpc -H lrauv-pontus -b -i eth0 root 774 1 0 Aug21 ? 00:00:00 /usr/sbin/inetd root 780 1 0 Aug21 ? 00:00:27 /usr/sbin/sshd root 794 2 0 Aug21 ? 00:00:04 [kjournald] root 805 1 0 Aug21 ttyS0 00:00:00 /bin/sh -- root 2499 1 0 Aug21 ? 00:00:09 /usr/bin/SCREEN -dmS app ./bin/LRAUV root 2500 2499 33 Aug21 pts/1 02:27:30 ./bin/LRAUV root 3008 780 0 Aug21 ? 00:00:03 sshd: root@pts/0 root 3012 3008 0 Aug21 pts/0 00:00:00 -sh root 3565 2 0 04:06 ? 00:00:00 [max3100-21/0] root 3614 1 46 04:25 pts/1 00:00:37 ./auv-shared/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 root 3615 2 0 04:25 ? 00:00:00 [max3100-12/0] root 3622 805 0 04:25 ttyS0 00:00:00 screen -r root 3623 2500 0 04:26 pts/1 00:00:00 ps -eaf 2019-08-22T04:27:06.472Z,1566448026.472 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-08-22T04:27:06.472Z,1566448026.472 [Rowe_600LCM] Communications Fault, FailCount= 6 2019-08-22T04:27:06.472Z,1566448026.472 [Rowe_600LCM](ERROR): Communications Fault 2019-08-22T04:27:06.763Z,1566448026.763 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-08-22T04:27:06.763Z,1566448026.763 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM 2019-08-22T04:27:06.876Z,1566448026.876 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-08-22T04:28:42.585Z,1566448122.585 [CommandLine](IMPORTANT): got command failComponent 2019-08-22T04:28:42.586Z,1566448122.586 [CommandLine](IMPORTANT): Failed components: 2019-08-22T04:28:42.586Z,1566448122.586 [CommandLine](IMPORTANT): Rowe_600LCM: Communications Fault 2019-08-22T04:29:06.722Z,1566448146.722 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-22T04:29:06.722Z,1566448146.722 [Default:CheckIn:C.Wait] Stopped 2019-08-22T04:29:06.722Z,1566448146.722 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-22T04:29:06.722Z,1566448146.722 [Default:CheckIn:D] Running Loop=1 2019-08-22T04:29:07.134Z,1566448147.134 [Default:CheckIn:D] Stopped 2019-08-22T04:29:07.134Z,1566448147.134 [Default:CheckIn:E] Running Loop=1 2019-08-22T04:29:07.539Z,1566448147.539 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 18.347481 min 2019-08-22T04:29:07.539Z,1566448147.539 [Default:CheckIn:E] Stopped 2019-08-22T04:29:07.539Z,1566448147.539 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-22T04:29:07.539Z,1566448147.539 [Default:CheckIn] Stopped 2019-08-22T04:29:07.539Z,1566448147.539 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-22T04:29:07.540Z,1566448147.540 [Default:CheckIn](INFO): Running loop #4 2019-08-22T04:29:07.540Z,1566448147.540 [Default:CheckIn] Running Loop=4 2019-08-22T04:29:07.540Z,1566448147.540 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-22T04:29:07.540Z,1566448147.540 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-22T04:29:09.132Z,1566448149.132 [NAL9602](DEBUG): Fix Requested 2019-08-22T04:29:09.526Z,1566448149.526 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,042909.00,A,3648.16490,N,12147.28373,W,0.078,139.63,220819,,,A*74 2019-08-22T04:29:09.529Z,1566448149.529 [NAL9602](INFO): GPS fix at 20190822T042909: (36.802748, -121.788062) 2019-08-22T04:29:09.550Z,1566448149.550 [Default:CheckIn:Read_GPS] Stopped 2019-08-22T04:29:09.550Z,1566448149.550 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-22T04:29:10.621Z,1566448150.621 [CommandLine](IMPORTANT): got command restart application 2019-08-22T04:29:11.628Z,1566448151.628 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2019-08-22T04:29:11.629Z,1566448151.629 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T04:29:11.629Z,1566448151.629 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:11.768Z,1566448151.768 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-08-22T04:29:11.768Z,1566448151.768 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:11.769Z,1566448151.769 [CommandLine](INFO): Join timeout helper Thread ID is 3628 2019-08-22T04:29:11.769Z,1566448151.769 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-08-22T04:29:11.769Z,1566448151.769 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:11.770Z,1566448151.770 [NavChartDb](INFO): Join timeout helper Thread ID is 3629 2019-08-22T04:29:12.096Z,1566448152.096 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T04:29:12.096Z,1566448152.096 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:12.112Z,1566448152.112 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-08-22T04:29:12.112Z,1566448152.112 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:12.112Z,1566448152.112 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3630 2019-08-22T04:29:12.196Z,1566448152.196 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T04:29:12.196Z,1566448152.196 [WetLabsBB2FL](INFO): Powering down 2019-08-22T04:29:12.197Z,1566448152.197 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:12.204Z,1566448152.204 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-08-22T04:29:12.204Z,1566448152.204 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:12.204Z,1566448152.204 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3631 2019-08-22T04:29:12.632Z,1566448152.632 [CTD_Seabird](INFO): Powering down 2019-08-22T04:29:12.644Z,1566448152.644 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T04:29:12.644Z,1566448152.644 [CTD_Seabird](INFO): Powering down 2019-08-22T04:29:12.656Z,1566448152.656 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:12.664Z,1566448152.664 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler 2019-08-22T04:29:12.664Z,1566448152.664 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:12.664Z,1566448152.664 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 3632 2019-08-22T04:29:12.668Z,1566448152.668 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T04:29:12.668Z,1566448152.668 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-08-22T04:29:12.911Z,1566448152.911 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:12.913Z,1566448152.913 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-08-22T04:29:12.913Z,1566448152.913 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:12.914Z,1566448152.914 [Radio_Surface](INFO): Join timeout helper Thread ID is 3634 2019-08-22T04:29:12.928Z,1566448152.928 [Radio_Surface](INFO): Powering down 2019-08-22T04:29:12.929Z,1566448152.929 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T04:29:12.929Z,1566448152.929 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:12.941Z,1566448152.941 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-08-22T04:29:12.941Z,1566448152.941 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:12.941Z,1566448152.941 [DataOverHttps](INFO): Join timeout helper Thread ID is 3635 2019-08-22T04:29:15.779Z,1566448155.779 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T04:29:15.784Z,1566448155.784 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:15.801Z,1566448155.801 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-08-22T04:29:15.801Z,1566448155.801 [logger ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:15.801Z,1566448155.801 [logger](INFO): Join timeout helper Thread ID is 3636 2019-08-22T04:29:15.836Z,1566448155.836 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T04:29:15.836Z,1566448155.836 [logger ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:15.841Z,1566448155.841 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-08-22T04:29:15.841Z,1566448155.841 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:15.841Z,1566448155.841 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-08-22T04:29:15.841Z,1566448155.841 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:15.841Z,1566448155.841 [controlThread](INFO): Join timeout helper Thread ID is 3637 2019-08-22T04:29:16.008Z,1566448156.008 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T04:29:16.008Z,1566448156.008 [controlThread](DEBUG): Uninitializing ControlThread 2019-08-22T04:29:16.009Z,1566448156.009 [AHRS_M2](INFO): Powering down 2019-08-22T04:29:16.080Z,1566448156.080 [NAL9602](INFO): Powering down 2019-08-22T04:29:16.082Z,1566448156.082 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-08-22T04:29:16.083Z,1566448156.083 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-08-22T04:29:16.084Z,1566448156.084 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-08-22T04:29:16.084Z,1566448156.084 [MissionManager](INFO): Uninitializing Mission Default 2019-08-22T04:29:16.084Z,1566448156.084 [Default] Stopped 2019-08-22T04:29:16.084Z,1566448156.084 [Default](DEBUG): Aggregate::uninitialize Default 2019-08-22T04:29:16.085Z,1566448156.085 [Default:B.GoToSurface] Stopped 2019-08-22T04:29:16.085Z,1566448156.085 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-08-22T04:29:16.085Z,1566448156.085 [Default:CheckIn] Stopped 2019-08-22T04:29:16.085Z,1566448156.085 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-22T04:29:16.085Z,1566448156.085 [Default:CheckIn:Read_Iridium] Stopped 2019-08-22T04:29:16.087Z,1566448156.087 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-08-22T04:29:16.088Z,1566448156.088 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-08-22T04:29:16.088Z,1566448156.088 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-08-22T04:29:16.088Z,1566448156.088 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-08-22T04:29:16.089Z,1566448156.089 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-08-22T04:29:16.089Z,1566448156.089 [BuoyancyServo](INFO): Powering down 2019-08-22T04:29:16.104Z,1566448156.104 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-08-22T04:29:16.104Z,1566448156.104 [ElevatorServo](INFO): Powering down 2019-08-22T04:29:16.105Z,1566448156.105 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-08-22T04:29:16.105Z,1566448156.105 [MassServo](INFO): Powering down 2019-08-22T04:29:16.106Z,1566448156.106 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-08-22T04:29:16.106Z,1566448156.106 [RudderServo](INFO): Powering down 2019-08-22T04:29:16.107Z,1566448156.107 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-08-22T04:29:16.107Z,1566448156.107 [ThrusterServo](INFO): Powering down 2019-08-22T04:29:16.108Z,1566448156.108 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-08-22T04:29:16.108Z,1566448156.108 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-08-22T04:29:16.108Z,1566448156.108 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-08-22T04:29:16.108Z,1566448156.108 [CBIT](DEBUG): Powering off loads. 2019-08-22T04:29:16.120Z,1566448156.120 [CBIT](DEBUG): Disabling WDT. 2019-08-22T04:29:16.132Z,1566448156.132 [CBIT](DEBUG): Opening all GF detection circuits. 2019-08-22T04:29:16.132Z,1566448156.132 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:16.226Z,1566448156.226 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:16.230Z,1566448156.230 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:16.235Z,1566448156.235 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:16.291Z,1566448156.291 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:16.293Z,1566448156.293 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:16.304Z,1566448156.304 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-22T04:29:16.375Z,1566448156.375 [logger ThreadHandler](INFO): Thread cancelled.