2019-02-16T03:32:17.898Z,1550287937.898 [Supervisor](DEBUG): Initializing supervisor. 2019-02-16T03:32:17.900Z,1550287937.900 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-02-16T03:32:17.901Z,1550287937.901 [SyncHandler](INFO): Protected caller Thread ID is 7064 2019-02-16T03:32:17.901Z,1550287937.901 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-02-16T03:32:17.902Z,1550287937.902 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-02-16T03:32:17.903Z,1550287937.903 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7065 2019-02-16T03:32:17.905Z,1550287937.905 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-02-16T03:32:17.917Z,1550287937.917 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-02-16T03:32:17.918Z,1550287937.918 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-02-16T03:32:17.919Z,1550287937.919 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7066 2019-02-16T03:32:17.919Z,1550287937.919 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-02-16T03:32:17.920Z,1550287937.920 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-02-16T03:32:17.921Z,1550287937.921 [logger ThreadHandler](INFO): Protected caller Thread ID is 7067 2019-02-16T03:32:17.923Z,1550287937.923 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-02-16T03:32:17.923Z,1550287937.923 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-02-16T03:32:17.925Z,1550287937.925 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-02-16T03:32:18.018Z,1550287938.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-02-16T03:32:18.019Z,1550287938.019 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-02-16T03:32:18.215Z,1550287938.215 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-02-16T03:32:18.215Z,1550287938.215 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-02-16T03:32:18.351Z,1550287938.351 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-02-16T03:32:18.351Z,1550287938.351 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-02-16T03:32:18.820Z,1550287938.820 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-02-16T03:32:18.821Z,1550287938.821 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-02-16T03:32:19.259Z,1550287939.259 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-02-16T03:32:19.260Z,1550287939.260 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-02-16T03:32:19.733Z,1550287939.733 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-02-16T03:32:19.734Z,1550287939.734 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-02-16T03:32:20.039Z,1550287940.039 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-02-16T03:32:20.040Z,1550287940.040 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-02-16T03:32:20.387Z,1550287940.387 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-02-16T03:32:20.388Z,1550287940.388 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-02-16T03:32:20.778Z,1550287940.778 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-02-16T03:32:20.779Z,1550287940.779 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-02-16T03:32:20.927Z,1550287940.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-02-16T03:32:20.928Z,1550287940.928 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-02-16T03:32:21.035Z,1550287941.035 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-02-16T03:32:21.035Z,1550287941.035 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-02-16T03:32:21.115Z,1550287941.115 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-02-16T03:32:21.215Z,1550287941.215 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-02-16T03:32:21.216Z,1550287941.216 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-02-16T03:32:21.482Z,1550287941.482 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-02-16T03:32:21.483Z,1550287941.483 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-02-16T03:32:21.692Z,1550287941.692 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-02-16T03:32:21.694Z,1550287941.694 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2019-02-16T03:32:21.695Z,1550287941.695 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2019-02-16T03:32:21.778Z,1550287941.778 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2019-02-16T03:32:22.011Z,1550287942.011 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-02-16T03:32:22.012Z,1550287942.012 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2019-02-16T03:32:22.106Z,1550287942.106 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2019-02-16T03:32:22.265Z,1550287942.265 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2019-02-16T03:32:22.470Z,1550287942.470 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2019-02-16T03:32:22.554Z,1550287942.554 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2019-02-16T03:32:22.680Z,1550287942.680 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2019-02-16T03:32:23.090Z,1550287943.090 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2019-02-16T03:32:23.546Z,1550287943.546 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2019-02-16T03:32:23.687Z,1550287943.687 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2019-02-16T03:32:23.785Z,1550287943.785 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/ 2019-02-16T03:32:23.785Z,1550287943.785 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2019-02-16T03:32:23.788Z,1550287943.788 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-02-16T03:32:23.888Z,1550287943.888 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-02-16T03:32:23.889Z,1550287943.889 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-02-16T03:32:23.991Z,1550287943.991 [BuoyancyServo] Loaded 2019-02-16T03:32:23.991Z,1550287943.991 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-02-16T03:32:24.007Z,1550287944.007 [ElevatorServo] Loaded 2019-02-16T03:32:24.007Z,1550287944.007 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-02-16T03:32:24.022Z,1550287944.022 [MassServo] Loaded 2019-02-16T03:32:24.022Z,1550287944.022 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-02-16T03:32:24.037Z,1550287944.037 [RudderServo] Loaded 2019-02-16T03:32:24.038Z,1550287944.038 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-02-16T03:32:24.052Z,1550287944.052 [ThrusterServo] Loaded 2019-02-16T03:32:24.052Z,1550287944.052 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-02-16T03:32:24.053Z,1550287944.053 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-02-16T03:32:24.053Z,1550287944.053 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-02-16T03:32:24.184Z,1550287944.184 [SBIT](DEBUG): Construct Startup Built In Test. 2019-02-16T03:32:24.213Z,1550287944.213 [SBIT] Loaded 2019-02-16T03:32:24.214Z,1550287944.214 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-02-16T03:32:24.214Z,1550287944.214 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-02-16T03:32:24.243Z,1550287944.243 [IBIT] Loaded 2019-02-16T03:32:24.243Z,1550287944.243 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-02-16T03:32:24.247Z,1550287944.247 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-02-16T03:32:24.642Z,1550287944.642 [CBIT] Loaded 2019-02-16T03:32:24.643Z,1550287944.643 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-02-16T03:32:24.643Z,1550287944.643 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-02-16T03:32:24.644Z,1550287944.644 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-02-16T03:32:24.819Z,1550287944.819 [Aanderaa_O2] Loaded 2019-02-16T03:32:24.820Z,1550287944.820 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2019-02-16T03:32:24.830Z,1550287944.830 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-02-16T03:32:24.835Z,1550287944.835 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-02-16T03:32:24.837Z,1550287944.837 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-02-16T03:32:24.841Z,1550287944.841 [CTD_Seabird](INFO): created writer for : depth 2019-02-16T03:32:24.842Z,1550287944.842 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-02-16T03:32:24.847Z,1550287944.847 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-02-16T03:32:24.848Z,1550287944.848 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-02-16T03:32:24.853Z,1550287944.853 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-02-16T03:32:24.854Z,1550287944.854 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-02-16T03:32:24.859Z,1550287944.859 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-02-16T03:32:24.860Z,1550287944.860 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-02-16T03:32:24.865Z,1550287944.865 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-02-16T03:32:24.866Z,1550287944.866 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-02-16T03:32:24.871Z,1550287944.871 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-02-16T03:32:24.899Z,1550287944.899 [CTD_Seabird] Loaded 2019-02-16T03:32:24.899Z,1550287944.899 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-02-16T03:32:24.900Z,1550287944.900 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4062F4E0 2019-02-16T03:32:24.901Z,1550287944.901 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 7147 2019-02-16T03:32:24.922Z,1550287944.922 [ESPComponent] Loaded 2019-02-16T03:32:24.923Z,1550287944.923 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2019-02-16T03:32:24.937Z,1550287944.937 [PAR_Licor] Loaded 2019-02-16T03:32:24.937Z,1550287944.937 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-02-16T03:32:24.986Z,1550287944.986 [WetLabsBB2FL] Loaded 2019-02-16T03:32:24.987Z,1550287944.987 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-02-16T03:32:24.988Z,1550287944.988 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4065F4E0 2019-02-16T03:32:24.988Z,1550287944.988 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 7148 2019-02-16T03:32:24.989Z,1550287944.989 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-02-16T03:32:24.989Z,1550287944.989 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-02-16T03:32:25.031Z,1550287945.031 [DepthRateCalculator] Loaded 2019-02-16T03:32:25.031Z,1550287945.031 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-02-16T03:32:25.037Z,1550287945.037 [PitchRateCalculator] Loaded 2019-02-16T03:32:25.037Z,1550287945.037 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-02-16T03:32:25.053Z,1550287945.053 [SpeedCalculator] Loaded 2019-02-16T03:32:25.053Z,1550287945.053 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-02-16T03:32:25.074Z,1550287945.074 [TempGradientCalculator] Loaded 2019-02-16T03:32:25.075Z,1550287945.075 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-02-16T03:32:25.081Z,1550287945.081 [YawRateCalculator] Loaded 2019-02-16T03:32:25.081Z,1550287945.081 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-02-16T03:32:25.115Z,1550287945.115 [ElevatorOffsetCalculator] Loaded 2019-02-16T03:32:25.115Z,1550287945.115 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-02-16T03:32:25.116Z,1550287945.116 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-02-16T03:32:25.116Z,1550287945.116 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-02-16T03:32:25.145Z,1550287945.145 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-02-16T03:32:25.146Z,1550287945.146 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-02-16T03:32:25.248Z,1550287945.248 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-02-16T03:32:25.249Z,1550287945.249 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-02-16T03:32:25.309Z,1550287945.309 [DeadReckonUsingSpeedCalculator] Loaded 2019-02-16T03:32:25.309Z,1550287945.309 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread. 2019-02-16T03:32:25.369Z,1550287945.369 [DeadReckonWithRespectToSeafloor] Loaded 2019-02-16T03:32:25.369Z,1550287945.369 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread. 2019-02-16T03:32:25.386Z,1550287945.386 [NavChart] Loaded 2019-02-16T03:32:25.386Z,1550287945.386 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-02-16T03:32:25.391Z,1550287945.391 [UniversalFixResidualReporter] Loaded 2019-02-16T03:32:25.391Z,1550287945.391 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-02-16T03:32:25.391Z,1550287945.391 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-02-16T03:32:25.392Z,1550287945.392 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-02-16T03:32:25.680Z,1550287945.680 [AcousticModem_Benthos_ATM900] Loaded 2019-02-16T03:32:25.681Z,1550287945.681 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread. 2019-02-16T03:32:25.763Z,1550287945.763 [DataOverHttps] Loaded 2019-02-16T03:32:25.763Z,1550287945.763 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-02-16T03:32:25.764Z,1550287945.764 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409264E0 2019-02-16T03:32:25.764Z,1550287945.764 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 7149 2019-02-16T03:32:25.778Z,1550287945.778 [Depth_Keller] Loaded 2019-02-16T03:32:25.778Z,1550287945.778 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-02-16T03:32:25.869Z,1550287945.869 [NAL9602] Loaded 2019-02-16T03:32:25.870Z,1550287945.870 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-02-16T03:32:25.875Z,1550287945.875 [Onboard] Loaded 2019-02-16T03:32:25.875Z,1550287945.875 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-02-16T03:32:25.883Z,1550287945.883 [Radio_Surface] Loaded 2019-02-16T03:32:25.883Z,1550287945.883 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-02-16T03:32:25.884Z,1550287945.884 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409564E0 2019-02-16T03:32:25.884Z,1550287945.884 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 7150 2019-02-16T03:32:25.932Z,1550287945.932 [PNI_TCM] Loaded 2019-02-16T03:32:25.932Z,1550287945.932 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread. 2019-02-16T03:32:25.994Z,1550287945.994 [Rowe_600LCM] Loaded 2019-02-16T03:32:25.994Z,1550287945.994 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread. 2019-02-16T03:32:25.995Z,1550287945.995 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 409864E0 2019-02-16T03:32:25.996Z,1550287945.996 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 7151 2019-02-16T03:32:27.583Z,1550287947.583 [BPC1] Loaded 2019-02-16T03:32:27.583Z,1550287947.583 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-02-16T03:32:27.584Z,1550287947.584 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-02-16T03:32:27.584Z,1550287947.584 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-02-16T03:32:27.648Z,1550287947.648 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-02-16T03:32:27.649Z,1550287947.649 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-02-16T03:32:27.717Z,1550287947.717 [VerticalControl](DEBUG): Construct VerticalControl. 2019-02-16T03:32:27.803Z,1550287947.803 [VerticalControl] Loaded 2019-02-16T03:32:27.803Z,1550287947.803 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-02-16T03:32:27.804Z,1550287947.804 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-02-16T03:32:27.978Z,1550287947.978 [HorizontalControl] Loaded 2019-02-16T03:32:27.979Z,1550287947.979 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-02-16T03:32:27.979Z,1550287947.979 [SpeedControl](DEBUG): Construct SpeedControl. 2019-02-16T03:32:27.981Z,1550287947.981 [SpeedControl] Loaded 2019-02-16T03:32:27.981Z,1550287947.981 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-02-16T03:32:27.982Z,1550287947.982 [LoopControl](DEBUG): Construct LoopControl. 2019-02-16T03:32:27.983Z,1550287947.983 [LoopControl] Loaded 2019-02-16T03:32:27.983Z,1550287947.983 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-02-16T03:32:27.983Z,1550287947.983 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-02-16T03:32:27.984Z,1550287947.984 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-02-16T03:32:28.128Z,1550287948.128 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-02-16T03:32:28.128Z,1550287948.128 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-02-16T03:32:28.395Z,1550287948.395 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-02-16T03:32:28.399Z,1550287948.399 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-02-16T03:32:28.400Z,1550287948.400 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-02-16T03:32:28.407Z,1550287948.407 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-02-16T03:32:28.408Z,1550287948.408 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AA84E0 2019-02-16T03:32:28.408Z,1550287948.408 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 7152 2019-02-16T03:32:28.413Z,1550287948.413 [Supervisor](INFO): Main Thread ID is 7063 2019-02-16T03:32:28.413Z,1550287948.413 [Supervisor](DEBUG): Running supervisor. 2019-02-16T03:32:28.414Z,1550287948.414 [CommandLine ThreadHandler](INFO): Handler Thread ID is 7153 2019-02-16T03:32:28.416Z,1550287948.416 [controlThread ThreadHandler](INFO): Handler Thread ID is 7154 2019-02-16T03:32:28.416Z,1550287948.416 [controlThread](DEBUG): Initializing ControlThread 2019-02-16T03:32:28.418Z,1550287948.418 [SBIT](INFO): Initialize SBIT Component. 2019-02-16T03:32:28.419Z,1550287948.419 [SBIT](IMPORTANT): git: 2019-02-11-18-g088f29c 2019-02-16T03:32:28.419Z,1550287948.419 [SBIT](INFO): git hash: 088f29c08f1651a006237423a6ffed1cbba6c6ba 2019-02-16T03:32:28.419Z,1550287948.419 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-02-16T03:32:28.420Z,1550287948.420 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 2019-02-16T03:32:28.422Z,1550287948.422 [SBIT](INFO): Beginning SBIT in 24.000000 seconds. 2019-02-16T03:32:28.423Z,1550287948.423 [IBIT](INFO): Initialize IBIT Component. 2019-02-16T03:32:28.423Z,1550287948.423 [CBIT](DEBUG): Initialize CBIT Component. 2019-02-16T03:32:28.424Z,1550287948.424 [logger ThreadHandler](INFO): Handler Thread ID is 7155 2019-02-16T03:32:28.437Z,1550287948.437 [CBIT](DEBUG): Initialized mux pins. 2019-02-16T03:32:28.437Z,1550287948.437 [CBIT](DEBUG): Initializing the watchdog timer. 2019-02-16T03:32:28.450Z,1550287948.450 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 7156 2019-02-16T03:32:28.450Z,1550287948.450 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-02-16T03:32:28.454Z,1550287948.454 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-02-16T03:32:28.455Z,1550287948.455 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 7158 2019-02-16T03:32:28.456Z,1550287948.456 [WetLabsBB2FL](INFO): Powering down 2019-02-16T03:32:28.461Z,1550287948.461 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-02-16T03:32:28.461Z,1550287948.461 [CBIT](DEBUG): Initializing heartbeat. 2019-02-16T03:32:28.488Z,1550287948.488 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 7159 2019-02-16T03:32:28.489Z,1550287948.489 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-02-16T03:32:28.506Z,1550287948.506 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 7160 2019-02-16T03:32:28.526Z,1550287948.526 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 7161 2019-02-16T03:32:28.526Z,1550287948.526 [Rowe_600LCM](INFO): Initializing 2019-02-16T03:32:28.533Z,1550287948.533 [CBIT](DEBUG): Deactivating GF circuits. 2019-02-16T03:32:28.534Z,1550287948.534 [CBIT](DEBUG): Deactivating emergency mode. 2019-02-16T03:32:28.536Z,1550287948.536 [Rowe_600LCM](INFO): Powering up 2019-02-16T03:32:28.546Z,1550287948.546 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 7162 2019-02-16T03:32:28.549Z,1550287948.549 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-02-16T03:32:28.549Z,1550287948.549 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-02-16T03:32:28.550Z,1550287948.550 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-02-16T03:32:28.550Z,1550287948.550 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-02-16T03:32:28.550Z,1550287948.550 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-02-16T03:32:28.550Z,1550287948.550 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-02-16T03:32:28.550Z,1550287948.550 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-02-16T03:32:28.551Z,1550287948.551 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-02-16T03:32:28.551Z,1550287948.551 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-02-16T03:32:28.551Z,1550287948.551 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-02-16T03:32:28.551Z,1550287948.551 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-02-16T03:32:28.551Z,1550287948.551 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-02-16T03:32:28.551Z,1550287948.551 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-02-16T03:32:28.552Z,1550287948.552 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-02-16T03:32:28.552Z,1550287948.552 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-02-16T03:32:28.552Z,1550287948.552 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-02-16T03:32:28.574Z,1550287948.574 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-02-16T03:32:28.574Z,1550287948.574 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-02-16T03:32:28.574Z,1550287948.574 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-02-16T03:32:28.575Z,1550287948.575 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-02-16T03:32:28.575Z,1550287948.575 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-02-16T03:32:28.576Z,1550287948.576 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-02-16T03:32:28.577Z,1550287948.577 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-02-16T03:32:28.578Z,1550287948.578 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-02-16T03:32:28.578Z,1550287948.578 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-02-16T03:32:28.591Z,1550287948.591 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-02-16T03:32:28.593Z,1550287948.593 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-02-16T03:32:28.594Z,1550287948.594 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-02-16T03:32:28.594Z,1550287948.594 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-02-16T03:32:28.595Z,1550287948.595 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-02-16T03:32:28.629Z,1550287948.629 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-02-16T03:32:28.656Z,1550287948.656 [MissionManager](DEBUG): 2019-02-16T03:32:28.657Z,1550287948.657 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-02-16T03:32:28.741Z,1550287948.741 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-02-16T03:32:28.754Z,1550287948.754 [Default:A.Wait](DEBUG): Construct Wait. 2019-02-16T03:32:28.756Z,1550287948.756 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-02-16T03:32:28.795Z,1550287948.795 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-02-16T03:32:28.813Z,1550287948.813 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-02-16T03:32:28.820Z,1550287948.820 [Default:E.Execute](DEBUG): Construct Execute. 2019-02-16T03:32:28.852Z,1550287948.852 [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-02-16T03:32:28.857Z,1550287948.857 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-02-16T03:32:28.905Z,1550287948.905 [ESPComponent](INFO): powering down ESP 2019-02-16T03:32:28.910Z,1550287948.910 [Radio_Surface](INFO): Powering up 2019-02-16T03:32:29.231Z,1550287949.231 [AcousticModem_Benthos_ATM900](INFO): Powering up 2019-02-16T03:32:29.232Z,1550287949.232 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900. 2019-02-16T03:32:29.726Z,1550287949.726 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-02-16T03:32:29.734Z,1550287949.734 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-02-16T03:32:29.753Z,1550287949.753 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-02-16T03:32:29.758Z,1550287949.758 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-02-16T03:32:29.780Z,1550287949.780 [MassServo](DEBUG): Initializing EZServoServo. 2019-02-16T03:32:29.786Z,1550287949.786 [MassServo](DEBUG): Initializing MassServo. 2019-02-16T03:32:29.799Z,1550287949.799 [RudderServo](DEBUG): Initializing EZServoServo. 2019-02-16T03:32:29.806Z,1550287949.806 [RudderServo](DEBUG): Initializing RudderServo. 2019-02-16T03:32:29.812Z,1550287949.812 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-02-16T03:32:29.818Z,1550287949.818 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-02-16T03:32:30.681Z,1550287950.681 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout 2019-02-16T03:32:30.682Z,1550287950.682 [BuoyancyServo](FAULT): Buoyancy failed to initialize 2019-02-16T03:32:30.682Z,1550287950.682 [BuoyancyServo] Communications Fault, FailCount= 1 2019-02-16T03:32:30.682Z,1550287950.682 [BuoyancyServo](ERROR): Communications Fault 2019-02-16T03:32:30.889Z,1550287950.889 [CBIT](ERROR): Communications Fault in component: BuoyancyServo 2019-02-16T03:32:32.226Z,1550287952.226 [Aanderaa_O2](INFO): Powering down 2019-02-16T03:32:32.951Z,1550287952.951 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-02-16T03:32:33.145Z,1550287953.145 [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 & 2019-02-16T03:32:33.171Z,1550287953.171 [CBIT](INFO): Clearing failed state for component BuoyancyServo 2019-02-16T03:32:33.171Z,1550287953.171 [BuoyancyServo] No Fault, FailCount= 1 2019-02-16T03:32:33.449Z,1550287953.449 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-02-16T03:32:33.566Z,1550287953.566 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-02-16T03:32:37.114Z,1550287957.114 [AcousticModem_Benthos_ATM900](DEBUG): 2019-02-16T03:32:38.335Z,1550287958.335 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire 2019-02-16T03:32:38.336Z,1550287958.336 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band 2019-02-16T03:32:38.337Z,1550287958.337 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3 2019-02-16T03:32:38.337Z,1550287958.337 [AcousticModem_Benthos_ATM900](DEBUG): Feb 11 2019 20:31:36 2019-02-16T03:32:38.482Z,1550287958.482 [CBIT](CRITICAL): Environmental Failure. Press:14.779251 PSI. Humidity:29%. Temp:24 C. ABORTING MISSION 2019-02-16T03:32:38.483Z,1550287958.483 [Supervisor](INFO): Stop Mission called by CBIT::monitorEnvironmentals 2019-02-16T03:32:38.735Z,1550287958.735 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low 2019-02-16T03:32:39.068Z,1550287959.068 [CommandLine](FAULT): Scheduling is paused 2019-02-16T03:32:39.069Z,1550287959.069 [CBIT](INFO): Critical error at 20190216T033238 2019-02-16T03:32:39.542Z,1550287959.542 [AcousticModem_Benthos_ATM900](INFO): entering command mode 2019-02-16T03:32:39.946Z,1550287959.946 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment 2019-02-16T03:32:39.947Z,1550287959.947 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1> 2019-02-16T03:32:39.947Z,1550287959.947 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged 2019-02-16T03:32:40.350Z,1550287960.350 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3 2019-02-16T03:32:40.758Z,1550287960.758 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment 2019-02-16T03:32:40.759Z,1550287960.759 [AcousticModem_Benthos_ATM900](INFO): set local address to 3 2019-02-16T03:32:41.159Z,1550287961.159 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2> 2019-02-16T03:32:42.648Z,1550287962.648 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005767 2019-02-16T03:32:52.972Z,1550287972.972 [SBIT](IMPORTANT): Beginning Startup BIT 2019-02-16T03:32:52.977Z,1550287972.977 [CBIT](IMPORTANT): Beginning ground fault scan 2019-02-16T03:32:56.262Z,1550287976.262 [NAL9602](INFO): Powering up NAL9602 2019-02-16T03:32:57.346Z,1550287977.346 [CommandLine](IMPORTANT): got command report mod platform_surface_radio_power 2019-02-16T03:32:57.632Z,1550287977.632 [Reporter](INFO): platform_surface_radio_power 1 bool 2019-02-16T03:33:04.039Z,1550287984.039 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.009262 CHAN A1 (24V): -0.012816 CHAN A2 (12V): -0.005184 CHAN A3 (5V): -0.002964 CHAN B0 (3.3V): -0.000976 CHAN B1 (3.15aV): -0.001029 CHAN B2 (3.15bV): -0.001440 CHAN B3 (GND): -0.000336 OPEN: 0.005065 Full Scale Calc: 4.765 mA, -1.589 mA 2019-02-16T03:33:07.175Z,1550287987.175 [NAL9602](INFO): NAL9602 initialized 2019-02-16T03:33:07.965Z,1550287987.965 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:33:34.855Z,1550288014.855 [BPC1](FAULT): Failed to parse data from all battery packs. 2019-02-16T03:33:34.855Z,1550288014.855 [BPC1] Data Fault, FailCount= 1 2019-02-16T03:33:34.855Z,1550288014.855 [BPC1](ERROR): Data Fault 2019-02-16T03:33:35.331Z,1550288015.331 [CBIT](ERROR): Data Fault in component: BPC1 2019-02-16T03:33:46.293Z,1550288026.293 [SBIT](IMPORTANT): SBIT PASSED 2019-02-16T03:33:46.354Z,1550288026.354 [CommandLine](IMPORTANT): got command configSet list 2019-02-16T03:33:46.355Z,1550288026.355 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-02-16T03:33:46.356Z,1550288026.356 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2019-02-16T03:33:46.710Z,1550288026.710 [MissionManager](IMPORTANT): Started mission Startup 2019-02-16T03:33:46.710Z,1550288026.710 [Startup] Running Loop=1 2019-02-16T03:33:46.710Z,1550288026.710 [Startup](DEBUG): Aggregate::initialize Startup 2019-02-16T03:33:46.710Z,1550288026.710 [Startup:A.GoToSurface] Running Loop=1 2019-02-16T03:33:46.710Z,1550288026.710 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-02-16T03:33:46.711Z,1550288026.711 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-02-16T03:33:46.711Z,1550288026.711 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-02-16T03:33:46.712Z,1550288026.712 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-02-16T03:33:46.712Z,1550288026.712 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-02-16T03:33:46.712Z,1550288026.712 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-02-16T03:33:46.719Z,1550288026.719 [Startup:StartupSatComms] Running Loop=1 2019-02-16T03:33:46.719Z,1550288026.719 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-02-16T03:33:46.719Z,1550288026.719 [Startup:StartupSatComms:A] Running Loop=1 2019-02-16T03:33:47.118Z,1550288027.118 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-02-16T03:34:28.789Z,1550288068.789 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-02-16T03:34:28.789Z,1550288068.789 [Rowe_600LCM] Communications Fault, FailCount= 1 2019-02-16T03:34:28.789Z,1550288068.789 [Rowe_600LCM](ERROR): Communications Fault 2019-02-16T03:34:29.133Z,1550288069.133 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-02-16T03:34:29.194Z,1550288069.194 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-02-16T03:34:29.294Z,1550288069.294 [Rowe_600LCM](INFO): Powering down 2019-02-16T03:34:30.765Z,1550288070.765 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2019-02-16T03:34:30.766Z,1550288070.766 [Rowe_600LCM] No Fault, FailCount= 1 2019-02-16T03:34:30.909Z,1550288070.909 [Rowe_600LCM](INFO): Initializing 2019-02-16T03:34:30.910Z,1550288070.910 [Rowe_600LCM](INFO): Powering up 2019-02-16T03:34:35.033Z,1550288075.033 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-02-16T03:34:35.100Z,1550288075.100 [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 & 2019-02-16T03:34:46.898Z,1550288086.898 [Startup:StartupSatComms:A](INFO): Timed out from 2019-02-16T03:33:46.7Z 2019-02-16T03:34:46.898Z,1550288086.898 [Startup:StartupSatComms:A] Stopped 2019-02-16T03:34:46.898Z,1550288086.898 [Startup:StartupSatComms:B] Running Loop=1 2019-02-16T03:34:47.293Z,1550288087.293 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-02-16T03:34:52.193Z,1550288092.193 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190216T012955/Courier0004.lzma 2019-02-16T03:34:52.999Z,1550288092.999 [DataOverHttps](INFO): Moved sent file to Logs/20190216T012955/Courier0004.lzma.bak 2019-02-16T03:34:52.999Z,1550288092.999 [DataOverHttps](INFO): SBD MOMSN=9925109 2019-02-16T03:35:06.129Z,1550288106.129 [DataOverHttps](INFO): Sending 143 bytes from file Logs/20190216T013331/Courier0000.lzma 2019-02-16T03:35:06.935Z,1550288106.935 [DataOverHttps](INFO): Moved sent file to Logs/20190216T013331/Courier0000.lzma.bak 2019-02-16T03:35:06.935Z,1550288106.935 [DataOverHttps](INFO): SBD MOMSN=9925111 2019-02-16T03:35:18.937Z,1550288118.937 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190216T013331/Courier0004.lzma 2019-02-16T03:35:19.743Z,1550288119.743 [DataOverHttps](INFO): Moved sent file to Logs/20190216T013331/Courier0004.lzma.bak 2019-02-16T03:35:19.743Z,1550288119.743 [DataOverHttps](INFO): SBD MOMSN=9925115 2019-02-16T03:35:28.925Z,1550288128.925 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-02-16T03:35:28.925Z,1550288128.925 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-02-16T03:35:28.930Z,1550288128.930 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1 2019-02-16T03:35:28.930Z,1550288128.930 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-02-16T03:35:28.931Z,1550288128.931 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1 2019-02-16T03:35:28.932Z,1550288128.932 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault 2019-02-16T03:35:28.956Z,1550288128.956 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-02-16T03:35:28.957Z,1550288128.957 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-02-16T03:35:28.957Z,1550288128.957 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor 2019-02-16T03:35:29.363Z,1550288129.363 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-02-16T03:35:29.363Z,1550288129.363 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-02-16T03:35:29.363Z,1550288129.363 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-02-16T03:35:29.363Z,1550288129.363 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1 2019-02-16T03:35:29.364Z,1550288129.364 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor 2019-02-16T03:35:29.364Z,1550288129.364 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1 2019-02-16T03:35:29.715Z,1550288129.715 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-02-16T03:35:31.893Z,1550288131.893 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20190216T033217/Courier0000.lzma 2019-02-16T03:35:32.699Z,1550288132.699 [DataOverHttps](INFO): Moved sent file to Logs/20190216T033217/Courier0000.lzma.bak 2019-02-16T03:35:32.699Z,1550288132.699 [DataOverHttps](INFO): SBD MOMSN=9925117 2019-02-16T03:35:45.810Z,1550288145.810 [DataOverHttps](INFO): Sending 354 bytes from file Logs/20190216T010247/Express0011.lzma 2019-02-16T03:35:46.615Z,1550288146.615 [DataOverHttps](INFO): Moved sent file to Logs/20190216T010247/Express0011.lzma.bak 2019-02-16T03:35:46.615Z,1550288146.615 [DataOverHttps](INFO): SBD MOMSN=9925121 2019-02-16T03:35:47.099Z,1550288147.099 [Startup:StartupSatComms:B](INFO): Timed out from 2019-02-16T03:34:46.9Z 2019-02-16T03:35:47.099Z,1550288147.099 [Startup:StartupSatComms:B] Stopped 2019-02-16T03:35:47.099Z,1550288147.099 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-02-16T03:35:47.099Z,1550288147.099 [Startup:StartupSatComms] Stopped 2019-02-16T03:35:47.099Z,1550288147.099 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-02-16T03:35:47.100Z,1550288147.100 [Startup](INFO): Completed Startup 2019-02-16T03:35:47.100Z,1550288147.100 [MissionManager](INFO): Startup is completed. 2019-02-16T03:35:47.101Z,1550288147.101 [MissionManager](INFO): Uninitializing Mission Startup 2019-02-16T03:35:47.101Z,1550288147.101 [Startup] Stopped 2019-02-16T03:35:47.101Z,1550288147.101 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-02-16T03:35:47.101Z,1550288147.101 [Startup:A.GoToSurface] Stopped 2019-02-16T03:35:47.101Z,1550288147.101 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-02-16T03:35:47.502Z,1550288147.502 [MissionManager](IMPORTANT): Started mission Default 2019-02-16T03:35:47.502Z,1550288147.502 [Default] Running Loop=1 2019-02-16T03:35:47.502Z,1550288147.502 [Default](DEBUG): Aggregate::initialize Default 2019-02-16T03:35:47.503Z,1550288147.503 [Default:B.GoToSurface] Running Loop=1 2019-02-16T03:35:47.503Z,1550288147.503 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-02-16T03:35:47.503Z,1550288147.503 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-02-16T03:35:47.503Z,1550288147.503 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-02-16T03:35:47.504Z,1550288147.504 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-02-16T03:35:47.504Z,1550288147.504 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-02-16T03:35:47.504Z,1550288147.504 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-02-16T03:35:47.504Z,1550288147.504 [Default:A.Wait] Running Loop=1 2019-02-16T03:35:47.505Z,1550288147.505 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-02-16T03:36:00.828Z,1550288160.828 [Default:A.Wait](INFO): Done Waiting. 2019-02-16T03:36:00.828Z,1550288160.828 [Default:A.Wait] Stopped 2019-02-16T03:36:00.828Z,1550288160.828 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-02-16T03:36:01.235Z,1550288161.235 [Default:CheckIn] Running Loop=1 2019-02-16T03:36:01.235Z,1550288161.235 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-02-16T03:36:01.235Z,1550288161.235 [Default:CheckIn:Read_GPS] Running Loop=1 2019-02-16T03:36:01.639Z,1550288161.639 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-02-16T03:36:06.007Z,1550288166.007 [CommandLine](IMPORTANT): got command failComponent 2019-02-16T03:36:06.007Z,1550288166.007 [CommandLine](IMPORTANT): Failed components: 2019-02-16T03:36:06.008Z,1550288166.008 [CommandLine](IMPORTANT): BPC1: Data Fault 2019-02-16T03:36:16.242Z,1550288176.242 [CommandLine](IMPORTANT): got command report list 2019-02-16T03:36:16.243Z,1550288176.243 [Reporter](INFO): platform_surface_radio_power reporting changes 2019-02-16T03:36:31.346Z,1550288191.346 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-02-16T03:36:31.346Z,1550288191.346 [Rowe_600LCM] Communications Fault, FailCount= 2 2019-02-16T03:36:31.346Z,1550288191.346 [Rowe_600LCM](ERROR): Communications Fault 2019-02-16T03:36:31.586Z,1550288191.586 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-02-16T03:36:31.750Z,1550288191.750 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-02-16T03:36:32.027Z,1550288192.027 [Rowe_600LCM](INFO): Powering down 2019-02-16T03:36:33.591Z,1550288193.591 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2019-02-16T03:36:33.591Z,1550288193.591 [Rowe_600LCM] No Fault, FailCount= 2 2019-02-16T03:36:33.642Z,1550288193.642 [Rowe_600LCM](INFO): Initializing 2019-02-16T03:36:33.643Z,1550288193.643 [Rowe_600LCM](INFO): Powering up 2019-02-16T03:36:36.760Z,1550288196.760 [CommandLine](IMPORTANT): got command failComponent hardware Radio_Surface 2019-02-16T03:36:36.760Z,1550288196.760 [Radio_Surface] Hardware Fault, FailCount= 1 2019-02-16T03:36:36.760Z,1550288196.760 [Radio_Surface](ERROR): Hardware Fault 2019-02-16T03:36:36.761Z,1550288196.761 [CommandLine](IMPORTANT): Radio_Surface failureMode is Hardware Fault 2019-02-16T03:36:36.833Z,1550288196.833 [CBIT](ERROR): Hardware Fault in component: Radio_Surface 2019-02-16T03:36:36.994Z,1550288196.994 [Radio_Surface](INFO): Powering down 2019-02-16T03:36:37.765Z,1550288197.765 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-02-16T03:36:37.833Z,1550288197.833 [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 & 2019-02-16T03:36:38.013Z,1550288198.013 [CBIT](INFO): Clearing failed state for component Radio_Surface 2019-02-16T03:36:38.013Z,1550288198.013 [Radio_Surface] No Fault, FailCount= 1 2019-02-16T03:36:38.206Z,1550288198.206 [Radio_Surface](INFO): Powering up 2019-02-16T03:37:12.839Z,1550288232.839 [CommandLine](IMPORTANT): got command get platform_surface_radio_power 2019-02-16T03:37:12.840Z,1550288232.840 [CommandLine](IMPORTANT): platform_surface_radio_power 1 bool 2019-02-16T03:37:17.862Z,1550288237.862 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-02-16T03:38:10.881Z,1550288290.881 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-02-16T03:38:11.705Z,1550288291.705 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:16.549Z,1550288296.549 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:18.058Z,1550288298.058 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-02-16T03:38:19.377Z,1550288299.377 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:22.209Z,1550288302.209 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:24.225Z,1550288304.225 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:27.461Z,1550288307.461 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:29.895Z,1550288309.895 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-02-16T03:38:29.895Z,1550288309.895 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-02-16T03:38:29.897Z,1550288309.897 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2 2019-02-16T03:38:29.897Z,1550288309.897 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-02-16T03:38:29.898Z,1550288309.898 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 2 2019-02-16T03:38:29.898Z,1550288309.898 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault 2019-02-16T03:38:29.910Z,1550288309.910 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-02-16T03:38:29.910Z,1550288309.910 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-02-16T03:38:29.911Z,1550288309.911 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor 2019-02-16T03:38:30.281Z,1550288310.281 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:30.326Z,1550288310.326 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-02-16T03:38:30.327Z,1550288310.327 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-02-16T03:38:30.327Z,1550288310.327 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-02-16T03:38:30.327Z,1550288310.327 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2 2019-02-16T03:38:30.328Z,1550288310.328 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor 2019-02-16T03:38:30.328Z,1550288310.328 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 2 2019-02-16T03:38:30.731Z,1550288310.731 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-02-16T03:38:33.513Z,1550288313.513 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:34.061Z,1550288314.061 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-02-16T03:38:34.061Z,1550288314.061 [Rowe_600LCM] Communications Fault, FailCount= 3 2019-02-16T03:38:34.061Z,1550288314.061 [Rowe_600LCM](ERROR): Communications Fault 2019-02-16T03:38:34.381Z,1550288314.381 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-02-16T03:38:34.466Z,1550288314.466 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-02-16T03:38:34.562Z,1550288314.562 [Rowe_600LCM](INFO): Powering down 2019-02-16T03:38:36.011Z,1550288316.011 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2019-02-16T03:38:36.011Z,1550288316.011 [Rowe_600LCM] No Fault, FailCount= 3 2019-02-16T03:38:36.178Z,1550288316.178 [Rowe_600LCM](INFO): Initializing 2019-02-16T03:38:36.178Z,1550288316.178 [Rowe_600LCM](INFO): Powering up 2019-02-16T03:38:36.337Z,1550288316.337 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:39.581Z,1550288319.581 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:40.302Z,1550288320.302 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-02-16T03:38:40.376Z,1550288320.376 [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 & 2019-02-16T03:38:42.405Z,1550288322.405 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:45.229Z,1550288325.229 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:47.257Z,1550288327.257 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:49.273Z,1550288329.273 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:52.501Z,1550288332.501 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:53.210Z,1550288333.210 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.187988 2019-02-16T03:38:55.333Z,1550288335.333 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:38:58.565Z,1550288338.565 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:01.389Z,1550288341.389 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:04.629Z,1550288344.629 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:07.458Z,1550288347.458 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:10.301Z,1550288350.301 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:12.305Z,1550288352.305 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:14.325Z,1550288354.325 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:17.549Z,1550288357.549 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:18.875Z,1550288358.875 [CommandLine](IMPORTANT): got command get Radio_Surface.simulateHardware 2019-02-16T03:39:18.876Z,1550288358.876 [CommandLine](IMPORTANT): Radio_Surface.simulateHardware 0 bool 2019-02-16T03:39:20.385Z,1550288360.385 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:23.621Z,1550288363.621 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:26.445Z,1550288366.445 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:29.669Z,1550288369.669 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:32.505Z,1550288372.505 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:35.325Z,1550288375.325 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:37.349Z,1550288377.349 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:40.581Z,1550288380.581 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:41.304Z,1550288381.304 [CommandLine](IMPORTANT): got command maintain sensor Depth_Keller.depth 4.000000 meter 2019-02-16T03:39:41.305Z,1550288381.305 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread. 2019-02-16T03:39:41.461Z,1550288381.461 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-02-16T03:39:42.228Z,1550288382.228 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -13.00 mm (1 active estimators). 2019-02-16T03:39:42.430Z,1550288382.430 [Radio_Surface](INFO): Powering down 2019-02-16T03:39:43.409Z,1550288383.409 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:45.258Z,1550288385.258 [ThrusterServo](FAULT): Overload Error 2019-02-16T03:39:45.258Z,1550288385.258 [ThrusterServo] Hardware Fault, FailCount= 1 2019-02-16T03:39:45.258Z,1550288385.258 [ThrusterServo](ERROR): Hardware Fault 2019-02-16T03:39:45.264Z,1550288385.264 [CBIT](ERROR): Hardware Fault in component: ThrusterServo 2019-02-16T03:39:45.635Z,1550288385.635 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-02-16T03:39:45.635Z,1550288385.635 [ThrusterServo](INFO): Powering down 2019-02-16T03:39:46.341Z,1550288386.341 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:46.547Z,1550288386.547 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-02-16T03:39:46.666Z,1550288386.666 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-02-16T03:39:46.670Z,1550288386.670 [CBIT](INFO): Clearing failed state for component ThrusterServo 2019-02-16T03:39:46.670Z,1550288386.670 [ThrusterServo] No Fault, FailCount= 1 2019-02-16T03:39:48.365Z,1550288388.365 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:51.589Z,1550288391.589 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:51.713Z,1550288391.713 [ThrusterServo](FAULT): Overload Error 2019-02-16T03:39:51.714Z,1550288391.714 [ThrusterServo] Hardware Fault, FailCount= 2 2019-02-16T03:39:51.714Z,1550288391.714 [ThrusterServo](ERROR): Hardware Fault 2019-02-16T03:39:51.730Z,1550288391.730 [CBIT](ERROR): Hardware Fault in component: ThrusterServo 2019-02-16T03:39:52.095Z,1550288392.095 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-02-16T03:39:52.095Z,1550288392.095 [ThrusterServo](INFO): Powering down 2019-02-16T03:39:52.875Z,1550288392.875 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-02-16T03:39:52.994Z,1550288392.994 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-02-16T03:39:52.999Z,1550288392.999 [CBIT](INFO): Clearing failed state for component ThrusterServo 2019-02-16T03:39:52.999Z,1550288392.999 [ThrusterServo] No Fault, FailCount= 2 2019-02-16T03:39:54.425Z,1550288394.425 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:39:57.653Z,1550288397.653 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:00.494Z,1550288400.494 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:00.866Z,1550288400.866 [CommandLine](IMPORTANT): got command maintain clear 2019-02-16T03:40:00.987Z,1550288400.987 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,Depth_Keller,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-02-16T03:40:01.822Z,1550288401.822 [Radio_Surface](INFO): Powering up 2019-02-16T03:40:03.786Z,1550288403.786 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:06.617Z,1550288406.617 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:09.449Z,1550288409.449 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:12.677Z,1550288412.677 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:15.501Z,1550288415.501 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:18.466Z,1550288418.466 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-02-16T03:40:18.737Z,1550288418.737 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:21.565Z,1550288421.565 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:24.389Z,1550288424.389 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:26.414Z,1550288426.414 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:28.429Z,1550288428.429 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:31.661Z,1550288431.661 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:34.494Z,1550288434.494 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:36.625Z,1550288436.625 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-02-16T03:40:36.625Z,1550288436.625 [Rowe_600LCM] Communications Fault, FailCount= 4 2019-02-16T03:40:36.626Z,1550288436.626 [Rowe_600LCM](ERROR): Communications Fault 2019-02-16T03:40:36.963Z,1550288436.963 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-02-16T03:40:37.030Z,1550288437.030 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-02-16T03:40:37.161Z,1550288437.161 [Rowe_600LCM](INFO): Powering down 2019-02-16T03:40:37.721Z,1550288437.721 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:38.574Z,1550288438.574 [CBIT](INFO): Clearing failed state for component Rowe_600LCM 2019-02-16T03:40:38.574Z,1550288438.574 [Rowe_600LCM] No Fault, FailCount= 4 2019-02-16T03:40:38.777Z,1550288438.777 [Rowe_600LCM](INFO): Initializing 2019-02-16T03:40:38.778Z,1550288438.778 [Rowe_600LCM](INFO): Powering up 2019-02-16T03:40:40.549Z,1550288440.549 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:42.906Z,1550288442.906 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface 2019-02-16T03:40:43.010Z,1550288443.010 [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 & 2019-02-16T03:40:43.781Z,1550288443.781 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:46.613Z,1550288446.613 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:49.441Z,1550288449.441 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:51.461Z,1550288451.461 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:54.689Z,1550288454.689 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:40:57.517Z,1550288457.517 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:41:00.749Z,1550288460.749 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:41:01.590Z,1550288461.590 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-02-16T03:36:01.2Z 2019-02-16T03:41:01.590Z,1550288461.590 [Default:CheckIn:Read_GPS] Stopped 2019-02-16T03:41:01.590Z,1550288461.590 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-02-16T03:41:01.988Z,1550288461.988 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-02-16T03:41:18.686Z,1550288478.686 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-02-16T03:41:31.072Z,1550288491.072 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-02-16T03:41:31.072Z,1550288491.072 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-02-16T03:41:31.073Z,1550288491.073 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3 2019-02-16T03:41:31.073Z,1550288491.073 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-02-16T03:41:31.074Z,1550288491.074 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 3 2019-02-16T03:41:31.074Z,1550288491.074 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault 2019-02-16T03:41:31.087Z,1550288491.087 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-02-16T03:41:31.087Z,1550288491.087 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-02-16T03:41:31.087Z,1550288491.087 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor 2019-02-16T03:41:31.495Z,1550288491.495 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-02-16T03:41:31.495Z,1550288491.495 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-02-16T03:41:31.495Z,1550288491.495 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-02-16T03:41:31.495Z,1550288491.495 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3 2019-02-16T03:41:31.496Z,1550288491.496 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor 2019-02-16T03:41:31.496Z,1550288491.496 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 3 2019-02-16T03:41:31.850Z,1550288491.850 [NAL9602](ERROR): Queried for signal strength and failed to receive proper response. 2019-02-16T03:41:31.929Z,1550288491.929 [NAL9602](ERROR): received: +CSQ:0 OK 2019-02-16T03:41:31.930Z,1550288491.930 [NAL9602] Data Fault, FailCount= 1 2019-02-16T03:41:31.930Z,1550288491.930 [NAL9602](ERROR): Data Fault 2019-02-16T03:41:31.959Z,1550288491.959 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-02-16T03:41:31.995Z,1550288491.995 [CBIT](ERROR): Data Fault in component: NAL9602 2019-02-16T03:41:32.247Z,1550288492.247 [NAL9602](INFO): Powering down 2019-02-16T03:41:33.099Z,1550288493.099 [CBIT](INFO): Clearing failed state for component NAL9602 2019-02-16T03:41:33.099Z,1550288493.099 [NAL9602] No Fault, FailCount= 1 2019-02-16T03:42:02.547Z,1550288522.547 [NAL9602](INFO): Powering up NAL9602 2019-02-16T03:42:13.463Z,1550288533.463 [NAL9602](INFO): NAL9602 initialized 2019-02-16T03:42:14.281Z,1550288534.281 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:18.321Z,1550288538.321 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:18.882Z,1550288538.882 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2019-02-16T03:42:22.761Z,1550288542.761 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:26.397Z,1550288546.397 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:30.850Z,1550288550.850 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:34.477Z,1550288554.477 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:38.921Z,1550288558.921 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:39.281Z,1550288559.281 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time. 2019-02-16T03:42:39.281Z,1550288559.281 [Rowe_600LCM] Communications Fault, FailCount= 5 2019-02-16T03:42:39.281Z,1550288559.281 [Rowe_600LCM](ERROR): Communications Fault 2019-02-16T03:42:39.380Z,1550288559.380 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM 2019-02-16T03:42:39.381Z,1550288559.381 [CBIT](FAULT): Communications Fault in component: Rowe_600LCM 2019-02-16T03:42:39.685Z,1550288559.685 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-02-16T03:42:39.876Z,1550288559.876 [Rowe_600LCM](INFO): Powering down 2019-02-16T03:42:42.561Z,1550288562.561 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:47.001Z,1550288567.001 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:50.637Z,1550288570.637 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:55.081Z,1550288575.081 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:42:55.123Z,1550288575.123 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003826 2019-02-16T03:42:57.105Z,1550288577.105 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:43:00.340Z,1550288580.340 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:43:01.081Z,1550288581.081 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190216T033217/Courier0004.lzma 2019-02-16T03:43:01.887Z,1550288581.887 [DataOverHttps](INFO): Moved sent file to Logs/20190216T033217/Courier0004.lzma.bak 2019-02-16T03:43:01.887Z,1550288581.887 [DataOverHttps](INFO): SBD MOMSN=9925132 2019-02-16T03:43:03.161Z,1550288583.161 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:43:06.398Z,1550288586.398 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:43:09.219Z,1550288589.219 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-02-16T03:43:09.219Z,1550288589.219 [NAL9602] Data Fault, FailCount= 2 2019-02-16T03:43:09.219Z,1550288589.219 [NAL9602](ERROR): Data Fault 2019-02-16T03:43:09.263Z,1550288589.263 [CBIT](ERROR): Data Fault in component: NAL9602 2019-02-16T03:43:09.611Z,1550288589.611 [NAL9602](INFO): Powering down 2019-02-16T03:43:10.509Z,1550288590.509 [CBIT](INFO): Clearing failed state for component NAL9602 2019-02-16T03:43:10.510Z,1550288590.510 [NAL9602] No Fault, FailCount= 2 2019-02-16T03:43:13.434Z,1550288593.434 [DataOverHttps](INFO): Sending 707 bytes from file Logs/20190216T012955/Express0001.lzma 2019-02-16T03:43:14.239Z,1550288594.239 [DataOverHttps](INFO): Moved sent file to Logs/20190216T012955/Express0001.lzma.bak 2019-02-16T03:43:14.239Z,1550288594.239 [DataOverHttps](INFO): SBD MOMSN=9925134 2019-02-16T03:43:26.777Z,1550288606.777 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20190216T012955/Express0005.lzma 2019-02-16T03:43:27.583Z,1550288607.583 [DataOverHttps](INFO): Moved sent file to Logs/20190216T012955/Express0005.lzma.bak 2019-02-16T03:43:27.583Z,1550288607.583 [DataOverHttps](INFO): SBD MOMSN=9925149 2019-02-16T03:43:35.922Z,1550288615.922 [CBIT](INFO): Clearing failed state for component BPC1 2019-02-16T03:43:35.922Z,1550288615.922 [BPC1] No Fault, FailCount= 1 2019-02-16T03:43:39.911Z,1550288619.911 [NAL9602](INFO): Powering up NAL9602 2019-02-16T03:43:40.610Z,1550288620.610 [DataOverHttps](INFO): Sending 845 bytes from file Logs/20190216T013331/Express0001.lzma 2019-02-16T03:43:41.415Z,1550288621.415 [DataOverHttps](INFO): Moved sent file to Logs/20190216T013331/Express0001.lzma.bak 2019-02-16T03:43:41.415Z,1550288621.415 [DataOverHttps](INFO): SBD MOMSN=9925153 2019-02-16T03:43:50.819Z,1550288630.819 [NAL9602](INFO): NAL9602 initialized 2019-02-16T03:43:51.641Z,1550288631.641 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:43:54.066Z,1550288634.066 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20190216T013331/Express0005.lzma 2019-02-16T03:43:54.474Z,1550288634.474 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:43:54.871Z,1550288634.871 [DataOverHttps](INFO): Moved sent file to Logs/20190216T013331/Express0005.lzma.bak 2019-02-16T03:43:54.871Z,1550288634.871 [DataOverHttps](INFO): SBD MOMSN=9925172 2019-02-16T03:43:57.701Z,1550288637.701 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:00.533Z,1550288640.533 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:03.764Z,1550288643.764 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:06.610Z,1550288646.610 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:09.260Z,1550288649.260 [DataOverHttps](INFO): Sending 828 bytes from file Logs/20190216T033217/Express0001.lzma 2019-02-16T03:44:09.422Z,1550288649.422 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:10.064Z,1550288650.064 [DataOverHttps](INFO): Moved sent file to Logs/20190216T033217/Express0001.lzma.bak 2019-02-16T03:44:10.065Z,1550288650.065 [DataOverHttps](INFO): SBD MOMSN=9925176 2019-02-16T03:44:12.649Z,1550288652.649 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:15.497Z,1550288655.497 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:18.733Z,1550288658.733 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:21.549Z,1550288661.549 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:23.022Z,1550288663.022 [DataOverHttps](INFO): Sending 534 bytes from file Logs/20190216T033217/Express0005.lzma 2019-02-16T03:44:23.827Z,1550288663.827 [DataOverHttps](INFO): Moved sent file to Logs/20190216T033217/Express0005.lzma.bak 2019-02-16T03:44:23.827Z,1550288663.827 [DataOverHttps](INFO): SBD MOMSN=9925194 2019-02-16T03:44:24.397Z,1550288664.397 [Default:CheckIn:Read_Iridium] Stopped 2019-02-16T03:44:24.398Z,1550288664.398 [Default:CheckIn:C.Wait] Running Loop=1 2019-02-16T03:44:24.398Z,1550288664.398 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-02-16T03:44:24.781Z,1550288664.781 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:27.601Z,1550288667.601 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:30.433Z,1550288670.433 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:32.076Z,1550288672.076 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-02-16T03:44:32.076Z,1550288672.076 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-02-16T03:44:32.077Z,1550288672.077 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4 2019-02-16T03:44:32.077Z,1550288672.077 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault 2019-02-16T03:44:32.078Z,1550288672.078 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 4 2019-02-16T03:44:32.079Z,1550288672.079 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault 2019-02-16T03:44:32.091Z,1550288672.091 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-02-16T03:44:32.091Z,1550288672.091 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator 2019-02-16T03:44:32.092Z,1550288672.092 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor 2019-02-16T03:44:32.469Z,1550288672.469 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:32.515Z,1550288672.515 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-02-16T03:44:32.515Z,1550288672.515 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-02-16T03:44:32.516Z,1550288672.516 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator 2019-02-16T03:44:32.516Z,1550288672.516 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4 2019-02-16T03:44:32.516Z,1550288672.516 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor 2019-02-16T03:44:32.516Z,1550288672.516 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 4 2019-02-16T03:44:32.956Z,1550288672.956 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component. 2019-02-16T03:44:34.477Z,1550288674.477 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:37.709Z,1550288677.709 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:40.533Z,1550288680.533 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:42.189Z,1550288682.189 [BPC1](FAULT): Failed to parse data from all battery packs. 2019-02-16T03:44:42.189Z,1550288682.189 [BPC1] Data Fault, FailCount= 2 2019-02-16T03:44:42.190Z,1550288682.190 [BPC1](ERROR): Data Fault 2019-02-16T03:44:42.217Z,1550288682.217 [CBIT](ERROR): Data Fault in component: BPC1 2019-02-16T03:44:43.765Z,1550288683.765 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:46.593Z,1550288686.593 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:49.825Z,1550288689.825 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:52.657Z,1550288692.657 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:55.488Z,1550288695.488 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:44:57.510Z,1550288697.510 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:00.737Z,1550288700.737 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:03.561Z,1550288703.561 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:06.793Z,1550288706.793 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:09.621Z,1550288709.621 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:12.853Z,1550288712.853 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:15.685Z,1550288715.685 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:18.542Z,1550288718.542 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:20.546Z,1550288720.546 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:23.774Z,1550288723.774 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:26.605Z,1550288726.605 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:29.838Z,1550288729.838 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:32.669Z,1550288732.669 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:35.902Z,1550288735.902 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:38.725Z,1550288738.725 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:41.553Z,1550288741.553 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:43.577Z,1550288743.577 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:46.805Z,1550288746.805 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:49.633Z,1550288749.633 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:52.234Z,1550288752.234 [CommandLine](IMPORTANT): got command restart application 2019-02-16T03:45:52.869Z,1550288752.869 [NAL9602](DEBUG): Fix Requested 2019-02-16T03:45:53.245Z,1550288753.245 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-02-16T03:45:53.245Z,1550288753.245 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:53.341Z,1550288753.341 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-02-16T03:45:53.342Z,1550288753.342 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:53.342Z,1550288753.342 [CommandLine](INFO): Join timeout helper Thread ID is 7239 2019-02-16T03:45:53.343Z,1550288753.343 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-02-16T03:45:53.344Z,1550288753.344 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:53.344Z,1550288753.344 [NavChartDb](INFO): Join timeout helper Thread ID is 7240 2019-02-16T03:45:53.654Z,1550288753.654 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-02-16T03:45:53.654Z,1550288753.654 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:53.665Z,1550288753.665 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler 2019-02-16T03:45:53.666Z,1550288753.666 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:53.666Z,1550288753.666 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 7241 2019-02-16T03:45:53.817Z,1550288753.817 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread. 2019-02-16T03:45:53.818Z,1550288753.818 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface 2019-02-16T03:45:53.905Z,1550288753.905 [Rowe_600LCM](INFO): Powering down 2019-02-16T03:45:53.906Z,1550288753.906 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:53.914Z,1550288753.914 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-02-16T03:45:53.914Z,1550288753.914 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:53.914Z,1550288753.914 [Radio_Surface](INFO): Join timeout helper Thread ID is 7243 2019-02-16T03:45:54.238Z,1550288754.238 [Radio_Surface](INFO): Powering down 2019-02-16T03:45:54.239Z,1550288754.239 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-02-16T03:45:54.239Z,1550288754.239 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.249Z,1550288754.249 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-02-16T03:45:54.250Z,1550288754.250 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.250Z,1550288754.250 [DataOverHttps](INFO): Join timeout helper Thread ID is 7244 2019-02-16T03:45:54.294Z,1550288754.294 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-02-16T03:45:54.294Z,1550288754.294 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.310Z,1550288754.310 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-02-16T03:45:54.311Z,1550288754.311 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.311Z,1550288754.311 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7245 2019-02-16T03:45:54.502Z,1550288754.502 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-02-16T03:45:54.502Z,1550288754.502 [WetLabsBB2FL](INFO): Powering down 2019-02-16T03:45:54.503Z,1550288754.503 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.510Z,1550288754.510 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-02-16T03:45:54.511Z,1550288754.511 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.511Z,1550288754.511 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7246 2019-02-16T03:45:54.734Z,1550288754.734 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-02-16T03:45:54.734Z,1550288754.734 [CTD_Seabird](INFO): Powering down 2019-02-16T03:45:54.751Z,1550288754.751 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.754Z,1550288754.754 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-02-16T03:45:54.754Z,1550288754.754 [logger ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.755Z,1550288754.755 [logger](INFO): Join timeout helper Thread ID is 7247 2019-02-16T03:45:54.850Z,1550288754.850 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-02-16T03:45:54.850Z,1550288754.850 [logger ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.854Z,1550288754.854 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-02-16T03:45:54.854Z,1550288754.854 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.855Z,1550288754.855 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-02-16T03:45:54.855Z,1550288754.855 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:54.855Z,1550288754.855 [controlThread](INFO): Join timeout helper Thread ID is 7248 2019-02-16T03:45:54.862Z,1550288754.862 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-02-16T03:45:54.862Z,1550288754.862 [controlThread](DEBUG): Uninitializing ControlThread 2019-02-16T03:45:54.862Z,1550288754.862 [Aanderaa_O2](INFO): Powering down 2019-02-16T03:45:54.865Z,1550288754.865 [AcousticModem_Benthos_ATM900](INFO): Powering down 2019-02-16T03:45:54.986Z,1550288754.986 [NAL9602](INFO): Powering down 2019-02-16T03:45:54.987Z,1550288754.987 [PNI_TCM](INFO): Powering down 2019-02-16T03:45:55.074Z,1550288755.074 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-02-16T03:45:55.075Z,1550288755.075 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-02-16T03:45:55.076Z,1550288755.076 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-02-16T03:45:55.076Z,1550288755.076 [MissionManager](INFO): Uninitializing Mission Default 2019-02-16T03:45:55.077Z,1550288755.077 [Default] Stopped 2019-02-16T03:45:55.077Z,1550288755.077 [Default](DEBUG): Aggregate::uninitialize Default 2019-02-16T03:45:55.077Z,1550288755.077 [Default:B.GoToSurface] Stopped 2019-02-16T03:45:55.077Z,1550288755.077 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-02-16T03:45:55.077Z,1550288755.077 [Default:CheckIn] Stopped 2019-02-16T03:45:55.077Z,1550288755.077 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-02-16T03:45:55.077Z,1550288755.077 [Default:CheckIn:C.Wait] Stopped 2019-02-16T03:45:55.077Z,1550288755.077 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-02-16T03:45:55.081Z,1550288755.081 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-02-16T03:45:55.081Z,1550288755.081 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-02-16T03:45:55.081Z,1550288755.081 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-02-16T03:45:55.082Z,1550288755.082 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-02-16T03:45:55.082Z,1550288755.082 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-02-16T03:45:55.082Z,1550288755.082 [BuoyancyServo](INFO): Powering down 2019-02-16T03:45:55.094Z,1550288755.094 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-02-16T03:45:55.094Z,1550288755.094 [ElevatorServo](INFO): Powering down 2019-02-16T03:45:55.095Z,1550288755.095 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-02-16T03:45:55.095Z,1550288755.095 [MassServo](INFO): Powering down 2019-02-16T03:45:55.096Z,1550288755.096 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-02-16T03:45:55.096Z,1550288755.096 [RudderServo](INFO): Powering down 2019-02-16T03:45:55.096Z,1550288755.096 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-02-16T03:45:55.097Z,1550288755.097 [ThrusterServo](INFO): Powering down 2019-02-16T03:45:55.098Z,1550288755.098 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-02-16T03:45:55.098Z,1550288755.098 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-02-16T03:45:55.098Z,1550288755.098 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-02-16T03:45:55.098Z,1550288755.098 [CBIT](DEBUG): Powering off loads. 2019-02-16T03:45:55.109Z,1550288755.109 [CBIT](DEBUG): Disabling WDT. 2019-02-16T03:45:55.121Z,1550288755.121 [CBIT](DEBUG): Opening all GF detection circuits. 2019-02-16T03:45:55.122Z,1550288755.122 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:55.179Z,1550288755.179 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:55.185Z,1550288755.185 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:55.271Z,1550288755.271 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:55.276Z,1550288755.276 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:55.281Z,1550288755.281 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:55.337Z,1550288755.337 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-02-16T03:45:55.397Z,1550288755.397 [logger ThreadHandler](INFO): Thread cancelled.