2020-05-18T16:04:11.020Z,1589817851.020 [Supervisor](DEBUG): Initializing supervisor.
2020-05-18T16:04:11.023Z,1589817851.023 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-05-18T16:04:11.024Z,1589817851.024 [SyncHandler](INFO): Protected caller Thread ID is 9765
2020-05-18T16:04:11.025Z,1589817851.025 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-05-18T16:04:11.026Z,1589817851.026 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-05-18T16:04:11.026Z,1589817851.026 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 9766
2020-05-18T16:04:11.030Z,1589817851.030 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-05-18T16:04:11.043Z,1589817851.043 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-05-18T16:04:11.044Z,1589817851.044 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-05-18T16:04:11.044Z,1589817851.044 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 9767
2020-05-18T16:04:11.045Z,1589817851.045 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-05-18T16:04:11.046Z,1589817851.046 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-05-18T16:04:11.046Z,1589817851.046 [logger ThreadHandler](INFO): Protected caller Thread ID is 9768
2020-05-18T16:04:11.048Z,1589817851.048 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-05-18T16:04:11.048Z,1589817851.048 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-05-18T16:04:11.050Z,1589817851.050 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-05-18T16:04:11.146Z,1589817851.146 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-05-18T16:04:11.146Z,1589817851.146 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-05-18T16:04:11.341Z,1589817851.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-05-18T16:04:11.342Z,1589817851.342 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-05-18T16:04:11.474Z,1589817851.474 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-05-18T16:04:11.475Z,1589817851.475 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-05-18T16:04:12.068Z,1589817852.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-05-18T16:04:12.069Z,1589817852.069 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-05-18T16:04:12.513Z,1589817852.513 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-05-18T16:04:12.514Z,1589817852.514 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-05-18T16:04:12.967Z,1589817852.967 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-05-18T16:04:12.968Z,1589817852.968 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-05-18T16:04:13.256Z,1589817853.256 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-05-18T16:04:13.256Z,1589817853.256 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-05-18T16:04:13.564Z,1589817853.564 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-05-18T16:04:13.564Z,1589817853.564 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-05-18T16:04:13.967Z,1589817853.967 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-05-18T16:04:13.967Z,1589817853.967 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-05-18T16:04:14.111Z,1589817854.111 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-05-18T16:04:14.111Z,1589817854.111 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-05-18T16:04:14.214Z,1589817854.214 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-05-18T16:04:14.214Z,1589817854.214 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-05-18T16:04:14.294Z,1589817854.294 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-05-18T16:04:14.395Z,1589817854.395 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-05-18T16:04:14.395Z,1589817854.395 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-05-18T16:04:14.588Z,1589817854.588 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-05-18T16:04:14.589Z,1589817854.589 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-05-18T16:04:14.790Z,1589817854.790 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-05-18T16:04:14.792Z,1589817854.792 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2020-05-18T16:04:14.793Z,1589817854.793 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2020-05-18T16:04:14.876Z,1589817854.876 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2020-05-18T16:04:15.101Z,1589817855.101 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-05-18T16:04:15.102Z,1589817855.102 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2020-05-18T16:04:15.213Z,1589817855.213 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2020-05-18T16:04:15.496Z,1589817855.496 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2020-05-18T16:04:15.896Z,1589817855.896 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2020-05-18T16:04:16.026Z,1589817856.026 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2020-05-18T16:04:16.186Z,1589817856.186 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2020-05-18T16:04:16.280Z,1589817856.280 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2020-05-18T16:04:16.425Z,1589817856.425 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2020-05-18T16:04:16.526Z,1589817856.526 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2020-05-18T16:04:16.624Z,1589817856.624 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2020-05-18T16:04:16.624Z,1589817856.624 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-05-18T16:04:16.635Z,1589817856.635 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-05-18T16:04:16.733Z,1589817856.733 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-05-18T16:04:16.733Z,1589817856.733 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-05-18T16:04:16.865Z,1589817856.865 [BuoyancyServo] Loaded
2020-05-18T16:04:16.865Z,1589817856.865 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-05-18T16:04:16.880Z,1589817856.880 [ElevatorServo] Loaded
2020-05-18T16:04:16.880Z,1589817856.880 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-05-18T16:04:16.896Z,1589817856.896 [MassServo] Loaded
2020-05-18T16:04:16.896Z,1589817856.896 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-05-18T16:04:16.911Z,1589817856.911 [RudderServo] Loaded
2020-05-18T16:04:16.911Z,1589817856.911 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-05-18T16:04:16.925Z,1589817856.925 [ThrusterServo] Loaded
2020-05-18T16:04:16.926Z,1589817856.926 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-05-18T16:04:16.926Z,1589817856.926 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-05-18T16:04:16.927Z,1589817856.927 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-05-18T16:04:17.060Z,1589817857.060 [SBIT](DEBUG): Construct Startup Built In Test.
2020-05-18T16:04:17.088Z,1589817857.088 [SBIT] Loaded
2020-05-18T16:04:17.089Z,1589817857.089 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-05-18T16:04:17.089Z,1589817857.089 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-05-18T16:04:17.118Z,1589817857.118 [IBIT] Loaded
2020-05-18T16:04:17.119Z,1589817857.119 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-05-18T16:04:17.122Z,1589817857.122 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-05-18T16:04:17.510Z,1589817857.510 [CBIT] Loaded
2020-05-18T16:04:17.511Z,1589817857.511 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-05-18T16:04:17.511Z,1589817857.511 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-05-18T16:04:17.512Z,1589817857.512 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-05-18T16:04:17.719Z,1589817857.719 [ESPComponent] Loaded
2020-05-18T16:04:17.719Z,1589817857.719 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2020-05-18T16:04:17.733Z,1589817857.733 [PAR_Licor] Loaded
2020-05-18T16:04:17.734Z,1589817857.734 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-05-18T16:04:17.740Z,1589817857.740 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-05-18T16:04:17.741Z,1589817857.741 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-05-18T16:04:17.747Z,1589817857.747 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-05-18T16:04:17.747Z,1589817857.747 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-05-18T16:04:17.751Z,1589817857.751 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-05-18T16:04:17.752Z,1589817857.752 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-05-18T16:04:17.756Z,1589817857.756 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-05-18T16:04:17.756Z,1589817857.756 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-05-18T16:04:17.760Z,1589817857.760 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-05-18T16:04:17.761Z,1589817857.761 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-05-18T16:04:17.765Z,1589817857.765 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-05-18T16:04:17.765Z,1589817857.765 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-05-18T16:04:17.770Z,1589817857.770 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-05-18T16:04:17.770Z,1589817857.770 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-05-18T16:04:17.774Z,1589817857.774 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-05-18T16:04:17.779Z,1589817857.779 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-05-18T16:04:17.779Z,1589817857.779 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-05-18T16:04:17.780Z,1589817857.780 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-05-18T16:04:17.784Z,1589817857.784 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-05-18T16:04:17.784Z,1589817857.784 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-05-18T16:04:17.788Z,1589817857.788 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-05-18T16:04:17.788Z,1589817857.788 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-05-18T16:04:17.793Z,1589817857.793 [WetLabsBB2FL] Loaded
2020-05-18T16:04:17.793Z,1589817857.793 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-05-18T16:04:17.794Z,1589817857.794 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406764E0
2020-05-18T16:04:17.795Z,1589817857.795 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 9847
2020-05-18T16:04:17.795Z,1589817857.795 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-05-18T16:04:17.796Z,1589817857.796 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-05-18T16:04:17.836Z,1589817857.836 [DepthRateCalculator] Loaded
2020-05-18T16:04:17.837Z,1589817857.837 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-05-18T16:04:17.842Z,1589817857.842 [PitchRateCalculator] Loaded
2020-05-18T16:04:17.842Z,1589817857.842 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-05-18T16:04:17.858Z,1589817857.858 [SpeedCalculator] Loaded
2020-05-18T16:04:17.858Z,1589817857.858 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-05-18T16:04:17.879Z,1589817857.879 [TempGradientCalculator] Loaded
2020-05-18T16:04:17.879Z,1589817857.879 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-05-18T16:04:17.884Z,1589817857.884 [YawRateCalculator] Loaded
2020-05-18T16:04:17.884Z,1589817857.884 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-05-18T16:04:17.917Z,1589817857.917 [ElevatorOffsetCalculator] Loaded
2020-05-18T16:04:17.917Z,1589817857.917 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-05-18T16:04:17.917Z,1589817857.917 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-05-18T16:04:17.918Z,1589817857.918 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-05-18T16:04:17.945Z,1589817857.945 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-05-18T16:04:17.946Z,1589817857.946 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-05-18T16:04:18.047Z,1589817858.047 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-05-18T16:04:18.048Z,1589817858.048 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-05-18T16:04:18.068Z,1589817858.068 [NavChart] Loaded
2020-05-18T16:04:18.068Z,1589817858.068 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-05-18T16:04:18.072Z,1589817858.072 [UniversalFixResidualReporter] Loaded
2020-05-18T16:04:18.072Z,1589817858.072 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-05-18T16:04:18.073Z,1589817858.073 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-05-18T16:04:18.073Z,1589817858.073 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-05-18T16:04:18.433Z,1589817858.433 [DataOverHttps] Loaded
2020-05-18T16:04:18.434Z,1589817858.434 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-05-18T16:04:18.435Z,1589817858.435 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409644E0
2020-05-18T16:04:18.435Z,1589817858.435 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 9848
2020-05-18T16:04:18.448Z,1589817858.448 [Depth_Keller] Loaded
2020-05-18T16:04:18.449Z,1589817858.449 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-05-18T16:04:18.453Z,1589817858.453 [DropWeight] Loaded
2020-05-18T16:04:18.454Z,1589817858.454 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-05-18T16:04:18.548Z,1589817858.548 [NAL9602] Loaded
2020-05-18T16:04:18.548Z,1589817858.548 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-05-18T16:04:18.586Z,1589817858.586 [Onboard] Loaded
2020-05-18T16:04:18.586Z,1589817858.586 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-05-18T16:04:18.587Z,1589817858.587 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409944E0
2020-05-18T16:04:18.588Z,1589817858.588 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 9849
2020-05-18T16:04:18.591Z,1589817858.591 [Radio_Surface] Loaded
2020-05-18T16:04:18.591Z,1589817858.591 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-05-18T16:04:18.592Z,1589817858.592 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409C44E0
2020-05-18T16:04:18.593Z,1589817858.593 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 9850
2020-05-18T16:04:18.725Z,1589817858.725 [DAT] Loaded
2020-05-18T16:04:18.726Z,1589817858.726 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-05-18T16:04:19.997Z,1589817859.997 [BPC1] Loaded
2020-05-18T16:04:19.998Z,1589817859.998 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-05-18T16:04:19.998Z,1589817859.998 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-05-18T16:04:19.998Z,1589817859.998 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-05-18T16:04:20.078Z,1589817860.078 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-05-18T16:04:20.079Z,1589817860.079 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-05-18T16:04:20.127Z,1589817860.127 [VerticalControl](DEBUG): Construct VerticalControl.
2020-05-18T16:04:20.210Z,1589817860.210 [VerticalControl] Loaded
2020-05-18T16:04:20.211Z,1589817860.211 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-05-18T16:04:20.211Z,1589817860.211 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-05-18T16:04:20.280Z,1589817860.280 [HorizontalControl] Loaded
2020-05-18T16:04:20.280Z,1589817860.280 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-05-18T16:04:20.280Z,1589817860.280 [SpeedControl](DEBUG): Construct SpeedControl.
2020-05-18T16:04:20.282Z,1589817860.282 [SpeedControl] Loaded
2020-05-18T16:04:20.282Z,1589817860.282 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-05-18T16:04:20.283Z,1589817860.283 [LoopControl](DEBUG): Construct LoopControl.
2020-05-18T16:04:20.284Z,1589817860.284 [LoopControl] Loaded
2020-05-18T16:04:20.284Z,1589817860.284 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-05-18T16:04:20.284Z,1589817860.284 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-05-18T16:04:20.285Z,1589817860.285 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-05-18T16:04:20.342Z,1589817860.342 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-05-18T16:04:20.342Z,1589817860.342 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-05-18T16:04:20.734Z,1589817860.734 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-05-18T16:04:20.737Z,1589817860.737 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-05-18T16:04:20.738Z,1589817860.738 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-05-18T16:04:20.745Z,1589817860.745 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-05-18T16:04:20.746Z,1589817860.746 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B054E0
2020-05-18T16:04:20.746Z,1589817860.746 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 9851
2020-05-18T16:04:20.751Z,1589817860.751 [Supervisor](INFO): Main Thread ID is 4394
2020-05-18T16:04:20.751Z,1589817860.751 [Supervisor](DEBUG): Running supervisor.
2020-05-18T16:04:20.752Z,1589817860.752 [CommandLine ThreadHandler](INFO): Handler Thread ID is 9852
2020-05-18T16:04:20.754Z,1589817860.754 [controlThread ThreadHandler](INFO): Handler Thread ID is 9853
2020-05-18T16:04:20.755Z,1589817860.755 [controlThread](DEBUG): Initializing ControlThread
2020-05-18T16:04:20.756Z,1589817860.756 [SBIT](INFO): Initialize SBIT Component.
2020-05-18T16:04:20.757Z,1589817860.757 [SBIT](IMPORTANT): git: 2020-02-26-39-g5ba86ef19
2020-05-18T16:04:20.757Z,1589817860.757 [SBIT](INFO): git hash: 5ba86ef19446a3a7971077fddc96013a7a660a2f
2020-05-18T16:04:20.757Z,1589817860.757 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-05-18T16:04:20.759Z,1589817860.759 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Nov 13 12:38:10 PST 2019
2020-05-18T16:04:20.760Z,1589817860.760 [SBIT](INFO): Beginning SBIT in 72.000000 seconds.
2020-05-18T16:04:20.760Z,1589817860.760 [IBIT](INFO): Initialize IBIT Component.
2020-05-18T16:04:20.761Z,1589817860.761 [CBIT](DEBUG): Initialize CBIT Component.
2020-05-18T16:04:20.762Z,1589817860.762 [logger ThreadHandler](INFO): Handler Thread ID is 9854
2020-05-18T16:04:20.775Z,1589817860.775 [CBIT](DEBUG): Initialized mux pins.
2020-05-18T16:04:20.775Z,1589817860.775 [CBIT](DEBUG): Initializing the watchdog timer.
2020-05-18T16:04:20.787Z,1589817860.787 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 9855
2020-05-18T16:04:20.789Z,1589817860.789 [WetLabsBB2FL](INFO): Powering down
2020-05-18T16:04:20.799Z,1589817860.799 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-05-18T16:04:20.799Z,1589817860.799 [CBIT](DEBUG): Initializing heartbeat.
2020-05-18T16:04:20.823Z,1589817860.823 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 9856
2020-05-18T16:04:20.824Z,1589817860.824 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-05-18T16:04:20.852Z,1589817860.852 [Onboard ThreadHandler](INFO): Handler Thread ID is 9857
2020-05-18T16:04:20.869Z,1589817860.869 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 9858
2020-05-18T16:04:20.871Z,1589817860.871 [CBIT](DEBUG): Deactivating GF circuits.
2020-05-18T16:04:20.871Z,1589817860.871 [CBIT](DEBUG): Deactivating emergency mode.
2020-05-18T16:04:20.900Z,1589817860.900 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 9859
2020-05-18T16:04:20.903Z,1589817860.903 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-05-18T16:04:20.903Z,1589817860.903 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-05-18T16:04:20.903Z,1589817860.903 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-05-18T16:04:20.904Z,1589817860.904 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-05-18T16:04:20.904Z,1589817860.904 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-05-18T16:04:20.904Z,1589817860.904 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-05-18T16:04:20.904Z,1589817860.904 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-05-18T16:04:20.904Z,1589817860.904 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-05-18T16:04:20.905Z,1589817860.905 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-05-18T16:04:20.905Z,1589817860.905 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-05-18T16:04:20.905Z,1589817860.905 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-05-18T16:04:20.905Z,1589817860.905 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-05-18T16:04:20.905Z,1589817860.905 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-05-18T16:04:20.906Z,1589817860.906 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-05-18T16:04:20.906Z,1589817860.906 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-05-18T16:04:20.906Z,1589817860.906 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-05-18T16:04:20.907Z,1589817860.907 [CBIT](DEBUG): Backplane powered.
2020-05-18T16:04:20.911Z,1589817860.911 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-05-18T16:04:20.912Z,1589817860.912 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-05-18T16:04:20.912Z,1589817860.912 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-05-18T16:04:20.912Z,1589817860.912 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-05-18T16:04:20.913Z,1589817860.913 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-05-18T16:04:20.913Z,1589817860.913 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-05-18T16:04:20.914Z,1589817860.914 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-05-18T16:04:20.915Z,1589817860.915 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-05-18T16:04:20.918Z,1589817860.918 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-05-18T16:04:20.924Z,1589817860.924 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-05-18T16:04:20.925Z,1589817860.925 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-05-18T16:04:20.926Z,1589817860.926 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-05-18T16:04:20.931Z,1589817860.931 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-05-18T16:04:20.959Z,1589817860.959 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-05-18T16:04:20.994Z,1589817860.994 [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>


2020-05-18T16:04:20.995Z,1589817860.995 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-05-18T16:04:21.067Z,1589817861.067 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-05-18T16:04:21.068Z,1589817861.068 [Default:A.Wait](DEBUG): Construct Wait.
2020-05-18T16:04:21.070Z,1589817861.070 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-05-18T16:04:21.105Z,1589817861.105 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-05-18T16:04:21.108Z,1589817861.108 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-05-18T16:04:21.129Z,1589817861.129 [Default:E.Execute](DEBUG): Construct Execute.
2020-05-18T16:04:21.133Z,1589817861.133 [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>


2020-05-18T16:04:21.156Z,1589817861.156 [controlThread](DEBUG): Component order: CycleStarter,ESPComponent,PAR_Licor,Depth_Keller,DropWeight,NAL9602,DAT,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-05-18T16:04:21.275Z,1589817861.275 [Radio_Surface](INFO): Powering up
2020-05-18T16:04:21.361Z,1589817861.361 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-18T16:04:21.362Z,1589817861.362 [DAT](INFO): Powering up
2020-05-18T16:04:21.362Z,1589817861.362 [DAT](DEBUG): Initializing DAT.
2020-05-18T16:04:21.451Z,1589817861.451 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-18T16:04:21.699Z,1589817861.699 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-05-18T16:04:21.707Z,1589817861.707 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-05-18T16:04:21.719Z,1589817861.719 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-05-18T16:04:21.739Z,1589817861.739 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-05-18T16:04:21.753Z,1589817861.753 [MassServo](DEBUG): Initializing EZServoServo.
2020-05-18T16:04:21.759Z,1589817861.759 [MassServo](DEBUG): Initializing MassServo.
2020-05-18T16:04:21.777Z,1589817861.777 [RudderServo](DEBUG): Initializing EZServoServo.
2020-05-18T16:04:21.783Z,1589817861.783 [RudderServo](DEBUG): Initializing RudderServo.
2020-05-18T16:04:21.805Z,1589817861.805 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-05-18T16:04:21.811Z,1589817861.811 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-05-18T16:04:21.968Z,1589817861.968 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2020-05-18T16:04:21.968Z,1589817861.968 [DropWeight] Hardware Fault, FailCount= 1
2020-05-18T16:04:21.968Z,1589817861.968 [DropWeight](ERROR): Hardware Fault
2020-05-18T16:04:22.024Z,1589817862.024 [CommandLine](FAULT): Scheduling is paused
2020-05-18T16:04:22.025Z,1589817862.025 [CBIT](INFO): Critical error at 20200518T160421
2020-05-18T16:04:22.025Z,1589817862.025 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-05-18T16:04:22.027Z,1589817862.027 [CBIT](ERROR): Hardware Fault in component: DropWeight
2020-05-18T16:04:22.028Z,1589817862.028 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2020-05-18T16:04:22.627Z,1589817862.627 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-05-18T16:04:22.627Z,1589817862.627 [RudderServo](FAULT): Rudder failed to initialize
2020-05-18T16:04:22.627Z,1589817862.627 [RudderServo] Communications Fault, FailCount= 1
2020-05-18T16:04:22.627Z,1589817862.627 [RudderServo](ERROR): Communications Fault
2020-05-18T16:04:22.773Z,1589817862.773 [CBIT](INFO): Critical error at 20200518T160422
2020-05-18T16:04:22.775Z,1589817862.775 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-05-18T16:04:22.944Z,1589817862.944 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-05-18T16:04:22.944Z,1589817862.944 [RudderServo](INFO): Powering down
2020-05-18T16:04:23.613Z,1589817863.613 [RudderServo](DEBUG): Initializing EZServoServo.
2020-05-18T16:04:23.732Z,1589817863.732 [RudderServo](DEBUG): Initializing RudderServo.
2020-05-18T16:04:23.736Z,1589817863.736 [CBIT](INFO): Clearing failed state for component RudderServo
2020-05-18T16:04:23.736Z,1589817863.736 [RudderServo] No Fault, FailCount= 1
2020-05-18T16:04:34.136Z,1589817874.136 [CommandLine](IMPORTANT): got command report mod Onboard.durationOfLastRun
2020-05-18T16:04:34.148Z,1589817874.148 [Reporter](INFO): Onboard.durationOfLastRun 0.029018 s
2020-05-18T16:04:36.169Z,1589817876.169 [Reporter](INFO): Onboard.durationOfLastRun 0.026673 s
2020-05-18T16:04:41.033Z,1589817881.033 [Reporter](INFO): Onboard.durationOfLastRun 0.025777 s
2020-05-18T16:04:46.293Z,1589817886.293 [Reporter](INFO): Onboard.durationOfLastRun 0.042028 s
2020-05-18T16:04:48.644Z,1589817888.644 [NAL9602](INFO): Powering up NAL9602
2020-05-18T16:04:51.161Z,1589817891.161 [Reporter](INFO): Onboard.durationOfLastRun 0.026077 s
2020-05-18T16:04:55.994Z,1589817895.994 [Reporter](INFO): Onboard.durationOfLastRun 0.025369 s
2020-05-18T16:04:59.556Z,1589817899.556 [NAL9602](INFO): NAL9602 initialized
2020-05-18T16:05:01.228Z,1589817901.228 [Reporter](INFO): Onboard.durationOfLastRun 0.025190 s
2020-05-18T16:05:06.091Z,1589817906.091 [Reporter](INFO): Onboard.durationOfLastRun 0.025802 s
2020-05-18T16:05:10.951Z,1589817910.951 [Reporter](INFO): Onboard.durationOfLastRun 0.044153 s
2020-05-18T16:05:16.133Z,1589817916.133 [Reporter](INFO): Onboard.durationOfLastRun 0.037984 s
2020-05-18T16:05:20.975Z,1589817920.975 [Reporter](INFO): Onboard.durationOfLastRun 0.024696 s
2020-05-18T16:05:21.373Z,1589817921.373 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-05-18T16:05:21.373Z,1589817921.373 [DAT] Communications Fault, FailCount= 1
2020-05-18T16:05:21.373Z,1589817921.373 [DAT](ERROR): Communications Fault
2020-05-18T16:05:21.389Z,1589817921.389 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-18T16:05:21.776Z,1589817921.776 [DAT](INFO): Powering down
2020-05-18T16:05:22.630Z,1589817922.630 [CBIT](INFO): Clearing failed state for component DAT
2020-05-18T16:05:22.630Z,1589817922.630 [DAT] No Fault, FailCount= 1
2020-05-18T16:05:25.011Z,1589817925.011 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-18T16:05:25.011Z,1589817925.011 [DAT](INFO): Powering up
2020-05-18T16:05:25.011Z,1589817925.011 [DAT](DEBUG): Initializing DAT.
2020-05-18T16:05:25.077Z,1589817925.077 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-18T16:05:26.240Z,1589817926.240 [Reporter](INFO): Onboard.durationOfLastRun 0.026074 s
2020-05-18T16:05:31.085Z,1589817931.085 [Reporter](INFO): Onboard.durationOfLastRun 0.024749 s
2020-05-18T16:05:33.507Z,1589817933.507 [SBIT](IMPORTANT): Beginning Startup BIT
2020-05-18T16:05:33.512Z,1589817933.512 [CBIT](IMPORTANT): Beginning ground fault scan
2020-05-18T16:05:35.974Z,1589817935.974 [Reporter](INFO): Onboard.durationOfLastRun 0.034341 s
2020-05-18T16:05:41.322Z,1589817941.322 [Reporter](INFO): Onboard.durationOfLastRun 0.026816 s
2020-05-18T16:05:44.583Z,1589817944.583 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.005531
CHAN A1 (24V): 0.000165
CHAN A2 (12V): -0.000335
CHAN A3 (5V): -0.000263
CHAN B0 (3.3V): -0.000287
CHAN B1 (3.15aV): 0.000054
CHAN B2 (3.15bV): 0.000542
CHAN B3 (GND): 0.000130
OPEN: 0.006329
Full Scale Calc: 4.765 mA, -1.589 mA
2020-05-18T16:05:46.162Z,1589817946.162 [Reporter](INFO): Onboard.durationOfLastRun 0.026091 s
2020-05-18T16:05:51.205Z,1589817951.205 [Reporter](INFO): Onboard.durationOfLastRun 0.026002 s
2020-05-18T16:05:56.026Z,1589817956.026 [Reporter](INFO): Onboard.durationOfLastRun 0.025745 s
2020-05-18T16:06:01.255Z,1589817961.255 [Reporter](INFO): Onboard.durationOfLastRun 0.024931 s
2020-05-18T16:06:06.072Z,1589817966.072 [Reporter](INFO): Onboard.durationOfLastRun 0.025210 s
2020-05-18T16:06:11.316Z,1589817971.316 [Reporter](INFO): Onboard.durationOfLastRun 0.025228 s
2020-05-18T16:06:16.373Z,1589817976.373 [Reporter](INFO): Onboard.durationOfLastRun 0.052193 s
2020-05-18T16:06:21.096Z,1589817981.096 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2020-05-18T16:06:21.096Z,1589817981.096 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-05-18T16:06:21.096Z,1589817981.096 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-05-18T16:06:21.108Z,1589817981.108 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-05-18T16:06:21.109Z,1589817981.109 [Reporter](INFO): Onboard.durationOfLastRun 0.024947 s
2020-05-18T16:06:21.517Z,1589817981.517 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-05-18T16:06:21.517Z,1589817981.517 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-05-18T16:06:25.113Z,1589817985.113 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-05-18T16:06:25.113Z,1589817985.113 [DAT] Communications Fault, FailCount= 2
2020-05-18T16:06:25.113Z,1589817985.113 [DAT](ERROR): Communications Fault
2020-05-18T16:06:25.130Z,1589817985.130 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-18T16:06:25.521Z,1589817985.521 [DAT](INFO): Powering down
2020-05-18T16:06:26.365Z,1589817986.365 [CBIT](INFO): Clearing failed state for component DAT
2020-05-18T16:06:26.366Z,1589817986.366 [DAT] No Fault, FailCount= 2
2020-05-18T16:06:26.367Z,1589817986.367 [Reporter](INFO): Onboard.durationOfLastRun 0.025948 s
2020-05-18T16:06:26.780Z,1589817986.780 [SBIT](IMPORTANT): SBIT PASSED
2020-05-18T16:06:26.780Z,1589817986.780 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-05-18T16:06:26.781Z,1589817986.781 [SBIT](IMPORTANT): AHRS_M2.loadAtStartup=0 bool;

2020-05-18T16:06:26.781Z,1589817986.781 [SBIT](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2020-05-18T16:06:26.782Z,1589817986.782 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2020-05-18T16:06:26.782Z,1589817986.782 [SBIT](IMPORTANT): CBIT.gf12Offset=61.5 microampere;

2020-05-18T16:06:26.782Z,1589817986.782 [SBIT](IMPORTANT): CBIT.gf24Offset=148.1 microampere;

2020-05-18T16:06:26.782Z,1589817986.782 [SBIT](IMPORTANT): CBIT.gf3_15Offset=-4.3 microampere;

2020-05-18T16:06:26.782Z,1589817986.782 [SBIT](IMPORTANT): CBIT.gf3_3Offset=-2.7 microampere;

2020-05-18T16:06:26.782Z,1589817986.782 [SBIT](IMPORTANT): CBIT.gf5Offset=8.7 microampere;

2020-05-18T16:06:26.782Z,1589817986.782 [SBIT](IMPORTANT): CBIT.gfCommOffset=-27.9 microampere;

2020-05-18T16:06:26.782Z,1589817986.782 [SBIT](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2020-05-18T16:06:26.782Z,1589817986.782 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;

2020-05-18T16:06:26.782Z,1589817986.782 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2020-05-18T16:06:27.157Z,1589817987.157 [MissionManager](IMPORTANT): Started mission Startup
2020-05-18T16:06:27.157Z,1589817987.157 [Startup] Running Loop=1
2020-05-18T16:06:27.157Z,1589817987.157 [Startup](DEBUG): Aggregate::initialize Startup
2020-05-18T16:06:27.157Z,1589817987.157 [Startup:A.GoToSurface] Running Loop=1
2020-05-18T16:06:27.158Z,1589817987.158 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-05-18T16:06:27.158Z,1589817987.158 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-05-18T16:06:27.159Z,1589817987.159 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-05-18T16:06:27.159Z,1589817987.159 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-05-18T16:06:27.160Z,1589817987.160 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-05-18T16:06:27.160Z,1589817987.160 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-05-18T16:06:27.166Z,1589817987.166 [Startup:StartupSatComms] Running Loop=1
2020-05-18T16:06:27.167Z,1589817987.167 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-05-18T16:06:27.167Z,1589817987.167 [Startup:StartupSatComms:A] Running Loop=1
2020-05-18T16:06:27.549Z,1589817987.549 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-05-18T16:06:28.758Z,1589817988.758 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-18T16:06:28.758Z,1589817988.758 [DAT](INFO): Powering up
2020-05-18T16:06:28.759Z,1589817988.759 [DAT](DEBUG): Initializing DAT.
2020-05-18T16:06:28.843Z,1589817988.843 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-18T16:06:31.202Z,1589817991.202 [Reporter](INFO): Onboard.durationOfLastRun 0.025270 s
2020-05-18T16:06:36.044Z,1589817996.044 [Reporter](INFO): Onboard.durationOfLastRun 0.025194 s
2020-05-18T16:06:41.296Z,1589818001.296 [Reporter](INFO): Onboard.durationOfLastRun 0.024779 s
2020-05-18T16:06:46.144Z,1589818006.144 [Reporter](INFO): Onboard.durationOfLastRun 0.026130 s
2020-05-18T16:06:51.027Z,1589818011.027 [Reporter](INFO): Onboard.durationOfLastRun 0.025409 s
2020-05-18T16:06:56.244Z,1589818016.244 [Reporter](INFO): Onboard.durationOfLastRun 0.025127 s
2020-05-18T16:07:01.108Z,1589818021.108 [Reporter](INFO): Onboard.durationOfLastRun 0.025707 s
2020-05-18T16:07:03.777Z,1589818023.777 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004760
2020-05-18T16:07:06.344Z,1589818026.344 [Reporter](INFO): Onboard.durationOfLastRun 0.028044 s
2020-05-18T16:07:11.192Z,1589818031.192 [Reporter](INFO): Onboard.durationOfLastRun 0.026293 s
2020-05-18T16:07:16.079Z,1589818036.079 [Reporter](INFO): Onboard.durationOfLastRun 0.042917 s
2020-05-18T16:07:21.354Z,1589818041.354 [Reporter](INFO): Onboard.durationOfLastRun 0.025600 s
2020-05-18T16:07:26.140Z,1589818046.140 [Reporter](INFO): Onboard.durationOfLastRun 0.028269 s
2020-05-18T16:07:27.339Z,1589818047.339 [Startup:StartupSatComms:A](INFO): Timed out from 2020-05-18T16:06:27.2Z
2020-05-18T16:07:27.339Z,1589818047.339 [Startup:StartupSatComms:A] Stopped
2020-05-18T16:07:27.339Z,1589818047.339 [Startup:StartupSatComms:B] Running Loop=1
2020-05-18T16:07:27.745Z,1589818047.745 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-05-18T16:07:28.964Z,1589818048.964 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-05-18T16:07:28.964Z,1589818048.964 [DAT] Communications Fault, FailCount= 3
2020-05-18T16:07:28.964Z,1589818048.964 [DAT](ERROR): Communications Fault
2020-05-18T16:07:29.044Z,1589818049.044 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-18T16:07:29.363Z,1589818049.363 [DAT](INFO): Powering down
2020-05-18T16:07:30.248Z,1589818050.248 [CBIT](INFO): Clearing failed state for component DAT
2020-05-18T16:07:30.248Z,1589818050.248 [DAT] No Fault, FailCount= 3
2020-05-18T16:07:31.133Z,1589818051.133 [Reporter](INFO): Onboard.durationOfLastRun 0.025347 s
2020-05-18T16:07:32.599Z,1589818052.599 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-18T16:07:32.599Z,1589818052.599 [DAT](INFO): Powering up
2020-05-18T16:07:32.599Z,1589818052.599 [DAT](DEBUG): Initializing DAT.
2020-05-18T16:07:32.629Z,1589818052.629 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-18T16:07:33.384Z,1589818053.384 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200518T153101/Courier0013.lzma
2020-05-18T16:07:34.381Z,1589818054.381 [DataOverHttps](INFO): Moved sent file to Logs/20200518T153101/Courier0013.lzma.bak
2020-05-18T16:07:34.381Z,1589818054.381 [DataOverHttps](INFO): SBD MOMSN=12335072
2020-05-18T16:07:36.263Z,1589818056.263 [Reporter](INFO): Onboard.durationOfLastRun 0.029253 s
2020-05-18T16:07:41.108Z,1589818061.108 [Reporter](INFO): Onboard.durationOfLastRun 0.026028 s
2020-05-18T16:07:46.388Z,1589818066.388 [Reporter](INFO): Onboard.durationOfLastRun 0.026072 s
2020-05-18T16:07:50.415Z,1589818070.415 [DataOverHttps](INFO): Sending 245 bytes from file Logs/20200518T160410/Courier0000.lzma
2020-05-18T16:07:51.227Z,1589818071.227 [Reporter](INFO): Onboard.durationOfLastRun 0.027890 s
2020-05-18T16:07:51.417Z,1589818071.417 [DataOverHttps](INFO): Moved sent file to Logs/20200518T160410/Courier0000.lzma.bak
2020-05-18T16:07:51.417Z,1589818071.417 [DataOverHttps](INFO): SBD MOMSN=12335074
2020-05-18T16:07:56.104Z,1589818076.104 [Reporter](INFO): Onboard.durationOfLastRun 0.025888 s
2020-05-18T16:08:01.308Z,1589818081.308 [Reporter](INFO): Onboard.durationOfLastRun 0.024687 s
2020-05-18T16:08:06.146Z,1589818086.146 [Reporter](INFO): Onboard.durationOfLastRun 0.025072 s
2020-05-18T16:08:07.011Z,1589818087.011 [DataOverHttps](INFO): Sending 268 bytes from file Logs/20200518T153101/Express0014.lzma
2020-05-18T16:08:07.997Z,1589818087.997 [DataOverHttps](INFO): Moved sent file to Logs/20200518T153101/Express0014.lzma.bak
2020-05-18T16:08:07.997Z,1589818087.997 [DataOverHttps](INFO): SBD MOMSN=12335079
2020-05-18T16:08:11.573Z,1589818091.573 [Reporter](INFO): Onboard.durationOfLastRun 0.025639 s
2020-05-18T16:08:16.264Z,1589818096.264 [Reporter](INFO): Onboard.durationOfLastRun 0.038353 s
2020-05-18T16:08:21.148Z,1589818101.148 [Reporter](INFO): Onboard.durationOfLastRun 0.052112 s
2020-05-18T16:08:21.908Z,1589818101.908 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2020-05-18T16:08:21.908Z,1589818101.908 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-05-18T16:08:21.908Z,1589818101.908 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-05-18T16:08:21.936Z,1589818101.936 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-05-18T16:08:22.340Z,1589818102.340 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-05-18T16:08:22.341Z,1589818102.341 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-05-18T16:08:23.828Z,1589818103.828 [DataOverHttps](INFO): Sending 1101 bytes from file Logs/20200518T160410/Express0001.lzma
2020-05-18T16:08:24.829Z,1589818104.829 [DataOverHttps](INFO): Moved sent file to Logs/20200518T160410/Express0001.lzma.bak
2020-05-18T16:08:24.829Z,1589818104.829 [DataOverHttps](INFO): SBD MOMSN=12335085
2020-05-18T16:08:26.377Z,1589818106.377 [Reporter](INFO): Onboard.durationOfLastRun 0.028894 s
2020-05-18T16:08:26.762Z,1589818106.762 [Startup:StartupSatComms:B] Stopped
2020-05-18T16:08:26.762Z,1589818106.762 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-05-18T16:08:26.762Z,1589818106.762 [Startup:StartupSatComms] Stopped
2020-05-18T16:08:26.762Z,1589818106.762 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-05-18T16:08:26.763Z,1589818106.763 [Startup](INFO): Completed Startup
2020-05-18T16:08:26.763Z,1589818106.763 [MissionManager](INFO): Startup is completed.
2020-05-18T16:08:26.763Z,1589818106.763 [MissionManager](INFO): Uninitializing Mission Startup
2020-05-18T16:08:26.763Z,1589818106.763 [Startup] Stopped
2020-05-18T16:08:26.763Z,1589818106.763 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-05-18T16:08:26.764Z,1589818106.764 [Startup:A.GoToSurface] Stopped
2020-05-18T16:08:26.764Z,1589818106.764 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-05-18T16:08:27.224Z,1589818107.224 [MissionManager](IMPORTANT): Started mission Default
2020-05-18T16:08:27.224Z,1589818107.224 [Default] Running Loop=1
2020-05-18T16:08:27.224Z,1589818107.224 [Default](DEBUG): Aggregate::initialize Default
2020-05-18T16:08:27.224Z,1589818107.224 [Default:B.GoToSurface] Running Loop=1
2020-05-18T16:08:27.224Z,1589818107.224 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-05-18T16:08:27.225Z,1589818107.225 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-05-18T16:08:27.225Z,1589818107.225 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-05-18T16:08:27.225Z,1589818107.225 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-05-18T16:08:27.226Z,1589818107.226 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-05-18T16:08:27.226Z,1589818107.226 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-05-18T16:08:27.226Z,1589818107.226 [Default:A.Wait] Running Loop=1
2020-05-18T16:08:27.226Z,1589818107.226 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-05-18T16:08:31.204Z,1589818111.204 [Reporter](INFO): Onboard.durationOfLastRun 0.025079 s
2020-05-18T16:08:32.795Z,1589818112.795 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-05-18T16:08:32.796Z,1589818112.796 [DAT] Communications Fault, FailCount= 4
2020-05-18T16:08:32.796Z,1589818112.796 [DAT](ERROR): Communications Fault
2020-05-18T16:08:32.838Z,1589818112.838 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-18T16:08:33.203Z,1589818113.203 [DAT](INFO): Powering down
2020-05-18T16:08:34.018Z,1589818114.018 [CBIT](INFO): Clearing failed state for component DAT
2020-05-18T16:08:34.018Z,1589818114.018 [DAT] No Fault, FailCount= 4
2020-05-18T16:08:36.427Z,1589818116.427 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-18T16:08:36.427Z,1589818116.427 [DAT](INFO): Powering up
2020-05-18T16:08:36.427Z,1589818116.427 [DAT](DEBUG): Initializing DAT.
2020-05-18T16:08:36.490Z,1589818116.490 [Reporter](INFO): Onboard.durationOfLastRun 0.040483 s
2020-05-18T16:08:36.525Z,1589818116.525 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-18T16:08:40.486Z,1589818120.486 [Default:A.Wait](INFO): Done Waiting.
2020-05-18T16:08:40.486Z,1589818120.486 [Default:A.Wait] Stopped
2020-05-18T16:08:40.486Z,1589818120.486 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-05-18T16:08:40.901Z,1589818120.901 [Default:CheckIn] Running Loop=1
2020-05-18T16:08:40.901Z,1589818120.901 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-05-18T16:08:40.901Z,1589818120.901 [Default:CheckIn:Read_GPS] Running Loop=1
2020-05-18T16:08:41.293Z,1589818121.293 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-05-18T16:08:41.326Z,1589818121.326 [Reporter](INFO): Onboard.durationOfLastRun 0.025589 s
2020-05-18T16:08:46.135Z,1589818126.135 [Reporter](INFO): Onboard.durationOfLastRun 0.025228 s
2020-05-18T16:08:51.389Z,1589818131.389 [Reporter](INFO): Onboard.durationOfLastRun 0.025736 s
2020-05-18T16:08:56.236Z,1589818136.236 [Reporter](INFO): Onboard.durationOfLastRun 0.026191 s
2020-05-18T16:09:01.144Z,1589818141.144 [Reporter](INFO): Onboard.durationOfLastRun 0.048800 s
2020-05-18T16:09:06.367Z,1589818146.367 [Reporter](INFO): Onboard.durationOfLastRun 0.025094 s
2020-05-18T16:09:11.202Z,1589818151.202 [Reporter](INFO): Onboard.durationOfLastRun 0.024714 s
2020-05-18T16:09:16.464Z,1589818156.464 [Reporter](INFO): Onboard.durationOfLastRun 0.040118 s
2020-05-18T16:09:21.308Z,1589818161.308 [Reporter](INFO): Onboard.durationOfLastRun 0.024699 s
2020-05-18T16:09:26.155Z,1589818166.155 [Reporter](INFO): Onboard.durationOfLastRun 0.028553 s
2020-05-18T16:09:31.515Z,1589818171.515 [Reporter](INFO): Onboard.durationOfLastRun 0.027265 s
2020-05-18T16:09:36.252Z,1589818176.252 [Reporter](INFO): Onboard.durationOfLastRun 0.027818 s
2020-05-18T16:09:36.617Z,1589818176.617 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-05-18T16:09:36.617Z,1589818176.617 [DAT] Communications Fault, FailCount= 5
2020-05-18T16:09:36.617Z,1589818176.617 [DAT](ERROR): Communications Fault
2020-05-18T16:09:36.634Z,1589818176.634 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-18T16:09:37.021Z,1589818177.021 [DAT](INFO): Powering down
2020-05-18T16:09:37.866Z,1589818177.866 [CBIT](INFO): Clearing failed state for component DAT
2020-05-18T16:09:37.866Z,1589818177.866 [DAT] No Fault, FailCount= 5
2020-05-18T16:09:40.265Z,1589818180.265 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-18T16:09:40.265Z,1589818180.265 [DAT](INFO): Powering up
2020-05-18T16:09:40.265Z,1589818180.265 [DAT](DEBUG): Initializing DAT.
2020-05-18T16:09:40.355Z,1589818180.355 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-18T16:09:41.512Z,1589818181.512 [Reporter](INFO): Onboard.durationOfLastRun 0.041958 s
2020-05-18T16:09:46.356Z,1589818186.356 [Reporter](INFO): Onboard.durationOfLastRun 0.027347 s
2020-05-18T16:09:51.204Z,1589818191.204 [Reporter](INFO): Onboard.durationOfLastRun 0.029192 s
2020-05-18T16:09:56.469Z,1589818196.469 [Reporter](INFO): Onboard.durationOfLastRun 0.027357 s
2020-05-18T16:10:01.337Z,1589818201.337 [Reporter](INFO): Onboard.durationOfLastRun 0.026146 s
2020-05-18T16:10:02.888Z,1589818202.888 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-05-18T16:10:06.573Z,1589818206.573 [Reporter](INFO): Onboard.durationOfLastRun 0.025735 s
2020-05-18T16:10:11.537Z,1589818211.537 [Reporter](INFO): Onboard.durationOfLastRun 0.054208 s
2020-05-18T16:10:16.228Z,1589818216.228 [Reporter](INFO): Onboard.durationOfLastRun 0.036177 s
2020-05-18T16:10:21.476Z,1589818221.476 [Reporter](INFO): Onboard.durationOfLastRun 0.025112 s
2020-05-18T16:10:23.083Z,1589818223.083 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2020-05-18T16:10:23.083Z,1589818223.083 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-05-18T16:10:23.083Z,1589818223.083 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-05-18T16:10:23.095Z,1589818223.095 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-05-18T16:10:23.498Z,1589818223.498 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-05-18T16:10:23.498Z,1589818223.498 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-05-18T16:10:26.362Z,1589818226.362 [Reporter](INFO): Onboard.durationOfLastRun 0.026051 s
2020-05-18T16:10:31.221Z,1589818231.221 [Reporter](INFO): Onboard.durationOfLastRun 0.025354 s
2020-05-18T16:10:36.428Z,1589818236.428 [Reporter](INFO): Onboard.durationOfLastRun 0.025080 s
2020-05-18T16:10:40.449Z,1589818240.449 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-05-18T16:10:40.449Z,1589818240.449 [DAT] Communications Fault, FailCount= 6
2020-05-18T16:10:40.449Z,1589818240.449 [DAT](ERROR): Communications Fault
2020-05-18T16:10:40.504Z,1589818240.504 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-18T16:10:40.863Z,1589818240.863 [DAT](INFO): Powering down
2020-05-18T16:10:41.325Z,1589818241.325 [Reporter](INFO): Onboard.durationOfLastRun 0.026982 s
2020-05-18T16:10:41.731Z,1589818241.731 [CBIT](INFO): Clearing failed state for component DAT
2020-05-18T16:10:41.731Z,1589818241.731 [DAT] No Fault, FailCount= 6
2020-05-18T16:10:44.097Z,1589818244.097 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-18T16:10:44.097Z,1589818244.097 [DAT](INFO): Powering up
2020-05-18T16:10:44.097Z,1589818244.097 [DAT](DEBUG): Initializing DAT.
2020-05-18T16:10:44.109Z,1589818244.109 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-18T16:10:46.534Z,1589818246.534 [Reporter](INFO): Onboard.durationOfLastRun 0.028321 s
2020-05-18T16:10:51.373Z,1589818251.373 [Reporter](INFO): Onboard.durationOfLastRun 0.027332 s
2020-05-18T16:10:56.271Z,1589818256.271 [Reporter](INFO): Onboard.durationOfLastRun 0.030973 s
2020-05-18T16:11:01.504Z,1589818261.504 [Reporter](INFO): Onboard.durationOfLastRun 0.027895 s
2020-05-18T16:11:06.390Z,1589818266.390 [Reporter](INFO): Onboard.durationOfLastRun 0.028834 s
2020-05-18T16:11:11.235Z,1589818271.235 [Reporter](INFO): Onboard.durationOfLastRun 0.032148 s
2020-05-18T16:11:16.434Z,1589818276.434 [Reporter](INFO): Onboard.durationOfLastRun 0.038621 s
2020-05-18T16:11:21.295Z,1589818281.295 [Reporter](INFO): Onboard.durationOfLastRun 0.025586 s
2020-05-18T16:11:26.544Z,1589818286.544 [Reporter](INFO): Onboard.durationOfLastRun 0.025085 s
2020-05-18T16:11:31.384Z,1589818291.384 [Reporter](INFO): Onboard.durationOfLastRun 0.027336 s
2020-05-18T16:11:36.258Z,1589818296.258 [Reporter](INFO): Onboard.durationOfLastRun 0.031325 s
2020-05-18T16:11:41.489Z,1589818301.489 [Reporter](INFO): Onboard.durationOfLastRun 0.026305 s
2020-05-18T16:11:44.281Z,1589818304.281 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-05-18T16:11:44.282Z,1589818304.282 [DAT] Communications Fault, FailCount= 7
2020-05-18T16:11:44.282Z,1589818304.282 [DAT](ERROR): Communications Fault
2020-05-18T16:11:44.331Z,1589818304.331 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-18T16:11:44.685Z,1589818304.685 [DAT](INFO): Powering down
2020-05-18T16:11:45.527Z,1589818305.527 [CBIT](INFO): Clearing failed state for component DAT
2020-05-18T16:11:45.527Z,1589818305.527 [DAT] No Fault, FailCount= 7
2020-05-18T16:11:46.393Z,1589818306.393 [Reporter](INFO): Onboard.durationOfLastRun 0.027256 s
2020-05-18T16:11:47.929Z,1589818307.929 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-05-18T16:11:47.929Z,1589818307.929 [DAT](INFO): Powering up
2020-05-18T16:11:47.929Z,1589818307.929 [DAT](DEBUG): Initializing DAT.
2020-05-18T16:11:48.019Z,1589818308.019 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-05-18T16:11:51.606Z,1589818311.606 [Reporter](INFO): Onboard.durationOfLastRun 0.026049 s
2020-05-18T16:11:56.436Z,1589818316.436 [Reporter](INFO): Onboard.durationOfLastRun 0.026184 s
2020-05-18T16:11:59.635Z,1589818319.635 [BPC1](ERROR): Battery stick #39 (s/n: 00F0) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AC0.
2020-05-18T16:11:59.635Z,1589818319.635 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2020-05-18T16:11:59.638Z,1589818319.638 [BPC1](INFO): Received data from all battery sticks.
2020-05-18T16:12:01.301Z,1589818321.301 [Reporter](INFO): Onboard.durationOfLastRun 0.036386 s
2020-05-18T16:12:06.560Z,1589818326.560 [Reporter](INFO): Onboard.durationOfLastRun 0.025148 s
2020-05-18T16:12:11.388Z,1589818331.388 [Reporter](INFO): Onboard.durationOfLastRun 0.027614 s
2020-05-18T16:12:16.615Z,1589818336.615 [Reporter](INFO): Onboard.durationOfLastRun 0.038774 s
2020-05-18T16:12:21.473Z,1589818341.473 [Reporter](INFO): Onboard.durationOfLastRun 0.026065 s
2020-05-18T16:12:24.302Z,1589818344.302 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2020-05-18T16:12:24.302Z,1589818344.302 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-05-18T16:12:24.302Z,1589818344.302 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-05-18T16:12:24.315Z,1589818344.315 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-05-18T16:12:24.731Z,1589818344.731 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-05-18T16:12:24.731Z,1589818344.731 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-05-18T16:12:26.315Z,1589818346.315 [Reporter](INFO): Onboard.durationOfLastRun 0.035165 s
2020-05-18T16:12:31.568Z,1589818351.568 [Reporter](INFO): Onboard.durationOfLastRun 0.024858 s
2020-05-18T16:12:36.444Z,1589818356.444 [Reporter](INFO): Onboard.durationOfLastRun 0.025160 s
2020-05-18T16:12:41.403Z,1589818361.403 [Reporter](INFO): Onboard.durationOfLastRun 0.026009 s
2020-05-18T16:12:46.540Z,1589818366.540 [Reporter](INFO): Onboard.durationOfLastRun 0.031140 s
2020-05-18T16:12:48.114Z,1589818368.114 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-05-18T16:12:48.114Z,1589818368.114 [DAT] Communications Fault, FailCount= 8
2020-05-18T16:12:48.114Z,1589818368.114 [DAT](ERROR): Communications Fault
2020-05-18T16:12:48.164Z,1589818368.164 [CBIT](ERROR): Communications Fault in component: DAT
2020-05-18T16:12:48.164Z,1589818368.164 [CBIT](FAULT): Communications Fault in component: DAT
2020-05-18T16:12:48.521Z,1589818368.521 [DAT](INFO): Powering down
2020-05-18T16:12:51.371Z,1589818371.371 [Reporter](INFO): Onboard.durationOfLastRun 0.027653 s
2020-05-18T16:12:56.644Z,1589818376.644 [Reporter](INFO): Onboard.durationOfLastRun 0.048155 s
2020-05-18T16:13:01.469Z,1589818381.469 [Reporter](INFO): Onboard.durationOfLastRun 0.025383 s
2020-05-18T16:13:04.688Z,1589818384.688 [CommandLine](IMPORTANT): got command restart application
2020-05-18T16:13:05.694Z,1589818385.694 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-18T16:13:05.695Z,1589818385.695 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:05.851Z,1589818385.851 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-05-18T16:13:05.851Z,1589818385.851 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:05.852Z,1589818385.852 [CommandLine](INFO): Join timeout helper Thread ID is 9907
2020-05-18T16:13:05.864Z,1589818385.864 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-05-18T16:13:05.864Z,1589818385.864 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:05.865Z,1589818385.865 [NavChartDb](INFO): Join timeout helper Thread ID is 9908
2020-05-18T16:13:06.099Z,1589818386.099 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-18T16:13:06.099Z,1589818386.099 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.103Z,1589818386.103 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-05-18T16:13:06.103Z,1589818386.103 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.103Z,1589818386.103 [Radio_Surface](INFO): Join timeout helper Thread ID is 9909
2020-05-18T16:13:06.151Z,1589818386.151 [Radio_Surface](INFO): Powering down
2020-05-18T16:13:06.152Z,1589818386.152 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-18T16:13:06.152Z,1589818386.152 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.155Z,1589818386.155 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-05-18T16:13:06.155Z,1589818386.155 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.156Z,1589818386.156 [Onboard](INFO): Join timeout helper Thread ID is 9910
2020-05-18T16:13:06.291Z,1589818386.291 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-18T16:13:06.291Z,1589818386.291 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.303Z,1589818386.303 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-05-18T16:13:06.303Z,1589818386.303 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.303Z,1589818386.303 [DataOverHttps](INFO): Join timeout helper Thread ID is 9911
2020-05-18T16:13:06.370Z,1589818386.370 [CBIT](FAULT): Humidity exceeds 50% of running average: Humidity:2305760 %. Average:268556.812500
2020-05-18T16:13:06.371Z,1589818386.371 [Reporter](INFO): Onboard.durationOfLastRun no_value
2020-05-18T16:13:06.411Z,1589818386.411 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-18T16:13:06.414Z,1589818386.414 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.416Z,1589818386.416 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-05-18T16:13:06.416Z,1589818386.416 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.417Z,1589818386.417 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 9912
2020-05-18T16:13:06.787Z,1589818386.787 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-18T16:13:06.788Z,1589818386.788 [WetLabsBB2FL](INFO): Powering down
2020-05-18T16:13:06.788Z,1589818386.788 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.806Z,1589818386.806 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-05-18T16:13:06.806Z,1589818386.806 [logger ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.807Z,1589818386.807 [logger](INFO): Join timeout helper Thread ID is 9913
2020-05-18T16:13:06.807Z,1589818386.807 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-18T16:13:06.808Z,1589818386.808 [logger ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.809Z,1589818386.809 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-05-18T16:13:06.809Z,1589818386.809 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.809Z,1589818386.809 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-05-18T16:13:06.809Z,1589818386.809 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:06.810Z,1589818386.810 [controlThread](INFO): Join timeout helper Thread ID is 9914
2020-05-18T16:13:07.083Z,1589818387.083 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-05-18T16:13:07.083Z,1589818387.083 [controlThread](DEBUG): Uninitializing ControlThread
2020-05-18T16:13:07.104Z,1589818387.104 [NAL9602](INFO): Powering down
2020-05-18T16:13:07.105Z,1589818387.105 [DAT](INFO): Powering down
2020-05-18T16:13:07.107Z,1589818387.107 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-05-18T16:13:07.108Z,1589818387.108 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-05-18T16:13:07.108Z,1589818387.108 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-05-18T16:13:07.109Z,1589818387.109 [MissionManager](INFO): Uninitializing Mission Default
2020-05-18T16:13:07.109Z,1589818387.109 [Default] Stopped
2020-05-18T16:13:07.109Z,1589818387.109 [Default](DEBUG): Aggregate::uninitialize Default
2020-05-18T16:13:07.109Z,1589818387.109 [Default:B.GoToSurface] Stopped
2020-05-18T16:13:07.109Z,1589818387.109 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-05-18T16:13:07.109Z,1589818387.109 [Default:CheckIn] Stopped
2020-05-18T16:13:07.109Z,1589818387.109 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-05-18T16:13:07.109Z,1589818387.109 [Default:CheckIn:Read_GPS] Stopped
2020-05-18T16:13:07.112Z,1589818387.112 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-05-18T16:13:07.112Z,1589818387.112 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-05-18T16:13:07.113Z,1589818387.113 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-05-18T16:13:07.113Z,1589818387.113 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-05-18T16:13:07.113Z,1589818387.113 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-05-18T16:13:07.113Z,1589818387.113 [BuoyancyServo](INFO): Powering down
2020-05-18T16:13:07.127Z,1589818387.127 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-05-18T16:13:07.127Z,1589818387.127 [ElevatorServo](INFO): Powering down
2020-05-18T16:13:07.128Z,1589818387.128 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-05-18T16:13:07.128Z,1589818387.128 [MassServo](INFO): Powering down
2020-05-18T16:13:07.129Z,1589818387.129 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-05-18T16:13:07.129Z,1589818387.129 [RudderServo](INFO): Powering down
2020-05-18T16:13:07.130Z,1589818387.130 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-05-18T16:13:07.130Z,1589818387.130 [ThrusterServo](INFO): Powering down
2020-05-18T16:13:07.130Z,1589818387.130 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-05-18T16:13:07.131Z,1589818387.131 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-05-18T16:13:07.131Z,1589818387.131 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-05-18T16:13:07.131Z,1589818387.131 [CBIT](DEBUG): Powering off loads.
2020-05-18T16:13:07.143Z,1589818387.143 [CBIT](DEBUG): Disabling WDT.
2020-05-18T16:13:07.155Z,1589818387.155 [CBIT](DEBUG): Opening all GF detection circuits.
2020-05-18T16:13:07.156Z,1589818387.156 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:07.188Z,1589818387.188 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:07.256Z,1589818387.256 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:07.257Z,1589818387.257 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:07.262Z,1589818387.262 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:07.317Z,1589818387.317 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-05-18T16:13:07.376Z,1589818387.376 [logger ThreadHandler](INFO): Thread cancelled.