2019-08-22T12:29:50.928Z,1566476990.928 [Supervisor](DEBUG): Initializing supervisor. 2019-08-22T12:29:50.931Z,1566476990.931 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-08-22T12:29:50.931Z,1566476990.931 [SyncHandler](INFO): Protected caller Thread ID is 808 2019-08-22T12:29:50.932Z,1566476990.932 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-08-22T12:29:50.933Z,1566476990.933 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-08-22T12:29:50.933Z,1566476990.933 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 809 2019-08-22T12:29:50.936Z,1566476990.936 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-08-22T12:29:50.948Z,1566476990.948 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-08-22T12:29:50.949Z,1566476990.949 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-08-22T12:29:50.950Z,1566476990.950 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 810 2019-08-22T12:29:50.951Z,1566476990.951 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-08-22T12:29:50.952Z,1566476990.952 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-08-22T12:29:50.952Z,1566476990.952 [logger ThreadHandler](INFO): Protected caller Thread ID is 811 2019-08-22T12:29:50.954Z,1566476990.954 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-08-22T12:29:50.954Z,1566476990.954 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-08-22T12:29:50.959Z,1566476990.959 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-08-22T12:29:51.057Z,1566476991.057 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-08-22T12:29:51.059Z,1566476991.059 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-08-22T12:29:51.280Z,1566476991.280 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-08-22T12:29:51.282Z,1566476991.282 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-08-22T12:29:51.427Z,1566476991.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-08-22T12:29:51.428Z,1566476991.428 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-08-22T12:29:52.057Z,1566476992.057 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-08-22T12:29:52.058Z,1566476992.058 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-08-22T12:29:52.546Z,1566476992.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-08-22T12:29:52.546Z,1566476992.546 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-08-22T12:29:53.062Z,1566476993.062 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-08-22T12:29:53.064Z,1566476993.064 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-08-22T12:29:53.402Z,1566476993.402 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-08-22T12:29:53.402Z,1566476993.402 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-08-22T12:29:53.773Z,1566476993.773 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-08-22T12:29:53.775Z,1566476993.775 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-08-22T12:29:54.207Z,1566476994.207 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-08-22T12:29:54.207Z,1566476994.207 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-08-22T12:29:54.368Z,1566476994.368 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-08-22T12:29:54.370Z,1566476994.370 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-08-22T12:29:54.801Z,1566476994.801 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-08-22T12:29:54.802Z,1566476994.802 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-08-22T12:29:54.886Z,1566476994.886 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-08-22T12:29:54.992Z,1566476994.992 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-08-22T12:29:54.993Z,1566476994.993 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-08-22T12:29:55.215Z,1566476995.215 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-08-22T12:29:55.216Z,1566476995.216 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-08-22T12:29:55.440Z,1566476995.440 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-08-22T12:29:55.442Z,1566476995.442 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/ 2019-08-22T12:29:55.444Z,1566476995.444 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg 2019-08-22T12:29:55.531Z,1566476995.531 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg 2019-08-22T12:29:55.769Z,1566476995.769 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-08-22T12:29:55.770Z,1566476995.770 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg 2019-08-22T12:29:55.871Z,1566476995.871 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg 2019-08-22T12:29:56.059Z,1566476996.059 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg 2019-08-22T12:29:56.295Z,1566476996.295 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg 2019-08-22T12:29:56.383Z,1566476996.383 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg 2019-08-22T12:29:56.490Z,1566476996.490 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg 2019-08-22T12:29:56.589Z,1566476996.589 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg 2019-08-22T12:29:56.764Z,1566476996.764 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg 2019-08-22T12:29:56.878Z,1566476996.878 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg 2019-08-22T12:29:56.981Z,1566476996.981 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2019-08-22T12:29:56.984Z,1566476996.984 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-08-22T12:29:57.114Z,1566476997.114 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-08-22T12:29:57.116Z,1566476997.116 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-08-22T12:29:57.272Z,1566476997.272 [BuoyancyServo] Loaded 2019-08-22T12:29:57.272Z,1566476997.272 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-08-22T12:29:57.287Z,1566476997.287 [ElevatorServo] Loaded 2019-08-22T12:29:57.288Z,1566476997.288 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-08-22T12:29:57.303Z,1566476997.303 [MassServo] Loaded 2019-08-22T12:29:57.303Z,1566476997.303 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-08-22T12:29:57.318Z,1566476997.318 [RudderServo] Loaded 2019-08-22T12:29:57.319Z,1566476997.319 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-08-22T12:29:57.334Z,1566476997.334 [ThrusterServo] Loaded 2019-08-22T12:29:57.334Z,1566476997.334 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-08-22T12:29:57.334Z,1566476997.334 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-08-22T12:29:57.336Z,1566476997.336 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-08-22T12:29:57.503Z,1566476997.503 [SBIT](DEBUG): Construct Startup Built In Test. 2019-08-22T12:29:57.533Z,1566476997.533 [SBIT] Loaded 2019-08-22T12:29:57.534Z,1566476997.534 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-08-22T12:29:57.534Z,1566476997.534 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-08-22T12:29:57.563Z,1566476997.563 [IBIT] Loaded 2019-08-22T12:29:57.563Z,1566476997.563 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-08-22T12:29:57.566Z,1566476997.566 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-08-22T12:29:57.963Z,1566476997.963 [CBIT] Loaded 2019-08-22T12:29:57.964Z,1566476997.964 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-08-22T12:29:57.964Z,1566476997.964 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-08-22T12:29:57.965Z,1566476997.965 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-08-22T12:29:58.225Z,1566476998.225 [Aanderaa_O2] Loaded 2019-08-22T12:29:58.225Z,1566476998.225 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2019-08-22T12:29:58.235Z,1566476998.235 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-08-22T12:29:58.240Z,1566476998.240 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-08-22T12:29:58.242Z,1566476998.242 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-08-22T12:29:58.246Z,1566476998.246 [CTD_Seabird](INFO): created writer for : depth 2019-08-22T12:29:58.247Z,1566476998.247 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-08-22T12:29:58.252Z,1566476998.252 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-08-22T12:29:58.253Z,1566476998.253 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-08-22T12:29:58.258Z,1566476998.258 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-08-22T12:29:58.259Z,1566476998.259 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-08-22T12:29:58.264Z,1566476998.264 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-08-22T12:29:58.265Z,1566476998.265 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-08-22T12:29:58.270Z,1566476998.270 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-08-22T12:29:58.271Z,1566476998.271 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-08-22T12:29:58.276Z,1566476998.276 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-08-22T12:29:58.303Z,1566476998.303 [CTD_Seabird] Loaded 2019-08-22T12:29:58.303Z,1566476998.303 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-08-22T12:29:58.304Z,1566476998.304 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4066B4E0 2019-08-22T12:29:58.304Z,1566476998.304 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 890 2019-08-22T12:29:58.336Z,1566476998.336 [ESPComponent] Loaded 2019-08-22T12:29:58.336Z,1566476998.336 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2019-08-22T12:29:58.351Z,1566476998.351 [PAR_Licor] Loaded 2019-08-22T12:29:58.351Z,1566476998.351 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-08-22T12:29:58.400Z,1566476998.400 [WetLabsBB2FL] Loaded 2019-08-22T12:29:58.400Z,1566476998.400 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-08-22T12:29:58.401Z,1566476998.401 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4069B4E0 2019-08-22T12:29:58.402Z,1566476998.402 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 891 2019-08-22T12:29:58.402Z,1566476998.402 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-08-22T12:29:58.403Z,1566476998.403 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-08-22T12:29:58.462Z,1566476998.462 [DepthRateCalculator] Loaded 2019-08-22T12:29:58.462Z,1566476998.462 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-08-22T12:29:58.468Z,1566476998.468 [PitchRateCalculator] Loaded 2019-08-22T12:29:58.468Z,1566476998.468 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-08-22T12:29:58.484Z,1566476998.484 [SpeedCalculator] Loaded 2019-08-22T12:29:58.485Z,1566476998.485 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-08-22T12:29:58.506Z,1566476998.506 [TempGradientCalculator] Loaded 2019-08-22T12:29:58.506Z,1566476998.506 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-08-22T12:29:58.512Z,1566476998.512 [YawRateCalculator] Loaded 2019-08-22T12:29:58.513Z,1566476998.513 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-08-22T12:29:58.546Z,1566476998.546 [ElevatorOffsetCalculator] Loaded 2019-08-22T12:29:58.547Z,1566476998.547 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-08-22T12:29:58.547Z,1566476998.547 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-08-22T12:29:58.548Z,1566476998.548 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-08-22T12:29:58.597Z,1566476998.597 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-08-22T12:29:58.598Z,1566476998.598 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-08-22T12:29:58.720Z,1566476998.720 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-08-22T12:29:58.720Z,1566476998.720 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-08-22T12:29:58.742Z,1566476998.742 [NavChart] Loaded 2019-08-22T12:29:58.742Z,1566476998.742 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-08-22T12:29:58.747Z,1566476998.747 [UniversalFixResidualReporter] Loaded 2019-08-22T12:29:58.747Z,1566476998.747 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-08-22T12:29:58.747Z,1566476998.747 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-08-22T12:29:58.749Z,1566476998.749 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-08-22T12:29:59.440Z,1566476999.440 [AHRS_M2] Loaded 2019-08-22T12:29:59.440Z,1566476999.440 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-08-22T12:29:59.585Z,1566476999.585 [DataOverHttps] Loaded 2019-08-22T12:29:59.585Z,1566476999.585 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-08-22T12:29:59.586Z,1566476999.586 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409744E0 2019-08-22T12:29:59.587Z,1566476999.587 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 892 2019-08-22T12:29:59.600Z,1566476999.600 [Depth_Keller] Loaded 2019-08-22T12:29:59.600Z,1566476999.600 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-08-22T12:29:59.606Z,1566476999.606 [DropWeight] Loaded 2019-08-22T12:29:59.606Z,1566476999.606 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-08-22T12:29:59.739Z,1566476999.739 [DVL_micro] Loaded 2019-08-22T12:29:59.739Z,1566476999.739 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2019-08-22T12:29:59.831Z,1566476999.831 [NAL9602] Loaded 2019-08-22T12:29:59.831Z,1566476999.831 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-08-22T12:29:59.837Z,1566476999.837 [Onboard] Loaded 2019-08-22T12:29:59.837Z,1566476999.837 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-08-22T12:29:59.840Z,1566476999.840 [Radio_Surface] Loaded 2019-08-22T12:29:59.841Z,1566476999.841 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-08-22T12:29:59.842Z,1566476999.842 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409A44E0 2019-08-22T12:29:59.842Z,1566476999.842 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 893 2019-08-22T12:29:59.974Z,1566476999.974 [DAT] Loaded 2019-08-22T12:29:59.974Z,1566476999.974 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-08-22T12:30:01.887Z,1566477001.887 [BPC1] Loaded 2019-08-22T12:30:01.887Z,1566477001.887 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-08-22T12:30:01.887Z,1566477001.887 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-08-22T12:30:01.888Z,1566477001.888 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-08-22T12:30:02.001Z,1566477002.001 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-08-22T12:30:02.002Z,1566477002.002 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-08-22T12:30:02.094Z,1566477002.094 [VerticalControl](DEBUG): Construct VerticalControl. 2019-08-22T12:30:02.180Z,1566477002.180 [VerticalControl] Loaded 2019-08-22T12:30:02.180Z,1566477002.180 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-08-22T12:30:02.181Z,1566477002.181 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-08-22T12:30:02.240Z,1566477002.240 [HorizontalControl] Loaded 2019-08-22T12:30:02.241Z,1566477002.241 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-08-22T12:30:02.242Z,1566477002.242 [SpeedControl](DEBUG): Construct SpeedControl. 2019-08-22T12:30:02.243Z,1566477002.243 [SpeedControl] Loaded 2019-08-22T12:30:02.244Z,1566477002.244 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-08-22T12:30:02.244Z,1566477002.244 [LoopControl](DEBUG): Construct LoopControl. 2019-08-22T12:30:02.245Z,1566477002.245 [LoopControl] Loaded 2019-08-22T12:30:02.245Z,1566477002.245 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-08-22T12:30:02.246Z,1566477002.246 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-08-22T12:30:02.246Z,1566477002.246 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-08-22T12:30:02.270Z,1566477002.270 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-08-22T12:30:02.271Z,1566477002.271 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-08-22T12:30:02.615Z,1566477002.615 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-08-22T12:30:02.619Z,1566477002.619 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-08-22T12:30:02.619Z,1566477002.619 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-08-22T12:30:02.626Z,1566477002.626 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-08-22T12:30:02.627Z,1566477002.627 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40ADF4E0 2019-08-22T12:30:02.628Z,1566477002.628 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 894 2019-08-22T12:30:02.633Z,1566477002.633 [Supervisor](INFO): Main Thread ID is 804 2019-08-22T12:30:02.633Z,1566477002.633 [Supervisor](DEBUG): Running supervisor. 2019-08-22T12:30:02.633Z,1566477002.633 [CommandLine ThreadHandler](INFO): Handler Thread ID is 895 2019-08-22T12:30:02.636Z,1566477002.636 [controlThread ThreadHandler](INFO): Handler Thread ID is 896 2019-08-22T12:30:02.636Z,1566477002.636 [controlThread](DEBUG): Initializing ControlThread 2019-08-22T12:30:02.638Z,1566477002.638 [SBIT](INFO): Initialize SBIT Component. 2019-08-22T12:30:02.638Z,1566477002.638 [SBIT](IMPORTANT): git: 2019-08-13 2019-08-22T12:30:02.639Z,1566477002.639 [SBIT](INFO): git hash: 6b080875362fb71081cecd990260e30fa66d1cc0 2019-08-22T12:30:02.639Z,1566477002.639 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-08-22T12:30:02.640Z,1566477002.640 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 2019-08-22T12:30:02.641Z,1566477002.641 [SBIT](INFO): Beginning SBIT in 24.000000 seconds. 2019-08-22T12:30:02.642Z,1566477002.642 [IBIT](INFO): Initialize IBIT Component. 2019-08-22T12:30:02.643Z,1566477002.643 [CBIT](DEBUG): Initialize CBIT Component. 2019-08-22T12:30:02.644Z,1566477002.644 [logger ThreadHandler](INFO): Handler Thread ID is 897 2019-08-22T12:30:02.657Z,1566477002.657 [CBIT](DEBUG): Initialized mux pins. 2019-08-22T12:30:02.657Z,1566477002.657 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2019-08-22T12:30:02.657Z,1566477002.657 [CBIT](DEBUG): Initializing the watchdog timer. 2019-08-22T12:30:02.669Z,1566477002.669 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 898 2019-08-22T12:30:02.670Z,1566477002.670 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-08-22T12:30:02.673Z,1566477002.673 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-08-22T12:30:02.675Z,1566477002.675 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 900 2019-08-22T12:30:02.676Z,1566477002.676 [WetLabsBB2FL](INFO): Powering down 2019-08-22T12:30:02.681Z,1566477002.681 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-08-22T12:30:02.681Z,1566477002.681 [CBIT](DEBUG): Initializing heartbeat. 2019-08-22T12:30:02.704Z,1566477002.704 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 901 2019-08-22T12:30:02.705Z,1566477002.705 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-08-22T12:30:02.717Z,1566477002.717 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 902 2019-08-22T12:30:02.729Z,1566477002.729 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 903 2019-08-22T12:30:02.738Z,1566477002.738 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-08-22T12:30:02.738Z,1566477002.738 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-08-22T12:30:02.739Z,1566477002.739 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-08-22T12:30:02.739Z,1566477002.739 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-08-22T12:30:02.739Z,1566477002.739 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-08-22T12:30:02.739Z,1566477002.739 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-08-22T12:30:02.739Z,1566477002.739 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-08-22T12:30:02.740Z,1566477002.740 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-08-22T12:30:02.740Z,1566477002.740 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-08-22T12:30:02.740Z,1566477002.740 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-08-22T12:30:02.740Z,1566477002.740 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-08-22T12:30:02.740Z,1566477002.740 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-08-22T12:30:02.740Z,1566477002.740 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-08-22T12:30:02.741Z,1566477002.741 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-08-22T12:30:02.741Z,1566477002.741 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-08-22T12:30:02.741Z,1566477002.741 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-08-22T12:30:02.753Z,1566477002.753 [CBIT](DEBUG): Deactivating GF circuits. 2019-08-22T12:30:02.753Z,1566477002.753 [CBIT](DEBUG): Deactivating emergency mode. 2019-08-22T12:30:02.789Z,1566477002.789 [CBIT](DEBUG): Backplane powered. 2019-08-22T12:30:02.793Z,1566477002.793 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-08-22T12:30:02.793Z,1566477002.793 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-08-22T12:30:02.794Z,1566477002.794 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-08-22T12:30:02.794Z,1566477002.794 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-08-22T12:30:02.795Z,1566477002.795 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-08-22T12:30:02.795Z,1566477002.795 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-08-22T12:30:02.796Z,1566477002.796 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-08-22T12:30:02.797Z,1566477002.797 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-08-22T12:30:02.808Z,1566477002.808 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-08-22T12:30:02.817Z,1566477002.817 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-08-22T12:30:02.818Z,1566477002.818 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-08-22T12:30:02.819Z,1566477002.819 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-08-22T12:30:02.819Z,1566477002.819 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-08-22T12:30:02.854Z,1566477002.854 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-08-22T12:30:02.880Z,1566477002.880 [MissionManager](DEBUG): 2019-08-22T12:30:02.891Z,1566477002.891 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-08-22T12:30:02.962Z,1566477002.962 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-08-22T12:30:02.963Z,1566477002.963 [Default:A.Wait](DEBUG): Construct Wait. 2019-08-22T12:30:02.965Z,1566477002.965 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-08-22T12:30:02.999Z,1566477002.999 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-08-22T12:30:03.001Z,1566477003.001 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-08-22T12:30:03.023Z,1566477003.023 [Default:E.Execute](DEBUG): Construct Execute. 2019-08-22T12:30:03.026Z,1566477003.026 [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-22T12:30:03.037Z,1566477003.037 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,PAR_Licor,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-22T12:30:03.074Z,1566477003.074 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-08-22T12:30:03.121Z,1566477003.121 [Radio_Surface](INFO): Powering up 2019-08-22T12:30:03.321Z,1566477003.321 [DVL_micro](INFO): Initializing 2019-08-22T12:30:03.347Z,1566477003.347 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-08-22T12:30:03.347Z,1566477003.347 [DAT](INFO): Powering up 2019-08-22T12:30:03.347Z,1566477003.347 [DAT](DEBUG): Initializing DAT. 2019-08-22T12:30:03.433Z,1566477003.433 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-08-22T12:30:03.470Z,1566477003.470 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-08-22T12:30:03.477Z,1566477003.477 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-08-22T12:30:03.478Z,1566477003.478 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-08-22T12:30:03.489Z,1566477003.489 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-08-22T12:30:03.490Z,1566477003.490 [MassServo](DEBUG): Initializing EZServoServo. 2019-08-22T12:30:03.501Z,1566477003.501 [MassServo](DEBUG): Initializing MassServo. 2019-08-22T12:30:03.502Z,1566477003.502 [RudderServo](DEBUG): Initializing EZServoServo. 2019-08-22T12:30:03.513Z,1566477003.513 [RudderServo](DEBUG): Initializing RudderServo. 2019-08-22T12:30:03.514Z,1566477003.514 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-08-22T12:30:03.521Z,1566477003.521 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-08-22T12:30:06.481Z,1566477006.481 [Aanderaa_O2](INFO): Powering down 2019-08-22T12:30:18.914Z,1566477018.914 [DAT](INFO): setting local address to 3 2019-08-22T12:30:19.331Z,1566477019.331 [DAT](INFO): set local address to 3 2019-08-22T12:30:27.427Z,1566477027.427 [SBIT](IMPORTANT): Beginning Startup BIT 2019-08-22T12:30:27.434Z,1566477027.434 [CBIT](IMPORTANT): Beginning ground fault scan 2019-08-22T12:30:29.835Z,1566477029.835 [NAL9602](INFO): Powering up NAL9602 2019-08-22T12:30:38.609Z,1566477038.609 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010566 CHAN A1 (24V): -0.023917 CHAN A2 (12V): -0.005119 CHAN A3 (5V): -0.002677 CHAN B0 (3.3V): -0.001181 CHAN B1 (3.15aV): -0.001323 CHAN B2 (3.15bV): -0.001578 CHAN B3 (GND): 0.000380 OPEN: 0.006709 Full Scale Calc: 4.765 mA, -1.589 mA 2019-08-22T12:30:40.887Z,1566477040.887 [NAL9602](INFO): NAL9602 initialized 2019-08-22T12:30:41.721Z,1566477041.721 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:31:21.142Z,1566477081.142 [SBIT](IMPORTANT): SBIT PASSED 2019-08-22T12:31:21.182Z,1566477081.182 [CommandLine](IMPORTANT): got command configSet list 2019-08-22T12:31:21.182Z,1566477081.182 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-08-22T12:31:21.185Z,1566477081.185 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count; 2019-08-22T12:31:21.186Z,1566477081.186 [CommandLine](IMPORTANT): BuoyancyServo.fastPumpDepth=6 meter; 2019-08-22T12:31:21.186Z,1566477081.186 [CommandLine](IMPORTANT): CBIT.stopDepth=10 meter; 2019-08-22T12:31:21.186Z,1566477081.186 [CommandLine](IMPORTANT): CTD_Seabird.minSalinityBound=0.01 practical_salinity_unit; 2019-08-22T12:31:21.186Z,1566477081.186 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool; 2019-08-22T12:31:21.186Z,1566477081.186 [CommandLine](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity; 2019-08-22T12:31:21.186Z,1566477081.186 [CommandLine](IMPORTANT): Express linearApproximation CTD_Seabird.sea_water_electrical_conductivity 0.001000 siemens_per_meter; 2019-08-22T12:31:21.186Z,1566477081.186 [CommandLine](IMPORTANT): Express linearApproximation mass_concentration_of_oxygen_in_sea_water 750.000000 microgram_per_liter; 2019-08-22T12:31:21.186Z,1566477081.186 [CommandLine](IMPORTANT): Express none platform_orientation; 2019-08-22T12:31:21.186Z,1566477081.186 [CommandLine](IMPORTANT): Normal linearApproximation platform_orientation; 2019-08-22T12:31:21.187Z,1566477081.187 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=375 cubic_centimeter; 2019-08-22T12:31:21.187Z,1566477081.187 [CommandLine](IMPORTANT): VerticalControl.elevDeadband=0.1 degree; 2019-08-22T12:31:21.187Z,1566477081.187 [CommandLine](IMPORTANT): VerticalControl.kiDepthBuoy=0.3 reciprocal_second; 2019-08-22T12:31:21.187Z,1566477081.187 [CommandLine](IMPORTANT): VerticalControl.kiPitchMass=0.00075 reciprocal_second; 2019-08-22T12:31:21.187Z,1566477081.187 [CommandLine](IMPORTANT): VerticalControl.massDeadband=0.25 millimeter; 2019-08-22T12:31:21.187Z,1566477081.187 [CommandLine](IMPORTANT): VerticalControl.massDefault=11 millimeter; 2019-08-22T12:31:21.542Z,1566477081.542 [MissionManager](IMPORTANT): Started mission Startup 2019-08-22T12:31:21.542Z,1566477081.542 [Startup] Running Loop=1 2019-08-22T12:31:21.542Z,1566477081.542 [Startup](DEBUG): Aggregate::initialize Startup 2019-08-22T12:31:21.542Z,1566477081.542 [Startup:A.GoToSurface] Running Loop=1 2019-08-22T12:31:21.542Z,1566477081.542 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-08-22T12:31:21.543Z,1566477081.543 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-08-22T12:31:21.543Z,1566477081.543 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-08-22T12:31:21.544Z,1566477081.544 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-08-22T12:31:21.544Z,1566477081.544 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-08-22T12:31:21.545Z,1566477081.545 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-08-22T12:31:21.547Z,1566477081.547 [Startup:StartupSatComms] Running Loop=1 2019-08-22T12:31:21.547Z,1566477081.547 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-08-22T12:31:21.547Z,1566477081.547 [Startup:StartupSatComms:A] Running Loop=1 2019-08-22T12:31:21.922Z,1566477081.922 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-08-22T12:32:21.725Z,1566477141.725 [Startup:StartupSatComms:A](INFO): Timed out from 2019-08-22T12:31:21.5Z 2019-08-22T12:32:21.725Z,1566477141.725 [Startup:StartupSatComms:A] Stopped 2019-08-22T12:32:21.725Z,1566477141.725 [Startup:StartupSatComms:B] Running Loop=1 2019-08-22T12:32:22.124Z,1566477142.124 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-08-22T12:33:02.927Z,1566477182.927 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-08-22T12:33:02.927Z,1566477182.927 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-22T12:33:02.937Z,1566477182.937 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-22T12:33:03.385Z,1566477183.385 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-22T12:33:03.385Z,1566477183.385 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-08-22T12:33:04.200Z,1566477184.200 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-08-22T12:33:07.338Z,1566477187.338 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-22T12:33:07.338Z,1566477187.338 [DVL_micro] Data Fault, FailCount= 1 2019-08-22T12:33:07.338Z,1566477187.338 [DVL_micro](ERROR): Data Fault 2019-08-22T12:33:07.375Z,1566477187.375 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-22T12:33:07.817Z,1566477187.817 [DVL_micro](INFO): uninitialize:Powering down 2019-08-22T12:33:08.591Z,1566477188.591 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-22T12:33:08.591Z,1566477188.591 [DVL_micro] No Fault, FailCount= 1 2019-08-22T12:33:08.960Z,1566477188.960 [DVL_micro](INFO): Initializing 2019-08-22T12:33:21.925Z,1566477201.925 [Startup:StartupSatComms:B](INFO): Timed out from 2019-08-22T12:32:21.7Z 2019-08-22T12:33:21.925Z,1566477201.925 [Startup:StartupSatComms:B] Stopped 2019-08-22T12:33:21.925Z,1566477201.925 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-08-22T12:33:21.926Z,1566477201.926 [Startup:StartupSatComms] Stopped 2019-08-22T12:33:21.926Z,1566477201.926 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-08-22T12:33:21.926Z,1566477201.926 [Startup](INFO): Completed Startup 2019-08-22T12:33:21.927Z,1566477201.927 [MissionManager](INFO): Startup is completed. 2019-08-22T12:33:21.927Z,1566477201.927 [MissionManager](INFO): Uninitializing Mission Startup 2019-08-22T12:33:21.927Z,1566477201.927 [Startup] Stopped 2019-08-22T12:33:21.927Z,1566477201.927 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-08-22T12:33:21.927Z,1566477201.927 [Startup:A.GoToSurface] Stopped 2019-08-22T12:33:21.927Z,1566477201.927 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-08-22T12:33:22.330Z,1566477202.330 [MissionManager](IMPORTANT): Started mission Default 2019-08-22T12:33:22.330Z,1566477202.330 [Default] Running Loop=1 2019-08-22T12:33:22.330Z,1566477202.330 [Default](DEBUG): Aggregate::initialize Default 2019-08-22T12:33:22.330Z,1566477202.330 [Default:B.GoToSurface] Running Loop=1 2019-08-22T12:33:22.330Z,1566477202.330 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-08-22T12:33:22.331Z,1566477202.331 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-08-22T12:33:22.331Z,1566477202.331 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-08-22T12:33:22.331Z,1566477202.331 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-08-22T12:33:22.331Z,1566477202.331 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-08-22T12:33:22.332Z,1566477202.332 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-08-22T12:33:22.332Z,1566477202.332 [Default:A.Wait] Running Loop=1 2019-08-22T12:33:22.332Z,1566477202.332 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-08-22T12:33:32.875Z,1566477212.875 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-08-22T12:33:35.646Z,1566477215.646 [Default:A.Wait](INFO): Done Waiting. 2019-08-22T12:33:35.647Z,1566477215.647 [Default:A.Wait] Stopped 2019-08-22T12:33:35.647Z,1566477215.647 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-08-22T12:33:36.051Z,1566477216.051 [Default:CheckIn] Running Loop=1 2019-08-22T12:33:36.051Z,1566477216.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-22T12:33:36.051Z,1566477216.051 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-22T12:33:36.516Z,1566477216.516 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-08-22T12:33:44.683Z,1566477224.683 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005005 2019-08-22T12:34:02.411Z,1566477242.411 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-08-22T12:34:28.544Z,1566477268.544 [NAL9602](INFO): SBD MO Status=2, MOMSN=32519, MT Status=2, MTMSN=0 2019-08-22T12:34:28.544Z,1566477268.544 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2019-08-22T12:34:39.856Z,1566477279.856 [NAL9602](INFO): SBD MO Status=0, MOMSN=32519, MT Status=0, MTMSN=0 2019-08-22T12:34:39.856Z,1566477279.856 [NAL9602](INFO): No messages in MT queue 2019-08-22T12:34:40.677Z,1566477280.677 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:34:43.505Z,1566477283.505 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:34:44.492Z,1566477284.492 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-08-22T12:34:46.733Z,1566477286.733 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:34:49.565Z,1566477289.565 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:34:52.801Z,1566477292.801 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:34:55.645Z,1566477295.645 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:34:58.941Z,1566477298.941 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:01.829Z,1566477301.829 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:04.721Z,1566477304.721 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:07.565Z,1566477307.565 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:09.569Z,1566477309.569 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:12.069Z,1566477312.069 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:13.851Z,1566477313.851 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-08-22T12:35:14.821Z,1566477314.821 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:18.053Z,1566477318.053 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:20.893Z,1566477320.893 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:23.705Z,1566477323.705 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:24.920Z,1566477324.920 [DVL_micro](ERROR): only read 43 of 46 data items 2019-08-22T12:35:24.920Z,1566477324.920 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -558 294 575 -494 2 3 3 2 -1512.1 1051.7 -49.4 2 -236.5 1826.6 -49.4 2 -1512 1051 -49 2 -236 1826 -49 2 8.95 -1.57 312.2 -3.0 24.1 0.005 35.0 1489 108 2019-08-22T12:35:26.945Z,1566477326.945 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:29.769Z,1566477329.769 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:31.088Z,1566477331.088 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T12:35:32.613Z,1566477332.613 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:34.642Z,1566477334.642 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:36.637Z,1566477336.637 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:39.873Z,1566477339.873 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:42.725Z,1566477342.725 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:45.933Z,1566477345.933 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:48.777Z,1566477348.777 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:51.993Z,1566477351.993 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:54.821Z,1566477354.821 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:57.653Z,1566477357.653 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:35:59.402Z,1566477359.402 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2019-08-22T12:36:00.073Z,1566477360.073 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:02.908Z,1566477362.908 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:03.714Z,1566477363.714 [DVL_micro](ERROR): only read 45 of 46 data items 2019-08-22T12:36:03.723Z,1566477363.723 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -381 333 365 -282 2 2 3 2 -995.6 820.8 9.4 1288.7 9.4 2 -995 820 9 2 -62 1288 9 2 8.93 -1.53 312.3 -3.0 24.15.0 1489 99 2019-08-22T12:36:03.966Z,1566477363.966 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-08-22T12:36:03.966Z,1566477363.966 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-22T12:36:03.988Z,1566477363.988 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-22T12:36:04.241Z,1566477364.241 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-22T12:36:04.241Z,1566477364.241 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-08-22T12:36:06.133Z,1566477366.133 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:08.965Z,1566477368.965 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:12.189Z,1566477372.189 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:13.386Z,1566477373.386 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-22T12:36:13.387Z,1566477373.387 [DVL_micro] Data Fault, FailCount= 1 2019-08-22T12:36:13.387Z,1566477373.387 [DVL_micro](ERROR): Data Fault 2019-08-22T12:36:13.448Z,1566477373.448 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-22T12:36:13.865Z,1566477373.865 [DVL_micro](INFO): uninitialize:Powering down 2019-08-22T12:36:14.617Z,1566477374.617 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:14.692Z,1566477374.692 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-22T12:36:14.692Z,1566477374.692 [DVL_micro] No Fault, FailCount= 1 2019-08-22T12:36:15.029Z,1566477375.029 [DVL_micro](INFO): Initializing 2019-08-22T12:36:16.339Z,1566477376.339 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-08-22T12:36:17.041Z,1566477377.041 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:19.877Z,1566477379.877 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:22.717Z,1566477382.717 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:25.941Z,1566477385.941 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:28.759Z,1566477388.759 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:31.985Z,1566477391.985 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:34.817Z,1566477394.817 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:38.045Z,1566477398.045 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:40.897Z,1566477400.897 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:43.705Z,1566477403.705 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:45.089Z,1566477405.089 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-08-22T12:36:45.725Z,1566477405.725 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:48.165Z,1566477408.165 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:50.977Z,1566477410.977 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:54.209Z,1566477414.209 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:57.069Z,1566477417.069 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:36:59.865Z,1566477419.865 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:03.113Z,1566477423.113 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:05.929Z,1566477425.929 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:08.789Z,1566477428.789 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:10.789Z,1566477430.789 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:14.025Z,1566477434.025 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:16.833Z,1566477436.833 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:20.073Z,1566477440.073 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:22.933Z,1566477442.933 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:26.149Z,1566477446.149 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:28.969Z,1566477448.969 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:31.789Z,1566477451.789 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:33.809Z,1566477453.809 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:36.225Z,1566477456.225 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:39.097Z,1566477459.097 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:42.305Z,1566477462.305 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:45.117Z,1566477465.117 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:47.949Z,1566477467.949 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:51.181Z,1566477471.181 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:54.009Z,1566477474.009 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:56.829Z,1566477476.829 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:37:58.853Z,1566477478.853 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:02.085Z,1566477482.085 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:04.941Z,1566477484.941 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:08.173Z,1566477488.173 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:10.973Z,1566477490.973 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:14.205Z,1566477494.205 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:17.033Z,1566477497.033 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:17.507Z,1566477497.507 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2019-08-22T12:38:19.861Z,1566477499.861 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:21.897Z,1566477501.897 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:24.337Z,1566477504.337 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:27.129Z,1566477507.129 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:30.365Z,1566477510.365 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:32.846Z,1566477512.846 [BPC1](ERROR): Battery stick #38 (s/n: 0139) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-08-22T12:38:32.847Z,1566477512.847 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2019-08-22T12:38:32.847Z,1566477512.847 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2019-08-22T12:38:32.854Z,1566477512.854 [BPC1](INFO): Received data from all battery sticks. 2019-08-22T12:38:33.213Z,1566477513.213 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:36.033Z,1566477516.033 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:36.078Z,1566477516.078 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-22T12:33:36.1Z 2019-08-22T12:38:36.078Z,1566477516.078 [Default:CheckIn:Read_GPS] Stopped 2019-08-22T12:38:36.078Z,1566477516.078 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-22T12:38:36.474Z,1566477516.474 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-08-22T12:38:39.069Z,1566477519.069 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:39.811Z,1566477519.811 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190821T203758/Courier0294.lzma 2019-08-22T12:38:40.627Z,1566477520.627 [DataOverHttps](INFO): Moved sent file to Logs/20190821T203758/Courier0294.lzma.bak 2019-08-22T12:38:40.627Z,1566477520.627 [DataOverHttps](INFO): SBD MOMSN=11667356 2019-08-22T12:38:42.309Z,1566477522.309 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:45.129Z,1566477525.129 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:48.365Z,1566477528.365 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:51.193Z,1566477531.193 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:54.021Z,1566477534.021 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:57.249Z,1566477537.249 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:38:57.521Z,1566477537.521 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190822T122613/Courier0000.lzma 2019-08-22T12:38:58.326Z,1566477538.326 [DataOverHttps](INFO): Moved sent file to Logs/20190822T122613/Courier0000.lzma.bak 2019-08-22T12:38:58.327Z,1566477538.327 [DataOverHttps](INFO): SBD MOMSN=11667358 2019-08-22T12:39:00.142Z,1566477540.142 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:02.933Z,1566477542.933 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:04.589Z,1566477544.589 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-08-22T12:39:04.589Z,1566477544.589 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-22T12:39:04.612Z,1566477544.612 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-22T12:39:05.039Z,1566477545.039 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-22T12:39:05.039Z,1566477545.039 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-08-22T12:39:06.189Z,1566477546.189 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:09.025Z,1566477549.025 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:12.249Z,1566477552.249 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:15.045Z,1566477555.045 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:18.277Z,1566477558.277 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:19.527Z,1566477559.527 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-22T12:39:19.527Z,1566477559.527 [DVL_micro] Data Fault, FailCount= 1 2019-08-22T12:39:19.527Z,1566477559.527 [DVL_micro](ERROR): Data Fault 2019-08-22T12:39:19.688Z,1566477559.688 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-22T12:39:20.006Z,1566477560.006 [DVL_micro](INFO): uninitialize:Powering down 2019-08-22T12:39:20.807Z,1566477560.807 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-22T12:39:20.807Z,1566477560.807 [DVL_micro] No Fault, FailCount= 1 2019-08-22T12:39:21.114Z,1566477561.114 [DVL_micro](INFO): Initializing 2019-08-22T12:39:21.137Z,1566477561.137 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:22.489Z,1566477562.489 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20190822T122950/Courier0004.lzma 2019-08-22T12:39:23.295Z,1566477563.295 [DataOverHttps](INFO): Moved sent file to Logs/20190822T122950/Courier0004.lzma.bak 2019-08-22T12:39:23.295Z,1566477563.295 [DataOverHttps](INFO): SBD MOMSN=11667361 2019-08-22T12:39:24.353Z,1566477564.353 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:27.177Z,1566477567.177 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:30.413Z,1566477570.413 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:33.238Z,1566477573.238 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:36.477Z,1566477576.477 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:39.298Z,1566477579.298 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:42.125Z,1566477582.125 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:44.025Z,1566477584.025 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190821T203758/Express0295.lzma 2019-08-22T12:39:44.832Z,1566477584.832 [DataOverHttps](INFO): Moved sent file to Logs/20190821T203758/Express0295.lzma.bak 2019-08-22T12:39:44.832Z,1566477584.832 [DataOverHttps](INFO): SBD MOMSN=11667366 2019-08-22T12:39:45.361Z,1566477585.361 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:48.201Z,1566477588.201 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:51.017Z,1566477591.017 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:54.281Z,1566477594.281 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:39:57.077Z,1566477597.077 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:00.313Z,1566477600.313 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:03.197Z,1566477603.197 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:06.385Z,1566477606.385 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:07.880Z,1566477607.880 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190822T122613/Express0001.lzma 2019-08-22T12:40:09.090Z,1566477609.090 [DataOverHttps](INFO): Moved sent file to Logs/20190822T122613/Express0001.lzma.bak 2019-08-22T12:40:09.091Z,1566477609.091 [DataOverHttps](INFO): SBD MOMSN=11667375 2019-08-22T12:40:09.201Z,1566477609.201 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:12.437Z,1566477612.437 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:15.273Z,1566477615.273 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:18.489Z,1566477618.489 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:21.325Z,1566477621.325 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:24.545Z,1566477624.545 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:26.582Z,1566477626.582 [DataOverHttps](INFO): Sending 1052 bytes from file Logs/20190822T122950/Express0001.lzma 2019-08-22T12:40:27.381Z,1566477627.381 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:27.786Z,1566477627.786 [DataOverHttps](INFO): Moved sent file to Logs/20190822T122950/Express0001.lzma.bak 2019-08-22T12:40:27.787Z,1566477627.787 [DataOverHttps](INFO): SBD MOMSN=11667378 2019-08-22T12:40:30.221Z,1566477630.221 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:33.033Z,1566477633.033 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:35.053Z,1566477635.053 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:37.077Z,1566477637.077 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:39.097Z,1566477639.097 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:40:42.322Z,1566477642.322 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-22T12:40:42.322Z,1566477642.322 [NAL9602] Data Fault, FailCount= 1 2019-08-22T12:40:42.322Z,1566477642.322 [NAL9602](ERROR): Data Fault 2019-08-22T12:40:42.384Z,1566477642.384 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-22T12:40:42.719Z,1566477642.719 [NAL9602](INFO): Powering down 2019-08-22T12:40:43.625Z,1566477643.625 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-22T12:40:43.625Z,1566477643.625 [NAL9602] No Fault, FailCount= 1 2019-08-22T12:40:49.217Z,1566477649.217 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20190822T122950/Express0005.lzma 2019-08-22T12:40:50.026Z,1566477650.026 [DataOverHttps](INFO): Moved sent file to Logs/20190822T122950/Express0005.lzma.bak 2019-08-22T12:40:50.027Z,1566477650.027 [DataOverHttps](INFO): SBD MOMSN=11667408 2019-08-22T12:40:52.466Z,1566477652.466 [Default:CheckIn:Read_Iridium] Stopped 2019-08-22T12:40:52.466Z,1566477652.466 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-22T12:40:52.466Z,1566477652.466 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-22T12:41:07.794Z,1566477667.794 [DVL_micro](ERROR): only read 43 of 46 data items 2019-08-22T12:41:07.794Z,1566477667.794 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -306 292 367 -255 2 2 3 2 -898.2 730.0 26.4 2 -64.5 1155.6 26.4 2 -898 730 26 2 -64 1155 26 2 8.90 -1.58 312.3 -3.0 24.2 0.005 35.0 1489 100 2019-08-22T12:41:13.027Z,1566477673.027 [NAL9602](INFO): Powering up NAL9602 2019-08-22T12:41:23.960Z,1566477683.960 [NAL9602](INFO): NAL9602 initialized 2019-08-22T12:41:24.765Z,1566477684.765 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:27.229Z,1566477687.229 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:30.441Z,1566477690.441 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:33.253Z,1566477693.253 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:36.489Z,1566477696.489 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:39.316Z,1566477699.316 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:42.141Z,1566477702.141 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:44.157Z,1566477704.157 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:46.187Z,1566477706.187 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:49.425Z,1566477709.425 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:52.241Z,1566477712.241 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:55.477Z,1566477715.477 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:41:58.305Z,1566477718.305 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:01.529Z,1566477721.529 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:04.365Z,1566477724.365 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:05.602Z,1566477725.602 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-08-22T12:42:05.602Z,1566477725.602 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-22T12:42:05.639Z,1566477725.639 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-22T12:42:06.138Z,1566477726.138 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-22T12:42:06.138Z,1566477726.138 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-08-22T12:42:07.193Z,1566477727.193 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:09.313Z,1566477729.313 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:12.649Z,1566477732.649 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:15.341Z,1566477735.341 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:18.194Z,1566477738.194 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:21.437Z,1566477741.437 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:24.265Z,1566477744.265 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:25.462Z,1566477745.462 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-22T12:42:25.463Z,1566477745.463 [DVL_micro] Data Fault, FailCount= 1 2019-08-22T12:42:25.463Z,1566477745.463 [DVL_micro](ERROR): Data Fault 2019-08-22T12:42:25.532Z,1566477745.532 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-22T12:42:25.929Z,1566477745.929 [DVL_micro](INFO): uninitialize:Powering down 2019-08-22T12:42:26.756Z,1566477746.756 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-22T12:42:26.756Z,1566477746.756 [DVL_micro] No Fault, FailCount= 1 2019-08-22T12:42:27.081Z,1566477747.081 [DVL_micro](INFO): Initializing 2019-08-22T12:42:27.497Z,1566477747.497 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:30.329Z,1566477750.329 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:33.625Z,1566477753.625 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:36.389Z,1566477756.389 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:39.217Z,1566477759.217 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:42.441Z,1566477762.441 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:45.269Z,1566477765.269 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:48.505Z,1566477768.505 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:51.329Z,1566477771.329 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:54.573Z,1566477774.573 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:42:57.389Z,1566477777.389 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:00.221Z,1566477780.221 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:02.678Z,1566477782.678 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:05.469Z,1566477785.469 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:08.297Z,1566477788.297 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:11.545Z,1566477791.545 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:14.369Z,1566477794.369 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:17.609Z,1566477797.609 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:20.429Z,1566477800.429 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:23.261Z,1566477803.261 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:25.317Z,1566477805.317 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:27.305Z,1566477807.305 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:29.337Z,1566477809.337 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:32.561Z,1566477812.561 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:34.963Z,1566477814.963 [DVL_micro](ERROR): only read 44 of 46 data items 2019-08-22T12:43:34.964Z,1566477814.964 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -366 -406 2 2 3 2 -922.2 1237.2 42.0 2 291.8 1515.2 42.0 2 -922 1237 42 2 291 1515 42 2 8.94 -1.60 312.4 -3.0 24.3 0.005 35.05 2019-08-22T12:43:35.381Z,1566477815.381 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:38.617Z,1566477818.617 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:06.153Z,1566477786.153 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:09.364Z,1566477789.364 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:12.176Z,1566477792.176 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:15.004Z,1566477795.004 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:18.236Z,1566477798.236 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:21.064Z,1566477801.064 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:23.084Z,1566477803.084 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:25.556Z,1566477805.556 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:28.340Z,1566477808.340 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:31.572Z,1566477811.572 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:34.396Z,1566477814.396 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:37.628Z,1566477817.628 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:40.456Z,1566477820.456 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:43.288Z,1566477823.288 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:46.116Z,1566477826.116 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:48.156Z,1566477828.156 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:50.156Z,1566477830.156 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:53.389Z,1566477833.389 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:56.224Z,1566477836.224 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:43:59.460Z,1566477839.460 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:02.272Z,1566477842.272 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:05.100Z,1566477845.100 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:07.540Z,1566477847.540 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:10.352Z,1566477850.352 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:13.584Z,1566477853.584 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:16.416Z,1566477856.416 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:19.644Z,1566477859.644 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:22.500Z,1566477862.500 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:25.309Z,1566477865.309 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:28.544Z,1566477868.544 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:31.396Z,1566477871.396 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:34.204Z,1566477874.204 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:37.456Z,1566477877.456 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:40.256Z,1566477880.256 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:43.493Z,1566477883.493 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:46.368Z,1566477886.368 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:49.605Z,1566477889.605 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:52.376Z,1566477892.376 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:55.608Z,1566477895.608 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:44:58.449Z,1566477898.449 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:01.701Z,1566477901.701 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:04.508Z,1566477904.508 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:06.547Z,1566477906.547 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2019-08-22T12:45:06.547Z,1566477906.547 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-22T12:45:06.557Z,1566477906.557 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-22T12:45:06.970Z,1566477906.970 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-22T12:45:06.970Z,1566477906.970 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2019-08-22T12:45:07.732Z,1566477907.732 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:10.556Z,1566477910.556 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:13.388Z,1566477913.388 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:16.220Z,1566477916.220 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:18.236Z,1566477918.236 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:21.464Z,1566477921.464 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:24.296Z,1566477924.296 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:27.532Z,1566477927.532 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:30.358Z,1566477930.358 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:31.146Z,1566477931.146 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-22T12:45:31.146Z,1566477931.146 [DVL_micro] Data Fault, FailCount= 1 2019-08-22T12:45:31.146Z,1566477931.146 [DVL_micro](ERROR): Data Fault 2019-08-22T12:45:31.217Z,1566477931.217 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-22T12:45:31.628Z,1566477931.628 [DVL_micro](INFO): uninitialize:Powering down 2019-08-22T12:45:32.394Z,1566477932.394 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-22T12:45:32.394Z,1566477932.394 [DVL_micro] No Fault, FailCount= 1 2019-08-22T12:45:32.772Z,1566477932.772 [DVL_micro](INFO): Initializing 2019-08-22T12:45:33.583Z,1566477933.583 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:36.421Z,1566477936.421 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:39.648Z,1566477939.648 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:42.496Z,1566477942.496 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:45.308Z,1566477945.308 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:48.569Z,1566477948.569 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:51.388Z,1566477951.388 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:53.039Z,1566477953.039 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-22T12:45:53.039Z,1566477953.039 [Default:CheckIn:C.Wait] Stopped 2019-08-22T12:45:53.039Z,1566477953.039 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-22T12:45:53.040Z,1566477953.040 [Default:CheckIn:D] Running Loop=1 2019-08-22T12:45:53.402Z,1566477953.402 [Default:CheckIn:D] Stopped 2019-08-22T12:45:53.402Z,1566477953.402 [Default:CheckIn:E] Running Loop=1 2019-08-22T12:45:53.827Z,1566477953.827 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.517866 min 2019-08-22T12:45:53.827Z,1566477953.827 [Default:CheckIn:E] Stopped 2019-08-22T12:45:53.827Z,1566477953.827 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-22T12:45:53.827Z,1566477953.827 [Default:CheckIn] Stopped 2019-08-22T12:45:53.827Z,1566477953.827 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-22T12:45:53.827Z,1566477953.827 [Default:CheckIn](INFO): Running loop #2 2019-08-22T12:45:53.827Z,1566477953.827 [Default:CheckIn] Running Loop=2 2019-08-22T12:45:53.827Z,1566477953.827 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-22T12:45:53.827Z,1566477953.827 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-22T12:45:54.600Z,1566477954.600 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:45:57.424Z,1566477957.424 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:00.657Z,1566477960.657 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:03.500Z,1566477963.500 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:06.312Z,1566477966.312 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:08.372Z,1566477968.372 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:10.352Z,1566477970.352 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:13.584Z,1566477973.584 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:16.408Z,1566477976.408 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:19.640Z,1566477979.640 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:22.472Z,1566477982.472 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:25.716Z,1566477985.716 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:28.556Z,1566477988.556 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:31.776Z,1566477991.776 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:34.194Z,1566477994.194 [DVL_micro](ERROR): checksum mismatch: reported101 , calculated:112 2019-08-22T12:46:34.195Z,1566477994.195 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -343 466 430 -393 2 3 3 3 -10315 43.1 2 145.6 1535.4 43.1 2 -1031 1146 43 2 145 1535 43 2 8.98 -1.56 312.6 -3.0 24.3 0.005 35.0 1489 101 2019-08-22T12:46:34.604Z,1566477994.604 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:37.869Z,1566477997.869 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:40.680Z,1566478000.680 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:44.068Z,1566478004.068 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:46.756Z,1566478006.756 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:49.669Z,1566478009.669 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:52.465Z,1566478012.465 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:55.696Z,1566478015.696 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:46:58.524Z,1566478018.524 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:01.768Z,1566478021.768 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:04.581Z,1566478024.581 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:07.812Z,1566478027.812 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:10.644Z,1566478030.644 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:13.877Z,1566478033.877 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:16.712Z,1566478036.712 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:19.932Z,1566478039.932 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:22.801Z,1566478042.801 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:25.588Z,1566478045.588 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:28.845Z,1566478048.845 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:31.648Z,1566478051.648 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:34.480Z,1566478054.480 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:37.720Z,1566478057.720 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:40.540Z,1566478060.540 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:43.773Z,1566478063.773 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:46.612Z,1566478066.612 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:49.832Z,1566478069.832 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:52.660Z,1566478072.660 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:55.928Z,1566478075.928 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:47:58.736Z,1566478078.736 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:01.952Z,1566478081.952 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:04.812Z,1566478084.812 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:07.611Z,1566478087.611 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2019-08-22T12:48:07.611Z,1566478087.611 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-22T12:48:07.621Z,1566478087.621 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-22T12:48:08.024Z,1566478088.024 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:08.059Z,1566478088.059 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-22T12:48:08.059Z,1566478088.059 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2019-08-22T12:48:10.868Z,1566478090.868 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:14.068Z,1566478094.068 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:16.900Z,1566478096.900 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:19.724Z,1566478099.724 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:22.552Z,1566478102.552 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:25.792Z,1566478105.792 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:28.616Z,1566478108.616 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:31.861Z,1566478111.861 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:34.680Z,1566478114.680 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:37.102Z,1566478117.102 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-22T12:48:37.102Z,1566478117.102 [DVL_micro] Data Fault, FailCount= 1 2019-08-22T12:48:37.102Z,1566478117.102 [DVL_micro](ERROR): Data Fault 2019-08-22T12:48:37.139Z,1566478117.139 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-22T12:48:37.585Z,1566478117.585 [DVL_micro](INFO): uninitialize:Powering down 2019-08-22T12:48:37.916Z,1566478117.916 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:38.366Z,1566478118.366 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-22T12:48:38.366Z,1566478118.366 [DVL_micro] No Fault, FailCount= 1 2019-08-22T12:48:38.712Z,1566478118.712 [DVL_micro](INFO): Initializing 2019-08-22T12:48:40.736Z,1566478120.736 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:43.972Z,1566478123.972 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:46.816Z,1566478126.816 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:50.052Z,1566478130.052 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:52.897Z,1566478132.897 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:56.100Z,1566478136.100 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:48:58.125Z,1566478138.125 [DVL_micro](ERROR): only read 45 of 46 data items 2019-08-22T12:48:58.126Z,1566478138.126 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -303 -291 465 -466 2 3 3 2 -1025.0 233.6 -160.4 2 -521.8 912.6 -160.4 2 -1025 233 -160 2 -521 912 -160 2 8.95 -1.58 312.6 -3.0 24.4 0. 1489 66 2019-08-22T12:48:58.932Z,1566478138.932 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:02.164Z,1566478142.164 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:04.992Z,1566478144.992 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:07.844Z,1566478147.844 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:10.664Z,1566478150.664 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:13.880Z,1566478153.880 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:16.712Z,1566478156.712 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:19.936Z,1566478159.936 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:22.764Z,1566478162.764 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:26.000Z,1566478166.000 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:28.824Z,1566478168.824 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:32.060Z,1566478172.060 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:34.888Z,1566478174.888 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:38.120Z,1566478178.120 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:40.952Z,1566478180.952 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:44.184Z,1566478184.184 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:47.052Z,1566478187.052 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:49.880Z,1566478189.880 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:53.117Z,1566478193.117 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:55.904Z,1566478195.904 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:49:58.724Z,1566478198.724 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:01.968Z,1566478201.968 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:04.788Z,1566478204.788 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:08.024Z,1566478208.024 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:10.848Z,1566478210.848 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:14.080Z,1566478214.080 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:16.908Z,1566478216.908 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:20.140Z,1566478220.140 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:22.992Z,1566478222.992 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:26.209Z,1566478226.209 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:29.044Z,1566478229.044 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:32.264Z,1566478232.264 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:35.128Z,1566478235.128 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:37.924Z,1566478237.924 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:40.752Z,1566478240.752 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:43.980Z,1566478243.980 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:46.857Z,1566478246.857 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:50.064Z,1566478250.064 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:52.888Z,1566478252.888 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:54.146Z,1566478254.146 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-08-22T12:45:53.8Z 2019-08-22T12:50:54.146Z,1566478254.146 [Default:CheckIn:Read_GPS] Stopped 2019-08-22T12:50:54.146Z,1566478254.146 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-08-22T12:50:56.324Z,1566478256.324 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:50:59.156Z,1566478259.156 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:51:01.961Z,1566478261.961 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:51:04.513Z,1566478264.513 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190822T122950/Courier0007.lzma 2019-08-22T12:51:04.796Z,1566478264.796 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:51:05.318Z,1566478265.318 [DataOverHttps](INFO): Moved sent file to Logs/20190822T122950/Courier0007.lzma.bak 2019-08-22T12:51:05.318Z,1566478265.318 [DataOverHttps](INFO): SBD MOMSN=11667438 2019-08-22T12:51:06.812Z,1566478266.812 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:51:08.853Z,1566478268.853 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2019-08-22T12:51:08.853Z,1566478268.853 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-22T12:51:08.876Z,1566478268.876 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-22T12:51:09.330Z,1566478269.330 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-22T12:51:09.330Z,1566478269.330 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2019-08-22T12:51:10.048Z,1566478270.048 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:51:12.872Z,1566478272.872 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:51:16.104Z,1566478276.104 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:51:18.932Z,1566478278.932 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:51:22.165Z,1566478282.165 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:51:24.979Z,1566478284.979 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-08-22T12:51:24.979Z,1566478284.979 [NAL9602] Data Fault, FailCount= 2 2019-08-22T12:51:24.979Z,1566478284.979 [NAL9602](ERROR): Data Fault 2019-08-22T12:51:25.079Z,1566478285.079 [CBIT](ERROR): Data Fault in component: NAL9602 2019-08-22T12:51:25.378Z,1566478285.378 [NAL9602](INFO): Powering down 2019-08-22T12:51:25.948Z,1566478285.948 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20190822T122950/Express0008.lzma 2019-08-22T12:51:26.268Z,1566478286.268 [CBIT](INFO): Clearing failed state for component NAL9602 2019-08-22T12:51:26.268Z,1566478286.268 [NAL9602] No Fault, FailCount= 2 2019-08-22T12:51:26.755Z,1566478286.755 [DataOverHttps](INFO): Moved sent file to Logs/20190822T122950/Express0008.lzma.bak 2019-08-22T12:51:26.755Z,1566478286.755 [DataOverHttps](INFO): SBD MOMSN=11667440 2019-08-22T12:51:29.046Z,1566478289.046 [Default:CheckIn:Read_Iridium] Stopped 2019-08-22T12:51:29.046Z,1566478289.046 [Default:CheckIn:C.Wait] Running Loop=1 2019-08-22T12:51:29.046Z,1566478289.046 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-08-22T12:51:42.763Z,1566478302.763 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-22T12:51:42.763Z,1566478302.763 [DVL_micro] Data Fault, FailCount= 1 2019-08-22T12:51:42.763Z,1566478302.763 [DVL_micro](ERROR): Data Fault 2019-08-22T12:51:42.889Z,1566478302.889 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-22T12:51:43.240Z,1566478303.240 [DVL_micro](INFO): uninitialize:Powering down 2019-08-22T12:51:44.056Z,1566478304.056 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-22T12:51:44.060Z,1566478304.060 [DVL_micro] No Fault, FailCount= 1 2019-08-22T12:51:44.371Z,1566478304.371 [DVL_micro](INFO): Initializing 2019-08-22T12:51:55.679Z,1566478315.679 [NAL9602](INFO): Powering up NAL9602 2019-08-22T12:52:06.591Z,1566478326.591 [NAL9602](INFO): NAL9602 initialized 2019-08-22T12:52:07.416Z,1566478327.416 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:09.840Z,1566478329.840 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:13.072Z,1566478333.072 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:15.900Z,1566478335.900 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:19.132Z,1566478339.132 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:21.961Z,1566478341.961 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:24.793Z,1566478344.793 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:28.021Z,1566478348.021 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:30.848Z,1566478350.848 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:34.084Z,1566478354.084 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:36.917Z,1566478356.917 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:40.136Z,1566478360.136 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:42.964Z,1566478362.964 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:45.885Z,1566478365.885 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:47.821Z,1566478367.821 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:49.832Z,1566478369.832 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:52.306Z,1566478372.306 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:55.109Z,1566478375.109 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:52:58.324Z,1566478378.324 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:01.149Z,1566478381.149 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:03.976Z,1566478383.976 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:07.216Z,1566478387.216 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:10.045Z,1566478390.045 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:13.269Z,1566478393.269 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:16.096Z,1566478396.096 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:18.925Z,1566478398.925 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:21.372Z,1566478401.372 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:24.180Z,1566478404.180 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:27.024Z,1566478407.024 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:30.257Z,1566478410.257 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:33.092Z,1566478413.092 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:36.304Z,1566478416.304 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:39.124Z,1566478419.124 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:42.357Z,1566478422.357 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:45.188Z,1566478425.188 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:48.013Z,1566478428.013 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:50.449Z,1566478430.449 [DVL_micro](ERROR): only read 43 of 46 data items 2019-08-22T12:53:50.450Z,1566478430.450 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 -281 -172 431 -321 2 2 3 2 -950.3 198.9 -92.5 2 -498.2 833.3 -92.5 2 -950 198 -92 2 -498 833 -92 2 8.98 -1.57 312.7 -3.0 24.6 0.005 35.0 1489 65 2019-08-22T12:53:50.464Z,1566478430.464 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:53.280Z,1566478433.280 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:56.504Z,1566478436.504 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:53:59.340Z,1566478439.340 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:02.564Z,1566478442.564 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:05.389Z,1566478445.389 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:08.217Z,1566478448.217 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:09.881Z,1566478449.881 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2019-08-22T12:54:09.881Z,1566478449.881 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-22T12:54:09.904Z,1566478449.904 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-22T12:54:10.294Z,1566478450.294 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-22T12:54:10.294Z,1566478450.294 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2019-08-22T12:54:11.040Z,1566478451.040 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:13.112Z,1566478453.112 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:15.080Z,1566478455.080 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:17.100Z,1566478457.100 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:20.333Z,1566478460.333 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:23.168Z,1566478463.168 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:26.401Z,1566478466.401 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:29.216Z,1566478469.216 [DVL_micro](ERROR): only read 15 of 46 data items 2019-08-22T12:54:29.216Z,1566478469.216 [DVL_micro](ERROR): Failed to parse:$#NQ.RES 0X0000 0 0 0 0 0 0 0 0 0 0 0 0 -3189 71 2019-08-22T12:54:29.229Z,1566478469.229 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:32.468Z,1566478472.468 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:35.284Z,1566478475.284 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:38.517Z,1566478478.517 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:41.340Z,1566478481.340 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:44.584Z,1566478484.584 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:47.400Z,1566478487.400 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:48.622Z,1566478488.622 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-22T12:54:48.622Z,1566478488.622 [DVL_micro] Data Fault, FailCount= 1 2019-08-22T12:54:48.622Z,1566478488.622 [DVL_micro](ERROR): Data Fault 2019-08-22T12:54:48.739Z,1566478488.739 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-22T12:54:49.089Z,1566478489.089 [DVL_micro](INFO): uninitialize:Powering down 2019-08-22T12:54:49.956Z,1566478489.956 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-22T12:54:49.956Z,1566478489.956 [DVL_micro] No Fault, FailCount= 1 2019-08-22T12:54:50.219Z,1566478490.219 [DVL_micro](INFO): Initializing 2019-08-22T12:54:50.648Z,1566478490.648 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:53.472Z,1566478493.472 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:56.312Z,1566478496.312 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:54:59.128Z,1566478499.128 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:02.360Z,1566478502.360 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:05.192Z,1566478505.192 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:08.424Z,1566478508.424 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:11.248Z,1566478511.248 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:14.480Z,1566478514.480 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:17.308Z,1566478517.308 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:20.540Z,1566478520.540 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:23.380Z,1566478523.380 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:26.604Z,1566478526.604 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:29.432Z,1566478529.432 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:32.660Z,1566478532.660 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:35.508Z,1566478535.508 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:38.772Z,1566478538.772 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:41.548Z,1566478541.548 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:44.385Z,1566478544.385 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:47.209Z,1566478547.209 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:49.245Z,1566478549.245 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:52.496Z,1566478552.496 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:55.284Z,1566478555.284 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:55:58.544Z,1566478558.544 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:01.368Z,1566478561.368 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:04.624Z,1566478564.624 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:07.420Z,1566478567.420 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:10.241Z,1566478570.241 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:12.281Z,1566478572.281 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:14.717Z,1566478574.717 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:17.528Z,1566478577.528 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:20.768Z,1566478580.768 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:23.568Z,1566478583.568 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:26.433Z,1566478586.433 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:29.649Z,1566478589.649 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:29.678Z,1566478589.678 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2019-08-22T12:56:29.678Z,1566478589.678 [Default:CheckIn:C.Wait] Stopped 2019-08-22T12:56:29.679Z,1566478589.679 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-08-22T12:56:29.679Z,1566478589.679 [Default:CheckIn:D] Running Loop=1 2019-08-22T12:56:30.155Z,1566478590.155 [Default:CheckIn:D] Stopped 2019-08-22T12:56:30.155Z,1566478590.155 [Default:CheckIn:E] Running Loop=1 2019-08-22T12:56:30.567Z,1566478590.567 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.130408 min 2019-08-22T12:56:30.567Z,1566478590.567 [Default:CheckIn:E] Stopped 2019-08-22T12:56:30.567Z,1566478590.567 [Default:CheckIn](INFO): Completed Default:CheckIn 2019-08-22T12:56:30.567Z,1566478590.567 [Default:CheckIn] Stopped 2019-08-22T12:56:30.567Z,1566478590.567 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-22T12:56:30.567Z,1566478590.567 [Default:CheckIn](INFO): Running loop #3 2019-08-22T12:56:30.568Z,1566478590.568 [Default:CheckIn] Running Loop=3 2019-08-22T12:56:30.568Z,1566478590.568 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-08-22T12:56:30.568Z,1566478590.568 [Default:CheckIn:Read_GPS] Running Loop=1 2019-08-22T12:56:32.472Z,1566478592.472 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:35.304Z,1566478595.304 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:38.540Z,1566478598.540 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:41.360Z,1566478601.360 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:44.651Z,1566478604.651 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:47.432Z,1566478607.432 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:50.668Z,1566478610.668 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:53.496Z,1566478613.496 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:56.732Z,1566478616.732 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:56:59.584Z,1566478619.584 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:02.816Z,1566478622.816 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:05.620Z,1566478625.620 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:08.852Z,1566478628.852 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:10.881Z,1566478630.881 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2019-08-22T12:57:10.881Z,1566478630.881 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-08-22T12:57:10.891Z,1566478630.891 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-08-22T12:57:11.297Z,1566478631.297 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-08-22T12:57:11.297Z,1566478631.297 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2019-08-22T12:57:11.677Z,1566478631.677 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:14.904Z,1566478634.904 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:17.332Z,1566478637.332 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:19.356Z,1566478639.356 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:21.372Z,1566478641.372 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:24.604Z,1566478644.604 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:27.432Z,1566478647.432 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:30.660Z,1566478650.660 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:33.492Z,1566478653.492 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:36.724Z,1566478656.724 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:39.568Z,1566478659.568 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:42.392Z,1566478662.392 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:44.828Z,1566478664.828 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:47.632Z,1566478667.632 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:50.864Z,1566478670.864 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:53.692Z,1566478673.692 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:54.486Z,1566478674.486 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-08-22T12:57:54.486Z,1566478674.486 [DVL_micro] Data Fault, FailCount= 1 2019-08-22T12:57:54.486Z,1566478674.486 [DVL_micro](ERROR): Data Fault 2019-08-22T12:57:54.534Z,1566478674.534 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-08-22T12:57:54.961Z,1566478674.961 [DVL_micro](INFO): uninitialize:Powering down 2019-08-22T12:57:55.731Z,1566478675.731 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-08-22T12:57:55.731Z,1566478675.731 [DVL_micro] No Fault, FailCount= 1 2019-08-22T12:57:56.116Z,1566478676.116 [DVL_micro](INFO): Initializing 2019-08-22T12:57:56.916Z,1566478676.916 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:57:59.754Z,1566478679.754 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:02.596Z,1566478682.596 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:05.408Z,1566478685.408 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:07.428Z,1566478687.428 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:09.488Z,1566478689.488 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:12.676Z,1566478692.676 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:15.521Z,1566478695.521 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:18.752Z,1566478698.752 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:21.568Z,1566478701.568 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:24.796Z,1566478704.796 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:27.624Z,1566478707.624 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:30.456Z,1566478710.456 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:32.880Z,1566478712.880 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:35.708Z,1566478715.708 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:38.952Z,1566478718.952 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:41.772Z,1566478721.772 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:45.000Z,1566478725.000 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:47.885Z,1566478727.885 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:50.660Z,1566478730.660 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:53.488Z,1566478733.488 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:55.512Z,1566478735.512 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:58:58.740Z,1566478738.740 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:59:01.568Z,1566478741.568 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:59:04.800Z,1566478744.800 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:59:07.628Z,1566478747.628 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:59:10.856Z,1566478750.856 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:59:13.700Z,1566478753.700 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:59:16.928Z,1566478756.928 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:59:19.748Z,1566478759.748 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:59:22.570Z,1566478762.570 [CommandLine](IMPORTANT): got command restart system 2019-08-22T12:59:22.576Z,1566478762.576 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:59:24.640Z,1566478764.640 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2019-08-22T12:59:24.641Z,1566478764.641 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T12:59:24.641Z,1566478764.641 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:24.664Z,1566478764.664 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-08-22T12:59:24.665Z,1566478764.665 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:24.665Z,1566478764.665 [CommandLine](INFO): Join timeout helper Thread ID is 1100 2019-08-22T12:59:24.666Z,1566478764.666 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-08-22T12:59:24.666Z,1566478764.666 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:24.667Z,1566478764.667 [NavChartDb](INFO): Join timeout helper Thread ID is 1101 2019-08-22T12:59:25.008Z,1566478765.008 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T12:59:25.009Z,1566478765.009 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:25.024Z,1566478765.024 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-08-22T12:59:25.025Z,1566478765.025 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:25.025Z,1566478765.025 [Radio_Surface](INFO): Join timeout helper Thread ID is 1102 2019-08-22T12:59:25.136Z,1566478765.136 [Radio_Surface](INFO): Powering down 2019-08-22T12:59:25.137Z,1566478765.137 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T12:59:25.138Z,1566478765.138 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:25.140Z,1566478765.140 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-08-22T12:59:25.140Z,1566478765.140 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:25.141Z,1566478765.141 [DataOverHttps](INFO): Join timeout helper Thread ID is 1103 2019-08-22T12:59:25.308Z,1566478765.308 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T12:59:25.309Z,1566478765.309 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:25.320Z,1566478765.320 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-08-22T12:59:25.320Z,1566478765.320 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:25.321Z,1566478765.321 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1104 2019-08-22T12:59:25.369Z,1566478765.369 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T12:59:25.369Z,1566478765.369 [WetLabsBB2FL](INFO): Powering down 2019-08-22T12:59:25.370Z,1566478765.370 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:25.382Z,1566478765.382 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-08-22T12:59:25.382Z,1566478765.382 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:25.382Z,1566478765.382 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1105 2019-08-22T12:59:25.804Z,1566478765.804 [NAL9602](DEBUG): Fix Requested 2019-08-22T12:59:25.972Z,1566478765.972 [CTD_Seabird](INFO): Powering down 2019-08-22T12:59:25.984Z,1566478765.984 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T12:59:25.984Z,1566478765.984 [CTD_Seabird](INFO): Powering down 2019-08-22T12:59:25.996Z,1566478765.996 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.009Z,1566478766.009 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-08-22T12:59:26.009Z,1566478766.009 [logger ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.010Z,1566478766.010 [logger](INFO): Join timeout helper Thread ID is 1106 2019-08-22T12:59:26.036Z,1566478766.036 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T12:59:26.037Z,1566478766.037 [logger ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.049Z,1566478766.049 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-08-22T12:59:26.049Z,1566478766.049 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.049Z,1566478766.049 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-08-22T12:59:26.049Z,1566478766.049 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.050Z,1566478766.050 [controlThread](INFO): Join timeout helper Thread ID is 1107 2019-08-22T12:59:26.180Z,1566478766.180 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-08-22T12:59:26.181Z,1566478766.181 [controlThread](DEBUG): Uninitializing ControlThread 2019-08-22T12:59:26.181Z,1566478766.181 [Aanderaa_O2](INFO): Powering down 2019-08-22T12:59:26.204Z,1566478766.204 [AHRS_M2](INFO): Powering down 2019-08-22T12:59:26.348Z,1566478766.348 [DVL_micro](INFO): uninitialize:Powering down 2019-08-22T12:59:26.349Z,1566478766.349 [NAL9602](INFO): Powering down 2019-08-22T12:59:26.351Z,1566478766.351 [DAT](INFO): Powering down 2019-08-22T12:59:26.469Z,1566478766.469 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-08-22T12:59:26.470Z,1566478766.470 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-08-22T12:59:26.471Z,1566478766.471 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-08-22T12:59:26.471Z,1566478766.471 [MissionManager](INFO): Uninitializing Mission Default 2019-08-22T12:59:26.471Z,1566478766.471 [Default] Stopped 2019-08-22T12:59:26.471Z,1566478766.471 [Default](DEBUG): Aggregate::uninitialize Default 2019-08-22T12:59:26.471Z,1566478766.471 [Default:B.GoToSurface] Stopped 2019-08-22T12:59:26.471Z,1566478766.471 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-08-22T12:59:26.472Z,1566478766.472 [Default:CheckIn] Stopped 2019-08-22T12:59:26.472Z,1566478766.472 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-08-22T12:59:26.472Z,1566478766.472 [Default:CheckIn:Read_GPS] Stopped 2019-08-22T12:59:26.475Z,1566478766.475 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-08-22T12:59:26.475Z,1566478766.475 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-08-22T12:59:26.475Z,1566478766.475 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-08-22T12:59:26.476Z,1566478766.476 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-08-22T12:59:26.476Z,1566478766.476 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-08-22T12:59:26.477Z,1566478766.477 [BuoyancyServo](INFO): Powering down 2019-08-22T12:59:26.489Z,1566478766.489 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-08-22T12:59:26.489Z,1566478766.489 [ElevatorServo](INFO): Powering down 2019-08-22T12:59:26.490Z,1566478766.490 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-08-22T12:59:26.490Z,1566478766.490 [MassServo](INFO): Powering down 2019-08-22T12:59:26.491Z,1566478766.491 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-08-22T12:59:26.491Z,1566478766.491 [RudderServo](INFO): Powering down 2019-08-22T12:59:26.491Z,1566478766.491 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-08-22T12:59:26.491Z,1566478766.491 [ThrusterServo](INFO): Powering down 2019-08-22T12:59:26.493Z,1566478766.493 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-08-22T12:59:26.493Z,1566478766.493 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-08-22T12:59:26.493Z,1566478766.493 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-08-22T12:59:26.493Z,1566478766.493 [CBIT](DEBUG): Powering off loads. 2019-08-22T12:59:26.504Z,1566478766.504 [CBIT](DEBUG): Disabling WDT. 2019-08-22T12:59:26.516Z,1566478766.516 [CBIT](DEBUG): Opening all GF detection circuits. 2019-08-22T12:59:26.517Z,1566478766.517 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.563Z,1566478766.563 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.569Z,1566478766.569 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.647Z,1566478766.647 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.656Z,1566478766.656 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.708Z,1566478766.708 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-08-22T12:59:26.771Z,1566478766.771 [logger ThreadHandler](INFO): Thread cancelled.