2019-10-17T17:50:55.237Z,1571334655.237 [Supervisor](DEBUG): Initializing supervisor. 2019-10-17T17:50:55.240Z,1571334655.240 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2019-10-17T17:50:55.240Z,1571334655.240 [SyncHandler](INFO): Protected caller Thread ID is 2004 2019-10-17T17:50:55.241Z,1571334655.241 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2019-10-17T17:50:55.242Z,1571334655.242 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2019-10-17T17:50:55.242Z,1571334655.242 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2005 2019-10-17T17:50:55.244Z,1571334655.244 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2019-10-17T17:50:55.255Z,1571334655.255 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2019-10-17T17:50:55.256Z,1571334655.256 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2019-10-17T17:50:55.257Z,1571334655.257 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2006 2019-10-17T17:50:55.257Z,1571334655.257 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2019-10-17T17:50:55.258Z,1571334655.258 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2019-10-17T17:50:55.259Z,1571334655.259 [logger ThreadHandler](INFO): Protected caller Thread ID is 2007 2019-10-17T17:50:55.261Z,1571334655.261 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2019-10-17T17:50:55.261Z,1571334655.261 [Supervisor](INFO): Looking for Config files in directory: Config/ 2019-10-17T17:50:55.263Z,1571334655.263 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2019-10-17T17:50:55.459Z,1571334655.459 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2019-10-17T17:50:55.460Z,1571334655.460 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2019-10-17T17:50:55.538Z,1571334655.538 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2019-10-17T17:50:55.957Z,1571334655.957 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2019-10-17T17:50:55.958Z,1571334655.958 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2019-10-17T17:50:56.273Z,1571334656.273 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2019-10-17T17:50:56.273Z,1571334656.273 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2019-10-17T17:50:56.368Z,1571334656.368 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2019-10-17T17:50:56.369Z,1571334656.369 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2019-10-17T17:50:56.658Z,1571334656.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2019-10-17T17:50:56.658Z,1571334656.658 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2019-10-17T17:50:56.849Z,1571334656.849 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2019-10-17T17:50:56.849Z,1571334656.849 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2019-10-17T17:50:57.291Z,1571334657.291 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2019-10-17T17:50:57.292Z,1571334657.292 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2019-10-17T17:50:57.396Z,1571334657.396 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2019-10-17T17:50:57.396Z,1571334657.396 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2019-10-17T17:50:57.496Z,1571334657.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2019-10-17T17:50:57.496Z,1571334657.496 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2019-10-17T17:50:58.150Z,1571334658.150 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2019-10-17T17:50:58.150Z,1571334658.150 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2019-10-17T17:50:58.532Z,1571334658.532 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2019-10-17T17:50:58.533Z,1571334658.533 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2019-10-17T17:50:58.720Z,1571334658.720 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2019-10-17T17:50:58.720Z,1571334658.720 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2019-10-17T17:50:58.862Z,1571334658.862 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2019-10-17T17:50:58.862Z,1571334658.862 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2019-10-17T17:50:59.007Z,1571334659.007 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2019-10-17T17:50:59.009Z,1571334659.009 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/ 2019-10-17T17:50:59.010Z,1571334659.010 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg 2019-10-17T17:50:59.100Z,1571334659.100 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg 2019-10-17T17:50:59.185Z,1571334659.185 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg 2019-10-17T17:50:59.286Z,1571334659.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg 2019-10-17T17:50:59.367Z,1571334659.367 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg 2019-10-17T17:50:59.461Z,1571334659.461 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg 2019-10-17T17:50:59.559Z,1571334659.559 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg 2019-10-17T17:50:59.763Z,1571334659.763 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg 2019-10-17T17:50:59.839Z,1571334659.839 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg 2019-10-17T17:51:00.016Z,1571334660.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg 2019-10-17T17:51:00.668Z,1571334660.668 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg 2019-10-17T17:51:00.993Z,1571334660.993 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg 2019-10-17T17:51:01.276Z,1571334661.276 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2019-10-17T17:51:01.277Z,1571334661.277 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/ 2019-10-17T17:51:01.277Z,1571334661.277 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg 2019-10-17T17:51:01.279Z,1571334661.279 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2019-10-17T17:51:01.345Z,1571334661.345 [VerticalControl](DEBUG): Construct VerticalControl. 2019-10-17T17:51:01.455Z,1571334661.455 [VerticalControl] Loaded 2019-10-17T17:51:01.455Z,1571334661.455 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2019-10-17T17:51:01.456Z,1571334661.456 [HorizontalControl](DEBUG): Construct HorizontalControl. 2019-10-17T17:51:01.523Z,1571334661.523 [HorizontalControl] Loaded 2019-10-17T17:51:01.523Z,1571334661.523 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2019-10-17T17:51:01.524Z,1571334661.524 [SpeedControl](DEBUG): Construct SpeedControl. 2019-10-17T17:51:01.529Z,1571334661.529 [SpeedControl] Loaded 2019-10-17T17:51:01.530Z,1571334661.530 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2019-10-17T17:51:01.530Z,1571334661.530 [LoopControl](DEBUG): Construct LoopControl. 2019-10-17T17:51:01.531Z,1571334661.531 [LoopControl] Loaded 2019-10-17T17:51:01.531Z,1571334661.531 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2019-10-17T17:51:01.532Z,1571334661.532 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2019-10-17T17:51:01.532Z,1571334661.532 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2019-10-17T17:51:01.545Z,1571334661.545 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2019-10-17T17:51:01.546Z,1571334661.546 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2019-10-17T17:51:01.642Z,1571334661.642 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2019-10-17T17:51:01.642Z,1571334661.642 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2019-10-17T17:51:01.742Z,1571334661.742 [BuoyancyServo] Loaded 2019-10-17T17:51:01.742Z,1571334661.742 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2019-10-17T17:51:01.753Z,1571334661.753 [ElevatorServo] Loaded 2019-10-17T17:51:01.753Z,1571334661.753 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2019-10-17T17:51:01.764Z,1571334661.764 [MassServo] Loaded 2019-10-17T17:51:01.764Z,1571334661.764 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2019-10-17T17:51:01.775Z,1571334661.775 [RudderServo] Loaded 2019-10-17T17:51:01.775Z,1571334661.775 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2019-10-17T17:51:01.786Z,1571334661.786 [ThrusterServo] Loaded 2019-10-17T17:51:01.786Z,1571334661.786 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2019-10-17T17:51:01.787Z,1571334661.787 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2019-10-17T17:51:01.787Z,1571334661.787 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2019-10-17T17:51:01.893Z,1571334661.893 [DeadReckonUsingMultipleVelocitySources] Loaded 2019-10-17T17:51:01.893Z,1571334661.893 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2019-10-17T17:51:01.913Z,1571334661.913 [NavChart] Loaded 2019-10-17T17:51:01.914Z,1571334661.914 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2019-10-17T17:51:01.917Z,1571334661.917 [UniversalFixResidualReporter] Loaded 2019-10-17T17:51:01.917Z,1571334661.917 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2019-10-17T17:51:01.918Z,1571334661.918 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2019-10-17T17:51:01.918Z,1571334661.918 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2019-10-17T17:51:01.988Z,1571334661.988 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2019-10-17T17:51:01.989Z,1571334661.989 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2019-10-17T17:51:02.242Z,1571334662.242 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2019-10-17T17:51:02.247Z,1571334662.247 [AHRS_M2](INFO): created writer for : platform_orientation 2019-10-17T17:51:02.249Z,1571334662.249 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2019-10-17T17:51:02.254Z,1571334662.254 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2019-10-17T17:51:02.254Z,1571334662.254 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2019-10-17T17:51:02.259Z,1571334662.259 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2019-10-17T17:51:02.260Z,1571334662.260 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2019-10-17T17:51:02.265Z,1571334662.265 [AHRS_M2](INFO): created writer for : platform_roll_angle 2019-10-17T17:51:02.334Z,1571334662.334 [AHRS_M2] Loaded 2019-10-17T17:51:02.335Z,1571334662.335 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2019-10-17T17:51:02.410Z,1571334662.410 [DataOverHttps] Loaded 2019-10-17T17:51:02.410Z,1571334662.410 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2019-10-17T17:51:02.411Z,1571334662.411 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087D4E0 2019-10-17T17:51:02.412Z,1571334662.412 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2090 2019-10-17T17:51:02.425Z,1571334662.425 [Depth_Keller] Loaded 2019-10-17T17:51:02.425Z,1571334662.425 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2019-10-17T17:51:02.430Z,1571334662.430 [DropWeight] Loaded 2019-10-17T17:51:02.430Z,1571334662.430 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2019-10-17T17:51:02.556Z,1571334662.556 [DVL_micro] Loaded 2019-10-17T17:51:02.556Z,1571334662.556 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2019-10-17T17:51:02.651Z,1571334662.651 [NAL9602] Loaded 2019-10-17T17:51:02.651Z,1571334662.651 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2019-10-17T17:51:02.667Z,1571334662.667 [Onboard] Loaded 2019-10-17T17:51:02.667Z,1571334662.667 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2019-10-17T17:51:02.671Z,1571334662.671 [Radio_Surface] Loaded 2019-10-17T17:51:02.671Z,1571334662.671 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2019-10-17T17:51:02.672Z,1571334662.672 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AD4E0 2019-10-17T17:51:02.672Z,1571334662.672 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2091 2019-10-17T17:51:02.796Z,1571334662.796 [DAT] Loaded 2019-10-17T17:51:02.796Z,1571334662.796 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2019-10-17T17:51:04.295Z,1571334664.295 [BPC1] Loaded 2019-10-17T17:51:04.296Z,1571334664.296 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2019-10-17T17:51:04.296Z,1571334664.296 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2019-10-17T17:51:04.297Z,1571334664.297 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2019-10-17T17:51:04.336Z,1571334664.336 [DepthRateCalculator] Loaded 2019-10-17T17:51:04.336Z,1571334664.336 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2019-10-17T17:51:04.342Z,1571334664.342 [PitchRateCalculator] Loaded 2019-10-17T17:51:04.342Z,1571334664.342 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2019-10-17T17:51:04.353Z,1571334664.353 [SpeedCalculator] Loaded 2019-10-17T17:51:04.354Z,1571334664.354 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2019-10-17T17:51:04.374Z,1571334664.374 [TempGradientCalculator] Loaded 2019-10-17T17:51:04.374Z,1571334664.374 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2019-10-17T17:51:04.379Z,1571334664.379 [YawRateCalculator] Loaded 2019-10-17T17:51:04.380Z,1571334664.380 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2019-10-17T17:51:04.409Z,1571334664.409 [ElevatorOffsetCalculator] Loaded 2019-10-17T17:51:04.409Z,1571334664.409 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2019-10-17T17:51:04.409Z,1571334664.409 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2019-10-17T17:51:04.410Z,1571334664.410 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2019-10-17T17:51:04.591Z,1571334664.591 [Aanderaa_O2] Loaded 2019-10-17T17:51:04.591Z,1571334664.591 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread. 2019-10-17T17:51:04.674Z,1571334664.674 [CTD_NeilBrown] Loaded 2019-10-17T17:51:04.675Z,1571334664.675 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread. 2019-10-17T17:51:04.676Z,1571334664.676 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409B04E0 2019-10-17T17:51:04.676Z,1571334664.676 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 2092 2019-10-17T17:51:04.685Z,1571334664.685 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2019-10-17T17:51:04.690Z,1571334664.690 [CTD_Seabird](INFO): created writer for : sea_water_density 2019-10-17T17:51:04.690Z,1571334664.690 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2019-10-17T17:51:04.695Z,1571334664.695 [CTD_Seabird](INFO): created writer for : depth 2019-10-17T17:51:04.696Z,1571334664.696 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2019-10-17T17:51:04.700Z,1571334664.700 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2019-10-17T17:51:04.701Z,1571334664.701 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2019-10-17T17:51:04.706Z,1571334664.706 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2019-10-17T17:51:04.706Z,1571334664.706 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2019-10-17T17:51:04.712Z,1571334664.712 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2019-10-17T17:51:04.712Z,1571334664.712 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2019-10-17T17:51:04.717Z,1571334664.717 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2019-10-17T17:51:04.718Z,1571334664.718 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2019-10-17T17:51:04.723Z,1571334664.723 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2019-10-17T17:51:04.750Z,1571334664.750 [CTD_Seabird] Loaded 2019-10-17T17:51:04.750Z,1571334664.750 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2019-10-17T17:51:04.751Z,1571334664.751 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409E04E0 2019-10-17T17:51:04.751Z,1571334664.751 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2093 2019-10-17T17:51:04.766Z,1571334664.766 [PAR_Licor] Loaded 2019-10-17T17:51:04.766Z,1571334664.766 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2019-10-17T17:51:04.813Z,1571334664.813 [WetLabsBB2FL] Loaded 2019-10-17T17:51:04.814Z,1571334664.814 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2019-10-17T17:51:04.815Z,1571334664.815 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A104E0 2019-10-17T17:51:04.815Z,1571334664.815 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2094 2019-10-17T17:51:04.816Z,1571334664.816 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2019-10-17T17:51:04.816Z,1571334664.816 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2019-10-17T17:51:04.848Z,1571334664.848 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2019-10-17T17:51:04.848Z,1571334664.848 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2019-10-17T17:51:05.132Z,1571334665.132 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2019-10-17T17:51:05.132Z,1571334665.132 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2019-10-17T17:51:05.400Z,1571334665.400 [SBIT](DEBUG): Construct Startup Built In Test. 2019-10-17T17:51:05.411Z,1571334665.411 [SBIT] Loaded 2019-10-17T17:51:05.411Z,1571334665.411 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2019-10-17T17:51:05.412Z,1571334665.412 [IBIT](DEBUG): Construct Initiated Built In Test. 2019-10-17T17:51:05.423Z,1571334665.423 [IBIT] Loaded 2019-10-17T17:51:05.423Z,1571334665.423 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2019-10-17T17:51:05.426Z,1571334665.426 [CBIT](DEBUG): Construct Continuous Built In Test. 2019-10-17T17:51:05.563Z,1571334665.563 [CBIT] Loaded 2019-10-17T17:51:05.564Z,1571334665.564 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2019-10-17T17:51:05.564Z,1571334665.564 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2019-10-17T17:51:05.568Z,1571334665.568 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2019-10-17T17:51:05.569Z,1571334665.569 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2019-10-17T17:51:05.575Z,1571334665.575 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2019-10-17T17:51:05.576Z,1571334665.576 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0 2019-10-17T17:51:05.577Z,1571334665.577 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2095 2019-10-17T17:51:05.581Z,1571334665.581 [Supervisor](INFO): Main Thread ID is 2003 2019-10-17T17:51:05.581Z,1571334665.581 [Supervisor](DEBUG): Running supervisor. 2019-10-17T17:51:05.582Z,1571334665.582 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2096 2019-10-17T17:51:05.585Z,1571334665.585 [controlThread ThreadHandler](INFO): Handler Thread ID is 2097 2019-10-17T17:51:05.585Z,1571334665.585 [controlThread](DEBUG): Initializing ControlThread 2019-10-17T17:51:05.586Z,1571334665.586 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2019-10-17T17:51:05.588Z,1571334665.588 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2019-10-17T17:51:05.588Z,1571334665.588 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2019-10-17T17:51:05.589Z,1571334665.589 [LoopControl](DEBUG): Initialize LoopControlComponent. 2019-10-17T17:51:05.591Z,1571334665.591 [NavChart](DEBUG): Initialize NavChart Navigation. 2019-10-17T17:51:05.591Z,1571334665.591 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2019-10-17T17:51:05.595Z,1571334665.595 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2019-10-17T17:51:05.596Z,1571334665.596 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2019-10-17T17:51:05.596Z,1571334665.596 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2019-10-17T17:51:05.596Z,1571334665.596 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2019-10-17T17:51:05.597Z,1571334665.597 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2019-10-17T17:51:05.597Z,1571334665.597 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2019-10-17T17:51:05.601Z,1571334665.601 [SBIT](INFO): Initialize SBIT Component. 2019-10-17T17:51:05.602Z,1571334665.602 [SBIT](IMPORTANT): git: 2019-09-10 2019-10-17T17:51:05.602Z,1571334665.602 [SBIT](INFO): git hash: e950883795b57abbf97d89589ea0268241928c93 2019-10-17T17:51:05.602Z,1571334665.602 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2019-10-17T17:51:05.603Z,1571334665.603 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018 Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018 2019-10-17T17:51:05.604Z,1571334665.604 [SBIT](INFO): Beginning SBIT in 23.000000 seconds. 2019-10-17T17:51:05.605Z,1571334665.605 [IBIT](INFO): Initialize IBIT Component. 2019-10-17T17:51:05.606Z,1571334665.606 [CBIT](DEBUG): Initialize CBIT Component. 2019-10-17T17:51:05.607Z,1571334665.607 [logger ThreadHandler](INFO): Handler Thread ID is 2098 2019-10-17T17:51:05.617Z,1571334665.617 [CBIT](DEBUG): Initialized mux pins. 2019-10-17T17:51:05.617Z,1571334665.617 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL. 2019-10-17T17:51:05.617Z,1571334665.617 [CBIT](DEBUG): Initializing the watchdog timer. 2019-10-17T17:51:05.625Z,1571334665.625 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2099 2019-10-17T17:51:05.626Z,1571334665.626 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2019-10-17T17:51:05.637Z,1571334665.637 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2100 2019-10-17T17:51:05.641Z,1571334665.641 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2019-10-17T17:51:05.641Z,1571334665.641 [CBIT](DEBUG): Initializing heartbeat. 2019-10-17T17:51:05.649Z,1571334665.649 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 2101 2019-10-17T17:51:05.650Z,1571334665.650 [CTD_NeilBrown](INFO): Powering down 2019-10-17T17:51:05.674Z,1571334665.674 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2102 2019-10-17T17:51:05.674Z,1571334665.674 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2019-10-17T17:51:05.681Z,1571334665.681 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20 2019-10-17T17:51:05.683Z,1571334665.683 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2104 2019-10-17T17:51:05.684Z,1571334665.684 [WetLabsBB2FL](INFO): Powering down 2019-10-17T17:51:05.713Z,1571334665.713 [CBIT](DEBUG): Deactivating GF circuits. 2019-10-17T17:51:05.713Z,1571334665.713 [CBIT](DEBUG): Deactivating emergency mode. 2019-10-17T17:51:05.714Z,1571334665.714 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2105 2019-10-17T17:51:05.717Z,1571334665.717 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2019-10-17T17:51:05.717Z,1571334665.717 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2019-10-17T17:51:05.717Z,1571334665.717 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2019-10-17T17:51:05.717Z,1571334665.717 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2019-10-17T17:51:05.718Z,1571334665.718 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2019-10-17T17:51:05.718Z,1571334665.718 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2019-10-17T17:51:05.718Z,1571334665.718 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2019-10-17T17:51:05.718Z,1571334665.718 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2019-10-17T17:51:05.718Z,1571334665.718 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2019-10-17T17:51:05.719Z,1571334665.719 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2019-10-17T17:51:05.719Z,1571334665.719 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2019-10-17T17:51:05.719Z,1571334665.719 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2019-10-17T17:51:05.719Z,1571334665.719 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2019-10-17T17:51:05.719Z,1571334665.719 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2019-10-17T17:51:05.719Z,1571334665.719 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2019-10-17T17:51:05.720Z,1571334665.720 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2019-10-17T17:51:05.749Z,1571334665.749 [CBIT](DEBUG): Backplane powered. 2019-10-17T17:51:05.750Z,1571334665.750 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2019-10-17T17:51:05.759Z,1571334665.759 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2019-10-17T17:51:05.770Z,1571334665.770 [MissionManager](DEBUG): 2019-10-17T17:51:05.771Z,1571334665.771 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2019-10-17T17:51:05.839Z,1571334665.839 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2019-10-17T17:51:05.861Z,1571334665.861 [Default:A.Wait](DEBUG): Construct Wait. 2019-10-17T17:51:05.862Z,1571334665.862 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2019-10-17T17:51:05.885Z,1571334665.885 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2019-10-17T17:51:05.887Z,1571334665.887 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2019-10-17T17:51:05.908Z,1571334665.908 [Default:E.Execute](DEBUG): Construct Execute. 2019-10-17T17:51:05.912Z,1571334665.912 [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-10-17T17:51:05.925Z,1571334665.925 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,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-10-17T17:51:05.937Z,1571334665.937 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2019-10-17T17:51:06.041Z,1571334666.041 [Radio_Surface](INFO): Powering up 2019-10-17T17:51:06.125Z,1571334666.125 [DVL_micro](INFO): Initializing 2019-10-17T17:51:06.147Z,1571334666.147 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-10-17T17:51:06.147Z,1571334666.147 [DAT](INFO): Powering up 2019-10-17T17:51:06.147Z,1571334666.147 [DAT](DEBUG): Initializing DAT. 2019-10-17T17:51:06.181Z,1571334666.181 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-10-17T17:51:06.292Z,1571334666.292 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2019-10-17T17:51:06.297Z,1571334666.297 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2019-10-17T17:51:06.298Z,1571334666.298 [ElevatorServo](DEBUG): Initializing EZServoServo. 2019-10-17T17:51:06.305Z,1571334666.305 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2019-10-17T17:51:06.306Z,1571334666.306 [MassServo](DEBUG): Initializing EZServoServo. 2019-10-17T17:51:06.313Z,1571334666.313 [MassServo](DEBUG): Initializing MassServo. 2019-10-17T17:51:06.314Z,1571334666.314 [RudderServo](DEBUG): Initializing EZServoServo. 2019-10-17T17:51:06.321Z,1571334666.321 [RudderServo](DEBUG): Initializing RudderServo. 2019-10-17T17:51:06.322Z,1571334666.322 [ThrusterServo](DEBUG): Initializing EZServoServo. 2019-10-17T17:51:06.329Z,1571334666.329 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2019-10-17T17:51:06.430Z,1571334666.430 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2019-10-17T17:51:06.430Z,1571334666.430 [DropWeight] Hardware Fault, FailCount= 1 2019-10-17T17:51:06.430Z,1571334666.430 [DropWeight](ERROR): Hardware Fault 2019-10-17T17:51:06.538Z,1571334666.538 [CommandLine](FAULT): Scheduling is paused 2019-10-17T17:51:06.539Z,1571334666.539 [CBIT](INFO): Critical error at 20191017T175106 2019-10-17T17:51:06.539Z,1571334666.539 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2019-10-17T17:51:06.541Z,1571334666.541 [CBIT](ERROR): Hardware Fault in component: DropWeight 2019-10-17T17:51:06.542Z,1571334666.542 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2019-10-17T17:51:07.149Z,1571334667.149 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2019-10-17T17:51:07.149Z,1571334667.149 [RudderServo](FAULT): Rudder failed to initialize 2019-10-17T17:51:07.149Z,1571334667.149 [RudderServo] Communications Fault, FailCount= 1 2019-10-17T17:51:07.149Z,1571334667.149 [RudderServo](ERROR): Communications Fault 2019-10-17T17:51:07.294Z,1571334667.294 [CBIT](INFO): Critical error at 20191017T175106 2019-10-17T17:51:07.296Z,1571334667.296 [CBIT](ERROR): Communications Fault in component: RudderServo 2019-10-17T17:51:07.500Z,1571334667.500 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-10-17T17:51:07.500Z,1571334667.500 [RudderServo](INFO): Powering down 2019-10-17T17:51:08.181Z,1571334668.181 [RudderServo](DEBUG): Initializing EZServoServo. 2019-10-17T17:51:08.302Z,1571334668.302 [RudderServo](DEBUG): Initializing RudderServo. 2019-10-17T17:51:08.306Z,1571334668.306 [CBIT](INFO): Clearing failed state for component RudderServo 2019-10-17T17:51:08.306Z,1571334668.306 [RudderServo] No Fault, FailCount= 1 2019-10-17T17:51:09.549Z,1571334669.549 [Aanderaa_O2](INFO): Powering down 2019-10-17T17:51:19.481Z,1571334679.481 [DAT](INFO): setting local address to 2 2019-10-17T17:51:19.870Z,1571334679.870 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-10-17T17:51:19.870Z,1571334679.870 [DVL_micro] Communications Fault, FailCount= 1 2019-10-17T17:51:19.870Z,1571334679.870 [DVL_micro](ERROR): Communications Fault 2019-10-17T17:51:19.886Z,1571334679.886 [DAT](INFO): set local address to 2 2019-10-17T17:51:19.940Z,1571334679.940 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-17T17:51:20.349Z,1571334680.349 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T17:51:21.138Z,1571334681.138 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-17T17:51:21.138Z,1571334681.138 [DVL_micro] No Fault, FailCount= 1 2019-10-17T17:51:21.508Z,1571334681.508 [DVL_micro](INFO): Initializing 2019-10-17T17:51:29.215Z,1571334689.215 [SBIT](IMPORTANT): Beginning Startup BIT 2019-10-17T17:51:29.228Z,1571334689.228 [CBIT](IMPORTANT): Beginning ground fault scan 2019-10-17T17:51:32.931Z,1571334692.931 [NAL9602](INFO): Powering up NAL9602 2019-10-17T17:51:35.334Z,1571334695.334 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-10-17T17:51:35.334Z,1571334695.334 [DVL_micro] Communications Fault, FailCount= 2 2019-10-17T17:51:35.334Z,1571334695.334 [DVL_micro](ERROR): Communications Fault 2019-10-17T17:51:35.464Z,1571334695.464 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-17T17:51:35.809Z,1571334695.809 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T17:51:36.642Z,1571334696.642 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-17T17:51:36.642Z,1571334696.642 [DVL_micro] No Fault, FailCount= 2 2019-10-17T17:51:36.956Z,1571334696.956 [DVL_micro](INFO): Initializing 2019-10-17T17:51:40.270Z,1571334700.270 [CBIT](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.010361 CHAN A1 (24V): 0.047477 CHAN A2 (12V): -0.002394 CHAN A3 (5V): -0.001469 CHAN B0 (3.3V): -0.000249 CHAN B1 (3.15aV): -0.000246 CHAN B2 (3.15bV): -0.000081 CHAN B3 (GND): -0.000068 OPEN: -0.000359 Full Scale Calc: 4.765 mA, -1.589 mA 2019-10-17T17:51:50.882Z,1571334710.882 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-10-17T17:51:50.882Z,1571334710.882 [DVL_micro] Communications Fault, FailCount= 3 2019-10-17T17:51:50.882Z,1571334710.882 [DVL_micro](ERROR): Communications Fault 2019-10-17T17:51:51.014Z,1571334711.014 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-17T17:51:51.353Z,1571334711.353 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T17:51:52.214Z,1571334712.214 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-17T17:51:52.214Z,1571334712.214 [DVL_micro] No Fault, FailCount= 3 2019-10-17T17:51:52.500Z,1571334712.500 [DVL_micro](INFO): Initializing 2019-10-17T17:51:53.706Z,1571334713.706 [NAL9602](ERROR): NAL9602 initialization error. 2019-10-17T17:51:53.706Z,1571334713.706 [NAL9602] Communications Fault, FailCount= 1 2019-10-17T17:51:53.706Z,1571334713.706 [NAL9602](ERROR): Communications Fault 2019-10-17T17:51:53.832Z,1571334713.832 [CBIT](ERROR): Communications Fault in component: NAL9602 2019-10-17T17:51:54.110Z,1571334714.110 [NAL9602](INFO): Powering down 2019-10-17T17:51:55.010Z,1571334715.010 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-17T17:51:55.010Z,1571334715.010 [NAL9602] No Fault, FailCount= 1 2019-10-17T17:52:06.230Z,1571334726.230 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-10-17T17:52:06.230Z,1571334726.230 [DVL_micro] Communications Fault, FailCount= 4 2019-10-17T17:52:06.230Z,1571334726.230 [DVL_micro](ERROR): Communications Fault 2019-10-17T17:52:06.316Z,1571334726.316 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-17T17:52:06.713Z,1571334726.713 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T17:52:07.490Z,1571334727.490 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-17T17:52:07.490Z,1571334727.490 [DVL_micro] No Fault, FailCount= 4 2019-10-17T17:52:07.852Z,1571334727.852 [DVL_micro](INFO): Initializing 2019-10-17T17:52:16.444Z,1571334736.444 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005029 2019-10-17T17:52:21.682Z,1571334741.682 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-10-17T17:52:21.682Z,1571334741.682 [DVL_micro] Communications Fault, FailCount= 5 2019-10-17T17:52:21.682Z,1571334741.682 [DVL_micro](ERROR): Communications Fault 2019-10-17T17:52:21.757Z,1571334741.757 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-17T17:52:21.757Z,1571334741.757 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-10-17T17:52:22.153Z,1571334742.153 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T17:52:22.205Z,1571334742.205 [CBIT](INFO): Critical error at 20191017T175221 2019-10-17T17:52:22.512Z,1571334742.512 [SBIT](IMPORTANT): SBIT PASSED 2019-10-17T17:52:22.565Z,1571334742.565 [CommandLine](IMPORTANT): got command configSet list 2019-10-17T17:52:22.566Z,1571334742.566 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2019-10-17T17:52:22.566Z,1571334742.566 [CommandLine](IMPORTANT): CBIT.gf24Offset=154 microampere; 2019-10-17T17:52:22.567Z,1571334742.567 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool; 2019-10-17T17:52:22.567Z,1571334742.567 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool; 2019-10-17T17:52:22.567Z,1571334742.567 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool; 2019-10-17T17:52:22.925Z,1571334742.925 [MissionManager](IMPORTANT): Started mission Startup 2019-10-17T17:52:22.925Z,1571334742.925 [Startup] Running Loop=1 2019-10-17T17:52:22.925Z,1571334742.925 [Startup](DEBUG): Aggregate::initialize Startup 2019-10-17T17:52:22.926Z,1571334742.926 [Startup:A.GoToSurface] Running Loop=1 2019-10-17T17:52:22.926Z,1571334742.926 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-10-17T17:52:22.926Z,1571334742.926 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-10-17T17:52:22.927Z,1571334742.927 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-10-17T17:52:22.927Z,1571334742.927 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-10-17T17:52:22.927Z,1571334742.927 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-10-17T17:52:22.928Z,1571334742.928 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-10-17T17:52:22.929Z,1571334742.929 [Startup:StartupSatComms] Running Loop=1 2019-10-17T17:52:22.929Z,1571334742.929 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2019-10-17T17:52:22.930Z,1571334742.930 [Startup:StartupSatComms:A] Running Loop=1 2019-10-17T17:52:23.327Z,1571334743.327 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2019-10-17T17:52:24.512Z,1571334744.512 [NAL9602](INFO): Powering up NAL9602 2019-10-17T17:52:35.414Z,1571334755.414 [NAL9602](INFO): NAL9602 initialized 2019-10-17T17:52:36.241Z,1571334756.241 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:53:12.274Z,1571334792.274 [CommandLine](IMPORTANT): got command show variable propomega 2019-10-17T17:53:12.367Z,1571334792.367 [CommandLine](IMPORTANT): SpeedControl.propOmegaAction (radian_per_second) 2019-10-17T17:53:23.123Z,1571334803.123 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-17T17:52:22.9Z 2019-10-17T17:53:23.123Z,1571334803.123 [Startup:StartupSatComms:A] Stopped 2019-10-17T17:53:23.123Z,1571334803.123 [Startup:StartupSatComms:B] Running Loop=1 2019-10-17T17:53:23.530Z,1571334803.530 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-10-17T17:53:30.313Z,1571334810.313 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20191017T174152/Courier0000.lzma 2019-10-17T17:53:32.319Z,1571334812.319 [DataOverHttps](INFO): Moved sent file to Logs/20191017T174152/Courier0000.lzma.bak 2019-10-17T17:53:32.319Z,1571334812.319 [DataOverHttps](INFO): SBD MOMSN=11920787 2019-10-17T17:53:49.388Z,1571334829.388 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20191017T174152/Courier0004.lzma 2019-10-17T17:53:50.068Z,1571334830.068 [CommandLine](IMPORTANT): got command maintain control SpeedControl.propOmegaAction 300.000000 revolution_per_minute 2019-10-17T17:53:50.070Z,1571334830.070 [ComponentRegistry](DEBUG): SyncComponent "Maintain_SpeedControl.propOmegaAction" handled in the control thread. 2019-10-17T17:53:50.222Z,1571334830.222 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_SpeedControl.propOmegaAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-10-17T17:53:51.394Z,1571334831.394 [DataOverHttps](INFO): Moved sent file to Logs/20191017T174152/Courier0004.lzma.bak 2019-10-17T17:53:51.395Z,1571334831.395 [DataOverHttps](INFO): SBD MOMSN=11920792 2019-10-17T17:54:05.968Z,1571334845.968 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2019-10-17T17:54:05.968Z,1571334845.968 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-17T17:54:06.029Z,1571334846.029 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-17T17:54:06.528Z,1571334846.528 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-17T17:54:06.528Z,1571334846.528 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2019-10-17T17:54:08.480Z,1571334848.480 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20191017T175055/Courier0000.lzma 2019-10-17T17:54:10.488Z,1571334850.488 [DataOverHttps](INFO): Moved sent file to Logs/20191017T175055/Courier0000.lzma.bak 2019-10-17T17:54:10.488Z,1571334850.488 [DataOverHttps](INFO): SBD MOMSN=11920794 2019-10-17T17:54:17.641Z,1571334857.641 [CommandLine](IMPORTANT): got command maintain clear 2019-10-17T17:54:17.742Z,1571334857.742 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,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-10-17T17:54:23.343Z,1571334863.343 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-17T17:53:23.1Z 2019-10-17T17:54:23.343Z,1571334863.343 [Startup:StartupSatComms:B] Stopped 2019-10-17T17:54:23.343Z,1571334863.343 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2019-10-17T17:54:23.343Z,1571334863.343 [Startup:StartupSatComms] Stopped 2019-10-17T17:54:23.344Z,1571334863.344 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2019-10-17T17:54:23.344Z,1571334863.344 [Startup](INFO): Completed Startup 2019-10-17T17:54:23.344Z,1571334863.344 [MissionManager](INFO): Startup is completed. 2019-10-17T17:54:23.369Z,1571334863.369 [MissionManager](INFO): Uninitializing Mission Startup 2019-10-17T17:54:23.369Z,1571334863.369 [Startup] Stopped 2019-10-17T17:54:23.369Z,1571334863.369 [Startup](DEBUG): Aggregate::uninitialize Startup 2019-10-17T17:54:23.369Z,1571334863.369 [Startup:A.GoToSurface] Stopped 2019-10-17T17:54:23.369Z,1571334863.369 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-10-17T17:54:23.774Z,1571334863.774 [MissionManager](IMPORTANT): Started mission Default 2019-10-17T17:54:23.774Z,1571334863.774 [Default] Running Loop=1 2019-10-17T17:54:23.774Z,1571334863.774 [Default](DEBUG): Aggregate::initialize Default 2019-10-17T17:54:23.774Z,1571334863.774 [Default:B.GoToSurface] Running Loop=1 2019-10-17T17:54:23.774Z,1571334863.774 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2019-10-17T17:54:23.775Z,1571334863.775 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2019-10-17T17:54:23.775Z,1571334863.775 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2019-10-17T17:54:23.775Z,1571334863.775 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2019-10-17T17:54:23.776Z,1571334863.776 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2019-10-17T17:54:23.776Z,1571334863.776 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2019-10-17T17:54:23.776Z,1571334863.776 [Default:A.Wait] Running Loop=1 2019-10-17T17:54:23.776Z,1571334863.776 [Default:A.Wait](DEBUG): Initialize Wait Component. 2019-10-17T17:54:27.441Z,1571334867.441 [DataOverHttps](INFO): Sending 401 bytes from file Logs/20191017T170819/Express0011.lzma 2019-10-17T17:54:29.446Z,1571334869.446 [DataOverHttps](INFO): Moved sent file to Logs/20191017T170819/Express0011.lzma.bak 2019-10-17T17:54:29.446Z,1571334869.446 [DataOverHttps](INFO): SBD MOMSN=11920800 2019-10-17T17:54:37.048Z,1571334877.048 [Default:A.Wait](INFO): Done Waiting. 2019-10-17T17:54:37.049Z,1571334877.049 [Default:A.Wait] Stopped 2019-10-17T17:54:37.049Z,1571334877.049 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2019-10-17T17:54:37.461Z,1571334877.461 [Default:CheckIn] Running Loop=1 2019-10-17T17:54:37.461Z,1571334877.461 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2019-10-17T17:54:37.461Z,1571334877.461 [Default:CheckIn:Read_GPS] Running Loop=1 2019-10-17T17:54:37.875Z,1571334877.875 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2019-10-17T17:54:44.032Z,1571334884.032 [CommandLine](IMPORTANT): got command show variable heading 2019-10-17T17:54:44.050Z,1571334884.050 [CommandLine](IMPORTANT): HorizontalControl.kdHeading (second) 2019-10-17T17:54:44.050Z,1571334884.050 [CommandLine](IMPORTANT): HorizontalControl.kiHeading (reciprocal_second) 2019-10-17T17:54:44.050Z,1571334884.050 [CommandLine](IMPORTANT): HorizontalControl.kiwpHeading (radian_per_second_per_meter) 2019-10-17T17:54:44.051Z,1571334884.051 [CommandLine](IMPORTANT): HorizontalControl.kpHeading (none) 2019-10-17T17:54:44.051Z,1571334884.051 [CommandLine](IMPORTANT): HorizontalControl.kwpHeading (radian_per_meter) 2019-10-17T17:54:44.202Z,1571334884.202 [CommandLine](IMPORTANT): Rowe_600.headingOffset (degree) 2019-10-17T17:54:44.280Z,1571334884.280 [CommandLine](IMPORTANT): HorizontalControl.headingInternal (radian) 2019-10-17T17:54:44.281Z,1571334884.281 [CommandLine](IMPORTANT): HorizontalControl.smoothHeadingInternal (radian) 2019-10-17T17:54:44.283Z,1571334884.283 [CommandLine](IMPORTANT): HorizontalControl.headingIntegralInternal (radian) 2019-10-17T17:55:46.988Z,1571334946.988 [CommandLine](IMPORTANT): got command maintain control VerticalControl.buoyancyAction 90.000000 cubic_centimeter 2019-10-17T17:55:46.990Z,1571334946.990 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.buoyancyAction" handled in the control thread. 2019-10-17T17:55:47.392Z,1571334947.392 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,Maintain_VerticalControl.buoyancyAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2019-10-17T17:57:06.977Z,1571335026.977 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2019-10-17T17:57:06.977Z,1571335026.977 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-17T17:57:06.992Z,1571335026.992 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-17T17:57:07.409Z,1571335027.409 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-17T17:57:07.409Z,1571335027.409 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2019-10-17T17:57:19.992Z,1571335039.992 [CommandLine](IMPORTANT): got command get platform_buoyancy_position 2019-10-17T17:57:19.993Z,1571335039.993 [CommandLine](IMPORTANT): platform_buoyancy_position 97.357414 cc 2019-10-17T17:57:28.480Z,1571335048.480 [CommandLine](IMPORTANT): got command maintain clear 2019-10-17T17:57:28.785Z,1571335048.785 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,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-10-17T17:57:38.826Z,1571335058.826 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2019-10-17T17:57:39.645Z,1571335059.645 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:57:42.473Z,1571335062.473 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:57:45.709Z,1571335065.709 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:57:48.544Z,1571335068.544 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:57:51.373Z,1571335071.373 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:57:53.401Z,1571335073.401 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:57:55.405Z,1571335075.405 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:57:58.637Z,1571335078.637 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:01.468Z,1571335081.468 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:04.697Z,1571335084.697 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:07.529Z,1571335087.529 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:10.761Z,1571335090.761 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:13.585Z,1571335093.585 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:16.409Z,1571335096.409 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:18.429Z,1571335098.429 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:21.665Z,1571335101.665 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:24.497Z,1571335104.497 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:26.944Z,1571335106.944 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2019-10-17T17:58:26.947Z,1571335106.947 [BPC1](INFO): Received data from all battery sticks. 2019-10-17T17:58:27.721Z,1571335107.721 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:30.553Z,1571335110.553 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:33.789Z,1571335113.789 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:36.621Z,1571335116.621 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:39.441Z,1571335119.441 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:41.469Z,1571335121.469 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:43.485Z,1571335123.485 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:46.713Z,1571335126.713 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:49.537Z,1571335129.537 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:52.769Z,1571335132.769 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:55.597Z,1571335135.597 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:58:58.829Z,1571335138.829 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:01.677Z,1571335141.677 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:04.493Z,1571335144.493 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:06.505Z,1571335146.505 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:09.745Z,1571335149.745 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:12.565Z,1571335152.565 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:15.801Z,1571335155.801 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:18.625Z,1571335158.625 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:21.857Z,1571335161.857 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:24.685Z,1571335164.685 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:27.517Z,1571335167.517 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:29.537Z,1571335169.537 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:31.553Z,1571335171.553 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:34.793Z,1571335174.793 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:37.636Z,1571335177.636 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:37.659Z,1571335177.659 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-17T17:54:37.5Z 2019-10-17T17:59:37.659Z,1571335177.659 [Default:CheckIn:Read_GPS] Stopped 2019-10-17T17:59:37.659Z,1571335177.659 [Default:CheckIn:Read_Iridium] Running Loop=1 2019-10-17T17:59:38.070Z,1571335178.070 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2019-10-17T17:59:40.585Z,1571335180.585 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:41.637Z,1571335181.637 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20191017T175055/Courier0004.lzma 2019-10-17T17:59:43.542Z,1571335183.542 [DataOverHttps](INFO): Moved sent file to Logs/20191017T175055/Courier0004.lzma.bak 2019-10-17T17:59:43.543Z,1571335183.543 [DataOverHttps](INFO): SBD MOMSN=11920828 2019-10-17T17:59:43.817Z,1571335183.817 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:46.348Z,1571335186.348 [CommandLine](IMPORTANT): got command show variable heading 2019-10-17T17:59:46.360Z,1571335186.360 [CommandLine](IMPORTANT): HorizontalControl.kdHeading (second) 2019-10-17T17:59:46.361Z,1571335186.361 [CommandLine](IMPORTANT): HorizontalControl.kiHeading (reciprocal_second) 2019-10-17T17:59:46.361Z,1571335186.361 [CommandLine](IMPORTANT): HorizontalControl.kiwpHeading (radian_per_second_per_meter) 2019-10-17T17:59:46.362Z,1571335186.362 [CommandLine](IMPORTANT): HorizontalControl.kpHeading (none) 2019-10-17T17:59:46.362Z,1571335186.362 [CommandLine](IMPORTANT): HorizontalControl.kwpHeading (radian_per_meter) 2019-10-17T17:59:46.385Z,1571335186.385 [CommandLine](IMPORTANT): Rowe_600.headingOffset (degree) 2019-10-17T17:59:46.474Z,1571335186.474 [CommandLine](IMPORTANT): HorizontalControl.headingInternal (radian) 2019-10-17T17:59:46.474Z,1571335186.474 [CommandLine](IMPORTANT): HorizontalControl.smoothHeadingInternal (radian) 2019-10-17T17:59:46.475Z,1571335186.475 [CommandLine](IMPORTANT): HorizontalControl.headingIntegralInternal (radian) 2019-10-17T17:59:46.649Z,1571335186.649 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:49.877Z,1571335189.877 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:52.709Z,1571335192.709 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:55.937Z,1571335195.937 [NAL9602](DEBUG): Fix Requested 2019-10-17T17:59:58.765Z,1571335198.765 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:00.306Z,1571335200.306 [DataOverHttps](INFO): Sending 942 bytes from file Logs/20191017T173826/Express0001.lzma 2019-10-17T18:00:01.605Z,1571335201.605 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:02.310Z,1571335202.310 [DataOverHttps](INFO): Moved sent file to Logs/20191017T173826/Express0001.lzma.bak 2019-10-17T18:00:02.310Z,1571335202.310 [DataOverHttps](INFO): SBD MOMSN=11920830 2019-10-17T18:00:04.833Z,1571335204.833 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:07.657Z,1571335207.657 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:08.102Z,1571335208.102 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2019-10-17T18:00:08.102Z,1571335208.102 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-17T18:00:08.120Z,1571335208.120 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-17T18:00:08.530Z,1571335208.530 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-17T18:00:08.530Z,1571335208.530 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2019-10-17T18:00:10.885Z,1571335210.885 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:13.721Z,1571335213.721 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:16.945Z,1571335216.945 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:19.026Z,1571335219.026 [DataOverHttps](INFO): Sending 745 bytes from file Logs/20191017T173948/Express0001.lzma 2019-10-17T18:00:19.781Z,1571335219.781 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:20.995Z,1571335220.995 [DataOverHttps](INFO): Moved sent file to Logs/20191017T173948/Express0001.lzma.bak 2019-10-17T18:00:20.995Z,1571335220.995 [DataOverHttps](INFO): SBD MOMSN=11920853 2019-10-17T18:00:22.605Z,1571335222.605 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:24.621Z,1571335224.621 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:25.049Z,1571335225.049 [CommandLine](IMPORTANT): got command report mod HorizontalControl.headingInternal 2019-10-17T18:00:25.128Z,1571335225.128 [Reporter](INFO): HorizontalControl.headingInternal no_value 2019-10-17T18:00:26.641Z,1571335226.641 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:29.877Z,1571335229.877 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:32.709Z,1571335232.709 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:35.949Z,1571335235.949 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:37.665Z,1571335237.665 [DataOverHttps](INFO): Sending 773 bytes from file Logs/20191017T174152/Express0001.lzma 2019-10-17T18:00:38.765Z,1571335238.765 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:39.652Z,1571335239.652 [CommandLine](IMPORTANT): got command show variable orientation 2019-10-17T18:00:39.658Z,1571335239.658 [CommandLine](IMPORTANT): platform_magnetic_orientation (radian) 2019-10-17T18:00:39.659Z,1571335239.659 [CommandLine](IMPORTANT): platform_orientation (radian) 2019-10-17T18:00:39.659Z,1571335239.659 [CommandLine](IMPORTANT): platform_orientation_matrix (none) 2019-10-17T18:00:39.665Z,1571335239.665 [CommandLine](IMPORTANT): DeadReckonUsingMultipleVelocitySources.orientationStaleAfter (minute) 2019-10-17T18:00:39.666Z,1571335239.666 [CommandLine](IMPORTANT): DeadReckonUsingSpeedCalculator.orientationStaleAfter (minute) 2019-10-17T18:00:39.668Z,1571335239.668 [CommandLine](IMPORTANT): DeadReckonWithRespectToWater.orientationStaleAfter (minute) 2019-10-17T18:00:39.671Z,1571335239.671 [DataOverHttps](INFO): Moved sent file to Logs/20191017T174152/Express0001.lzma.bak 2019-10-17T18:00:39.671Z,1571335239.671 [DataOverHttps](INFO): SBD MOMSN=11920874 2019-10-17T18:00:39.676Z,1571335239.676 [CommandLine](IMPORTANT): DeadReckonWithRespectToSeafloor.orientationStaleAfter (minute) 2019-10-17T18:00:39.709Z,1571335239.709 [CommandLine](IMPORTANT): DeadReckonUsingDVLWaterTrack.orientationStaleAfter (minute) 2019-10-17T18:00:39.711Z,1571335239.711 [CommandLine](IMPORTANT): DeadReckonUsingCompactModelForecast.orientationStaleAfter (minute) 2019-10-17T18:00:39.881Z,1571335239.881 [CommandLine](IMPORTANT): DeadReckonUsingMultipleVelocitySources.elapsed_since_orientation_read (second) 2019-10-17T18:00:39.883Z,1571335239.883 [CommandLine](IMPORTANT): AHRS_M2.platform_orientation (radian) 2019-10-17T18:00:39.883Z,1571335239.883 [CommandLine](IMPORTANT): AHRS_M2.platform_magnetic_orientation (radian) 2019-10-17T18:00:39.884Z,1571335239.884 [CommandLine](IMPORTANT): AHRS_M2.platform_orientation_matrix (none) 2019-10-17T18:00:39.884Z,1571335239.884 [CommandLine](IMPORTANT): AHRS_M2.orientation_error (radian) 2019-10-17T18:00:39.885Z,1571335239.885 [CommandLine](IMPORTANT): AHRS_M2.orientation (radian) 2019-10-17T18:00:39.887Z,1571335239.887 [CommandLine](IMPORTANT): DVL_micro.platform_orientation (radian) 2019-10-17T18:00:39.887Z,1571335239.887 [CommandLine](IMPORTANT): DVL_micro.platform_magnetic_orientation (radian) 2019-10-17T18:00:39.888Z,1571335239.888 [CommandLine](IMPORTANT): DVL_micro.platform_orientation_matrix (none) 2019-10-17T18:00:41.993Z,1571335241.993 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:44.829Z,1571335244.829 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:47.653Z,1571335247.653 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:49.677Z,1571335249.677 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:52.901Z,1571335252.901 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:55.733Z,1571335255.733 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:00:58.969Z,1571335258.969 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:01.398Z,1571335261.398 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20191017T174152/Express0005.lzma 2019-10-17T18:01:01.789Z,1571335261.789 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:03.350Z,1571335263.350 [DataOverHttps](INFO): Moved sent file to Logs/20191017T174152/Express0005.lzma.bak 2019-10-17T18:01:03.350Z,1571335263.350 [DataOverHttps](INFO): SBD MOMSN=11920895 2019-10-17T18:01:05.021Z,1571335265.021 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:07.849Z,1571335267.849 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:10.689Z,1571335270.689 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:12.705Z,1571335272.705 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:15.929Z,1571335275.929 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:18.757Z,1571335278.757 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:20.694Z,1571335280.694 [DataOverHttps](INFO): Sending 821 bytes from file Logs/20191017T175055/Express0001.lzma 2019-10-17T18:01:21.989Z,1571335281.989 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:22.698Z,1571335282.698 [DataOverHttps](INFO): Moved sent file to Logs/20191017T175055/Express0001.lzma.bak 2019-10-17T18:01:22.698Z,1571335282.698 [DataOverHttps](INFO): SBD MOMSN=11920897 2019-10-17T18:01:24.584Z,1571335284.584 [CommandLine](IMPORTANT): got command show best platform_orientation 2019-10-17T18:01:24.584Z,1571335284.584 [CommandLine](IMPORTANT): platform_orientation best is AHRS_M2.platform_orientation 2019-10-17T18:01:24.825Z,1571335284.825 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:28.056Z,1571335288.056 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:30.877Z,1571335290.877 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:33.709Z,1571335293.709 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:35.725Z,1571335295.725 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:37.745Z,1571335297.745 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:39.349Z,1571335299.349 [DataOverHttps](INFO): Sending 526 bytes from file Logs/20191017T175055/Express0005.lzma 2019-10-17T18:01:40.981Z,1571335300.981 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:41.354Z,1571335301.354 [DataOverHttps](INFO): Moved sent file to Logs/20191017T175055/Express0005.lzma.bak 2019-10-17T18:01:41.354Z,1571335301.354 [DataOverHttps](INFO): SBD MOMSN=11920919 2019-10-17T18:01:43.026Z,1571335303.026 [Default:CheckIn:Read_Iridium] Stopped 2019-10-17T18:01:43.026Z,1571335303.026 [Default:CheckIn:C.Wait] Running Loop=1 2019-10-17T18:01:43.026Z,1571335303.026 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2019-10-17T18:01:43.809Z,1571335303.809 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:47.037Z,1571335307.037 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:49.869Z,1571335309.869 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:53.097Z,1571335313.097 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:55.933Z,1571335315.933 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:55.972Z,1571335315.972 [CommandLine](IMPORTANT): got command report mod AHRS_M2.platform_orientation 2019-10-17T18:01:56.380Z,1571335316.380 [Reporter](INFO): AHRS_M2.platform_orientation 4.732457 rad 2019-10-17T18:01:56.787Z,1571335316.787 [Reporter](INFO): AHRS_M2.platform_orientation 4.732137 rad 2019-10-17T18:01:57.169Z,1571335317.169 [Reporter](INFO): AHRS_M2.platform_orientation 4.732243 rad 2019-10-17T18:01:57.576Z,1571335317.576 [Reporter](INFO): AHRS_M2.platform_orientation 4.731913 rad 2019-10-17T18:01:57.982Z,1571335317.982 [Reporter](INFO): AHRS_M2.platform_orientation 4.732494 rad 2019-10-17T18:01:58.400Z,1571335318.400 [Reporter](INFO): AHRS_M2.platform_orientation 4.732670 rad 2019-10-17T18:01:58.765Z,1571335318.765 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:01:58.814Z,1571335318.814 [Reporter](INFO): AHRS_M2.platform_orientation 4.732619 rad 2019-10-17T18:01:59.200Z,1571335319.200 [Reporter](INFO): AHRS_M2.platform_orientation 4.732993 rad 2019-10-17T18:01:59.611Z,1571335319.611 [Reporter](INFO): AHRS_M2.platform_orientation 4.732997 rad 2019-10-17T18:02:00.009Z,1571335320.009 [Reporter](INFO): AHRS_M2.platform_orientation 4.733573 rad 2019-10-17T18:02:00.404Z,1571335320.404 [Reporter](INFO): AHRS_M2.platform_orientation 4.733512 rad 2019-10-17T18:02:00.777Z,1571335320.777 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:00.825Z,1571335320.825 [Reporter](INFO): AHRS_M2.platform_orientation 4.733077 rad 2019-10-17T18:02:01.228Z,1571335321.228 [Reporter](INFO): AHRS_M2.platform_orientation 4.733223 rad 2019-10-17T18:02:01.631Z,1571335321.631 [Reporter](INFO): AHRS_M2.platform_orientation 4.732882 rad 2019-10-17T18:02:02.024Z,1571335322.024 [Reporter](INFO): AHRS_M2.platform_orientation 4.732638 rad 2019-10-17T18:02:02.419Z,1571335322.419 [Reporter](INFO): AHRS_M2.platform_orientation 4.732978 rad 2019-10-17T18:02:02.797Z,1571335322.797 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:02.844Z,1571335322.844 [Reporter](INFO): AHRS_M2.platform_orientation 4.733015 rad 2019-10-17T18:02:03.252Z,1571335323.252 [Reporter](INFO): AHRS_M2.platform_orientation 4.733256 rad 2019-10-17T18:02:03.658Z,1571335323.658 [Reporter](INFO): AHRS_M2.platform_orientation 4.733079 rad 2019-10-17T18:02:04.038Z,1571335324.038 [Reporter](INFO): AHRS_M2.platform_orientation 4.733056 rad 2019-10-17T18:02:04.447Z,1571335324.447 [Reporter](INFO): AHRS_M2.platform_orientation 4.732793 rad 2019-10-17T18:02:04.861Z,1571335324.861 [Reporter](INFO): AHRS_M2.platform_orientation 4.733383 rad 2019-10-17T18:02:05.245Z,1571335325.245 [Reporter](INFO): AHRS_M2.platform_orientation 4.733676 rad 2019-10-17T18:02:05.656Z,1571335325.656 [Reporter](INFO): AHRS_M2.platform_orientation 4.733566 rad 2019-10-17T18:02:06.025Z,1571335326.025 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:06.072Z,1571335326.072 [Reporter](INFO): AHRS_M2.platform_orientation 4.732939 rad 2019-10-17T18:02:06.479Z,1571335326.479 [Reporter](INFO): AHRS_M2.platform_orientation 4.732296 rad 2019-10-17T18:02:06.893Z,1571335326.893 [Reporter](INFO): AHRS_M2.platform_orientation 4.733027 rad 2019-10-17T18:02:07.270Z,1571335327.270 [Reporter](INFO): AHRS_M2.platform_orientation 4.733371 rad 2019-10-17T18:02:07.678Z,1571335327.678 [Reporter](INFO): AHRS_M2.platform_orientation 4.733646 rad 2019-10-17T18:02:08.087Z,1571335328.087 [Reporter](INFO): AHRS_M2.platform_orientation 4.734330 rad 2019-10-17T18:02:08.481Z,1571335328.481 [Reporter](INFO): AHRS_M2.platform_orientation 4.734733 rad 2019-10-17T18:02:08.860Z,1571335328.860 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:08.897Z,1571335328.897 [Reporter](INFO): AHRS_M2.platform_orientation 4.735082 rad 2019-10-17T18:02:09.309Z,1571335329.309 [Reporter](INFO): AHRS_M2.platform_orientation 4.737358 rad 2019-10-17T18:02:09.710Z,1571335329.710 [Reporter](INFO): AHRS_M2.platform_orientation 4.741650 rad 2019-10-17T18:02:10.104Z,1571335330.104 [Reporter](INFO): AHRS_M2.platform_orientation 4.740708 rad 2019-10-17T18:02:10.502Z,1571335330.502 [Reporter](INFO): AHRS_M2.platform_orientation 4.735099 rad 2019-10-17T18:02:10.908Z,1571335330.908 [Reporter](INFO): AHRS_M2.platform_orientation 4.710714 rad 2019-10-17T18:02:11.327Z,1571335331.327 [Reporter](INFO): AHRS_M2.platform_orientation 4.675961 rad 2019-10-17T18:02:11.704Z,1571335331.704 [Reporter](INFO): AHRS_M2.platform_orientation 4.644494 rad 2019-10-17T18:02:12.087Z,1571335332.087 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:12.125Z,1571335332.125 [Reporter](INFO): AHRS_M2.platform_orientation 4.611671 rad 2019-10-17T18:02:12.536Z,1571335332.536 [Reporter](INFO): AHRS_M2.platform_orientation 4.563664 rad 2019-10-17T18:02:12.939Z,1571335332.939 [Reporter](INFO): AHRS_M2.platform_orientation 4.528087 rad 2019-10-17T18:02:13.345Z,1571335333.345 [Reporter](INFO): AHRS_M2.platform_orientation 4.517190 rad 2019-10-17T18:02:13.738Z,1571335333.738 [Reporter](INFO): AHRS_M2.platform_orientation 4.508065 rad 2019-10-17T18:02:14.145Z,1571335334.145 [Reporter](INFO): AHRS_M2.platform_orientation 4.504414 rad 2019-10-17T18:02:14.560Z,1571335334.560 [Reporter](INFO): AHRS_M2.platform_orientation 4.501492 rad 2019-10-17T18:02:14.917Z,1571335334.917 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:14.968Z,1571335334.968 [Reporter](INFO): AHRS_M2.platform_orientation 4.500196 rad 2019-10-17T18:02:15.375Z,1571335335.375 [Reporter](INFO): AHRS_M2.platform_orientation 4.498770 rad 2019-10-17T18:02:15.820Z,1571335335.820 [Reporter](INFO): AHRS_M2.platform_orientation 4.498312 rad 2019-10-17T18:02:16.222Z,1571335336.222 [Reporter](INFO): AHRS_M2.platform_orientation 4.496706 rad 2019-10-17T18:02:16.593Z,1571335336.593 [Reporter](INFO): AHRS_M2.platform_orientation 4.496209 rad 2019-10-17T18:02:16.996Z,1571335336.996 [Reporter](INFO): AHRS_M2.platform_orientation 4.496376 rad 2019-10-17T18:02:17.423Z,1571335337.423 [Reporter](INFO): AHRS_M2.platform_orientation 4.496872 rad 2019-10-17T18:02:17.799Z,1571335337.799 [Reporter](INFO): AHRS_M2.platform_orientation 4.496931 rad 2019-10-17T18:02:18.153Z,1571335338.153 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:18.215Z,1571335338.215 [Reporter](INFO): AHRS_M2.platform_orientation 4.497235 rad 2019-10-17T18:02:18.635Z,1571335338.635 [Reporter](INFO): AHRS_M2.platform_orientation 4.497517 rad 2019-10-17T18:02:19.041Z,1571335339.041 [Reporter](INFO): AHRS_M2.platform_orientation 4.497955 rad 2019-10-17T18:02:19.398Z,1571335339.398 [Reporter](INFO): AHRS_M2.platform_orientation 4.497818 rad 2019-10-17T18:02:19.784Z,1571335339.784 [Reporter](INFO): AHRS_M2.platform_orientation 4.497785 rad 2019-10-17T18:02:20.202Z,1571335340.202 [Reporter](INFO): AHRS_M2.platform_orientation 4.497564 rad 2019-10-17T18:02:20.603Z,1571335340.603 [Reporter](INFO): AHRS_M2.platform_orientation 4.497142 rad 2019-10-17T18:02:20.973Z,1571335340.973 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:21.049Z,1571335341.049 [Reporter](INFO): AHRS_M2.platform_orientation 4.499828 rad 2019-10-17T18:02:21.840Z,1571335341.840 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-17T18:02:21.840Z,1571335341.840 [DVL_micro] No Fault, FailCount= 5 2019-10-17T18:02:21.842Z,1571335341.842 [Reporter](INFO): AHRS_M2.platform_orientation 4.562455 rad 2019-10-17T18:02:22.190Z,1571335342.190 [DVL_micro](INFO): Initializing 2019-10-17T18:02:22.251Z,1571335342.251 [Reporter](INFO): AHRS_M2.platform_orientation 4.613715 rad 2019-10-17T18:02:22.632Z,1571335342.632 [Reporter](INFO): AHRS_M2.platform_orientation 4.654285 rad 2019-10-17T18:02:23.038Z,1571335343.038 [Reporter](INFO): AHRS_M2.platform_orientation 4.664676 rad 2019-10-17T18:02:23.453Z,1571335343.453 [Reporter](INFO): AHRS_M2.platform_orientation 4.628787 rad 2019-10-17T18:02:23.805Z,1571335343.805 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:23.841Z,1571335343.841 [Reporter](INFO): AHRS_M2.platform_orientation 4.568517 rad 2019-10-17T18:02:24.253Z,1571335344.253 [Reporter](INFO): AHRS_M2.platform_orientation 4.511585 rad 2019-10-17T18:02:24.654Z,1571335344.654 [Reporter](INFO): AHRS_M2.platform_orientation 4.500325 rad 2019-10-17T18:02:25.061Z,1571335345.061 [Reporter](INFO): AHRS_M2.platform_orientation 4.497937 rad 2019-10-17T18:02:25.453Z,1571335345.453 [Reporter](INFO): AHRS_M2.platform_orientation 4.534266 rad 2019-10-17T18:02:25.832Z,1571335345.832 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:25.868Z,1571335345.868 [Reporter](INFO): AHRS_M2.platform_orientation 4.591444 rad 2019-10-17T18:02:26.218Z,1571335346.218 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout. 2019-10-17T18:02:26.218Z,1571335346.218 [DVL_micro] Data Fault, FailCount= 1 2019-10-17T18:02:26.218Z,1571335346.218 [DVL_micro](ERROR): Data Fault 2019-10-17T18:02:26.310Z,1571335346.310 [CBIT](ERROR): Data Fault in component: DVL_micro 2019-10-17T18:02:26.312Z,1571335346.312 [Reporter](INFO): AHRS_M2.platform_orientation 4.652339 rad 2019-10-17T18:02:26.685Z,1571335346.685 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T18:02:26.752Z,1571335346.752 [Reporter](INFO): AHRS_M2.platform_orientation 4.670877 rad 2019-10-17T18:02:27.069Z,1571335347.069 [Reporter](INFO): AHRS_M2.platform_orientation 4.680440 rad 2019-10-17T18:02:27.469Z,1571335347.469 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-17T18:02:27.470Z,1571335347.470 [DVL_micro] No Fault, FailCount= 1 2019-10-17T18:02:27.471Z,1571335347.471 [Reporter](INFO): AHRS_M2.platform_orientation 4.690186 rad 2019-10-17T18:02:27.836Z,1571335347.836 [DVL_micro](INFO): Initializing 2019-10-17T18:02:27.898Z,1571335347.898 [Reporter](INFO): AHRS_M2.platform_orientation 4.694544 rad 2019-10-17T18:02:28.280Z,1571335348.280 [Reporter](INFO): AHRS_M2.platform_orientation 4.697290 rad 2019-10-17T18:02:28.688Z,1571335348.688 [Reporter](INFO): AHRS_M2.platform_orientation 4.698364 rad 2019-10-17T18:02:29.053Z,1571335349.053 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:29.101Z,1571335349.101 [Reporter](INFO): AHRS_M2.platform_orientation 4.699936 rad 2019-10-17T18:02:29.513Z,1571335349.513 [Reporter](INFO): AHRS_M2.platform_orientation 4.700607 rad 2019-10-17T18:02:29.925Z,1571335349.925 [Reporter](INFO): AHRS_M2.platform_orientation 4.701131 rad 2019-10-17T18:02:30.296Z,1571335350.296 [Reporter](INFO): AHRS_M2.platform_orientation 4.702224 rad 2019-10-17T18:02:30.707Z,1571335350.707 [Reporter](INFO): AHRS_M2.platform_orientation 4.701241 rad 2019-10-17T18:02:31.127Z,1571335351.127 [Reporter](INFO): AHRS_M2.platform_orientation 4.701219 rad 2019-10-17T18:02:31.199Z,1571335351.199 [CommandLine](IMPORTANT): got command report clear 2019-10-17T18:02:31.889Z,1571335351.889 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:35.121Z,1571335355.121 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:02:37.547Z,1571335357.547 [DAT](FAULT): unknown deviceResponse_: uisition stats SNR:04.9 MPD:16.5 SPD:+07.8 2019-10-17T18:02:37.547Z,1571335357.547 [DAT] Communications Fault, FailCount= 1 2019-10-17T18:02:37.547Z,1571335357.547 [DAT](ERROR): Communications Fault 2019-10-17T18:02:37.548Z,1571335357.548 [DAT](FAULT): unknown deviceResponse_: Header stats CRC:Fail PSNR:10.1 CCERR:006 Mod:MFSK 2019-10-17T18:02:37.610Z,1571335357.610 [CBIT](ERROR): Communications Fault in component: DAT 2019-10-17T18:02:37.938Z,1571335357.938 [NAL9602](FAULT): GPS failed to acquire within timeout. 2019-10-17T18:02:37.938Z,1571335357.938 [NAL9602] Data Fault, FailCount= 2 2019-10-17T18:02:37.938Z,1571335357.938 [NAL9602](ERROR): Data Fault 2019-10-17T18:02:37.953Z,1571335357.953 [DAT](INFO): Powering down 2019-10-17T18:02:38.101Z,1571335358.101 [CBIT](ERROR): Data Fault in component: NAL9602 2019-10-17T18:02:38.339Z,1571335358.339 [NAL9602](INFO): Powering down 2019-10-17T18:02:38.785Z,1571335358.785 [CBIT](INFO): Clearing failed state for component DAT 2019-10-17T18:02:38.785Z,1571335358.785 [DAT] No Fault, FailCount= 1 2019-10-17T18:02:39.204Z,1571335359.204 [CBIT](INFO): Clearing failed state for component NAL9602 2019-10-17T18:02:39.204Z,1571335359.204 [NAL9602] No Fault, FailCount= 2 2019-10-17T18:02:41.184Z,1571335361.184 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2019-10-17T18:02:41.184Z,1571335361.184 [DAT](INFO): Powering up 2019-10-17T18:02:41.184Z,1571335361.184 [DAT](DEBUG): Initializing DAT. 2019-10-17T18:02:41.250Z,1571335361.250 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2019-10-17T18:02:41.570Z,1571335361.570 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-10-17T18:02:41.570Z,1571335361.570 [DVL_micro] Communications Fault, FailCount= 2 2019-10-17T18:02:41.571Z,1571335361.571 [DVL_micro](ERROR): Communications Fault 2019-10-17T18:02:41.657Z,1571335361.657 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-17T18:02:42.041Z,1571335362.041 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T18:02:42.820Z,1571335362.820 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-17T18:02:42.820Z,1571335362.820 [DVL_micro] No Fault, FailCount= 2 2019-10-17T18:02:43.192Z,1571335363.192 [DVL_micro](INFO): Initializing 2019-10-17T18:02:54.520Z,1571335374.520 [DAT](INFO): setting local address to 2 2019-10-17T18:02:54.913Z,1571335374.913 [DAT](INFO): set local address to 2 2019-10-17T18:02:56.918Z,1571335376.918 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-10-17T18:02:56.918Z,1571335376.918 [DVL_micro] Communications Fault, FailCount= 3 2019-10-17T18:02:56.918Z,1571335376.918 [DVL_micro](ERROR): Communications Fault 2019-10-17T18:02:57.003Z,1571335377.003 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-17T18:02:57.397Z,1571335377.397 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T18:02:58.181Z,1571335378.181 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-17T18:02:58.181Z,1571335378.181 [DVL_micro] No Fault, FailCount= 3 2019-10-17T18:02:58.552Z,1571335378.552 [DVL_micro](INFO): Initializing 2019-10-17T18:03:08.635Z,1571335388.635 [NAL9602](INFO): Powering up NAL9602 2019-10-17T18:03:09.069Z,1571335389.069 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2019-10-17T18:03:09.069Z,1571335389.069 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2019-10-17T18:03:09.079Z,1571335389.079 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2019-10-17T18:03:09.486Z,1571335389.486 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2019-10-17T18:03:09.486Z,1571335389.486 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2019-10-17T18:03:12.271Z,1571335392.271 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-10-17T18:03:12.272Z,1571335392.272 [DVL_micro] Communications Fault, FailCount= 4 2019-10-17T18:03:12.272Z,1571335392.272 [DVL_micro](ERROR): Communications Fault 2019-10-17T18:03:12.303Z,1571335392.303 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-17T18:03:12.745Z,1571335392.745 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T18:03:13.513Z,1571335393.513 [CBIT](INFO): Clearing failed state for component DVL_micro 2019-10-17T18:03:13.513Z,1571335393.513 [DVL_micro] No Fault, FailCount= 4 2019-10-17T18:03:13.897Z,1571335393.897 [DVL_micro](INFO): Initializing 2019-10-17T18:03:19.543Z,1571335399.543 [NAL9602](INFO): NAL9602 initialized 2019-10-17T18:03:20.365Z,1571335400.365 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:23.207Z,1571335403.207 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:26.024Z,1571335406.024 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:27.622Z,1571335407.622 [DVL_micro](ERROR): No DVL communication! Re-initializing 2019-10-17T18:03:27.622Z,1571335407.622 [DVL_micro] Communications Fault, FailCount= 5 2019-10-17T18:03:27.622Z,1571335407.622 [DVL_micro](ERROR): Communications Fault 2019-10-17T18:03:27.696Z,1571335407.696 [CBIT](ERROR): Communications Fault in component: DVL_micro 2019-10-17T18:03:27.696Z,1571335407.696 [CBIT](CRITICAL): Communications Fault in component: DVL_micro 2019-10-17T18:03:28.097Z,1571335408.097 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T18:03:28.109Z,1571335408.109 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:28.160Z,1571335408.160 [CBIT](INFO): Critical error at 20191017T180327 2019-10-17T18:03:31.269Z,1571335411.269 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:34.105Z,1571335414.105 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:37.333Z,1571335417.333 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:40.165Z,1571335420.165 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:43.401Z,1571335423.401 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:46.225Z,1571335426.225 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:49.051Z,1571335429.051 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:51.065Z,1571335431.065 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:54.297Z,1571335434.297 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:03:57.129Z,1571335437.129 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:00.365Z,1571335440.365 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:03.197Z,1571335443.197 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:06.425Z,1571335446.425 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:09.253Z,1571335449.253 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:12.073Z,1571335452.073 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:14.093Z,1571335454.093 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:16.113Z,1571335456.113 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:19.345Z,1571335459.345 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:22.177Z,1571335462.177 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:23.072Z,1571335463.072 [CommandLine](IMPORTANT): got command quit 2019-10-17T18:04:24.085Z,1571335464.085 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-17T18:04:24.086Z,1571335464.086 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:24.241Z,1571335464.241 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2019-10-17T18:04:24.241Z,1571335464.241 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:24.242Z,1571335464.242 [CommandLine](INFO): Join timeout helper Thread ID is 2144 2019-10-17T18:04:24.249Z,1571335464.249 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2019-10-17T18:04:24.249Z,1571335464.249 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:24.249Z,1571335464.249 [NavChartDb](INFO): Join timeout helper Thread ID is 2145 2019-10-17T18:04:24.341Z,1571335464.341 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-17T18:04:24.341Z,1571335464.341 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:24.349Z,1571335464.349 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2019-10-17T18:04:24.349Z,1571335464.349 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:24.349Z,1571335464.349 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2146 2019-10-17T18:04:24.807Z,1571335464.807 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-17T18:04:24.808Z,1571335464.808 [WetLabsBB2FL](INFO): Powering down 2019-10-17T18:04:24.810Z,1571335464.810 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:24.813Z,1571335464.813 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2019-10-17T18:04:24.813Z,1571335464.813 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:24.813Z,1571335464.813 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2147 2019-10-17T18:04:25.017Z,1571335465.017 [CTD_Seabird](INFO): Powering down 2019-10-17T18:04:25.029Z,1571335465.029 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-17T18:04:25.029Z,1571335465.029 [CTD_Seabird](INFO): Powering down 2019-10-17T18:04:25.041Z,1571335465.041 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.057Z,1571335465.057 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler 2019-10-17T18:04:25.057Z,1571335465.057 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.057Z,1571335465.057 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 2148 2019-10-17T18:04:25.157Z,1571335465.157 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-17T18:04:25.157Z,1571335465.157 [CTD_NeilBrown](INFO): Powering down 2019-10-17T18:04:25.169Z,1571335465.169 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.182Z,1571335465.182 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2019-10-17T18:04:25.182Z,1571335465.182 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.182Z,1571335465.182 [Radio_Surface](INFO): Join timeout helper Thread ID is 2149 2019-10-17T18:04:25.405Z,1571335465.405 [NAL9602](DEBUG): Fix Requested 2019-10-17T18:04:25.569Z,1571335465.569 [Radio_Surface](INFO): Powering down 2019-10-17T18:04:25.570Z,1571335465.570 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-17T18:04:25.570Z,1571335465.570 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.574Z,1571335465.574 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2019-10-17T18:04:25.574Z,1571335465.574 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.574Z,1571335465.574 [DataOverHttps](INFO): Join timeout helper Thread ID is 2150 2019-10-17T18:04:25.913Z,1571335465.913 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-17T18:04:25.913Z,1571335465.913 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.921Z,1571335465.921 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2019-10-17T18:04:25.922Z,1571335465.922 [logger ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.922Z,1571335465.922 [logger](INFO): Join timeout helper Thread ID is 2151 2019-10-17T18:04:25.945Z,1571335465.945 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-17T18:04:25.945Z,1571335465.945 [logger ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.961Z,1571335465.961 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2019-10-17T18:04:25.962Z,1571335465.962 [CommandLine ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.962Z,1571335465.962 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2019-10-17T18:04:25.962Z,1571335465.962 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:25.962Z,1571335465.962 [controlThread](INFO): Join timeout helper Thread ID is 2152 2019-10-17T18:04:26.193Z,1571335466.193 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2019-10-17T18:04:26.193Z,1571335466.193 [controlThread](DEBUG): Uninitializing ControlThread 2019-10-17T18:04:26.193Z,1571335466.193 [AHRS_M2](INFO): Powering down 2019-10-17T18:04:26.265Z,1571335466.265 [DVL_micro](INFO): uninitialize:Powering down 2019-10-17T18:04:26.266Z,1571335466.266 [NAL9602](INFO): Powering down 2019-10-17T18:04:26.268Z,1571335466.268 [DAT](INFO): Powering down 2019-10-17T18:04:26.385Z,1571335466.385 [Aanderaa_O2](INFO): Powering down 2019-10-17T18:04:26.387Z,1571335466.387 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2019-10-17T18:04:26.388Z,1571335466.388 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2019-10-17T18:04:26.388Z,1571335466.388 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2019-10-17T18:04:26.389Z,1571335466.389 [MissionManager](INFO): Uninitializing Mission Default 2019-10-17T18:04:26.389Z,1571335466.389 [Default] Stopped 2019-10-17T18:04:26.389Z,1571335466.389 [Default](DEBUG): Aggregate::uninitialize Default 2019-10-17T18:04:26.389Z,1571335466.389 [Default:B.GoToSurface] Stopped 2019-10-17T18:04:26.389Z,1571335466.389 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2019-10-17T18:04:26.389Z,1571335466.389 [Default:CheckIn] Stopped 2019-10-17T18:04:26.389Z,1571335466.389 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2019-10-17T18:04:26.389Z,1571335466.389 [Default:CheckIn:C.Wait] Stopped 2019-10-17T18:04:26.389Z,1571335466.389 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2019-10-17T18:04:26.392Z,1571335466.392 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2019-10-17T18:04:26.392Z,1571335466.392 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2019-10-17T18:04:26.392Z,1571335466.392 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2019-10-17T18:04:26.393Z,1571335466.393 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2019-10-17T18:04:26.393Z,1571335466.393 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2019-10-17T18:04:26.393Z,1571335466.393 [BuoyancyServo](INFO): Powering down 2019-10-17T18:04:26.405Z,1571335466.405 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2019-10-17T18:04:26.405Z,1571335466.405 [ElevatorServo](INFO): Powering down 2019-10-17T18:04:26.406Z,1571335466.406 [MassServo](DEBUG): Uninitialize Mass Servo. 2019-10-17T18:04:26.406Z,1571335466.406 [MassServo](INFO): Powering down 2019-10-17T18:04:26.407Z,1571335466.407 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2019-10-17T18:04:26.407Z,1571335466.407 [RudderServo](INFO): Powering down 2019-10-17T18:04:26.407Z,1571335466.407 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2019-10-17T18:04:26.408Z,1571335466.408 [ThrusterServo](INFO): Powering down 2019-10-17T18:04:26.408Z,1571335466.408 [SBIT](DEBUG): Uninitialize SBIT Component. 2019-10-17T18:04:26.409Z,1571335466.409 [IBIT](DEBUG): Uninitialize IBIT Component. 2019-10-17T18:04:26.409Z,1571335466.409 [CBIT](DEBUG): Uninitialize CBIT Component. 2019-10-17T18:04:26.409Z,1571335466.409 [CBIT](DEBUG): Powering off loads. 2019-10-17T18:04:26.421Z,1571335466.421 [CBIT](DEBUG): Disabling WDT. 2019-10-17T18:04:26.433Z,1571335466.433 [CBIT](DEBUG): Opening all GF detection circuits. 2019-10-17T18:04:26.433Z,1571335466.433 [controlThread ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:26.516Z,1571335466.516 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:26.525Z,1571335466.525 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:26.556Z,1571335466.556 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:26.559Z,1571335466.559 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:26.562Z,1571335466.562 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:26.599Z,1571335466.599 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2019-10-17T18:04:26.657Z,1571335466.657 [logger ThreadHandler](INFO): Thread cancelled.