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.