2019-10-17T17:08:19.574Z,1571332099.574 [Supervisor](DEBUG): Initializing supervisor.
2019-10-17T17:08:19.577Z,1571332099.577 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-10-17T17:08:19.577Z,1571332099.577 [SyncHandler](INFO): Protected caller Thread ID is 807
2019-10-17T17:08:19.578Z,1571332099.578 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-10-17T17:08:19.579Z,1571332099.579 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-10-17T17:08:19.579Z,1571332099.579 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 808
2019-10-17T17:08:19.582Z,1571332099.582 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-10-17T17:08:19.592Z,1571332099.592 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-10-17T17:08:19.593Z,1571332099.593 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-10-17T17:08:19.594Z,1571332099.594 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 809
2019-10-17T17:08:19.594Z,1571332099.594 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-10-17T17:08:19.595Z,1571332099.595 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-10-17T17:08:19.596Z,1571332099.596 [logger ThreadHandler](INFO): Protected caller Thread ID is 810
2019-10-17T17:08:19.598Z,1571332099.598 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-10-17T17:08:19.598Z,1571332099.598 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-10-17T17:08:19.602Z,1571332099.602 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-10-17T17:08:19.798Z,1571332099.798 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-10-17T17:08:19.800Z,1571332099.800 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-10-17T17:08:19.881Z,1571332099.881 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-10-17T17:08:20.302Z,1571332100.302 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-10-17T17:08:20.303Z,1571332100.303 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-10-17T17:08:20.621Z,1571332100.621 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-10-17T17:08:20.623Z,1571332100.623 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-10-17T17:08:20.717Z,1571332100.717 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-10-17T17:08:20.719Z,1571332100.719 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-10-17T17:08:21.008Z,1571332101.008 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-10-17T17:08:21.009Z,1571332101.009 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-10-17T17:08:21.198Z,1571332101.198 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-10-17T17:08:21.199Z,1571332101.199 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-10-17T17:08:21.638Z,1571332101.638 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-10-17T17:08:21.639Z,1571332101.639 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-10-17T17:08:21.741Z,1571332101.741 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-10-17T17:08:21.743Z,1571332101.743 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-10-17T17:08:21.842Z,1571332101.842 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-10-17T17:08:21.844Z,1571332101.844 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-10-17T17:08:22.426Z,1571332102.426 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-10-17T17:08:22.426Z,1571332102.426 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-10-17T17:08:22.810Z,1571332102.810 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-10-17T17:08:22.812Z,1571332102.812 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-10-17T17:08:23.003Z,1571332103.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-10-17T17:08:23.005Z,1571332103.005 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-10-17T17:08:23.750Z,1571332103.750 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-10-17T17:08:23.751Z,1571332103.751 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-10-17T17:08:24.123Z,1571332104.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-10-17T17:08:24.125Z,1571332104.125 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-10-17T17:08:24.129Z,1571332104.129 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-10-17T17:08:24.219Z,1571332104.219 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-10-17T17:08:24.304Z,1571332104.304 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-10-17T17:08:24.407Z,1571332104.407 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-10-17T17:08:24.490Z,1571332104.490 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-10-17T17:08:24.584Z,1571332104.584 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-10-17T17:08:24.684Z,1571332104.684 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-10-17T17:08:24.890Z,1571332104.890 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-10-17T17:08:24.966Z,1571332104.966 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-10-17T17:08:25.130Z,1571332105.130 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-10-17T17:08:25.263Z,1571332105.263 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-10-17T17:08:25.379Z,1571332105.379 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-10-17T17:08:25.605Z,1571332105.605 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-10-17T17:08:25.605Z,1571332105.605 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2019-10-17T17:08:25.611Z,1571332105.611 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-10-17T17:08:25.699Z,1571332105.699 [VerticalControl](DEBUG): Construct VerticalControl.
2019-10-17T17:08:25.808Z,1571332105.808 [VerticalControl] Loaded
2019-10-17T17:08:25.809Z,1571332105.809 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-10-17T17:08:25.809Z,1571332105.809 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-10-17T17:08:25.876Z,1571332105.876 [HorizontalControl] Loaded
2019-10-17T17:08:25.876Z,1571332105.876 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-10-17T17:08:25.877Z,1571332105.877 [SpeedControl](DEBUG): Construct SpeedControl.
2019-10-17T17:08:25.882Z,1571332105.882 [SpeedControl] Loaded
2019-10-17T17:08:25.883Z,1571332105.883 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-10-17T17:08:25.883Z,1571332105.883 [LoopControl](DEBUG): Construct LoopControl.
2019-10-17T17:08:25.884Z,1571332105.884 [LoopControl] Loaded
2019-10-17T17:08:25.884Z,1571332105.884 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-10-17T17:08:25.885Z,1571332105.885 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-10-17T17:08:25.887Z,1571332105.887 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-10-17T17:08:25.910Z,1571332105.910 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-10-17T17:08:25.912Z,1571332105.912 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-10-17T17:08:26.035Z,1571332106.035 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-10-17T17:08:26.036Z,1571332106.036 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-10-17T17:08:26.186Z,1571332106.186 [BuoyancyServo] Loaded
2019-10-17T17:08:26.187Z,1571332106.187 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-10-17T17:08:26.197Z,1571332106.197 [ElevatorServo] Loaded
2019-10-17T17:08:26.198Z,1571332106.198 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-10-17T17:08:26.208Z,1571332106.208 [MassServo] Loaded
2019-10-17T17:08:26.209Z,1571332106.209 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-10-17T17:08:26.219Z,1571332106.219 [RudderServo] Loaded
2019-10-17T17:08:26.220Z,1571332106.220 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-10-17T17:08:26.231Z,1571332106.231 [ThrusterServo] Loaded
2019-10-17T17:08:26.231Z,1571332106.231 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-10-17T17:08:26.231Z,1571332106.231 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-10-17T17:08:26.232Z,1571332106.232 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-10-17T17:08:26.354Z,1571332106.354 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-10-17T17:08:26.354Z,1571332106.354 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-10-17T17:08:26.374Z,1571332106.374 [NavChart] Loaded
2019-10-17T17:08:26.374Z,1571332106.374 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-10-17T17:08:26.378Z,1571332106.378 [UniversalFixResidualReporter] Loaded
2019-10-17T17:08:26.378Z,1571332106.378 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-10-17T17:08:26.379Z,1571332106.379 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-10-17T17:08:26.381Z,1571332106.381 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-10-17T17:08:26.491Z,1571332106.491 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-10-17T17:08:26.492Z,1571332106.492 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-10-17T17:08:26.972Z,1571332106.972 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-10-17T17:08:26.977Z,1571332106.977 [AHRS_M2](INFO): created writer for : platform_orientation
2019-10-17T17:08:26.979Z,1571332106.979 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-10-17T17:08:26.984Z,1571332106.984 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-10-17T17:08:26.985Z,1571332106.985 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-10-17T17:08:26.989Z,1571332106.989 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-10-17T17:08:26.990Z,1571332106.990 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-10-17T17:08:26.995Z,1571332106.995 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-10-17T17:08:27.170Z,1571332107.170 [AHRS_M2] Loaded
2019-10-17T17:08:27.171Z,1571332107.171 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-10-17T17:08:27.314Z,1571332107.314 [DataOverHttps] Loaded
2019-10-17T17:08:27.314Z,1571332107.314 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-10-17T17:08:27.315Z,1571332107.315 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4087D4E0
2019-10-17T17:08:27.315Z,1571332107.315 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 892
2019-10-17T17:08:27.328Z,1571332107.328 [Depth_Keller] Loaded
2019-10-17T17:08:27.329Z,1571332107.329 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-10-17T17:08:27.334Z,1571332107.334 [DropWeight] Loaded
2019-10-17T17:08:27.334Z,1571332107.334 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-10-17T17:08:27.459Z,1571332107.459 [DVL_micro] Loaded
2019-10-17T17:08:27.460Z,1571332107.460 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2019-10-17T17:08:27.555Z,1571332107.555 [NAL9602] Loaded
2019-10-17T17:08:27.555Z,1571332107.555 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-10-17T17:08:27.571Z,1571332107.571 [Onboard] Loaded
2019-10-17T17:08:27.571Z,1571332107.571 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-10-17T17:08:27.574Z,1571332107.574 [Radio_Surface] Loaded
2019-10-17T17:08:27.575Z,1571332107.575 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-10-17T17:08:27.575Z,1571332107.575 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408AD4E0
2019-10-17T17:08:27.576Z,1571332107.576 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 893
2019-10-17T17:08:27.700Z,1571332107.700 [DAT] Loaded
2019-10-17T17:08:27.700Z,1571332107.700 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2019-10-17T17:08:30.032Z,1571332110.032 [BPC1] Loaded
2019-10-17T17:08:30.032Z,1571332110.032 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-10-17T17:08:30.033Z,1571332110.033 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-10-17T17:08:30.033Z,1571332110.033 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-10-17T17:08:30.088Z,1571332110.088 [DepthRateCalculator] Loaded
2019-10-17T17:08:30.088Z,1571332110.088 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-10-17T17:08:30.093Z,1571332110.093 [PitchRateCalculator] Loaded
2019-10-17T17:08:30.093Z,1571332110.093 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-10-17T17:08:30.104Z,1571332110.104 [SpeedCalculator] Loaded
2019-10-17T17:08:30.105Z,1571332110.105 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-10-17T17:08:30.125Z,1571332110.125 [TempGradientCalculator] Loaded
2019-10-17T17:08:30.126Z,1571332110.126 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-10-17T17:08:30.131Z,1571332110.131 [YawRateCalculator] Loaded
2019-10-17T17:08:30.131Z,1571332110.131 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-10-17T17:08:30.160Z,1571332110.160 [ElevatorOffsetCalculator] Loaded
2019-10-17T17:08:30.160Z,1571332110.160 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-10-17T17:08:30.160Z,1571332110.160 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-10-17T17:08:30.161Z,1571332110.161 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-10-17T17:08:30.417Z,1571332110.417 [Aanderaa_O2] Loaded
2019-10-17T17:08:30.417Z,1571332110.417 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-10-17T17:08:30.500Z,1571332110.500 [CTD_NeilBrown] Loaded
2019-10-17T17:08:30.500Z,1571332110.500 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-10-17T17:08:30.501Z,1571332110.501 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 409B04E0
2019-10-17T17:08:30.502Z,1571332110.502 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 894
2019-10-17T17:08:30.511Z,1571332110.511 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-10-17T17:08:30.515Z,1571332110.515 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-10-17T17:08:30.516Z,1571332110.516 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-10-17T17:08:30.521Z,1571332110.521 [CTD_Seabird](INFO): created writer for : depth
2019-10-17T17:08:30.521Z,1571332110.521 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-10-17T17:08:30.526Z,1571332110.526 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-10-17T17:08:30.527Z,1571332110.527 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-10-17T17:08:30.532Z,1571332110.532 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-10-17T17:08:30.532Z,1571332110.532 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-10-17T17:08:30.537Z,1571332110.537 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-10-17T17:08:30.538Z,1571332110.538 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-10-17T17:08:30.543Z,1571332110.543 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-10-17T17:08:30.543Z,1571332110.543 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-10-17T17:08:30.548Z,1571332110.548 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-10-17T17:08:30.575Z,1571332110.575 [CTD_Seabird] Loaded
2019-10-17T17:08:30.575Z,1571332110.575 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-10-17T17:08:30.576Z,1571332110.576 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409E04E0
2019-10-17T17:08:30.577Z,1571332110.577 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 895
2019-10-17T17:08:30.591Z,1571332110.591 [PAR_Licor] Loaded
2019-10-17T17:08:30.591Z,1571332110.591 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-10-17T17:08:30.639Z,1571332110.639 [WetLabsBB2FL] Loaded
2019-10-17T17:08:30.639Z,1571332110.639 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-10-17T17:08:30.640Z,1571332110.640 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A104E0
2019-10-17T17:08:30.640Z,1571332110.640 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 896
2019-10-17T17:08:30.641Z,1571332110.641 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-10-17T17:08:30.643Z,1571332110.643 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-10-17T17:08:30.691Z,1571332110.691 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-10-17T17:08:30.691Z,1571332110.691 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-10-17T17:08:31.023Z,1571332111.023 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-10-17T17:08:31.024Z,1571332111.024 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-10-17T17:08:31.182Z,1571332111.182 [SBIT](DEBUG): Construct Startup Built In Test.
2019-10-17T17:08:31.193Z,1571332111.193 [SBIT] Loaded
2019-10-17T17:08:31.193Z,1571332111.193 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-10-17T17:08:31.194Z,1571332111.194 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-10-17T17:08:31.205Z,1571332111.205 [IBIT] Loaded
2019-10-17T17:08:31.205Z,1571332111.205 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-10-17T17:08:31.208Z,1571332111.208 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-10-17T17:08:31.346Z,1571332111.346 [CBIT] Loaded
2019-10-17T17:08:31.346Z,1571332111.346 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-10-17T17:08:31.347Z,1571332111.347 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-10-17T17:08:31.350Z,1571332111.350 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-10-17T17:08:31.351Z,1571332111.351 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-10-17T17:08:31.358Z,1571332111.358 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-10-17T17:08:31.359Z,1571332111.359 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B0F4E0
2019-10-17T17:08:31.359Z,1571332111.359 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 897
2019-10-17T17:08:31.364Z,1571332111.364 [Supervisor](INFO): Main Thread ID is 803
2019-10-17T17:08:31.364Z,1571332111.364 [Supervisor](DEBUG): Running supervisor.
2019-10-17T17:08:31.364Z,1571332111.364 [CommandLine ThreadHandler](INFO): Handler Thread ID is 898
2019-10-17T17:08:31.367Z,1571332111.367 [controlThread ThreadHandler](INFO): Handler Thread ID is 899
2019-10-17T17:08:31.367Z,1571332111.367 [controlThread](DEBUG): Initializing ControlThread
2019-10-17T17:08:31.368Z,1571332111.368 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-10-17T17:08:31.369Z,1571332111.369 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-10-17T17:08:31.370Z,1571332111.370 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-10-17T17:08:31.371Z,1571332111.371 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-10-17T17:08:31.372Z,1571332111.372 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-10-17T17:08:31.373Z,1571332111.373 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-10-17T17:08:31.379Z,1571332111.379 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-10-17T17:08:31.380Z,1571332111.380 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-10-17T17:08:31.380Z,1571332111.380 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-10-17T17:08:31.380Z,1571332111.380 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-10-17T17:08:31.381Z,1571332111.381 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-10-17T17:08:31.381Z,1571332111.381 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-10-17T17:08:31.385Z,1571332111.385 [SBIT](INFO): Initialize SBIT Component.
2019-10-17T17:08:31.386Z,1571332111.386 [SBIT](IMPORTANT): git: 2019-09-10
2019-10-17T17:08:31.386Z,1571332111.386 [SBIT](INFO): git hash: e950883795b57abbf97d89589ea0268241928c93
2019-10-17T17:08:31.386Z,1571332111.386 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-10-17T17:08:31.387Z,1571332111.387 [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:08:31.388Z,1571332111.388 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2019-10-17T17:08:31.389Z,1571332111.389 [IBIT](INFO): Initialize IBIT Component.
2019-10-17T17:08:31.390Z,1571332111.390 [CBIT](DEBUG): Initialize CBIT Component.
2019-10-17T17:08:31.391Z,1571332111.391 [logger ThreadHandler](INFO): Handler Thread ID is 900
2019-10-17T17:08:31.401Z,1571332111.401 [CBIT](DEBUG): Initialized mux pins.
2019-10-17T17:08:31.401Z,1571332111.401 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2019-10-17T17:08:31.401Z,1571332111.401 [CBIT](DEBUG): Initializing the watchdog timer.
2019-10-17T17:08:31.409Z,1571332111.409 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 901
2019-10-17T17:08:31.410Z,1571332111.410 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-10-17T17:08:31.421Z,1571332111.421 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 902
2019-10-17T17:08:31.425Z,1571332111.425 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-10-17T17:08:31.425Z,1571332111.425 [CBIT](DEBUG): Initializing heartbeat.
2019-10-17T17:08:31.433Z,1571332111.433 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 903
2019-10-17T17:08:31.434Z,1571332111.434 [CTD_NeilBrown](INFO): Powering down
2019-10-17T17:08:31.458Z,1571332111.458 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 904
2019-10-17T17:08:31.458Z,1571332111.458 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-10-17T17:08:31.465Z,1571332111.465 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-10-17T17:08:31.467Z,1571332111.467 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 906
2019-10-17T17:08:31.468Z,1571332111.468 [WetLabsBB2FL](INFO): Powering down
2019-10-17T17:08:31.497Z,1571332111.497 [CBIT](DEBUG): Deactivating GF circuits.
2019-10-17T17:08:31.497Z,1571332111.497 [CBIT](DEBUG): Deactivating emergency mode.
2019-10-17T17:08:31.498Z,1571332111.498 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 907
2019-10-17T17:08:31.509Z,1571332111.509 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-10-17T17:08:31.509Z,1571332111.509 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-10-17T17:08:31.509Z,1571332111.509 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-10-17T17:08:31.509Z,1571332111.509 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-10-17T17:08:31.510Z,1571332111.510 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-10-17T17:08:31.510Z,1571332111.510 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-10-17T17:08:31.510Z,1571332111.510 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-10-17T17:08:31.510Z,1571332111.510 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-10-17T17:08:31.510Z,1571332111.510 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-10-17T17:08:31.510Z,1571332111.510 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-10-17T17:08:31.511Z,1571332111.511 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-10-17T17:08:31.511Z,1571332111.511 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-10-17T17:08:31.511Z,1571332111.511 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-10-17T17:08:31.511Z,1571332111.511 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-10-17T17:08:31.511Z,1571332111.511 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-10-17T17:08:31.512Z,1571332111.512 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-10-17T17:08:31.533Z,1571332111.533 [CBIT](DEBUG): Backplane powered.
2019-10-17T17:08:31.534Z,1571332111.534 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-10-17T17:08:31.558Z,1571332111.558 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-17T17:08:31.569Z,1571332111.569 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2019-10-17T17:08:31.570Z,1571332111.570 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-10-17T17:08:31.645Z,1571332111.645 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-10-17T17:08:31.646Z,1571332111.646 [Default:A.Wait](DEBUG): Construct Wait.
2019-10-17T17:08:31.648Z,1571332111.648 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-10-17T17:08:31.678Z,1571332111.678 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-10-17T17:08:31.697Z,1571332111.697 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-10-17T17:08:31.702Z,1571332111.702 [Default:E.Execute](DEBUG): Construct Execute.
2019-10-17T17:08:31.725Z,1571332111.725 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2019-10-17T17:08:31.730Z,1571332111.730 [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:08:31.735Z,1571332111.735 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-10-17T17:08:31.825Z,1571332111.825 [Radio_Surface](INFO): Powering up
2019-10-17T17:08:31.886Z,1571332111.886 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2019-10-17T17:08:31.905Z,1571332111.905 [DVL_micro](INFO): Initializing
2019-10-17T17:08:31.931Z,1571332111.931 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-10-17T17:08:31.931Z,1571332111.931 [DAT](INFO): Powering up
2019-10-17T17:08:31.931Z,1571332111.931 [DAT](DEBUG): Initializing DAT.
2019-10-17T17:08:31.965Z,1571332111.965 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-10-17T17:08:32.007Z,1571332112.007 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-10-17T17:08:32.063Z,1571332112.063 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:08:32.069Z,1571332112.069 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-10-17T17:08:32.070Z,1571332112.070 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:08:32.081Z,1571332112.081 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-17T17:08:32.082Z,1571332112.082 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:08:32.093Z,1571332112.093 [MassServo](DEBUG): Initializing MassServo.
2019-10-17T17:08:32.094Z,1571332112.094 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:08:32.105Z,1571332112.105 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-17T17:08:32.106Z,1571332112.106 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:08:32.113Z,1571332112.113 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-10-17T17:08:32.299Z,1571332112.299 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-10-17T17:08:32.299Z,1571332112.299 [DropWeight] Hardware Fault, FailCount= 1
2019-10-17T17:08:32.299Z,1571332112.299 [DropWeight](ERROR): Hardware Fault
2019-10-17T17:08:32.378Z,1571332112.378 [CommandLine](FAULT): Scheduling is paused
2019-10-17T17:08:32.378Z,1571332112.378 [CBIT](INFO): Critical error at 20191017T170832
2019-10-17T17:08:32.379Z,1571332112.379 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-10-17T17:08:32.381Z,1571332112.381 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-10-17T17:08:32.382Z,1571332112.382 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-10-17T17:08:32.949Z,1571332112.949 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-10-17T17:08:32.949Z,1571332112.949 [RudderServo](FAULT): Rudder failed to initialize
2019-10-17T17:08:32.949Z,1571332112.949 [RudderServo] Communications Fault, FailCount= 1
2019-10-17T17:08:32.949Z,1571332112.949 [RudderServo](ERROR): Communications Fault
2019-10-17T17:08:33.130Z,1571332113.130 [CBIT](INFO): Critical error at 20191017T170832
2019-10-17T17:08:33.133Z,1571332113.133 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-10-17T17:08:33.335Z,1571332113.335 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-17T17:08:33.336Z,1571332113.336 [RudderServo](INFO): Powering down
2019-10-17T17:08:34.020Z,1571332114.020 [RudderServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:08:34.146Z,1571332114.146 [RudderServo](DEBUG): Initializing RudderServo.
2019-10-17T17:08:34.150Z,1571332114.150 [CBIT](INFO): Clearing failed state for component RudderServo
2019-10-17T17:08:34.150Z,1571332114.150 [RudderServo] No Fault, FailCount= 1
2019-10-17T17:08:35.381Z,1571332115.381 [Aanderaa_O2](INFO): Powering down
2019-10-17T17:08:45.814Z,1571332125.814 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:08:45.814Z,1571332125.814 [DVL_micro] Communications Fault, FailCount= 1
2019-10-17T17:08:45.814Z,1571332125.814 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:08:45.830Z,1571332125.830 [DAT](INFO): setting local address to 2
2019-10-17T17:08:45.890Z,1571332125.890 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:08:46.293Z,1571332126.293 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:08:46.310Z,1571332126.310 [DAT](INFO): set local address to 2
2019-10-17T17:08:47.121Z,1571332127.121 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:08:47.121Z,1571332127.121 [DVL_micro] No Fault, FailCount= 1
2019-10-17T17:08:47.436Z,1571332127.436 [DVL_micro](INFO): Initializing
2019-10-17T17:08:54.759Z,1571332134.759 [SBIT](IMPORTANT): Beginning Startup BIT
2019-10-17T17:08:54.771Z,1571332134.771 [CBIT](IMPORTANT): Beginning ground fault scan
2019-10-17T17:08:57.765Z,1571332137.765 [NAL9602](INFO): Powering up NAL9602
2019-10-17T17:09:01.394Z,1571332141.394 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:09:01.394Z,1571332141.394 [DVL_micro] Communications Fault, FailCount= 2
2019-10-17T17:09:01.394Z,1571332141.394 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:09:01.498Z,1571332141.498 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:09:01.877Z,1571332141.877 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:09:02.698Z,1571332142.698 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:09:02.699Z,1571332142.699 [DVL_micro] No Fault, FailCount= 2
2019-10-17T17:09:03.016Z,1571332143.016 [DVL_micro](INFO): Initializing
2019-10-17T17:09:05.523Z,1571332145.523 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.011041
CHAN A1 (24V): 0.046835
CHAN A2 (12V): 4.697929
CHAN A3 (5V): -0.001177
CHAN B0 (3.3V): -0.000242
CHAN B1 (3.15aV): -0.000117
CHAN B2 (3.15bV): -0.000166
CHAN B3 (GND): -0.000157
OPEN: -0.000450
Full Scale Calc: 4.765 mA, -1.589 mA
2019-10-17T17:09:08.674Z,1571332148.674 [NAL9602](INFO): NAL9602 initialized
2019-10-17T17:09:09.485Z,1571332149.485 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:09:16.890Z,1571332156.890 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:09:16.890Z,1571332156.890 [DVL_micro] Communications Fault, FailCount= 3
2019-10-17T17:09:16.890Z,1571332156.890 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:09:17.014Z,1571332157.014 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:09:17.365Z,1571332157.365 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:09:18.224Z,1571332158.224 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:09:18.225Z,1571332158.225 [DVL_micro] No Fault, FailCount= 3
2019-10-17T17:09:18.512Z,1571332158.512 [DVL_micro](INFO): Initializing
2019-10-17T17:09:32.246Z,1571332172.246 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:09:32.246Z,1571332172.246 [DVL_micro] Communications Fault, FailCount= 4
2019-10-17T17:09:32.246Z,1571332172.246 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:09:32.312Z,1571332172.312 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:09:32.725Z,1571332172.725 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:09:33.519Z,1571332173.519 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:09:33.519Z,1571332173.519 [DVL_micro] No Fault, FailCount= 4
2019-10-17T17:09:33.864Z,1571332173.864 [DVL_micro](INFO): Initializing
2019-10-17T17:09:47.698Z,1571332187.698 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:09:47.698Z,1571332187.698 [DVL_micro] Communications Fault, FailCount= 5
2019-10-17T17:09:47.698Z,1571332187.698 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:09:47.797Z,1571332187.797 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:09:47.798Z,1571332187.798 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2019-10-17T17:09:48.177Z,1571332188.177 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:09:48.287Z,1571332188.287 [CBIT](INFO): Critical error at 20191017T170947
2019-10-17T17:09:48.618Z,1571332188.618 [SBIT](IMPORTANT): SBIT PASSED
2019-10-17T17:09:48.682Z,1571332188.682 [CommandLine](IMPORTANT): got command configSet list
2019-10-17T17:09:48.682Z,1571332188.682 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-10-17T17:09:48.686Z,1571332188.686 [CommandLine](IMPORTANT): CBIT.gf24Offset=154 microampere;

2019-10-17T17:09:48.686Z,1571332188.686 [CommandLine](IMPORTANT): CTD_NeilBrown.loadAtStartup=0 bool;

2019-10-17T17:09:48.686Z,1571332188.686 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2019-10-17T17:09:48.686Z,1571332188.686 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-10-17T17:09:48.958Z,1571332188.958 [MissionManager](IMPORTANT): Started mission Startup
2019-10-17T17:09:48.958Z,1571332188.958 [Startup] Running Loop=1
2019-10-17T17:09:48.959Z,1571332188.959 [Startup](DEBUG): Aggregate::initialize Startup
2019-10-17T17:09:48.959Z,1571332188.959 [Startup:A.GoToSurface] Running Loop=1
2019-10-17T17:09:48.959Z,1571332188.959 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-17T17:09:48.959Z,1571332188.959 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-17T17:09:48.960Z,1571332188.960 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-17T17:09:48.960Z,1571332188.960 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-17T17:09:48.960Z,1571332188.960 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-17T17:09:48.961Z,1571332188.961 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-17T17:09:48.962Z,1571332188.962 [Startup:StartupSatComms] Running Loop=1
2019-10-17T17:09:48.963Z,1571332188.963 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-10-17T17:09:48.963Z,1571332188.963 [Startup:StartupSatComms:A] Running Loop=1
2019-10-17T17:09:49.364Z,1571332189.364 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-10-17T17:09:51.011Z,1571332191.011 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2019-10-17T17:09:53.378Z,1571332193.378 [DAT](FAULT): unknown deviceResponse_: s CRC:Fail PSNR:07.8 CCERR:005 Mod:MFSK

2019-10-17T17:09:53.378Z,1571332193.378 [DAT] Communications Fault, FailCount= 1
2019-10-17T17:09:53.378Z,1571332193.378 [DAT](ERROR): Communications Fault
2019-10-17T17:09:53.461Z,1571332193.461 [CBIT](ERROR): Communications Fault in component: DAT
2019-10-17T17:09:53.791Z,1571332193.791 [DAT](INFO): Powering down
2019-10-17T17:09:54.697Z,1571332194.697 [CBIT](INFO): Clearing failed state for component DAT
2019-10-17T17:09:54.697Z,1571332194.697 [DAT] No Fault, FailCount= 1
2019-10-17T17:09:57.007Z,1571332197.007 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2019-10-17T17:09:57.007Z,1571332197.007 [DAT](INFO): Powering up
2019-10-17T17:09:57.007Z,1571332197.007 [DAT](DEBUG): Initializing DAT.
2019-10-17T17:09:57.102Z,1571332197.102 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2019-10-17T17:10:10.343Z,1571332210.343 [DAT](INFO): setting local address to 2
2019-10-17T17:10:10.760Z,1571332210.760 [DAT](INFO): set local address to 2
2019-10-17T17:10:49.144Z,1571332249.144 [Startup:StartupSatComms:A](INFO): Timed out from 2019-10-17T17:09:48.0Z
2019-10-17T17:10:49.144Z,1571332249.144 [Startup:StartupSatComms:A] Stopped
2019-10-17T17:10:49.144Z,1571332249.144 [Startup:StartupSatComms:B] Running Loop=1
2019-10-17T17:10:49.672Z,1571332249.672 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-17T17:11:01.467Z,1571332261.467 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004822
2019-10-17T17:11:08.741Z,1571332268.741 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20191017T170819/Courier0000.lzma
2019-10-17T17:11:10.749Z,1571332270.749 [DataOverHttps](INFO): Moved sent file to Logs/20191017T170819/Courier0000.lzma.bak
2019-10-17T17:11:10.749Z,1571332270.749 [DataOverHttps](INFO): SBD MOMSN=11920517
2019-10-17T17:11:26.540Z,1571332286.540 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20191017T171606/Courier0004.lzma
2019-10-17T17:11:28.546Z,1571332288.546 [DataOverHttps](INFO): Moved sent file to Logs/20191017T171606/Courier0004.lzma.bak
2019-10-17T17:11:28.546Z,1571332288.546 [DataOverHttps](INFO): SBD MOMSN=11920523
2019-10-17T17:11:31.714Z,1571332291.714 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-10-17T17:11:31.714Z,1571332291.714 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-17T17:11:31.728Z,1571332291.728 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-17T17:11:32.115Z,1571332292.115 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-17T17:11:32.115Z,1571332292.115 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-10-17T17:11:49.154Z,1571332309.154 [Startup:StartupSatComms:B](INFO): Timed out from 2019-10-17T17:10:49.1Z
2019-10-17T17:11:49.154Z,1571332309.154 [Startup:StartupSatComms:B] Stopped
2019-10-17T17:11:49.154Z,1571332309.154 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-10-17T17:11:49.154Z,1571332309.154 [Startup:StartupSatComms] Stopped
2019-10-17T17:11:49.154Z,1571332309.154 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-10-17T17:11:49.155Z,1571332309.155 [Startup](INFO): Completed Startup
2019-10-17T17:11:49.155Z,1571332309.155 [MissionManager](INFO): Startup is completed.
2019-10-17T17:11:49.155Z,1571332309.155 [MissionManager](INFO): Uninitializing Mission Startup
2019-10-17T17:11:49.156Z,1571332309.156 [Startup] Stopped
2019-10-17T17:11:49.156Z,1571332309.156 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-10-17T17:11:49.156Z,1571332309.156 [Startup:A.GoToSurface] Stopped
2019-10-17T17:11:49.156Z,1571332309.156 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-17T17:11:49.479Z,1571332309.479 [MissionManager](IMPORTANT): Started mission Default
2019-10-17T17:11:49.479Z,1571332309.479 [Default] Running Loop=1
2019-10-17T17:11:49.479Z,1571332309.479 [Default](DEBUG): Aggregate::initialize Default
2019-10-17T17:11:49.479Z,1571332309.479 [Default:B.GoToSurface] Running Loop=1
2019-10-17T17:11:49.479Z,1571332309.479 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-10-17T17:11:49.480Z,1571332309.480 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-10-17T17:11:49.480Z,1571332309.480 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-10-17T17:11:49.480Z,1571332309.480 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-10-17T17:11:49.480Z,1571332309.480 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-10-17T17:11:49.481Z,1571332309.481 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-10-17T17:11:49.481Z,1571332309.481 [Default:A.Wait] Running Loop=1
2019-10-17T17:11:49.481Z,1571332309.481 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-10-17T17:11:54.751Z,1571332314.751 [DataOverHttps](INFO): Sending 1014 bytes from file Logs/20191017T010304/Express0001.lzma
2019-10-17T17:11:56.754Z,1571332316.754 [DataOverHttps](INFO): Moved sent file to Logs/20191017T010304/Express0001.lzma.bak
2019-10-17T17:11:56.754Z,1571332316.754 [DataOverHttps](INFO): SBD MOMSN=11920528
2019-10-17T17:12:02.801Z,1571332322.801 [Default:A.Wait](INFO): Done Waiting.
2019-10-17T17:12:02.801Z,1571332322.801 [Default:A.Wait] Stopped
2019-10-17T17:12:02.801Z,1571332322.801 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-10-17T17:12:03.199Z,1571332323.199 [Default:CheckIn] Running Loop=1
2019-10-17T17:12:03.199Z,1571332323.199 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-17T17:12:03.200Z,1571332323.200 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-17T17:12:03.661Z,1571332323.661 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-10-17T17:14:12.063Z,1571332452.063 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-10-17T17:14:12.873Z,1571332452.873 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:15.701Z,1571332455.701 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:18.941Z,1571332458.941 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:21.761Z,1571332461.761 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:24.993Z,1571332464.993 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:27.821Z,1571332467.821 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:31.057Z,1571332471.057 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:32.704Z,1571332472.704 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2019-10-17T17:14:32.704Z,1571332472.704 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-17T17:14:32.714Z,1571332472.714 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-17T17:14:33.129Z,1571332473.129 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-17T17:14:33.129Z,1571332473.129 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2019-10-17T17:14:33.885Z,1571332473.885 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:36.729Z,1571332476.729 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:39.941Z,1571332479.941 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:42.773Z,1571332482.773 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:46.005Z,1571332486.005 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:48.837Z,1571332488.837 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:52.069Z,1571332492.069 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:54.897Z,1571332494.897 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:14:57.717Z,1571332497.717 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:00.953Z,1571332500.953 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:03.781Z,1571332503.781 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:04.223Z,1571332504.223 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2019-10-17T17:15:04.227Z,1571332504.227 [BPC1](INFO): Received data from all battery sticks.
2019-10-17T17:15:07.009Z,1571332507.009 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:09.841Z,1571332509.841 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:13.085Z,1571332513.085 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:15.905Z,1571332515.905 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:19.137Z,1571332519.137 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:21.961Z,1571332521.961 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:24.785Z,1571332524.785 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:28.017Z,1571332528.017 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:30.849Z,1571332530.849 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:34.081Z,1571332534.081 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:36.909Z,1571332536.909 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:40.137Z,1571332540.137 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:42.969Z,1571332542.969 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:45.801Z,1571332545.801 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:49.036Z,1571332549.036 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:51.861Z,1571332551.861 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:55.089Z,1571332555.089 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:15:57.921Z,1571332557.921 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:01.149Z,1571332561.149 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:03.981Z,1571332563.981 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:07.213Z,1571332567.213 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:10.033Z,1571332570.033 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:12.865Z,1571332572.865 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:16.093Z,1571332576.093 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:18.925Z,1571332578.925 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:22.177Z,1571332582.177 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:24.981Z,1571332584.981 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:28.217Z,1571332588.217 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:31.041Z,1571332591.041 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:33.873Z,1571332593.873 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:37.105Z,1571332597.105 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:39.933Z,1571332599.933 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:43.165Z,1571332603.165 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:45.997Z,1571332605.997 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:49.233Z,1571332609.233 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:52.053Z,1571332612.053 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:55.281Z,1571332615.281 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:16:58.109Z,1571332618.109 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:00.945Z,1571332620.945 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:03.376Z,1571332623.376 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-17T17:12:03.2Z
2019-10-17T17:17:03.377Z,1571332623.377 [Default:CheckIn:Read_GPS] Stopped
2019-10-17T17:17:03.377Z,1571332623.377 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-17T17:17:03.787Z,1571332623.787 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-10-17T17:17:04.177Z,1571332624.177 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:06.997Z,1571332626.997 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:10.237Z,1571332630.237 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:10.757Z,1571332630.757 [DataOverHttps](INFO): Sending 187 bytes from file Logs/20191017T170819/Courier0004.lzma
2019-10-17T17:17:12.762Z,1571332632.762 [DataOverHttps](INFO): Moved sent file to Logs/20191017T170819/Courier0004.lzma.bak
2019-10-17T17:17:12.762Z,1571332632.762 [DataOverHttps](INFO): SBD MOMSN=11920574
2019-10-17T17:17:13.057Z,1571332633.057 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:16.289Z,1571332636.289 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:19.117Z,1571332639.117 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:21.949Z,1571332641.949 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:25.177Z,1571332645.177 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:28.005Z,1571332648.005 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:29.351Z,1571332649.351 [DataOverHttps](INFO): Sending 784 bytes from file Logs/20191017T162823/Express0001.lzma
2019-10-17T17:17:31.237Z,1571332651.237 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:31.355Z,1571332651.355 [DataOverHttps](INFO): Moved sent file to Logs/20191017T162823/Express0001.lzma.bak
2019-10-17T17:17:31.355Z,1571332651.355 [DataOverHttps](INFO): SBD MOMSN=11920579
2019-10-17T17:17:33.687Z,1571332653.687 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2019-10-17T17:17:33.687Z,1571332653.687 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-17T17:17:33.721Z,1571332653.721 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-17T17:17:34.077Z,1571332654.077 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:34.127Z,1571332654.127 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-17T17:17:34.127Z,1571332654.127 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2019-10-17T17:17:37.305Z,1571332657.305 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:40.129Z,1571332660.129 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:43.365Z,1571332663.365 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:46.185Z,1571332666.185 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:48.447Z,1571332668.447 [DataOverHttps](INFO): Sending 435 bytes from file Logs/20191017T162823/Express0005.lzma
2019-10-17T17:17:49.013Z,1571332669.013 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:50.450Z,1571332670.450 [DataOverHttps](INFO): Moved sent file to Logs/20191017T162823/Express0005.lzma.bak
2019-10-17T17:17:50.450Z,1571332670.450 [DataOverHttps](INFO): SBD MOMSN=11920607
2019-10-17T17:17:52.249Z,1571332672.249 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:55.089Z,1571332675.089 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:17:58.309Z,1571332678.309 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:01.133Z,1571332681.133 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:04.365Z,1571332684.365 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:07.118Z,1571332687.118 [DataOverHttps](INFO): Sending 839 bytes from file Logs/20191017T170819/Express0001.lzma
2019-10-17T17:18:07.197Z,1571332687.197 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:09.123Z,1571332689.123 [DataOverHttps](INFO): Moved sent file to Logs/20191017T170819/Express0001.lzma.bak
2019-10-17T17:18:09.123Z,1571332689.123 [DataOverHttps](INFO): SBD MOMSN=11920627
2019-10-17T17:18:10.033Z,1571332690.033 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:13.253Z,1571332693.253 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:16.085Z,1571332696.085 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:19.321Z,1571332699.321 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:22.145Z,1571332702.145 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:25.377Z,1571332705.377 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:26.053Z,1571332706.053 [DataOverHttps](INFO): Sending 175 bytes from file Logs/20191017T170819/Express0005.lzma
2019-10-17T17:18:28.066Z,1571332708.066 [DataOverHttps](INFO): Moved sent file to Logs/20191017T170819/Express0005.lzma.bak
2019-10-17T17:18:28.066Z,1571332708.066 [DataOverHttps](INFO): SBD MOMSN=11920649
2019-10-17T17:18:28.209Z,1571332708.209 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:31.029Z,1571332711.029 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:33.058Z,1571332713.058 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:36.285Z,1571332716.285 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:39.117Z,1571332719.117 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:42.357Z,1571332722.357 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:44.673Z,1571332724.673 [DataOverHttps](INFO): Sending 687 bytes from file Logs/20191017T171606/Express0001.lzma
2019-10-17T17:18:45.181Z,1571332725.181 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:46.678Z,1571332726.678 [DataOverHttps](INFO): Moved sent file to Logs/20191017T171606/Express0001.lzma.bak
2019-10-17T17:18:46.678Z,1571332726.678 [DataOverHttps](INFO): SBD MOMSN=11920653
2019-10-17T17:18:48.405Z,1571332728.405 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:51.229Z,1571332731.229 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:54.468Z,1571332734.468 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:18:57.293Z,1571332737.293 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:19:00.117Z,1571332740.117 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:19:03.272Z,1571332743.272 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20191017T171606/Express0005.lzma
2019-10-17T17:19:03.349Z,1571332743.349 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:19:05.278Z,1571332745.278 [DataOverHttps](INFO): Moved sent file to Logs/20191017T171606/Express0005.lzma.bak
2019-10-17T17:19:05.278Z,1571332745.278 [DataOverHttps](INFO): SBD MOMSN=11920672
2019-10-17T17:19:06.181Z,1571332746.181 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:19:06.626Z,1571332746.626 [Default:CheckIn:Read_Iridium] Stopped
2019-10-17T17:19:06.626Z,1571332746.626 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-17T17:19:06.626Z,1571332746.626 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-17T17:19:09.409Z,1571332749.409 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:19:09.802Z,1571332749.802 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-10-17T17:19:09.802Z,1571332749.802 [NAL9602] Data Fault, FailCount= 1
2019-10-17T17:19:09.802Z,1571332749.802 [NAL9602](ERROR): Data Fault
2019-10-17T17:19:09.879Z,1571332749.879 [CBIT](ERROR): Data Fault in component: NAL9602
2019-10-17T17:19:10.214Z,1571332750.214 [NAL9602](INFO): Powering down
2019-10-17T17:19:11.079Z,1571332751.079 [CBIT](INFO): Clearing failed state for component NAL9602
2019-10-17T17:19:11.079Z,1571332751.079 [NAL9602] No Fault, FailCount= 1
2019-10-17T17:19:40.506Z,1571332780.506 [NAL9602](INFO): Powering up NAL9602
2019-10-17T17:19:47.829Z,1571332787.829 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:19:47.829Z,1571332787.829 [DVL_micro] No Fault, FailCount= 5
2019-10-17T17:19:48.194Z,1571332788.194 [DVL_micro](INFO): Initializing
2019-10-17T17:19:51.428Z,1571332791.428 [NAL9602](INFO): NAL9602 initialized
2019-10-17T17:19:52.226Z,1571332792.226 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-10-17T17:19:52.226Z,1571332792.226 [DVL_micro] Data Fault, FailCount= 1
2019-10-17T17:19:52.226Z,1571332792.226 [DVL_micro](ERROR): Data Fault
2019-10-17T17:19:52.293Z,1571332792.293 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-10-17T17:19:52.713Z,1571332792.713 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:19:53.484Z,1571332793.484 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:19:53.484Z,1571332793.484 [DVL_micro] No Fault, FailCount= 1
2019-10-17T17:19:53.865Z,1571332793.865 [DVL_micro](INFO): Initializing
2019-10-17T17:19:55.072Z,1571332795.072 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:19:57.897Z,1571332797.897 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:19:59.916Z,1571332799.916 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:03.149Z,1571332803.149 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:05.977Z,1571332805.977 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:07.581Z,1571332807.581 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:20:07.581Z,1571332807.581 [DVL_micro] Communications Fault, FailCount= 2
2019-10-17T17:20:07.581Z,1571332807.581 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:20:07.613Z,1571332807.613 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:20:08.049Z,1571332808.049 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:20:08.820Z,1571332808.820 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:20:08.820Z,1571332808.820 [DVL_micro] No Fault, FailCount= 2
2019-10-17T17:20:09.200Z,1571332809.200 [DVL_micro](INFO): Initializing
2019-10-17T17:20:09.213Z,1571332809.213 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:12.045Z,1571332812.045 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:15.269Z,1571332815.269 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:18.097Z,1571332818.097 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:20.924Z,1571332820.924 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:22.930Z,1571332822.930 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:20:22.930Z,1571332822.930 [DVL_micro] Communications Fault, FailCount= 3
2019-10-17T17:20:22.930Z,1571332822.930 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:20:22.945Z,1571332822.945 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:23.016Z,1571332823.016 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:20:23.405Z,1571332823.405 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:20:24.187Z,1571332824.187 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:20:24.188Z,1571332824.188 [DVL_micro] No Fault, FailCount= 3
2019-10-17T17:20:24.548Z,1571332824.548 [DVL_micro](INFO): Initializing
2019-10-17T17:20:26.177Z,1571332826.177 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:29.017Z,1571332829.017 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:32.237Z,1571332832.237 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:34.670Z,1571332834.670 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2019-10-17T17:20:34.670Z,1571332834.670 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-17T17:20:34.680Z,1571332834.680 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-17T17:20:35.065Z,1571332835.065 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:35.116Z,1571332835.116 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-17T17:20:35.116Z,1571332835.116 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2019-10-17T17:20:38.285Z,1571332838.285 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:20:38.285Z,1571332838.285 [DVL_micro] Communications Fault, FailCount= 4
2019-10-17T17:20:38.285Z,1571332838.285 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:20:38.301Z,1571332838.301 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:38.356Z,1571332838.356 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:20:38.753Z,1571332838.753 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:20:39.541Z,1571332839.541 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:20:39.541Z,1571332839.541 [DVL_micro] No Fault, FailCount= 4
2019-10-17T17:20:39.910Z,1571332839.910 [DVL_micro](INFO): Initializing
2019-10-17T17:20:41.117Z,1571332841.117 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:43.949Z,1571332843.949 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:45.973Z,1571332845.973 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:48.005Z,1571332848.005 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:51.221Z,1571332851.221 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:53.640Z,1571332853.640 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:20:53.640Z,1571332853.640 [DVL_micro] Communications Fault, FailCount= 5
2019-10-17T17:20:53.640Z,1571332853.640 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:20:53.672Z,1571332853.672 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:20:53.673Z,1571332853.673 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2019-10-17T17:20:54.105Z,1571332854.105 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:20:54.121Z,1571332854.121 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:20:54.180Z,1571332854.180 [CBIT](INFO): Critical error at 20191017T172053
2019-10-17T17:20:57.277Z,1571332857.277 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:00.113Z,1571332860.113 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:03.345Z,1571332863.345 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:06.177Z,1571332866.177 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:09.017Z,1571332869.017 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:11.013Z,1571332871.013 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:14.249Z,1571332874.249 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:17.077Z,1571332877.077 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:20.309Z,1571332880.309 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:23.137Z,1571332883.137 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:26.365Z,1571332886.365 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:29.197Z,1571332889.197 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:32.025Z,1571332892.025 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:34.045Z,1571332894.045 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:36.061Z,1571332896.061 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:39.293Z,1571332899.293 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:42.121Z,1571332902.121 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:45.361Z,1571332905.361 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:48.186Z,1571332908.186 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:51.419Z,1571332911.419 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:54.249Z,1571332914.249 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:57.069Z,1571332917.069 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:21:59.097Z,1571332919.097 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:02.329Z,1571332922.329 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:05.153Z,1571332925.153 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:08.385Z,1571332928.385 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:11.213Z,1571332931.213 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:14.441Z,1571332934.441 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:17.276Z,1571332937.276 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:20.101Z,1571332940.101 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:22.117Z,1571332942.117 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:24.141Z,1571332944.141 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:27.373Z,1571332947.373 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:30.204Z,1571332950.204 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:33.437Z,1571332953.437 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:36.261Z,1571332956.261 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:39.497Z,1571332959.497 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:42.317Z,1571332962.317 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:45.145Z,1571332965.145 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:47.165Z,1571332967.165 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:50.397Z,1571332970.397 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:53.225Z,1571332973.225 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:56.461Z,1571332976.461 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:22:59.289Z,1571332979.289 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:02.521Z,1571332982.521 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:05.345Z,1571332985.345 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:08.173Z,1571332988.173 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:10.193Z,1571332990.193 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:12.217Z,1571332992.217 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:15.445Z,1571332995.445 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:18.273Z,1571332998.273 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:21.505Z,1571333001.505 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:24.345Z,1571333004.345 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:27.169Z,1571333007.169 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:29.189Z,1571333009.189 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:31.217Z,1571333011.217 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:32.461Z,1571333012.461 [CBIT](INFO): Clearing failed state for component DropWeight
2019-10-17T17:23:32.461Z,1571333012.461 [DropWeight] No Fault, FailCount= 1
2019-10-17T17:23:33.235Z,1571333013.235 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:35.253Z,1571333015.253 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:35.691Z,1571333015.691 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2019-10-17T17:23:35.691Z,1571333015.691 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-17T17:23:35.701Z,1571333015.701 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-17T17:23:36.098Z,1571333016.098 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-17T17:23:36.098Z,1571333016.098 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2019-10-17T17:23:38.489Z,1571333018.489 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:41.313Z,1571333021.313 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:44.541Z,1571333024.541 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:47.373Z,1571333027.373 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:50.605Z,1571333030.605 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:53.437Z,1571333033.437 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:56.265Z,1571333036.265 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:23:58.281Z,1571333038.281 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:01.517Z,1571333041.517 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:04.345Z,1571333044.345 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:07.180Z,1571333047.180 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-17T17:24:07.181Z,1571333047.181 [Default:CheckIn:C.Wait] Stopped
2019-10-17T17:24:07.181Z,1571333047.181 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-17T17:24:07.181Z,1571333047.181 [Default:CheckIn:D] Running Loop=1
2019-10-17T17:24:07.573Z,1571333047.573 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:07.595Z,1571333047.595 [Default:CheckIn:D] Stopped
2019-10-17T17:24:07.595Z,1571333047.595 [Default:CheckIn:E] Running Loop=1
2019-10-17T17:24:08.007Z,1571333048.007 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.301934 min 
2019-10-17T17:24:08.007Z,1571333048.007 [Default:CheckIn:E] Stopped
2019-10-17T17:24:08.007Z,1571333048.007 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-17T17:24:08.007Z,1571333048.007 [Default:CheckIn] Stopped
2019-10-17T17:24:08.008Z,1571333048.008 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-17T17:24:08.008Z,1571333048.008 [Default:CheckIn](INFO): Running loop #2
2019-10-17T17:24:08.008Z,1571333048.008 [Default:CheckIn] Running Loop=2
2019-10-17T17:24:08.008Z,1571333048.008 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-17T17:24:08.008Z,1571333048.008 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-17T17:24:10.401Z,1571333050.401 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:13.637Z,1571333053.637 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:16.461Z,1571333056.461 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:19.293Z,1571333059.293 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:21.309Z,1571333061.309 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:24.541Z,1571333064.541 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:27.369Z,1571333067.369 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:30.597Z,1571333070.597 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:33.433Z,1571333073.433 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:36.665Z,1571333076.665 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:39.493Z,1571333079.493 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:42.317Z,1571333082.317 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:44.333Z,1571333084.333 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:46.353Z,1571333086.353 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:49.585Z,1571333089.585 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:52.421Z,1571333092.421 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:55.653Z,1571333095.653 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:24:58.477Z,1571333098.477 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:01.705Z,1571333101.705 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:04.533Z,1571333104.533 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:07.369Z,1571333107.369 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:09.389Z,1571333109.389 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:12.621Z,1571333112.621 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:15.449Z,1571333115.449 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:18.677Z,1571333118.677 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:21.501Z,1571333121.501 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:24.733Z,1571333124.733 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:27.561Z,1571333127.561 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:30.396Z,1571333130.396 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:32.409Z,1571333132.409 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:35.645Z,1571333135.645 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:38.476Z,1571333138.476 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:41.707Z,1571333141.707 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:44.529Z,1571333144.529 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:47.769Z,1571333147.769 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:50.593Z,1571333150.593 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:53.421Z,1571333153.421 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:55.437Z,1571333155.437 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:25:57.461Z,1571333157.461 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:00.693Z,1571333160.693 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:03.521Z,1571333163.521 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:06.753Z,1571333166.753 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:09.581Z,1571333169.581 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:12.816Z,1571333172.816 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:15.645Z,1571333175.645 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:18.473Z,1571333178.473 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:20.497Z,1571333180.497 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:22.521Z,1571333182.521 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:25.741Z,1571333185.741 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:28.569Z,1571333188.569 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:31.801Z,1571333191.801 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:34.629Z,1571333194.629 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:36.656Z,1571333196.656 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2019-10-17T17:26:36.656Z,1571333196.656 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-17T17:26:36.666Z,1571333196.666 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-17T17:26:37.084Z,1571333197.084 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-17T17:26:37.084Z,1571333197.084 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2019-10-17T17:26:37.861Z,1571333197.861 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:40.693Z,1571333200.693 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:43.521Z,1571333203.521 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:45.537Z,1571333205.537 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:47.560Z,1571333207.560 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:50.791Z,1571333210.791 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:53.621Z,1571333213.621 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:56.861Z,1571333216.861 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:26:59.673Z,1571333219.673 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:02.905Z,1571333222.905 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:05.740Z,1571333225.740 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:08.569Z,1571333228.569 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:10.581Z,1571333230.581 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:13.817Z,1571333233.817 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:16.645Z,1571333236.645 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:19.877Z,1571333239.877 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:22.701Z,1571333242.701 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:25.933Z,1571333245.933 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:28.768Z,1571333248.768 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:31.597Z,1571333251.597 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:33.617Z,1571333253.617 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:36.853Z,1571333256.853 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:39.669Z,1571333259.669 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:42.901Z,1571333262.901 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:45.729Z,1571333265.729 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:48.969Z,1571333268.969 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:51.801Z,1571333271.801 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:54.621Z,1571333274.621 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:56.645Z,1571333276.645 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:27:58.664Z,1571333278.664 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:01.897Z,1571333281.897 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:04.725Z,1571333284.725 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:07.961Z,1571333287.961 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:10.781Z,1571333290.781 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:14.013Z,1571333294.013 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:16.845Z,1571333296.845 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:19.672Z,1571333299.672 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:21.693Z,1571333301.693 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:24.921Z,1571333304.921 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:27.749Z,1571333307.749 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:30.985Z,1571333310.985 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:33.813Z,1571333313.813 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:37.041Z,1571333317.041 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:39.871Z,1571333319.871 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:42.709Z,1571333322.709 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:44.725Z,1571333324.725 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:47.953Z,1571333327.953 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:50.777Z,1571333330.777 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:54.009Z,1571333334.009 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:28:56.837Z,1571333336.837 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:00.073Z,1571333340.073 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:02.905Z,1571333342.905 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:05.725Z,1571333345.725 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:07.749Z,1571333347.749 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:08.174Z,1571333348.174 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-10-17T17:24:08.0Z
2019-10-17T17:29:08.175Z,1571333348.175 [Default:CheckIn:Read_GPS] Stopped
2019-10-17T17:29:08.175Z,1571333348.175 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-10-17T17:29:09.761Z,1571333349.761 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:12.993Z,1571333352.993 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:15.829Z,1571333355.829 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:15.876Z,1571333355.876 [DataOverHttps](INFO): Sending 79 bytes from file Logs/20191017T170819/Courier0007.lzma
2019-10-17T17:29:17.882Z,1571333357.882 [DataOverHttps](INFO): Moved sent file to Logs/20191017T170819/Courier0007.lzma.bak
2019-10-17T17:29:17.882Z,1571333357.882 [DataOverHttps](INFO): SBD MOMSN=11920698
2019-10-17T17:29:19.065Z,1571333359.065 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:21.881Z,1571333361.881 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:25.117Z,1571333365.117 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:27.949Z,1571333367.949 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:30.777Z,1571333370.777 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:32.798Z,1571333372.798 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:34.809Z,1571333374.809 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:37.661Z,1571333377.661 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2019-10-17T17:29:37.661Z,1571333377.661 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-17T17:29:37.671Z,1571333377.671 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-17T17:29:38.041Z,1571333378.041 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:38.086Z,1571333378.086 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-17T17:29:38.086Z,1571333378.086 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2019-10-17T17:29:40.869Z,1571333380.869 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:43.789Z,1571333383.789 [DataOverHttps](INFO): Sending 206 bytes from file Logs/20191017T170819/Express0008.lzma
2019-10-17T17:29:44.113Z,1571333384.113 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:45.795Z,1571333385.795 [DataOverHttps](INFO): Moved sent file to Logs/20191017T170819/Express0008.lzma.bak
2019-10-17T17:29:45.795Z,1571333385.795 [DataOverHttps](INFO): SBD MOMSN=11920704
2019-10-17T17:29:46.929Z,1571333386.929 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:47.379Z,1571333387.379 [Default:CheckIn:Read_Iridium] Stopped
2019-10-17T17:29:47.379Z,1571333387.379 [Default:CheckIn:C.Wait] Running Loop=1
2019-10-17T17:29:47.379Z,1571333387.379 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-10-17T17:29:50.161Z,1571333390.161 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:29:52.998Z,1571333392.998 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-10-17T17:29:52.998Z,1571333392.998 [NAL9602] Data Fault, FailCount= 2
2019-10-17T17:29:52.998Z,1571333392.998 [NAL9602](ERROR): Data Fault
2019-10-17T17:29:53.029Z,1571333393.029 [CBIT](ERROR): Data Fault in component: NAL9602
2019-10-17T17:29:53.386Z,1571333393.386 [NAL9602](INFO): Powering down
2019-10-17T17:29:54.236Z,1571333394.236 [CBIT](INFO): Clearing failed state for component NAL9602
2019-10-17T17:29:54.236Z,1571333394.236 [NAL9602] No Fault, FailCount= 2
2019-10-17T17:30:23.695Z,1571333423.695 [NAL9602](INFO): Powering up NAL9602
2019-10-17T17:30:34.594Z,1571333434.594 [NAL9602](INFO): NAL9602 initialized
2019-10-17T17:30:35.425Z,1571333435.425 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:30:38.245Z,1571333438.245 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:30:41.077Z,1571333441.077 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:30:43.097Z,1571333443.097 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:30:46.329Z,1571333446.329 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:30:49.157Z,1571333449.157 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:30:52.393Z,1571333452.393 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:30:54.032Z,1571333454.032 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:30:54.032Z,1571333454.032 [DVL_micro] No Fault, FailCount= 5
2019-10-17T17:30:54.400Z,1571333454.400 [DVL_micro](INFO): Initializing
2019-10-17T17:30:55.221Z,1571333455.221 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:30:58.438Z,1571333458.438 [DVL_micro](FAULT): DVL failed to acquire valid data within timeout.
2019-10-17T17:30:58.438Z,1571333458.438 [DVL_micro] Data Fault, FailCount= 1
2019-10-17T17:30:58.439Z,1571333458.439 [DVL_micro](ERROR): Data Fault
2019-10-17T17:30:58.453Z,1571333458.453 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:30:58.515Z,1571333458.515 [CBIT](ERROR): Data Fault in component: DVL_micro
2019-10-17T17:30:58.913Z,1571333458.913 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:30:59.696Z,1571333459.696 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:30:59.696Z,1571333459.696 [DVL_micro] No Fault, FailCount= 1
2019-10-17T17:31:00.061Z,1571333460.061 [DVL_micro](INFO): Initializing
2019-10-17T17:31:01.281Z,1571333461.281 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:04.117Z,1571333464.117 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:06.129Z,1571333466.129 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:08.145Z,1571333468.145 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:11.377Z,1571333471.377 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:13.794Z,1571333473.794 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:31:13.794Z,1571333473.794 [DVL_micro] Communications Fault, FailCount= 2
2019-10-17T17:31:13.794Z,1571333473.794 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:31:13.844Z,1571333473.844 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:31:14.261Z,1571333474.261 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:31:14.277Z,1571333474.277 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:15.062Z,1571333475.062 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:31:15.063Z,1571333475.063 [DVL_micro] No Fault, FailCount= 2
2019-10-17T17:31:15.416Z,1571333475.416 [DVL_micro](INFO): Initializing
2019-10-17T17:31:17.437Z,1571333477.437 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:20.265Z,1571333480.265 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:23.509Z,1571333483.509 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:26.325Z,1571333486.325 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:29.142Z,1571333489.142 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:31:29.142Z,1571333489.142 [DVL_micro] Communications Fault, FailCount= 3
2019-10-17T17:31:29.142Z,1571333489.142 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:31:29.157Z,1571333489.157 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:29.225Z,1571333489.225 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:31:29.613Z,1571333489.613 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:31:30.393Z,1571333490.393 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:31:30.393Z,1571333490.393 [DVL_micro] No Fault, FailCount= 3
2019-10-17T17:31:30.764Z,1571333490.764 [DVL_micro](INFO): Initializing
2019-10-17T17:31:31.173Z,1571333491.173 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:34.409Z,1571333494.409 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:37.237Z,1571333497.237 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:40.476Z,1571333500.476 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:43.297Z,1571333503.297 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:44.494Z,1571333504.494 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:31:44.494Z,1571333504.494 [DVL_micro] Communications Fault, FailCount= 4
2019-10-17T17:31:44.495Z,1571333504.495 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:31:44.548Z,1571333504.548 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:31:44.969Z,1571333504.969 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:31:45.749Z,1571333505.749 [CBIT](INFO): Clearing failed state for component DVL_micro
2019-10-17T17:31:45.749Z,1571333505.749 [DVL_micro] No Fault, FailCount= 4
2019-10-17T17:31:46.116Z,1571333506.116 [DVL_micro](INFO): Initializing
2019-10-17T17:31:46.533Z,1571333506.533 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:49.353Z,1571333509.353 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:52.181Z,1571333512.181 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:54.201Z,1571333514.201 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:56.225Z,1571333516.225 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:59.457Z,1571333519.457 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:31:59.846Z,1571333519.846 [DVL_micro](ERROR): No DVL communication! Re-initializing
2019-10-17T17:31:59.846Z,1571333519.846 [DVL_micro] Communications Fault, FailCount= 5
2019-10-17T17:31:59.846Z,1571333519.846 [DVL_micro](ERROR): Communications Fault
2019-10-17T17:31:59.914Z,1571333519.914 [CBIT](ERROR): Communications Fault in component: DVL_micro
2019-10-17T17:31:59.915Z,1571333519.915 [CBIT](CRITICAL): Communications Fault in component: DVL_micro
2019-10-17T17:32:00.313Z,1571333520.313 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:32:00.366Z,1571333520.366 [CBIT](INFO): Critical error at 20191017T173159
2019-10-17T17:32:02.281Z,1571333522.281 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:05.509Z,1571333525.509 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:08.341Z,1571333528.341 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:11.573Z,1571333531.573 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:14.403Z,1571333534.403 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:17.233Z,1571333537.233 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:19.253Z,1571333539.253 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:22.485Z,1571333542.485 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:25.309Z,1571333545.309 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:28.537Z,1571333548.537 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:31.369Z,1571333551.369 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:34.601Z,1571333554.601 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:37.433Z,1571333557.433 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:38.658Z,1571333558.658 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2019-10-17T17:32:38.658Z,1571333558.658 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-17T17:32:38.693Z,1571333558.693 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-17T17:32:39.067Z,1571333559.067 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-17T17:32:39.067Z,1571333559.067 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2019-10-17T17:32:40.257Z,1571333560.257 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:42.281Z,1571333562.281 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:44.300Z,1571333564.300 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:47.533Z,1571333567.533 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:50.109Z,1571333570.109 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-17T17:32:50.365Z,1571333570.365 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:53.593Z,1571333573.593 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:56.413Z,1571333576.413 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:32:59.649Z,1571333579.649 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:02.480Z,1571333582.480 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:05.309Z,1571333585.309 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:07.328Z,1571333587.328 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:10.561Z,1571333590.561 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:13.385Z,1571333593.385 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:16.625Z,1571333596.625 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:19.445Z,1571333599.445 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:21.245Z,1571333601.245 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-17T17:33:22.677Z,1571333602.677 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:25.516Z,1571333605.516 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:28.333Z,1571333608.333 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:30.353Z,1571333610.353 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:32.369Z,1571333612.369 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:35.601Z,1571333615.601 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:38.438Z,1571333618.438 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:41.665Z,1571333621.665 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:44.497Z,1571333624.497 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:47.733Z,1571333627.733 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:50.549Z,1571333630.549 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:52.369Z,1571333632.369 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-17T17:33:53.381Z,1571333633.381 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:56.613Z,1571333636.613 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:33:59.457Z,1571333639.457 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:02.677Z,1571333642.677 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:05.505Z,1571333645.505 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:08.741Z,1571333648.741 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:11.558Z,1571333651.558 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:14.389Z,1571333654.389 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:16.409Z,1571333656.409 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:18.437Z,1571333658.437 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:20.449Z,1571333660.449 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:23.493Z,1571333663.493 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2019-10-17T17:34:23.689Z,1571333663.689 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:26.506Z,1571333666.506 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=180.075928
2019-10-17T17:34:26.509Z,1571333666.509 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:29.741Z,1571333669.741 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:32.569Z,1571333672.569 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:35.808Z,1571333675.808 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:38.629Z,1571333678.629 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:41.457Z,1571333681.457 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:43.481Z,1571333683.481 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:46.709Z,1571333686.709 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:47.939Z,1571333687.939 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-10-17T17:34:47.939Z,1571333687.939 [Default:CheckIn:C.Wait] Stopped
2019-10-17T17:34:47.939Z,1571333687.939 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-10-17T17:34:47.939Z,1571333687.939 [Default:CheckIn:D] Running Loop=1
2019-10-17T17:34:48.340Z,1571333688.340 [Default:CheckIn:D] Stopped
2019-10-17T17:34:48.340Z,1571333688.340 [Default:CheckIn:E] Running Loop=1
2019-10-17T17:34:48.751Z,1571333688.751 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 22.981018 min 
2019-10-17T17:34:48.751Z,1571333688.751 [Default:CheckIn:E] Stopped
2019-10-17T17:34:48.751Z,1571333688.751 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-10-17T17:34:48.752Z,1571333688.752 [Default:CheckIn] Stopped
2019-10-17T17:34:48.752Z,1571333688.752 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-17T17:34:48.752Z,1571333688.752 [Default:CheckIn](INFO): Running loop #3
2019-10-17T17:34:48.752Z,1571333688.752 [Default:CheckIn] Running Loop=3
2019-10-17T17:34:48.752Z,1571333688.752 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-10-17T17:34:48.752Z,1571333688.752 [Default:CheckIn:Read_GPS] Running Loop=1
2019-10-17T17:34:49.533Z,1571333689.533 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:52.765Z,1571333692.765 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:55.600Z,1571333695.600 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:34:58.829Z,1571333698.829 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:01.657Z,1571333701.657 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:04.485Z,1571333704.485 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:06.505Z,1571333706.505 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:08.529Z,1571333708.529 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:10.942Z,1571333710.942 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003279
2019-10-17T17:35:11.765Z,1571333711.765 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:14.581Z,1571333714.581 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:17.817Z,1571333717.817 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:20.645Z,1571333720.645 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:23.877Z,1571333723.877 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:26.705Z,1571333726.705 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:29.537Z,1571333729.537 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:31.553Z,1571333731.553 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:34.789Z,1571333734.789 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:37.633Z,1571333737.633 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:39.654Z,1571333739.654 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2019-10-17T17:35:39.654Z,1571333739.654 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-17T17:35:39.664Z,1571333739.664 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-17T17:35:40.066Z,1571333740.066 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-17T17:35:40.066Z,1571333740.066 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2019-10-17T17:35:40.849Z,1571333740.849 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:43.673Z,1571333743.673 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:46.909Z,1571333746.909 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:49.733Z,1571333749.733 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:52.561Z,1571333752.561 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:54.581Z,1571333754.581 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:35:57.813Z,1571333757.813 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:00.637Z,1571333760.637 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:03.877Z,1571333763.877 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:06.705Z,1571333766.705 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:09.937Z,1571333769.937 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:12.757Z,1571333772.757 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:15.589Z,1571333775.589 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:17.605Z,1571333777.605 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:20.853Z,1571333780.853 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:23.669Z,1571333783.669 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:26.901Z,1571333786.901 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:29.725Z,1571333789.725 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:32.961Z,1571333792.961 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:35.793Z,1571333795.793 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:38.621Z,1571333798.621 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:40.637Z,1571333800.637 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:42.653Z,1571333802.653 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:45.889Z,1571333805.889 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:48.721Z,1571333808.721 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:51.949Z,1571333811.949 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:54.789Z,1571333814.789 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:36:58.017Z,1571333818.017 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:00.841Z,1571333820.841 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:03.661Z,1571333823.661 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:05.689Z,1571333825.689 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:07.708Z,1571333827.708 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:10.941Z,1571333830.941 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:13.765Z,1571333833.765 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:16.997Z,1571333836.997 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:19.833Z,1571333839.833 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:23.053Z,1571333843.053 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:25.889Z,1571333845.889 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:28.717Z,1571333848.717 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:30.744Z,1571333850.744 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:34.013Z,1571333854.013 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:36.801Z,1571333856.801 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:40.029Z,1571333860.029 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:42.857Z,1571333862.857 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:46.085Z,1571333866.085 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:48.917Z,1571333868.917 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:51.746Z,1571333871.746 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:53.757Z,1571333873.757 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:56.993Z,1571333876.993 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:37:59.817Z,1571333879.817 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:03.057Z,1571333883.057 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:05.889Z,1571333885.889 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:09.117Z,1571333889.117 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:11.941Z,1571333891.941 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:14.765Z,1571333894.765 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:16.789Z,1571333896.789 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:18.813Z,1571333898.813 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:22.045Z,1571333902.045 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:24.865Z,1571333904.865 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:28.101Z,1571333908.101 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:30.929Z,1571333910.929 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:34.157Z,1571333914.157 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:36.993Z,1571333916.993 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:39.817Z,1571333919.817 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:40.677Z,1571333920.677 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2019-10-17T17:38:40.677Z,1571333920.677 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-10-17T17:38:40.696Z,1571333920.696 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-10-17T17:38:41.104Z,1571333921.104 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-10-17T17:38:41.104Z,1571333921.104 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2019-10-17T17:38:41.834Z,1571333921.834 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:45.149Z,1571333925.149 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:45.414Z,1571333925.414 [PAR_Licor](INFO): A/D timeout, 4 tries over 247 ms

2019-10-17T17:38:45.414Z,1571333925.414 [PAR_Licor] Data Fault, FailCount= 1
2019-10-17T17:38:45.414Z,1571333925.414 [PAR_Licor](ERROR): Data Fault
2019-10-17T17:38:45.547Z,1571333925.547 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-10-17T17:38:45.547Z,1571333925.547 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-10-17T17:38:45.547Z,1571333925.547 [PAR_Licor] No Fault, FailCount= 1
2019-10-17T17:38:47.749Z,1571333927.749 [PAR_Licor](INFO): A/D timeout, 10 tries over 132 ms

2019-10-17T17:38:47.749Z,1571333927.749 [PAR_Licor] Data Fault, FailCount= 1
2019-10-17T17:38:47.749Z,1571333927.749 [PAR_Licor](ERROR): Data Fault
2019-10-17T17:38:47.832Z,1571333927.832 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-10-17T17:38:47.851Z,1571333927.851 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-10-17T17:38:47.851Z,1571333927.851 [PAR_Licor] No Fault, FailCount= 1
2019-10-17T17:38:48.026Z,1571333928.026 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:50.897Z,1571333930.897 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:54.077Z,1571333934.077 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:56.897Z,1571333936.897 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:38:58.901Z,1571333938.901 [AHRS_M2](FAULT): Failed to acquire valid data within timeout.
2019-10-17T17:38:58.901Z,1571333938.901 [AHRS_M2] Data Fault, FailCount= 1
2019-10-17T17:38:58.901Z,1571333938.901 [AHRS_M2](ERROR): Data Fault
2019-10-17T17:38:59.008Z,1571333939.008 [CBIT](ERROR): Data Fault in component: AHRS_M2
2019-10-17T17:38:59.292Z,1571333939.292 [AHRS_M2](INFO): Powering down
2019-10-17T17:39:00.229Z,1571333940.229 [Depth_Keller](INFO): A/D timeout, 5 tries over 128 ms

2019-10-17T17:39:00.229Z,1571333940.229 [Depth_Keller] Data Fault, FailCount= 1
2019-10-17T17:39:00.229Z,1571333940.229 [Depth_Keller](ERROR): Data Fault
2019-10-17T17:39:00.245Z,1571333940.245 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:39:00.297Z,1571333940.297 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2019-10-17T17:39:00.313Z,1571333940.313 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2019-10-17T17:39:00.439Z,1571333940.439 [CBIT](INFO): Clearing failed state for component AHRS_M2
2019-10-17T17:39:00.439Z,1571333940.439 [AHRS_M2] No Fault, FailCount= 1
2019-10-17T17:39:00.439Z,1571333940.439 [CBIT](ERROR): Data Fault in component: Depth_Keller
2019-10-17T17:39:00.440Z,1571333940.440 [CBIT](INFO): Clearing failed state for component Depth_Keller
2019-10-17T17:39:00.440Z,1571333940.440 [Depth_Keller] No Fault, FailCount= 1
2019-10-17T17:39:00.515Z,1571333940.515 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-10-17T17:39:02.953Z,1571333942.953 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:39:06.201Z,1571333946.201 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:39:09.017Z,1571333949.017 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:39:10.465Z,1571333950.465 [Depth_Keller](INFO): A/D timeout, 5 tries over 242 ms

2019-10-17T17:39:10.465Z,1571333950.465 [Depth_Keller] Data Fault, FailCount= 1
2019-10-17T17:39:10.465Z,1571333950.465 [Depth_Keller](ERROR): Data Fault
2019-10-17T17:39:10.537Z,1571333950.537 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2019-10-17T17:39:10.572Z,1571333950.572 [CBIT](ERROR): Data Fault in component: Depth_Keller
2019-10-17T17:39:10.572Z,1571333950.572 [CBIT](INFO): Clearing failed state for component Depth_Keller
2019-10-17T17:39:10.572Z,1571333950.572 [Depth_Keller] No Fault, FailCount= 1
2019-10-17T17:39:11.146Z,1571333951.146 [NAL9602](ERROR): parseGSV uart error: serial timeout
2019-10-17T17:39:11.853Z,1571333951.853 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:39:13.529Z,1571333953.529 [ElevatorServo](ERROR): getPosition uart error serial timeout
2019-10-17T17:39:13.529Z,1571333953.529 [ElevatorServo](FAULT): Elevator uart error - getPosition.serial timeout
2019-10-17T17:39:13.529Z,1571333953.529 [ElevatorServo] Communications Fault, FailCount= 1
2019-10-17T17:39:13.529Z,1571333953.529 [ElevatorServo](ERROR): Communications Fault
2019-10-17T17:39:13.570Z,1571333953.570 [CBIT](ERROR): Communications Fault in component: ElevatorServo
2019-10-17T17:39:13.668Z,1571333953.668 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-10-17T17:39:13.668Z,1571333953.668 [ElevatorServo](INFO): Powering down
2019-10-17T17:39:14.460Z,1571333954.460 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:39:14.469Z,1571333954.469 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-17T17:39:14.517Z,1571333954.517 [CBIT](INFO): Clearing failed state for component ElevatorServo
2019-10-17T17:39:14.517Z,1571333954.517 [ElevatorServo] No Fault, FailCount= 1
2019-10-17T17:39:15.313Z,1571333955.313 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:39:15.677Z,1571333955.677 [ElevatorServo](ERROR): Elevator initialization uart error I:serial timeout
2019-10-17T17:39:15.677Z,1571333955.677 [ElevatorServo](FAULT): Elevator failed to initialize
2019-10-17T17:39:15.677Z,1571333955.677 [ElevatorServo] Communications Fault, FailCount= 2
2019-10-17T17:39:15.677Z,1571333955.677 [ElevatorServo](ERROR): Communications Fault
2019-10-17T17:39:15.990Z,1571333955.990 [MassServo](ERROR): getPosition uart error serial timeout
2019-10-17T17:39:15.990Z,1571333955.990 [MassServo](FAULT): Invalid EZ Servo response:""
2019-10-17T17:39:15.990Z,1571333955.990 [MassServo] Communications Fault, FailCount= 1
2019-10-17T17:39:15.990Z,1571333955.990 [MassServo](ERROR): Communications Fault
2019-10-17T17:39:15.994Z,1571333955.994 [CBIT](ERROR): Communications Fault in component: ElevatorServo
2019-10-17T17:39:15.995Z,1571333955.995 [CBIT](ERROR): Communications Fault in component: MassServo
2019-10-17T17:39:16.264Z,1571333956.264 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-10-17T17:39:16.264Z,1571333956.264 [ElevatorServo](INFO): Powering down
2019-10-17T17:39:16.313Z,1571333956.313 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-10-17T17:39:16.313Z,1571333956.313 [MassServo](INFO): Powering down
2019-10-17T17:39:16.978Z,1571333956.978 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:39:16.979Z,1571333956.979 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-10-17T17:39:16.979Z,1571333956.979 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:39:16.980Z,1571333956.980 [MassServo](DEBUG): Initializing MassServo.
2019-10-17T17:39:17.000Z,1571333957.000 [CBIT](INFO): Clearing failed state for component ElevatorServo
2019-10-17T17:39:17.000Z,1571333957.000 [ElevatorServo] No Fault, FailCount= 2
2019-10-17T17:39:17.026Z,1571333957.026 [CBIT](INFO): Clearing failed state for component MassServo
2019-10-17T17:39:17.026Z,1571333957.026 [MassServo] No Fault, FailCount= 1
2019-10-17T17:39:17.865Z,1571333957.865 [PAR_Licor](INFO): A/D timeout, 8 tries over 152 ms

2019-10-17T17:39:17.865Z,1571333957.865 [PAR_Licor] Data Fault, FailCount= 1
2019-10-17T17:39:17.865Z,1571333957.865 [PAR_Licor](ERROR): Data Fault
2019-10-17T17:39:18.008Z,1571333958.008 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-10-17T17:39:18.021Z,1571333958.021 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-10-17T17:39:18.021Z,1571333958.021 [PAR_Licor] No Fault, FailCount= 1
2019-10-17T17:39:18.185Z,1571333958.185 [Depth_Keller](INFO): A/D timeout, 6 tries over 135 ms

2019-10-17T17:39:18.185Z,1571333958.185 [Depth_Keller] Data Fault, FailCount= 1
2019-10-17T17:39:18.185Z,1571333958.185 [Depth_Keller](ERROR): Data Fault
2019-10-17T17:39:18.201Z,1571333958.201 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:39:18.294Z,1571333958.294 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2019-10-17T17:39:18.341Z,1571333958.341 [CBIT](ERROR): Data Fault in component: Depth_Keller
2019-10-17T17:39:18.341Z,1571333958.341 [CBIT](INFO): Clearing failed state for component Depth_Keller
2019-10-17T17:39:18.341Z,1571333958.341 [Depth_Keller] No Fault, FailCount= 1
2019-10-17T17:39:19.649Z,1571333959.649 [MassServo](FAULT): Mass initialization uart error:serial timeout
2019-10-17T17:39:19.649Z,1571333959.649 [MassServo] Communications Fault, FailCount= 2
2019-10-17T17:39:19.649Z,1571333959.649 [MassServo](ERROR): Communications Fault
2019-10-17T17:39:19.653Z,1571333959.653 [CBIT](ERROR): Communications Fault in component: MassServo
2019-10-17T17:39:19.821Z,1571333959.821 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-10-17T17:39:19.821Z,1571333959.821 [MassServo](INFO): Powering down
2019-10-17T17:39:20.209Z,1571333960.209 [Depth_Keller](INFO): A/D timeout, 7 tries over 144 ms

2019-10-17T17:39:20.209Z,1571333960.209 [Depth_Keller] Data Fault, FailCount= 1
2019-10-17T17:39:20.209Z,1571333960.209 [Depth_Keller](ERROR): Data Fault
2019-10-17T17:39:20.334Z,1571333960.334 [CTD_NeilBrown](INFO): Opening uart, block timeout 10ths=4
2019-10-17T17:39:20.593Z,1571333960.593 [CBIT](ERROR): Data Fault in component: Depth_Keller
2019-10-17T17:39:20.593Z,1571333960.593 [CBIT](INFO): Clearing failed state for component Depth_Keller
2019-10-17T17:39:20.594Z,1571333960.594 [Depth_Keller] No Fault, FailCount= 1
2019-10-17T17:39:21.005Z,1571333961.005 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:39:21.005Z,1571333961.005 [MassServo](DEBUG): Initializing MassServo.
2019-10-17T17:39:21.026Z,1571333961.026 [CBIT](INFO): Clearing failed state for component MassServo
2019-10-17T17:39:21.026Z,1571333961.026 [MassServo] No Fault, FailCount= 2
2019-10-17T17:39:21.113Z,1571333961.113 [NAL9602](DEBUG): Fix Requested
2019-10-17T17:39:22.495Z,1571333962.495 [CommandLine](IMPORTANT): got command quit
2019-10-17T17:39:23.477Z,1571333963.477 [MassServo](FAULT): Mass shifter EEPROM initialization uart error serial timeout
2019-10-17T17:39:23.477Z,1571333963.477 [MassServo] Communications Fault, FailCount= 3
2019-10-17T17:39:23.477Z,1571333963.477 [MassServo](ERROR): Communications Fault
2019-10-17T17:39:23.481Z,1571333963.481 [CBIT](ERROR): Communications Fault in component: MassServo
2019-10-17T17:39:23.505Z,1571333963.505 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-17T17:39:23.505Z,1571333963.505 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:23.517Z,1571333963.517 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-10-17T17:39:23.517Z,1571333963.517 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:23.518Z,1571333963.518 [CommandLine](INFO): Join timeout helper Thread ID is 1125
2019-10-17T17:39:23.530Z,1571333963.530 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-10-17T17:39:23.530Z,1571333963.530 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:23.531Z,1571333963.531 [NavChartDb](INFO): Join timeout helper Thread ID is 1126
2019-10-17T17:39:23.654Z,1571333963.654 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-17T17:39:23.654Z,1571333963.654 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:23.655Z,1571333963.655 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-10-17T17:39:23.655Z,1571333963.655 [MassServo](INFO): Powering down
2019-10-17T17:39:23.657Z,1571333963.657 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-10-17T17:39:23.657Z,1571333963.657 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:23.657Z,1571333963.657 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1127
2019-10-17T17:39:23.721Z,1571333963.721 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-17T17:39:23.722Z,1571333963.722 [WetLabsBB2FL](INFO): Powering down
2019-10-17T17:39:23.722Z,1571333963.722 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:23.723Z,1571333963.723 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-10-17T17:39:23.723Z,1571333963.723 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:23.723Z,1571333963.723 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1128
2019-10-17T17:39:24.141Z,1571333964.141 [CTD_Seabird](INFO): Powering down
2019-10-17T17:39:24.153Z,1571333964.153 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-17T17:39:24.153Z,1571333964.153 [CTD_Seabird](INFO): Powering down
2019-10-17T17:39:24.165Z,1571333964.165 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.185Z,1571333964.185 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-10-17T17:39:24.185Z,1571333964.185 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.185Z,1571333964.185 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1129
2019-10-17T17:39:24.218Z,1571333964.218 [CTD_NeilBrown](INFO): Powering down
2019-10-17T17:39:24.229Z,1571333964.229 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-17T17:39:24.229Z,1571333964.229 [CTD_NeilBrown](INFO): Powering down
2019-10-17T17:39:24.241Z,1571333964.241 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.254Z,1571333964.254 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-10-17T17:39:24.254Z,1571333964.254 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.254Z,1571333964.254 [Radio_Surface](INFO): Join timeout helper Thread ID is 1130
2019-10-17T17:39:24.430Z,1571333964.430 [MassServo](DEBUG): Initializing EZServoServo.
2019-10-17T17:39:24.430Z,1571333964.430 [MassServo](DEBUG): Initializing MassServo.
2019-10-17T17:39:24.434Z,1571333964.434 [CBIT](INFO): Clearing failed state for component MassServo
2019-10-17T17:39:24.434Z,1571333964.434 [MassServo] No Fault, FailCount= 3
2019-10-17T17:39:24.629Z,1571333964.629 [Radio_Surface](INFO): Powering down
2019-10-17T17:39:24.630Z,1571333964.630 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-17T17:39:24.630Z,1571333964.630 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.642Z,1571333964.642 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-10-17T17:39:24.642Z,1571333964.642 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.642Z,1571333964.642 [DataOverHttps](INFO): Join timeout helper Thread ID is 1131
2019-10-17T17:39:24.697Z,1571333964.697 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-17T17:39:24.698Z,1571333964.698 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.710Z,1571333964.710 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-10-17T17:39:24.710Z,1571333964.710 [logger ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.710Z,1571333964.710 [logger](INFO): Join timeout helper Thread ID is 1132
2019-10-17T17:39:24.753Z,1571333964.753 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-17T17:39:24.753Z,1571333964.753 [logger ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.755Z,1571333964.755 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-10-17T17:39:24.755Z,1571333964.755 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.755Z,1571333964.755 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-10-17T17:39:24.755Z,1571333964.755 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:24.755Z,1571333964.755 [controlThread](INFO): Join timeout helper Thread ID is 1133
2019-10-17T17:39:24.795Z,1571333964.795 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-10-17T17:39:24.795Z,1571333964.795 [controlThread](DEBUG): Uninitializing ControlThread
2019-10-17T17:39:24.795Z,1571333964.795 [AHRS_M2](INFO): Powering down
2019-10-17T17:39:24.796Z,1571333964.796 [DVL_micro](INFO): uninitialize:Powering down
2019-10-17T17:39:24.797Z,1571333964.797 [NAL9602](INFO): Powering down
2019-10-17T17:39:24.798Z,1571333964.798 [DAT](INFO): Powering down
2019-10-17T17:39:24.799Z,1571333964.799 [Aanderaa_O2](INFO): Powering down
2019-10-17T17:39:24.801Z,1571333964.801 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-10-17T17:39:24.802Z,1571333964.802 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-10-17T17:39:24.802Z,1571333964.802 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-10-17T17:39:24.803Z,1571333964.803 [MissionManager](INFO): Uninitializing Mission Default
2019-10-17T17:39:24.803Z,1571333964.803 [Default] Stopped
2019-10-17T17:39:24.803Z,1571333964.803 [Default](DEBUG): Aggregate::uninitialize Default
2019-10-17T17:39:24.803Z,1571333964.803 [Default:B.GoToSurface] Stopped
2019-10-17T17:39:24.803Z,1571333964.803 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-10-17T17:39:24.803Z,1571333964.803 [Default:CheckIn] Stopped
2019-10-17T17:39:24.803Z,1571333964.803 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-10-17T17:39:24.804Z,1571333964.804 [Default:CheckIn:Read_GPS] Stopped
2019-10-17T17:39:24.818Z,1571333964.818 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-10-17T17:39:24.818Z,1571333964.818 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-10-17T17:39:24.819Z,1571333964.819 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-10-17T17:39:24.819Z,1571333964.819 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-10-17T17:39:24.819Z,1571333964.819 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-10-17T17:39:24.819Z,1571333964.819 [BuoyancyServo](INFO): Powering down
2019-10-17T17:39:24.833Z,1571333964.833 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-10-17T17:39:24.833Z,1571333964.833 [ElevatorServo](INFO): Powering down
2019-10-17T17:39:24.834Z,1571333964.834 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-10-17T17:39:24.834Z,1571333964.834 [MassServo](INFO): Powering down
2019-10-17T17:39:24.835Z,1571333964.835 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-10-17T17:39:24.835Z,1571333964.835 [RudderServo](INFO): Powering down
2019-10-17T17:39:24.836Z,1571333964.836 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-10-17T17:39:24.836Z,1571333964.836 [ThrusterServo](INFO): Powering down
2019-10-17T17:39:24.837Z,1571333964.837 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-10-17T17:39:24.838Z,1571333964.838 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-10-17T17:39:24.838Z,1571333964.838 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-10-17T17:39:24.838Z,1571333964.838 [CBIT](DEBUG): Powering off loads.
2019-10-17T17:39:24.849Z,1571333964.849 [CBIT](DEBUG): Disabling WDT.
2019-10-17T17:39:24.861Z,1571333964.861 [CBIT](DEBUG): Opening all GF detection circuits.
2019-10-17T17:39:24.862Z,1571333964.862 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:25.234Z,1571333965.234 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:25.276Z,1571333965.276 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:25.441Z,1571333965.441 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:25.448Z,1571333965.448 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:25.471Z,1571333965.471 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:25.673Z,1571333965.673 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-10-17T17:39:25.937Z,1571333965.937 [logger ThreadHandler](INFO): Thread cancelled.