2020-06-08T18:09:03.536Z,1591639743.536 [Supervisor](DEBUG): Initializing supervisor.
2020-06-08T18:09:03.540Z,1591639743.540 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-06-08T18:09:03.541Z,1591639743.541 [SyncHandler](INFO): Protected caller Thread ID is 7915
2020-06-08T18:09:03.541Z,1591639743.541 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-06-08T18:09:03.542Z,1591639743.542 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-06-08T18:09:03.542Z,1591639743.542 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 7916
2020-06-08T18:09:03.546Z,1591639743.546 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-06-08T18:09:03.559Z,1591639743.559 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-06-08T18:09:03.560Z,1591639743.560 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-06-08T18:09:03.561Z,1591639743.561 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 7917
2020-06-08T18:09:03.561Z,1591639743.561 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-06-08T18:09:03.562Z,1591639743.562 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-06-08T18:09:03.563Z,1591639743.563 [logger ThreadHandler](INFO): Protected caller Thread ID is 7918
2020-06-08T18:09:03.564Z,1591639743.564 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-06-08T18:09:03.565Z,1591639743.565 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-06-08T18:09:03.566Z,1591639743.566 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-06-08T18:09:03.901Z,1591639743.901 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-06-08T18:09:03.901Z,1591639743.901 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-06-08T18:09:04.924Z,1591639744.924 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-06-08T18:09:04.924Z,1591639744.924 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-06-08T18:09:05.068Z,1591639745.068 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-06-08T18:09:05.069Z,1591639745.069 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-06-08T18:09:05.551Z,1591639745.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-06-08T18:09:05.552Z,1591639745.552 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-06-08T18:09:05.648Z,1591639745.648 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-06-08T18:09:05.649Z,1591639745.649 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-06-08T18:09:05.729Z,1591639745.729 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-06-08T18:09:06.044Z,1591639746.044 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-06-08T18:09:06.044Z,1591639746.044 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-06-08T18:09:06.194Z,1591639746.194 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-06-08T18:09:06.194Z,1591639746.194 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-06-08T18:09:06.298Z,1591639746.298 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-06-08T18:09:06.299Z,1591639746.299 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-06-08T18:09:06.509Z,1591639746.509 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-06-08T18:09:06.510Z,1591639746.510 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-06-08T18:09:07.011Z,1591639747.011 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-06-08T18:09:07.011Z,1591639747.011 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-06-08T18:09:07.450Z,1591639747.450 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-06-08T18:09:07.450Z,1591639747.450 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-06-08T18:09:07.552Z,1591639747.552 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-06-08T18:09:07.553Z,1591639747.553 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-06-08T18:09:07.760Z,1591639747.760 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-06-08T18:09:07.760Z,1591639747.760 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-06-08T18:09:07.974Z,1591639747.974 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-06-08T18:09:07.975Z,1591639747.975 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-06-08T18:09:08.210Z,1591639748.210 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-06-08T18:09:08.212Z,1591639748.211 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/
2020-06-08T18:09:08.212Z,1591639748.212 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg
2020-06-08T18:09:08.307Z,1591639748.307 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg
2020-06-08T18:09:08.453Z,1591639748.453 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg
2020-06-08T18:09:08.538Z,1591639748.538 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg
2020-06-08T18:09:08.620Z,1591639748.620 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg
2020-06-08T18:09:08.728Z,1591639748.728 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg
2020-06-08T18:09:08.921Z,1591639748.921 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg
2020-06-08T18:09:09.150Z,1591639749.150 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-06-08T18:09:09.151Z,1591639749.151 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg
2020-06-08T18:09:09.264Z,1591639749.264 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg
2020-06-08T18:09:09.359Z,1591639749.359 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg
2020-06-08T18:09:09.465Z,1591639749.465 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg
2020-06-08T18:09:09.560Z,1591639749.560 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/root/
2020-06-08T18:09:09.560Z,1591639749.560 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-06-08T18:09:09.566Z,1591639749.566 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-06-08T18:09:09.642Z,1591639749.642 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-06-08T18:09:09.643Z,1591639749.643 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-06-08T18:09:09.662Z,1591639749.662 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-06-08T18:09:09.663Z,1591639749.663 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-06-08T18:09:09.704Z,1591639749.704 [DepthRateCalculator] Loaded
2020-06-08T18:09:09.705Z,1591639749.705 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-06-08T18:09:09.710Z,1591639749.710 [PitchRateCalculator] Loaded
2020-06-08T18:09:09.711Z,1591639749.711 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-06-08T18:09:09.726Z,1591639749.726 [SpeedCalculator] Loaded
2020-06-08T18:09:09.726Z,1591639749.726 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-06-08T18:09:09.747Z,1591639749.747 [TempGradientCalculator] Loaded
2020-06-08T18:09:09.747Z,1591639749.747 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-06-08T18:09:09.753Z,1591639749.753 [YawRateCalculator] Loaded
2020-06-08T18:09:09.753Z,1591639749.753 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-06-08T18:09:09.792Z,1591639749.792 [ElevatorOffsetCalculator] Loaded
2020-06-08T18:09:09.792Z,1591639749.792 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-06-08T18:09:09.792Z,1591639749.792 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-06-08T18:09:09.793Z,1591639749.793 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-06-08T18:09:09.917Z,1591639749.917 [VerticalControl](DEBUG): Construct VerticalControl.
2020-06-08T18:09:10.069Z,1591639750.069 [VerticalControl] Loaded
2020-06-08T18:09:10.069Z,1591639750.069 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-06-08T18:09:10.070Z,1591639750.070 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-06-08T18:09:10.257Z,1591639750.257 [HorizontalControl] Loaded
2020-06-08T18:09:10.257Z,1591639750.257 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-06-08T18:09:10.257Z,1591639750.257 [SpeedControl](DEBUG): Construct SpeedControl.
2020-06-08T18:09:10.262Z,1591639750.262 [SpeedControl] Loaded
2020-06-08T18:09:10.263Z,1591639750.263 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-06-08T18:09:10.263Z,1591639750.263 [LoopControl](DEBUG): Construct LoopControl.
2020-06-08T18:09:10.264Z,1591639750.264 [LoopControl] Loaded
2020-06-08T18:09:10.264Z,1591639750.264 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-06-08T18:09:10.264Z,1591639750.264 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-06-08T18:09:10.277Z,1591639750.277 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-06-08T18:09:10.569Z,1591639750.569 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-06-08T18:09:10.569Z,1591639750.569 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-06-08T18:09:10.589Z,1591639750.589 [NavChart] Loaded
2020-06-08T18:09:10.589Z,1591639750.589 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-06-08T18:09:10.593Z,1591639750.593 [UniversalFixResidualReporter] Loaded
2020-06-08T18:09:10.593Z,1591639750.593 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-06-08T18:09:10.594Z,1591639750.594 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-06-08T18:09:10.594Z,1591639750.594 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-06-08T18:09:10.804Z,1591639750.804 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-06-08T18:09:10.804Z,1591639750.804 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-06-08T18:09:11.303Z,1591639751.303 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-06-08T18:09:11.308Z,1591639751.308 [AHRS_M2](INFO): created writer for : platform_orientation
2020-06-08T18:09:11.310Z,1591639751.310 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-06-08T18:09:11.315Z,1591639751.315 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-06-08T18:09:11.315Z,1591639751.315 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-06-08T18:09:11.320Z,1591639751.320 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-06-08T18:09:11.321Z,1591639751.321 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-06-08T18:09:11.326Z,1591639751.326 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-06-08T18:09:11.395Z,1591639751.395 [AHRS_M2] Loaded
2020-06-08T18:09:11.396Z,1591639751.396 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-06-08T18:09:11.484Z,1591639751.484 [DataOverHttps] Loaded
2020-06-08T18:09:11.484Z,1591639751.484 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-06-08T18:09:11.485Z,1591639751.485 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408544E0
2020-06-08T18:09:11.486Z,1591639751.486 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8000
2020-06-08T18:09:11.499Z,1591639751.499 [Depth_Keller] Loaded
2020-06-08T18:09:11.499Z,1591639751.499 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-06-08T18:09:11.504Z,1591639751.504 [DropWeight] Loaded
2020-06-08T18:09:11.504Z,1591639751.504 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-06-08T18:09:11.548Z,1591639751.548 [DVL_micro] Loaded
2020-06-08T18:09:11.548Z,1591639751.548 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread.
2020-06-08T18:09:11.642Z,1591639751.642 [NAL9602] Loaded
2020-06-08T18:09:11.642Z,1591639751.642 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-06-08T18:09:11.681Z,1591639751.681 [Onboard] Loaded
2020-06-08T18:09:11.681Z,1591639751.681 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-06-08T18:09:11.684Z,1591639751.684 [Radio_Surface] Loaded
2020-06-08T18:09:11.685Z,1591639751.685 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-06-08T18:09:11.686Z,1591639751.686 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408844E0
2020-06-08T18:09:11.686Z,1591639751.686 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8001
2020-06-08T18:09:11.816Z,1591639751.816 [DAT] Loaded
2020-06-08T18:09:11.816Z,1591639751.816 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-06-08T18:09:13.280Z,1591639753.280 [BPC1] Loaded
2020-06-08T18:09:13.280Z,1591639753.280 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-06-08T18:09:13.280Z,1591639753.280 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-06-08T18:09:13.281Z,1591639753.281 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-06-08T18:09:13.384Z,1591639753.384 [BuoyancyServo] Loaded
2020-06-08T18:09:13.385Z,1591639753.385 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-06-08T18:09:13.396Z,1591639753.396 [ElevatorServo] Loaded
2020-06-08T18:09:13.396Z,1591639753.396 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-06-08T18:09:13.407Z,1591639753.407 [MassServo] Loaded
2020-06-08T18:09:13.407Z,1591639753.407 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-06-08T18:09:13.418Z,1591639753.418 [RudderServo] Loaded
2020-06-08T18:09:13.418Z,1591639753.418 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-06-08T18:09:13.428Z,1591639753.428 [ThrusterServo] Loaded
2020-06-08T18:09:13.429Z,1591639753.429 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-06-08T18:09:13.429Z,1591639753.429 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-06-08T18:09:13.429Z,1591639753.429 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-06-08T18:09:13.514Z,1591639753.514 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-06-08T18:09:13.515Z,1591639753.515 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-06-08T18:09:13.542Z,1591639753.542 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-06-08T18:09:13.542Z,1591639753.542 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-06-08T18:09:13.830Z,1591639753.830 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-06-08T18:09:13.830Z,1591639753.830 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-06-08T18:09:14.021Z,1591639754.021 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-06-08T18:09:14.026Z,1591639754.026 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-06-08T18:09:14.026Z,1591639754.026 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-06-08T18:09:14.031Z,1591639754.031 [CTD_Seabird](INFO): created writer for : depth
2020-06-08T18:09:14.031Z,1591639754.031 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-06-08T18:09:14.036Z,1591639754.036 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-06-08T18:09:14.037Z,1591639754.037 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-06-08T18:09:14.042Z,1591639754.042 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-06-08T18:09:14.042Z,1591639754.042 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-06-08T18:09:14.047Z,1591639754.047 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-06-08T18:09:14.048Z,1591639754.048 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-06-08T18:09:14.053Z,1591639754.053 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-06-08T18:09:14.054Z,1591639754.054 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-06-08T18:09:14.059Z,1591639754.059 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-06-08T18:09:14.086Z,1591639754.086 [CTD_Seabird] Loaded
2020-06-08T18:09:14.086Z,1591639754.086 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-06-08T18:09:14.087Z,1591639754.087 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A904E0
2020-06-08T18:09:14.088Z,1591639754.088 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8002
2020-06-08T18:09:14.117Z,1591639754.117 [ESPComponent] Loaded
2020-06-08T18:09:14.118Z,1591639754.118 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2020-06-08T18:09:14.132Z,1591639754.132 [PAR_Licor] Loaded
2020-06-08T18:09:14.132Z,1591639754.132 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-06-08T18:09:14.138Z,1591639754.138 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-06-08T18:09:14.138Z,1591639754.138 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-06-08T18:09:14.142Z,1591639754.142 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-06-08T18:09:14.142Z,1591639754.142 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-06-08T18:09:14.146Z,1591639754.146 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-06-08T18:09:14.147Z,1591639754.147 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-06-08T18:09:14.151Z,1591639754.151 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-06-08T18:09:14.151Z,1591639754.151 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-06-08T18:09:14.155Z,1591639754.155 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-06-08T18:09:14.155Z,1591639754.155 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-06-08T18:09:14.159Z,1591639754.159 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-06-08T18:09:14.159Z,1591639754.159 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-06-08T18:09:14.163Z,1591639754.163 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-06-08T18:09:14.163Z,1591639754.163 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-06-08T18:09:14.168Z,1591639754.168 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-06-08T18:09:14.172Z,1591639754.172 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-06-08T18:09:14.172Z,1591639754.172 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-06-08T18:09:14.173Z,1591639754.173 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-06-08T18:09:14.177Z,1591639754.177 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-06-08T18:09:14.177Z,1591639754.177 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-06-08T18:09:14.181Z,1591639754.181 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-06-08T18:09:14.181Z,1591639754.181 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-06-08T18:09:14.186Z,1591639754.186 [WetLabsBB2FL] Loaded
2020-06-08T18:09:14.186Z,1591639754.186 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-06-08T18:09:14.187Z,1591639754.187 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC04E0
2020-06-08T18:09:14.187Z,1591639754.187 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8003
2020-06-08T18:09:14.188Z,1591639754.188 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-06-08T18:09:14.189Z,1591639754.189 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-06-08T18:09:14.322Z,1591639754.322 [SBIT](DEBUG): Construct Startup Built In Test.
2020-06-08T18:09:14.333Z,1591639754.333 [SBIT] Loaded
2020-06-08T18:09:14.333Z,1591639754.333 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-06-08T18:09:14.334Z,1591639754.334 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-06-08T18:09:14.347Z,1591639754.347 [IBIT] Loaded
2020-06-08T18:09:14.347Z,1591639754.347 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-06-08T18:09:14.350Z,1591639754.350 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-06-08T18:09:14.486Z,1591639754.486 [CBIT] Loaded
2020-06-08T18:09:14.486Z,1591639754.486 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-06-08T18:09:14.487Z,1591639754.487 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-06-08T18:09:14.490Z,1591639754.490 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-06-08T18:09:14.491Z,1591639754.491 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-06-08T18:09:14.499Z,1591639754.499 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-06-08T18:09:14.500Z,1591639754.500 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B2B4E0
2020-06-08T18:09:14.501Z,1591639754.501 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8004
2020-06-08T18:09:14.506Z,1591639754.506 [Supervisor](INFO): Main Thread ID is 7554
2020-06-08T18:09:14.506Z,1591639754.506 [Supervisor](DEBUG): Running supervisor.
2020-06-08T18:09:14.506Z,1591639754.506 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8005
2020-06-08T18:09:14.509Z,1591639754.509 [controlThread ThreadHandler](INFO): Handler Thread ID is 8006
2020-06-08T18:09:14.509Z,1591639754.509 [controlThread](DEBUG): Initializing ControlThread
2020-06-08T18:09:14.510Z,1591639754.510 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-06-08T18:09:14.511Z,1591639754.511 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-06-08T18:09:14.511Z,1591639754.511 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-06-08T18:09:14.511Z,1591639754.511 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-06-08T18:09:14.512Z,1591639754.512 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-06-08T18:09:14.512Z,1591639754.512 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-06-08T18:09:14.513Z,1591639754.513 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-06-08T18:09:14.514Z,1591639754.514 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-06-08T18:09:14.515Z,1591639754.515 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-06-08T18:09:14.515Z,1591639754.515 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-06-08T18:09:14.516Z,1591639754.516 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-06-08T18:09:14.517Z,1591639754.517 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-06-08T18:09:14.526Z,1591639754.526 [SBIT](INFO): Initialize SBIT Component.
2020-06-08T18:09:14.526Z,1591639754.526 [SBIT](IMPORTANT): git: 2020-06-08
2020-06-08T18:09:14.527Z,1591639754.527 [SBIT](INFO): git hash: e0f639ec5017482b41982bca3db784e9d0ef310d
2020-06-08T18:09:14.527Z,1591639754.527 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-06-08T18:09:14.527Z,1591639754.527 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019
2020-06-08T18:09:14.528Z,1591639754.528 [SBIT](INFO): Beginning SBIT in 59.000000 seconds.
2020-06-08T18:09:14.529Z,1591639754.529 [IBIT](INFO): Initialize IBIT Component.
2020-06-08T18:09:14.530Z,1591639754.530 [CBIT](DEBUG): Initialize CBIT Component.
2020-06-08T18:09:14.531Z,1591639754.531 [logger ThreadHandler](INFO): Handler Thread ID is 8007
2020-06-08T18:09:14.541Z,1591639754.541 [CBIT](DEBUG): Initialized mux pins.
2020-06-08T18:09:14.541Z,1591639754.541 [CBIT](DEBUG): Initializing the watchdog timer.
2020-06-08T18:09:14.549Z,1591639754.549 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8008
2020-06-08T18:09:14.550Z,1591639754.550 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-06-08T18:09:14.561Z,1591639754.561 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8009
2020-06-08T18:09:14.565Z,1591639754.565 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-06-08T18:09:14.565Z,1591639754.565 [CBIT](DEBUG): Initializing heartbeat.
2020-06-08T18:09:14.573Z,1591639754.573 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8010
2020-06-08T18:09:14.574Z,1591639754.574 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-06-08T18:09:14.578Z,1591639754.578 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8012
2020-06-08T18:09:14.579Z,1591639754.579 [WetLabsBB2FL](INFO): Powering down
2020-06-08T18:09:14.609Z,1591639754.609 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8013
2020-06-08T18:09:14.613Z,1591639754.613 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-06-08T18:09:14.613Z,1591639754.613 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-06-08T18:09:14.613Z,1591639754.613 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-06-08T18:09:14.613Z,1591639754.613 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-06-08T18:09:14.614Z,1591639754.614 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-06-08T18:09:14.614Z,1591639754.614 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-06-08T18:09:14.614Z,1591639754.614 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-06-08T18:09:14.614Z,1591639754.614 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-06-08T18:09:14.614Z,1591639754.614 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-06-08T18:09:14.614Z,1591639754.614 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-06-08T18:09:14.615Z,1591639754.615 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-06-08T18:09:14.615Z,1591639754.615 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-06-08T18:09:14.615Z,1591639754.615 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-06-08T18:09:14.615Z,1591639754.615 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-06-08T18:09:14.615Z,1591639754.615 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-06-08T18:09:14.616Z,1591639754.616 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-06-08T18:09:14.637Z,1591639754.637 [CBIT](DEBUG): Deactivating GF circuits.
2020-06-08T18:09:14.637Z,1591639754.637 [CBIT](DEBUG): Deactivating emergency mode.
2020-06-08T18:09:14.673Z,1591639754.673 [CBIT](DEBUG): Backplane powered.
2020-06-08T18:09:14.674Z,1591639754.674 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-06-08T18:09:14.685Z,1591639754.685 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-06-08T18:09:14.703Z,1591639754.703 [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-06-08T18:09:14.704Z,1591639754.704 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-06-08T18:09:14.767Z,1591639754.767 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-06-08T18:09:14.768Z,1591639754.768 [Default:A.Wait](DEBUG): Construct Wait.
2020-06-08T18:09:14.786Z,1591639754.786 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-06-08T18:09:14.809Z,1591639754.809 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-06-08T18:09:14.811Z,1591639754.811 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-06-08T18:09:14.838Z,1591639754.838 [Default:E.Execute](DEBUG): Construct Execute.
2020-06-08T18:09:14.845Z,1591639754.845 [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-06-08T18:09:14.869Z,1591639754.869 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,ESPComponent,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,
2020-06-08T18:09:14.881Z,1591639754.881 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-06-08T18:09:14.908Z,1591639754.908 [Depth_Keller](ERROR): Pressure reading out of range: 1829.799438 decibar
2020-06-08T18:09:14.951Z,1591639754.951 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-06-08T18:09:14.952Z,1591639754.952 [DAT](INFO): Powering up
2020-06-08T18:09:14.952Z,1591639754.952 [DAT](DEBUG): Initializing DAT.
2020-06-08T18:09:14.965Z,1591639754.965 [Radio_Surface](INFO): Powering up
2020-06-08T18:09:15.029Z,1591639755.029 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-06-08T18:09:15.058Z,1591639755.058 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-06-08T18:09:15.201Z,1591639755.201 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-06-08T18:09:15.221Z,1591639755.221 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-06-08T18:09:15.222Z,1591639755.222 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-06-08T18:09:15.229Z,1591639755.229 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-06-08T18:09:15.230Z,1591639755.230 [MassServo](DEBUG): Initializing EZServoServo.
2020-06-08T18:09:15.292Z,1591639755.292 [MassServo](DEBUG): Initializing MassServo.
2020-06-08T18:09:15.293Z,1591639755.293 [RudderServo](DEBUG): Initializing EZServoServo.
2020-06-08T18:09:15.373Z,1591639755.373 [RudderServo](DEBUG): Initializing RudderServo.
2020-06-08T18:09:15.374Z,1591639755.374 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-06-08T18:09:15.491Z,1591639755.491 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-06-08T18:09:16.341Z,1591639756.341 [ThrusterServo](ERROR): Thruster halt for initialization uart error serial timeout
2020-06-08T18:09:16.413Z,1591639756.413 [ThrusterServo](FAULT): Thruster failed to initialize
2020-06-08T18:09:16.413Z,1591639756.413 [ThrusterServo] Communications Fault, FailCount= 1
2020-06-08T18:09:16.413Z,1591639756.413 [ThrusterServo](ERROR): Communications Fault
2020-06-08T18:09:16.416Z,1591639756.416 [CBIT](ERROR): Communications Fault in component: ThrusterServo
2020-06-08T18:09:16.590Z,1591639756.590 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-06-08T18:09:16.590Z,1591639756.590 [ThrusterServo](INFO): Powering down
2020-06-08T18:09:17.416Z,1591639757.416 [CBIT](INFO): Clearing failed state for component ThrusterServo
2020-06-08T18:09:17.416Z,1591639757.416 [ThrusterServo] No Fault, FailCount= 1
2020-06-08T18:09:17.697Z,1591639757.697 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-06-08T18:09:17.741Z,1591639757.741 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-06-08T18:09:18.673Z,1591639758.673 [ThrusterServo](ERROR): Thruster halt for initialization uart error serial timeout
2020-06-08T18:09:18.745Z,1591639758.745 [ThrusterServo](FAULT): Thruster failed to initialize
2020-06-08T18:09:18.745Z,1591639758.745 [ThrusterServo] Communications Fault, FailCount= 2
2020-06-08T18:09:18.745Z,1591639758.745 [ThrusterServo](ERROR): Communications Fault
2020-06-08T18:09:18.748Z,1591639758.748 [CBIT](ERROR): Communications Fault in component: ThrusterServo
2020-06-08T18:09:18.890Z,1591639758.890 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-06-08T18:09:18.890Z,1591639758.890 [ThrusterServo](INFO): Powering down
2020-06-08T18:09:20.036Z,1591639760.036 [CBIT](INFO): Clearing failed state for component ThrusterServo
2020-06-08T18:09:20.036Z,1591639760.036 [ThrusterServo] No Fault, FailCount= 2
2020-06-08T18:09:20.234Z,1591639760.234 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-06-08T18:09:20.237Z,1591639760.237 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-06-08T18:09:41.863Z,1591639781.863 [NAL9602](INFO): Powering up NAL9602
2020-06-08T18:09:52.780Z,1591639792.780 [NAL9602](INFO): NAL9602 initialized
2020-06-08T18:10:14.224Z,1591639814.224 [SBIT](IMPORTANT): Beginning Startup BIT
2020-06-08T18:10:14.228Z,1591639814.228 [CBIT](IMPORTANT): Beginning ground fault scan
2020-06-08T18:10:15.045Z,1591639815.045 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-06-08T18:10:15.045Z,1591639815.045 [DAT] Communications Fault, FailCount= 1
2020-06-08T18:10:15.045Z,1591639815.045 [DAT](ERROR): Communications Fault
2020-06-08T18:10:15.092Z,1591639815.092 [CBIT](ERROR): Communications Fault in component: DAT
2020-06-08T18:10:15.420Z,1591639815.420 [DAT](INFO): Powering down
2020-06-08T18:10:16.717Z,1591639816.717 [CBIT](INFO): Clearing failed state for component DAT
2020-06-08T18:10:16.717Z,1591639816.717 [DAT] No Fault, FailCount= 1
2020-06-08T18:10:18.767Z,1591639818.767 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-06-08T18:10:18.767Z,1591639818.767 [DAT](INFO): Powering up
2020-06-08T18:10:18.767Z,1591639818.767 [DAT](DEBUG): Initializing DAT.
2020-06-08T18:10:18.806Z,1591639818.806 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-06-08T18:10:23.602Z,1591639823.602 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: -1071
2020-06-08T18:10:23.604Z,1591639823.604 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.0000.00,999.00
2020-06-08T18:10:25.329Z,1591639825.329 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.003636
CHAN A1 (24V): -0.001600
CHAN A2 (12V): 0.000899
CHAN A3 (5V): 0.000198
CHAN B0 (3.3V): 0.000168
CHAN B1 (3.15aV): -0.000474
CHAN B2 (3.15bV): 0.000610
CHAN B3 (GND): -0.000204
OPEN: 0.003788
Full Scale Calc: 4.765 mA, -1.589 mA
2020-06-08T18:10:33.550Z,1591639833.550 [DVL_micro](ERROR): Failed to parse:
:WI,-00169,-01303,+01136,+00000,A
2020-06-08T18:10:53.851Z,1591639853.851 [SBIT](FAULT): Rudder: EXPECTED:-15.000000 ACTUAL:-14.799875
2020-06-08T18:10:53.851Z,1591639853.851 [SBIT](FAULT): Control surface position failure.
2020-06-08T18:10:54.163Z,1591639854.163 [DVL_micro](ERROR): only read 3 of 4 data items
2020-06-08T18:10:54.163Z,1591639854.163 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+99999.99,+9999.99
2020-06-08T18:11:08.004Z,1591639868.004 [SBIT](CRITICAL): SBIT FAILED
2020-06-08T18:11:08.004Z,1591639868.004 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-06-08T18:11:08.029Z,1591639868.029 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2020-06-08T18:11:08.029Z,1591639868.029 [SBIT](IMPORTANT): ESPComponent.simulateHardware=0 bool;

2020-06-08T18:11:08.029Z,1591639868.029 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=242.907926 cubic_centimeter;

2020-06-08T18:11:08.029Z,1591639868.029 [SBIT](IMPORTANT): VerticalControl.massDefault=9.890285 millimeter;

2020-06-08T18:11:08.031Z,1591639868.031 [CommandLine](FAULT): Scheduling is paused
2020-06-08T18:11:08.031Z,1591639868.031 [CBIT](INFO): Critical error at 20200608T181108
2020-06-08T18:11:08.032Z,1591639868.032 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-06-08T18:11:08.414Z,1591639868.414 [MissionManager](IMPORTANT): Started mission Startup
2020-06-08T18:11:08.415Z,1591639868.415 [Startup] Running Loop=1
2020-06-08T18:11:08.415Z,1591639868.415 [Startup](DEBUG): Aggregate::initialize Startup
2020-06-08T18:11:08.415Z,1591639868.415 [Startup:A.GoToSurface] Running Loop=1
2020-06-08T18:11:08.415Z,1591639868.415 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-06-08T18:11:08.416Z,1591639868.416 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-06-08T18:11:08.416Z,1591639868.416 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-06-08T18:11:08.416Z,1591639868.416 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-06-08T18:11:08.417Z,1591639868.417 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-06-08T18:11:08.417Z,1591639868.417 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-06-08T18:11:08.419Z,1591639868.419 [Startup:StartupSatComms] Running Loop=1
2020-06-08T18:11:08.419Z,1591639868.419 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-06-08T18:11:08.419Z,1591639868.419 [Startup:StartupSatComms:A] Running Loop=1
2020-06-08T18:11:08.816Z,1591639868.816 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-06-08T18:11:11.666Z,1591639871.666 [CommandLine](IMPORTANT): got command failComponent
2020-06-08T18:11:11.666Z,1591639871.666 [CommandLine](IMPORTANT): Failed components:
2020-06-08T18:11:11.666Z,1591639871.666 [CommandLine](IMPORTANT): No failed Components.
2020-06-08T18:11:18.907Z,1591639878.907 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-06-08T18:11:18.907Z,1591639878.907 [DAT] Communications Fault, FailCount= 2
2020-06-08T18:11:18.907Z,1591639878.907 [DAT](ERROR): Communications Fault
2020-06-08T18:11:18.952Z,1591639878.952 [CBIT](ERROR): Communications Fault in component: DAT
2020-06-08T18:11:19.314Z,1591639879.314 [DAT](INFO): Powering down
2020-06-08T18:11:20.140Z,1591639880.140 [CBIT](INFO): Clearing failed state for component DAT
2020-06-08T18:11:20.140Z,1591639880.140 [DAT] No Fault, FailCount= 2
2020-06-08T18:11:22.540Z,1591639882.540 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-06-08T18:11:22.540Z,1591639882.540 [DAT](INFO): Powering up
2020-06-08T18:11:22.540Z,1591639882.540 [DAT](DEBUG): Initializing DAT.
2020-06-08T18:11:22.577Z,1591639882.577 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-06-08T18:11:26.294Z,1591639886.294 [CommandLine](IMPORTANT): got command strobe off
2020-06-08T18:11:26.294Z,1591639886.294 [CommandLine](IMPORTANT): Deactivating strobe
2020-06-08T18:11:42.584Z,1591639902.584 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005310
2020-06-08T18:12:08.662Z,1591639928.662 [Startup:StartupSatComms:A](INFO): Timed out from 2020-06-08T18:11:08.4Z
2020-06-08T18:12:08.662Z,1591639928.662 [Startup:StartupSatComms:A] Stopped
2020-06-08T18:12:08.662Z,1591639928.662 [Startup:StartupSatComms:B] Running Loop=1
2020-06-08T18:12:09.021Z,1591639929.021 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-06-08T18:12:13.027Z,1591639933.027 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-06-08T18:12:13.028Z,1591639933.028 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+19.81489.0,0-02158,-01209,+01575,+00000,A
2020-06-08T18:12:14.662Z,1591639934.662 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-06-08T18:12:14.662Z,1591639934.662 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:12:14.680Z,1591639934.680 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:12:15.119Z,1591639935.119 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:12:15.119Z,1591639935.119 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-06-08T18:12:17.989Z,1591639937.989 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200608T170205/Courier0024.lzma
2020-06-08T18:12:18.991Z,1591639938.991 [DataOverHttps](INFO): Moved sent file to Logs/20200608T170205/Courier0024.lzma.bak
2020-06-08T18:12:18.991Z,1591639938.991 [DataOverHttps](INFO): SBD MOMSN=12372483
2020-06-08T18:12:22.733Z,1591639942.733 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-06-08T18:12:22.733Z,1591639942.733 [DAT] Communications Fault, FailCount= 3
2020-06-08T18:12:22.733Z,1591639942.733 [DAT](ERROR): Communications Fault
2020-06-08T18:12:22.798Z,1591639942.798 [CBIT](ERROR): Communications Fault in component: DAT
2020-06-08T18:12:23.151Z,1591639943.151 [DAT](INFO): Powering down
2020-06-08T18:12:23.547Z,1591639943.547 [DAT](FAULT): LCB fault:  Software Overcurrent.
2020-06-08T18:12:23.547Z,1591639943.547 [DAT] Hardware Fault, FailCount= 3
2020-06-08T18:12:23.547Z,1591639943.547 [DAT](ERROR): Hardware Fault
2020-06-08T18:12:23.982Z,1591639943.982 [CBIT](INFO): Clearing failed state for component DAT
2020-06-08T18:12:23.982Z,1591639943.982 [DAT] No Fault, FailCount= 3
2020-06-08T18:12:26.372Z,1591639946.372 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-06-08T18:12:26.372Z,1591639946.372 [DAT](INFO): Powering up
2020-06-08T18:12:26.372Z,1591639946.372 [DAT](DEBUG): Initializing DAT.
2020-06-08T18:12:26.469Z,1591639946.469 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-06-08T18:12:36.590Z,1591639956.590 [DataOverHttps](INFO): Sending 185 bytes from file Logs/20200608T180903/Courier0000.lzma
2020-06-08T18:12:37.590Z,1591639957.590 [DataOverHttps](INFO): Moved sent file to Logs/20200608T180903/Courier0000.lzma.bak
2020-06-08T18:12:37.591Z,1591639957.591 [DataOverHttps](INFO): SBD MOMSN=12372485
2020-06-08T18:12:57.841Z,1591639977.841 [DataOverHttps](INFO): Sending 380 bytes from file Logs/20200608T170205/Express0022.lzma
2020-06-08T18:12:58.843Z,1591639978.843 [DataOverHttps](INFO): Moved sent file to Logs/20200608T170205/Express0022.lzma.bak
2020-06-08T18:12:58.843Z,1591639978.843 [DataOverHttps](INFO): SBD MOMSN=12372489
2020-06-08T18:13:08.831Z,1591639988.831 [Startup:StartupSatComms:B](INFO): Timed out from 2020-06-08T18:12:08.7Z
2020-06-08T18:13:08.831Z,1591639988.831 [Startup:StartupSatComms:B] Stopped
2020-06-08T18:13:08.831Z,1591639988.831 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-06-08T18:13:08.831Z,1591639988.831 [Startup:StartupSatComms] Stopped
2020-06-08T18:13:08.831Z,1591639988.831 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-06-08T18:13:08.832Z,1591639988.832 [Startup](INFO): Completed Startup
2020-06-08T18:13:08.832Z,1591639988.832 [MissionManager](INFO): Startup is completed.
2020-06-08T18:13:08.832Z,1591639988.832 [MissionManager](INFO): Uninitializing Mission Startup
2020-06-08T18:13:08.863Z,1591639988.863 [Startup] Stopped
2020-06-08T18:13:08.863Z,1591639988.863 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-06-08T18:13:08.863Z,1591639988.863 [Startup:A.GoToSurface] Stopped
2020-06-08T18:13:08.863Z,1591639988.863 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-06-08T18:13:09.223Z,1591639989.223 [MissionManager](IMPORTANT): Started mission Default
2020-06-08T18:13:09.223Z,1591639989.223 [Default] Running Loop=1
2020-06-08T18:13:09.223Z,1591639989.223 [Default](DEBUG): Aggregate::initialize Default
2020-06-08T18:13:09.223Z,1591639989.223 [Default:B.GoToSurface] Running Loop=1
2020-06-08T18:13:09.223Z,1591639989.223 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-06-08T18:13:09.224Z,1591639989.224 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-06-08T18:13:09.224Z,1591639989.224 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-06-08T18:13:09.224Z,1591639989.224 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-06-08T18:13:09.225Z,1591639989.225 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-06-08T18:13:09.225Z,1591639989.225 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-06-08T18:13:09.225Z,1591639989.225 [Default:A.Wait] Running Loop=1
2020-06-08T18:13:09.226Z,1591639989.226 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-06-08T18:13:18.061Z,1591639998.061 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20200608T170205/Express0025.lzma
2020-06-08T18:13:19.063Z,1591639999.063 [DataOverHttps](INFO): Moved sent file to Logs/20200608T170205/Express0025.lzma.bak
2020-06-08T18:13:19.063Z,1591639999.063 [DataOverHttps](INFO): SBD MOMSN=12372502
2020-06-08T18:13:22.534Z,1591640002.534 [Default:A.Wait](INFO): Done Waiting.
2020-06-08T18:13:22.534Z,1591640002.534 [Default:A.Wait] Stopped
2020-06-08T18:13:22.534Z,1591640002.534 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-06-08T18:13:22.938Z,1591640002.938 [Default:CheckIn] Running Loop=1
2020-06-08T18:13:22.939Z,1591640002.939 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-08T18:13:22.939Z,1591640002.939 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-08T18:13:23.347Z,1591640003.347 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-06-08T18:13:26.575Z,1591640006.575 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-06-08T18:13:26.575Z,1591640006.575 [DAT] Communications Fault, FailCount= 4
2020-06-08T18:13:26.575Z,1591640006.575 [DAT](ERROR): Communications Fault
2020-06-08T18:13:26.625Z,1591640006.625 [CBIT](ERROR): Communications Fault in component: DAT
2020-06-08T18:13:26.965Z,1591640006.965 [DAT](INFO): Powering down
2020-06-08T18:13:27.824Z,1591640007.824 [CBIT](INFO): Clearing failed state for component DAT
2020-06-08T18:13:27.824Z,1591640007.824 [DAT] No Fault, FailCount= 4
2020-06-08T18:13:30.222Z,1591640010.222 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-06-08T18:13:30.222Z,1591640010.222 [DAT](INFO): Powering up
2020-06-08T18:13:30.222Z,1591640010.222 [DAT](DEBUG): Initializing DAT.
2020-06-08T18:13:30.301Z,1591640010.301 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-06-08T18:14:30.403Z,1591640070.403 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-06-08T18:14:30.403Z,1591640070.403 [DAT] Communications Fault, FailCount= 5
2020-06-08T18:14:30.403Z,1591640070.403 [DAT](ERROR): Communications Fault
2020-06-08T18:14:30.462Z,1591640070.462 [CBIT](ERROR): Communications Fault in component: DAT
2020-06-08T18:14:30.802Z,1591640070.802 [DAT](INFO): Powering down
2020-06-08T18:14:31.685Z,1591640071.685 [CBIT](INFO): Clearing failed state for component DAT
2020-06-08T18:14:31.685Z,1591640071.685 [DAT] No Fault, FailCount= 5
2020-06-08T18:14:34.036Z,1591640074.036 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-06-08T18:14:34.036Z,1591640074.036 [DAT](INFO): Powering up
2020-06-08T18:14:34.036Z,1591640074.036 [DAT](DEBUG): Initializing DAT.
2020-06-08T18:14:34.093Z,1591640074.093 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-06-08T18:14:45.746Z,1591640085.746 [DVL_micro](ERROR): only read 3 of 4 data items
2020-06-08T18:14:45.747Z,1591640085.747 [DVL_micro](ERROR): Failed to parse:
:BI,+0437,+00135,+00000,I
2020-06-08T18:14:55.850Z,1591640095.850 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-06-08T18:15:11.201Z,1591640111.201 [DVL_micro](ERROR): only read 0 of 4 data items
2020-06-08T18:15:11.201Z,1591640111.201 [DVL_micro](ERROR): Failed to parse:
:RD,++9999.999,+9999.99
2020-06-08T18:15:15.677Z,1591640115.677 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-06-08T18:15:15.677Z,1591640115.677 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:15:15.687Z,1591640115.687 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:15:16.080Z,1591640116.080 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:15:16.080Z,1591640116.080 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-06-08T18:15:34.240Z,1591640134.240 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-06-08T18:15:34.240Z,1591640134.240 [DAT] Communications Fault, FailCount= 6
2020-06-08T18:15:34.240Z,1591640134.240 [DAT](ERROR): Communications Fault
2020-06-08T18:15:34.257Z,1591640134.257 [CBIT](ERROR): Communications Fault in component: DAT
2020-06-08T18:15:34.634Z,1591640134.634 [DAT](INFO): Powering down
2020-06-08T18:15:35.498Z,1591640135.498 [CBIT](INFO): Clearing failed state for component DAT
2020-06-08T18:15:35.498Z,1591640135.498 [DAT] No Fault, FailCount= 6
2020-06-08T18:15:37.887Z,1591640137.887 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-06-08T18:15:37.887Z,1591640137.887 [DAT](INFO): Powering up
2020-06-08T18:15:37.888Z,1591640137.888 [DAT](DEBUG): Initializing DAT.
2020-06-08T18:15:37.985Z,1591640137.985 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-06-08T18:15:39.079Z,1591640139.079 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000009.99,000.+9999.999,+9999.99,+9999.99
2020-06-08T18:15:54.418Z,1591640154.418 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 321
2020-06-08T18:15:54.420Z,1591640154.420 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2020-06-08T18:16:38.075Z,1591640198.075 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-06-08T18:16:38.075Z,1591640198.075 [DAT] Communications Fault, FailCount= 7
2020-06-08T18:16:38.075Z,1591640198.075 [DAT](ERROR): Communications Fault
2020-06-08T18:16:38.091Z,1591640198.091 [CBIT](ERROR): Communications Fault in component: DAT
2020-06-08T18:16:38.486Z,1591640198.486 [DAT](INFO): Powering down
2020-06-08T18:16:39.323Z,1591640199.323 [CBIT](INFO): Clearing failed state for component DAT
2020-06-08T18:16:39.323Z,1591640199.323 [DAT] No Fault, FailCount= 7
2020-06-08T18:16:41.719Z,1591640201.719 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-06-08T18:16:41.719Z,1591640201.719 [DAT](INFO): Powering up
2020-06-08T18:16:41.720Z,1591640201.720 [DAT](DEBUG): Initializing DAT.
2020-06-08T18:16:41.757Z,1591640201.757 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-06-08T18:16:45.321Z,1591640205.321 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: -134
2020-06-08T18:16:45.323Z,1591640205.323 [DVL_micro](ERROR): Failed to parse:
:RD,+9999.99,+9999.99,+9999.99,+9999.99
2020-06-08T18:17:10.774Z,1591640230.774 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-06-08T18:17:10.774Z,1591640230.774 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+19.8,0000.0,1489:WI,+02062,00767,+0:BI,+02062,-01111,+00767,+00000,I
2020-06-08T18:17:16.472Z,1591640236.472 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2020-06-08T18:17:16.489Z,1591640236.489 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2020-06-08T18:17:16.492Z,1591640236.492 [BPC1](INFO): Received data from all battery sticks.
2020-06-08T18:17:41.892Z,1591640261.892 [DAT](FAULT): failed to initialize, no bytes available on serial interface
2020-06-08T18:17:41.892Z,1591640261.892 [DAT] Communications Fault, FailCount= 8
2020-06-08T18:17:41.892Z,1591640261.892 [DAT](ERROR): Communications Fault
2020-06-08T18:17:41.934Z,1591640261.934 [CBIT](ERROR): Communications Fault in component: DAT
2020-06-08T18:17:41.934Z,1591640261.934 [CBIT](FAULT): Communications Fault in component: DAT
2020-06-08T18:17:42.309Z,1591640262.309 [DAT](INFO): Powering down
2020-06-08T18:18:16.675Z,1591640296.675 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-06-08T18:18:16.676Z,1591640296.676 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:18:16.685Z,1591640296.685 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:18:17.089Z,1591640297.089 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:18:17.089Z,1591640297.089 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-06-08T18:18:23.143Z,1591640303.143 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-08T18:13:22.9Z
2020-06-08T18:18:23.143Z,1591640303.143 [Default:CheckIn:Read_GPS] Stopped
2020-06-08T18:18:23.144Z,1591640303.144 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-08T18:18:23.550Z,1591640303.550 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-06-08T18:18:32.437Z,1591640312.437 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20200608T180903/Courier0004.lzma
2020-06-08T18:18:33.439Z,1591640313.439 [DataOverHttps](INFO): Moved sent file to Logs/20200608T180903/Courier0004.lzma.bak
2020-06-08T18:18:33.439Z,1591640313.439 [DataOverHttps](INFO): SBD MOMSN=12372599
2020-06-08T18:18:47.338Z,1591640327.338 [DVL_micro](ERROR): Failed to parse:
:SA,-00.98,-06.71,039.1
2020-06-08T18:18:52.539Z,1591640332.539 [DataOverHttps](INFO): Sending 1039 bytes from file Logs/20200608T180903/Express0001.lzma
2020-06-08T18:18:53.538Z,1591640333.538 [DataOverHttps](INFO): Moved sent file to Logs/20200608T180903/Express0001.lzma.bak
2020-06-08T18:18:53.539Z,1591640333.539 [DataOverHttps](INFO): SBD MOMSN=12372601
2020-06-08T18:19:14.269Z,1591640354.269 [DataOverHttps](INFO): Sending 394 bytes from file Logs/20200608T180903/Express0005.lzma
2020-06-08T18:19:15.270Z,1591640355.270 [DataOverHttps](INFO): Moved sent file to Logs/20200608T180903/Express0005.lzma.bak
2020-06-08T18:19:15.271Z,1591640355.271 [DataOverHttps](INFO): SBD MOMSN=12372631
2020-06-08T18:19:19.710Z,1591640359.710 [Default:CheckIn:Read_Iridium] Stopped
2020-06-08T18:19:19.710Z,1591640359.710 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-08T18:19:19.711Z,1591640359.711 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-08T18:19:35.806Z,1591640375.806 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-06-08T18:19:35.806Z,1591640375.806 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+19.9,0000.0,1489.WI,+03099,-01514,+00632,+00000,A
2020-06-08T18:19:55.599Z,1591640395.599 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-06-08T18:19:55.599Z,1591640395.599 [NAL9602] Data Fault, FailCount= 1
2020-06-08T18:19:55.599Z,1591640395.599 [NAL9602](ERROR): Data Fault
2020-06-08T18:19:55.676Z,1591640395.676 [CBIT](ERROR): Data Fault in component: NAL9602
2020-06-08T18:19:56.020Z,1591640396.020 [NAL9602](INFO): Powering down
2020-06-08T18:19:56.856Z,1591640396.856 [CBIT](INFO): Clearing failed state for component NAL9602
2020-06-08T18:19:56.856Z,1591640396.856 [NAL9602] No Fault, FailCount= 1
2020-06-08T18:20:26.311Z,1591640426.311 [NAL9602](INFO): Powering up NAL9602
2020-06-08T18:20:26.709Z,1591640426.709 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-06-08T18:20:26.710Z,1591640426.710 [DVL_micro](ERROR): Failed to parse:
:TS,000000035.0,+19.9,489.0,0000262,-0196,+00000-00262,-0196,+00000,I
2020-06-08T18:20:37.219Z,1591640437.219 [NAL9602](INFO): NAL9602 initialized
2020-06-08T18:20:52.163Z,1591640452.163 [DVL_micro](ERROR): Failed to parse:
:WI,+01692,-01155,+00868,+00000+01692,-0868,+000D,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2020-06-08T18:20:59.235Z,1591640459.235 [CommandLine](IMPORTANT): got command show stack
2020-06-08T18:20:59.235Z,1591640459.235 [CommandLine](IMPORTANT): Behavior Stack:

2020-06-08T18:20:59.235Z,1591640459.235 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2020-06-08T18:20:59.235Z,1591640459.235 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:C.Wait
2020-06-08T18:21:03.278Z,1591640463.278 [CommandLine](IMPORTANT): got command get latitude
2020-06-08T18:21:03.279Z,1591640463.279 [CommandLine](FAULT): Element has no value
2020-06-08T18:21:12.552Z,1591640472.552 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.799999 degree
2020-06-08T18:21:12.554Z,1591640472.554 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2020-06-08T18:21:12.555Z,1591640472.555 [CommandLine](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.900002 degree
2020-06-08T18:21:12.556Z,1591640472.556 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2020-06-08T18:21:12.817Z,1591640472.817 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DVL_micro,NAL9602,Onboard,DAT,BPC1,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,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-06-08T18:21:13.189Z,1591640473.189 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-06-08T18:21:13.189Z,1591640473.189 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-06-08T18:21:13.189Z,1591640473.189 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:21:13.211Z,1591640473.211 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:13.635Z,1591640473.635 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:13.635Z,1591640473.635 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-06-08T18:21:14.442Z,1591640474.442 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-06-08T18:21:14.442Z,1591640474.442 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-06-08T18:21:14.442Z,1591640474.442 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:21:14.487Z,1591640474.487 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:14.854Z,1591640474.854 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:14.854Z,1591640474.854 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-06-08T18:21:15.656Z,1591640475.656 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-06-08T18:21:15.656Z,1591640475.656 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-06-08T18:21:15.656Z,1591640475.656 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:21:15.675Z,1591640475.675 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:16.060Z,1591640476.060 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:16.060Z,1591640476.060 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-06-08T18:21:16.851Z,1591640476.851 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-06-08T18:21:16.851Z,1591640476.851 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2020-06-08T18:21:16.851Z,1591640476.851 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:21:16.895Z,1591640476.895 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:17.303Z,1591640477.303 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:17.303Z,1591640477.303 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2020-06-08T18:21:18.043Z,1591640478.043 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-06-08T18:21:18.043Z,1591640478.043 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2020-06-08T18:21:18.043Z,1591640478.043 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:21:18.086Z,1591640478.086 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:18.508Z,1591640478.508 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:18.508Z,1591640478.508 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2020-06-08T18:21:19.286Z,1591640479.286 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-06-08T18:21:19.286Z,1591640479.286 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2020-06-08T18:21:19.286Z,1591640479.286 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:21:19.296Z,1591640479.296 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:19.707Z,1591640479.707 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:19.707Z,1591640479.707 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2020-06-08T18:21:20.489Z,1591640480.489 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-06-08T18:21:20.490Z,1591640480.490 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2020-06-08T18:21:20.490Z,1591640480.490 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:21:20.537Z,1591640480.537 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:20.911Z,1591640480.911 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:20.911Z,1591640480.911 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2020-06-08T18:21:21.718Z,1591640481.718 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-06-08T18:21:21.718Z,1591640481.718 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2020-06-08T18:21:21.718Z,1591640481.718 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:21:21.729Z,1591640481.729 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:22.131Z,1591640482.131 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:22.131Z,1591640482.131 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2020-06-08T18:21:22.888Z,1591640482.888 [DeadReckonUsingMultipleVelocitySources](ERROR): Caught NaN! Will not write estimated position: latitude_ = nan, longitude_ = nan, depth_ = nan, horizontalPathLengthSinceLastFix_ = nan, latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = nan
2020-06-08T18:21:22.888Z,1591640482.888 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2020-06-08T18:21:22.888Z,1591640482.888 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-08T18:21:22.941Z,1591640482.941 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:23.312Z,1591640483.312 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-08T18:21:23.312Z,1591640483.312 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2020-06-08T18:21:23.578Z,1591640483.578 [CommandLine](IMPORTANT): got command set NAL9602.time_fix 1591640448.000000 second
2020-06-08T18:21:54.786Z,1591640514.786 [NAL9602](INFO): Not Powering down - fast GPS
2020-06-08T18:22:42.095Z,1591640562.095 [CBIT](INFO): Clearing failed state for component DAT
2020-06-08T18:22:42.095Z,1591640562.095 [DAT] No Fault, FailCount= 8
2020-06-08T18:22:42.478Z,1591640562.478 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-06-08T18:22:42.479Z,1591640562.479 [DAT](INFO): Powering up
2020-06-08T18:22:42.479Z,1591640562.479 [DAT](DEBUG): Initializing DAT.
2020-06-08T18:22:42.549Z,1591640562.549 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-06-08T18:22:56.640Z,1591640576.640 [DAT](INFO): commRate: 800
2020-06-08T18:22:56.641Z,1591640576.641 [DAT](INFO): commRate: 800
2020-06-08T18:22:57.016Z,1591640577.016 [DAT](INFO): entering command mode
2020-06-08T18:22:57.425Z,1591640577.425 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:22:57.834Z,1591640577.834 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:22:58.227Z,1591640578.227 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:22:58.636Z,1591640578.636 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:22:59.046Z,1591640579.046 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:22:59.444Z,1591640579.444 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:22:59.855Z,1591640579.855 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:00.253Z,1591640580.253 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:00.653Z,1591640580.653 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:01.065Z,1591640581.065 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:01.477Z,1591640581.477 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:01.874Z,1591640581.874 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:02.287Z,1591640582.287 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:02.689Z,1591640582.689 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:03.095Z,1591640583.095 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:03.496Z,1591640583.496 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:03.893Z,1591640583.893 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:04.307Z,1591640584.307 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:04.697Z,1591640584.697 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:05.099Z,1591640585.099 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:05.514Z,1591640585.514 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:05.921Z,1591640585.921 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:06.320Z,1591640586.320 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:06.745Z,1591640586.745 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:07.117Z,1591640587.117 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-08T18:23:07.117Z,1591640587.117 [DAT](FAULT): failed to enter command mode
2020-06-08T18:23:07.526Z,1591640587.526 [DAT](INFO): entering command mode
2020-06-08T18:23:07.933Z,1591640587.933 [DAT](INFO): setting verbose to 3
2020-06-08T18:23:08.330Z,1591640588.330 [DAT](INFO): set verbose to 3
2020-06-08T18:23:08.330Z,1591640588.330 [DAT](INFO): setting DatVerbose to 27440
2020-06-08T18:23:08.734Z,1591640588.734 [DAT](INFO): set DatVerbose to 27440
2020-06-08T18:23:08.734Z,1591640588.734 [DAT](INFO): setting transmit power to 8
2020-06-08T18:23:09.150Z,1591640589.150 [DAT](INFO): set transmit power to 8
2020-06-08T18:23:09.150Z,1591640589.150 [DAT](INFO): setting local address to 8
2020-06-08T18:23:09.532Z,1591640589.532 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-06-08T18:23:09.532Z,1591640589.532 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0,+20.0,0000.0,14
2020-06-08T18:23:09.577Z,1591640589.577 [DAT](INFO): set local address to 8
2020-06-08T18:24:20.261Z,1591640660.261 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-06-08T18:24:20.261Z,1591640660.261 [Default:CheckIn:C.Wait] Stopped
2020-06-08T18:24:20.262Z,1591640660.262 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-08T18:24:20.262Z,1591640660.262 [Default:CheckIn:D] Running Loop=1
2020-06-08T18:24:20.683Z,1591640660.683 [Default:CheckIn:D] Stopped
2020-06-08T18:24:20.683Z,1591640660.683 [Default:CheckIn:E] Running Loop=1
2020-06-08T18:24:21.063Z,1591640661.063 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 11.190994 min 
2020-06-08T18:24:21.063Z,1591640661.063 [Default:CheckIn:E] Stopped
2020-06-08T18:24:21.063Z,1591640661.063 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-06-08T18:24:21.063Z,1591640661.063 [Default:CheckIn] Stopped
2020-06-08T18:24:21.063Z,1591640661.063 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-08T18:24:21.063Z,1591640661.063 [Default:CheckIn](INFO): Running loop #2
2020-06-08T18:24:21.063Z,1591640661.063 [Default:CheckIn] Running Loop=2
2020-06-08T18:24:21.063Z,1591640661.063 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-08T18:24:21.064Z,1591640661.064 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-08T18:24:46.101Z,1591640686.101 [DVL_micro](ERROR): Failed to parse:99.99,+9999.99,+9999.99,+9999.99
2020-06-08T18:27:08.706Z,1591640828.706 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-06-08T18:27:08.706Z,1591640828.706 [DVL_micro](ERROR): Failed to parse:
:TS0000000,35.0,+20.0,0000.0,1489.0,000
2020-06-08T18:28:45.264Z,1591640925.264 [DVL_micro](ERROR): Failed to parse:99.99,++9999.99,+9999.99
2020-06-08T18:29:21.242Z,1591640961.242 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-08T18:24:21.1Z
2020-06-08T18:29:21.242Z,1591640961.242 [Default:CheckIn:Read_GPS] Stopped
2020-06-08T18:29:21.242Z,1591640961.242 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-08T18:29:25.651Z,1591640965.651 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-06-08T18:29:30.485Z,1591640970.485 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20200608T180903/Courier0007.lzma
2020-06-08T18:29:31.487Z,1591640971.487 [DataOverHttps](INFO): Moved sent file to Logs/20200608T180903/Courier0007.lzma.bak
2020-06-08T18:29:31.487Z,1591640971.487 [DataOverHttps](INFO): SBD MOMSN=12372715
2020-06-08T18:29:33.735Z,1591640973.735 [DVL_micro](ERROR): Failed to parse:
:000000000,35.0000.0,10
2020-06-08T18:29:51.642Z,1591640991.642 [DataOverHttps](INFO): Sending 590 bytes from file Logs/20200608T180903/Express0008.lzma
2020-06-08T18:29:52.642Z,1591640992.642 [DataOverHttps](INFO): Moved sent file to Logs/20200608T180903/Express0008.lzma.bak
2020-06-08T18:29:52.643Z,1591640992.643 [DataOverHttps](INFO): SBD MOMSN=12372717
2020-06-08T18:29:56.388Z,1591640996.388 [NAL9602](INFO): Not Powering down - fast GPS
2020-06-08T18:29:57.622Z,1591640997.622 [Default:CheckIn:Read_Iridium] Stopped
2020-06-08T18:29:57.622Z,1591640997.622 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-08T18:29:57.622Z,1591640997.622 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-08T18:32:26.655Z,1591641146.655 [DVL_micro](ERROR): Failed to parse:
:R99,+9999..99,+9999.99
2020-06-08T18:34:05.668Z,1591641245.668 [DVL_micro](ERROR): Failed to parse:
:BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00
2020-06-08T18:34:10.881Z,1591641250.881 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error
2020-06-08T18:34:10.881Z,1591641250.881 [DVL_micro](ERROR): Failed to parse:
:TS,00000000000000,35.0000.0,1489.0,000
2020-06-08T18:34:13.306Z,1591641253.306 [DVL_micro](ERROR): Failed to parse:
:WI,+02917,-02116,+00695,+00000,A2917,-02116,+00695,+00000,I
2020-06-08T18:34:17.675Z,1591641257.675 [CommandLine](IMPORTANT): got command help
2020-06-08T18:34:23.840Z,1591641263.840 [DVL_micro](ERROR): Failed to parse:
:WI,+00982,-01711,+01120,+00000,A
2020-06-08T18:34:30.283Z,1591641270.283 [CommandLine](IMPORTANT): got command quit
2020-06-08T18:34:31.293Z,1591641271.293 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-06-08T18:34:31.293Z,1591641271.293 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:31.433Z,1591641271.433 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-06-08T18:34:31.434Z,1591641271.434 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:31.434Z,1591641271.434 [CommandLine](INFO): Join timeout helper Thread ID is 8055
2020-06-08T18:34:31.436Z,1591641271.436 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-06-08T18:34:31.436Z,1591641271.436 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:31.437Z,1591641271.437 [NavChartDb](INFO): Join timeout helper Thread ID is 8056
2020-06-08T18:34:31.449Z,1591641271.449 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-06-08T18:34:31.449Z,1591641271.449 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:31.509Z,1591641271.509 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-06-08T18:34:31.510Z,1591641271.510 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:31.525Z,1591641271.525 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 8057
2020-06-08T18:34:31.573Z,1591641271.573 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-06-08T18:34:31.574Z,1591641271.574 [WetLabsBB2FL](INFO): Powering down
2020-06-08T18:34:31.574Z,1591641271.574 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:31.581Z,1591641271.581 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-06-08T18:34:31.581Z,1591641271.581 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:31.581Z,1591641271.581 [CTD_Seabird](INFO): Join timeout helper Thread ID is 8058
2020-06-08T18:34:31.881Z,1591641271.881 [CTD_Seabird](INFO): Powering down
2020-06-08T18:34:31.894Z,1591641271.894 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-06-08T18:34:31.895Z,1591641271.895 [CTD_Seabird](INFO): Powering down
2020-06-08T18:34:31.909Z,1591641271.909 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:31.929Z,1591641271.929 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-06-08T18:34:31.929Z,1591641271.929 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:31.929Z,1591641271.929 [Radio_Surface](INFO): Join timeout helper Thread ID is 8059
2020-06-08T18:34:32.089Z,1591641272.089 [Radio_Surface](INFO): Powering down
2020-06-08T18:34:32.090Z,1591641272.090 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-06-08T18:34:32.090Z,1591641272.090 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:32.094Z,1591641272.094 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-06-08T18:34:32.094Z,1591641272.094 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:32.094Z,1591641272.094 [DataOverHttps](INFO): Join timeout helper Thread ID is 8060
2020-06-08T18:34:32.877Z,1591641272.877 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-06-08T18:34:32.881Z,1591641272.881 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:32.890Z,1591641272.890 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-06-08T18:34:32.890Z,1591641272.890 [logger ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:32.890Z,1591641272.890 [logger](INFO): Join timeout helper Thread ID is 8061
2020-06-08T18:34:32.921Z,1591641272.921 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-06-08T18:34:32.921Z,1591641272.921 [logger ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:32.930Z,1591641272.930 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-06-08T18:34:32.930Z,1591641272.930 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:32.930Z,1591641272.930 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-06-08T18:34:32.930Z,1591641272.930 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:32.930Z,1591641272.930 [controlThread](INFO): Join timeout helper Thread ID is 8062
2020-06-08T18:34:33.081Z,1591641273.081 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-06-08T18:34:33.082Z,1591641273.082 [controlThread](DEBUG): Uninitializing ControlThread
2020-06-08T18:34:33.082Z,1591641273.082 [AHRS_M2](INFO): Powering down
2020-06-08T18:34:33.226Z,1591641273.226 [DVL_micro](INFO): Powering down
2020-06-08T18:34:33.227Z,1591641273.227 [NAL9602](INFO): Powering down
2020-06-08T18:34:33.228Z,1591641273.228 [DAT](INFO): Powering down
2020-06-08T18:34:33.388Z,1591641273.388 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-06-08T18:34:33.389Z,1591641273.389 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-06-08T18:34:33.390Z,1591641273.390 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-06-08T18:34:33.392Z,1591641273.392 [MissionManager](INFO): Uninitializing Mission Default
2020-06-08T18:34:33.392Z,1591641273.392 [Default] Stopped
2020-06-08T18:34:33.392Z,1591641273.392 [Default](DEBUG): Aggregate::uninitialize Default
2020-06-08T18:34:33.392Z,1591641273.392 [Default:B.GoToSurface] Stopped
2020-06-08T18:34:33.392Z,1591641273.392 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-06-08T18:34:33.392Z,1591641273.392 [Default:CheckIn] Stopped
2020-06-08T18:34:33.392Z,1591641273.392 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-08T18:34:33.392Z,1591641273.392 [Default:CheckIn:C.Wait] Stopped
2020-06-08T18:34:33.393Z,1591641273.393 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-08T18:34:33.395Z,1591641273.395 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-06-08T18:34:33.395Z,1591641273.395 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-06-08T18:34:33.395Z,1591641273.395 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-06-08T18:34:33.396Z,1591641273.396 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-06-08T18:34:33.398Z,1591641273.398 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-06-08T18:34:33.398Z,1591641273.398 [BuoyancyServo](INFO): Powering down
2020-06-08T18:34:33.413Z,1591641273.413 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-06-08T18:34:33.413Z,1591641273.413 [ElevatorServo](INFO): Powering down
2020-06-08T18:34:33.414Z,1591641273.414 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-06-08T18:34:33.414Z,1591641273.414 [MassServo](INFO): Powering down
2020-06-08T18:34:33.415Z,1591641273.415 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-06-08T18:34:33.415Z,1591641273.415 [RudderServo](INFO): Powering down
2020-06-08T18:34:33.416Z,1591641273.416 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-06-08T18:34:33.416Z,1591641273.416 [ThrusterServo](INFO): Powering down
2020-06-08T18:34:33.433Z,1591641273.433 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-06-08T18:34:33.434Z,1591641273.434 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-06-08T18:34:33.434Z,1591641273.434 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-06-08T18:34:33.434Z,1591641273.434 [CBIT](DEBUG): Powering off loads.
2020-06-08T18:34:33.445Z,1591641273.445 [CBIT](DEBUG): Disabling WDT.
2020-06-08T18:34:33.457Z,1591641273.457 [CBIT](DEBUG): Opening all GF detection circuits.
2020-06-08T18:34:33.458Z,1591641273.458 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:33.659Z,1591641273.659 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:33.676Z,1591641273.676 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:33.966Z,1591641273.966 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:33.971Z,1591641273.971 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:34.094Z,1591641274.094 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-06-08T18:34:34.241Z,1591641274.241 [logger ThreadHandler](INFO): Thread cancelled.