2020-06-09T16:46:45.696Z,1591721205.696 [Supervisor](DEBUG): Initializing supervisor. 2020-06-09T16:46:45.698Z,1591721205.698 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-06-09T16:46:45.699Z,1591721205.699 [SyncHandler](INFO): Protected caller Thread ID is 620 2020-06-09T16:46:45.699Z,1591721205.699 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-06-09T16:46:45.700Z,1591721205.700 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-06-09T16:46:45.701Z,1591721205.701 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 621 2020-06-09T16:46:45.703Z,1591721205.703 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-06-09T16:46:45.716Z,1591721205.716 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-06-09T16:46:45.717Z,1591721205.717 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-06-09T16:46:45.717Z,1591721205.717 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 622 2020-06-09T16:46:45.718Z,1591721205.718 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-06-09T16:46:45.719Z,1591721205.719 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-06-09T16:46:45.719Z,1591721205.719 [logger ThreadHandler](INFO): Protected caller Thread ID is 623 2020-06-09T16:46:45.721Z,1591721205.721 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-06-09T16:46:45.721Z,1591721205.721 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-06-09T16:46:45.723Z,1591721205.723 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-06-09T16:46:46.031Z,1591721206.031 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-06-09T16:46:46.031Z,1591721206.031 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-06-09T16:46:46.727Z,1591721206.727 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-06-09T16:46:46.727Z,1591721206.727 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-06-09T16:46:46.863Z,1591721206.863 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-06-09T16:46:46.864Z,1591721206.864 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-06-09T16:46:47.318Z,1591721207.318 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-06-09T16:46:47.319Z,1591721207.319 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-06-09T16:46:47.413Z,1591721207.413 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-06-09T16:46:47.413Z,1591721207.413 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-06-09T16:46:47.493Z,1591721207.493 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-06-09T16:46:47.786Z,1591721207.786 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-06-09T16:46:47.787Z,1591721207.787 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-06-09T16:46:47.929Z,1591721207.929 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-06-09T16:46:47.930Z,1591721207.930 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-06-09T16:46:48.032Z,1591721208.032 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-06-09T16:46:48.032Z,1591721208.032 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2020-06-09T16:46:48.228Z,1591721208.228 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2020-06-09T16:46:48.229Z,1591721208.229 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-06-09T16:46:48.699Z,1591721208.699 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-06-09T16:46:48.700Z,1591721208.700 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-06-09T16:46:49.113Z,1591721209.113 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-06-09T16:46:49.113Z,1591721209.113 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-06-09T16:46:49.213Z,1591721209.213 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-06-09T16:46:49.214Z,1591721209.214 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-06-09T16:46:49.402Z,1591721209.402 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-06-09T16:46:49.402Z,1591721209.402 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-06-09T16:46:49.605Z,1591721209.605 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-06-09T16:46:49.606Z,1591721209.606 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-06-09T16:46:49.828Z,1591721209.828 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-06-09T16:46:49.830Z,1591721209.830 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/ 2020-06-09T16:46:49.831Z,1591721209.831 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg 2020-06-09T16:46:49.923Z,1591721209.923 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg 2020-06-09T16:46:50.059Z,1591721210.059 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg 2020-06-09T16:46:50.143Z,1591721210.143 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg 2020-06-09T16:46:50.225Z,1591721210.225 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg 2020-06-09T16:46:50.329Z,1591721210.329 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg 2020-06-09T16:46:50.508Z,1591721210.508 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg 2020-06-09T16:46:50.732Z,1591721210.732 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-06-09T16:46:50.733Z,1591721210.733 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg 2020-06-09T16:46:50.841Z,1591721210.841 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg 2020-06-09T16:46:50.934Z,1591721210.934 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg 2020-06-09T16:46:51.029Z,1591721211.029 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg 2020-06-09T16:46:51.121Z,1591721211.121 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2020-06-09T16:46:51.127Z,1591721211.127 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2020-06-09T16:46:51.201Z,1591721211.201 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2020-06-09T16:46:51.201Z,1591721211.201 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-06-09T16:46:51.219Z,1591721211.219 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-06-09T16:46:51.220Z,1591721211.220 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-06-09T16:46:51.260Z,1591721211.260 [DepthRateCalculator] Loaded 2020-06-09T16:46:51.260Z,1591721211.260 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-06-09T16:46:51.266Z,1591721211.266 [PitchRateCalculator] Loaded 2020-06-09T16:46:51.266Z,1591721211.266 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-06-09T16:46:51.281Z,1591721211.281 [SpeedCalculator] Loaded 2020-06-09T16:46:51.282Z,1591721211.282 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-06-09T16:46:51.302Z,1591721211.302 [TempGradientCalculator] Loaded 2020-06-09T16:46:51.303Z,1591721211.303 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-06-09T16:46:51.308Z,1591721211.308 [YawRateCalculator] Loaded 2020-06-09T16:46:51.308Z,1591721211.308 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-06-09T16:46:51.347Z,1591721211.347 [ElevatorOffsetCalculator] Loaded 2020-06-09T16:46:51.347Z,1591721211.347 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-06-09T16:46:51.348Z,1591721211.348 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-06-09T16:46:51.348Z,1591721211.348 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-06-09T16:46:51.395Z,1591721211.395 [VerticalControl](DEBUG): Construct VerticalControl. 2020-06-09T16:46:51.491Z,1591721211.491 [VerticalControl] Loaded 2020-06-09T16:46:51.491Z,1591721211.491 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-06-09T16:46:51.492Z,1591721211.492 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-06-09T16:46:51.570Z,1591721211.570 [HorizontalControl] Loaded 2020-06-09T16:46:51.570Z,1591721211.570 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-06-09T16:46:51.571Z,1591721211.571 [SpeedControl](DEBUG): Construct SpeedControl. 2020-06-09T16:46:51.576Z,1591721211.576 [SpeedControl] Loaded 2020-06-09T16:46:51.576Z,1591721211.576 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-06-09T16:46:51.576Z,1591721211.576 [LoopControl](DEBUG): Construct LoopControl. 2020-06-09T16:46:51.577Z,1591721211.577 [LoopControl] Loaded 2020-06-09T16:46:51.577Z,1591721211.577 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-06-09T16:46:51.578Z,1591721211.578 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-06-09T16:46:51.578Z,1591721211.578 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-06-09T16:46:51.691Z,1591721211.691 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-06-09T16:46:51.692Z,1591721211.692 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-06-09T16:46:51.711Z,1591721211.711 [NavChart] Loaded 2020-06-09T16:46:51.711Z,1591721211.711 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-06-09T16:46:51.715Z,1591721211.715 [UniversalFixResidualReporter] Loaded 2020-06-09T16:46:51.716Z,1591721211.716 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-06-09T16:46:51.716Z,1591721211.716 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-06-09T16:46:51.717Z,1591721211.717 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-06-09T16:46:52.056Z,1591721212.056 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-06-09T16:46:52.057Z,1591721212.057 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-06-09T16:46:52.699Z,1591721212.699 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-06-09T16:46:52.703Z,1591721212.703 [AHRS_M2](INFO): created writer for : platform_orientation 2020-06-09T16:46:52.705Z,1591721212.705 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-06-09T16:46:52.710Z,1591721212.710 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-06-09T16:46:52.711Z,1591721212.711 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-06-09T16:46:52.715Z,1591721212.715 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-06-09T16:46:52.716Z,1591721212.716 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-06-09T16:46:52.721Z,1591721212.721 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-06-09T16:46:52.791Z,1591721212.791 [AHRS_M2] Loaded 2020-06-09T16:46:52.792Z,1591721212.792 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-06-09T16:46:52.869Z,1591721212.869 [DataOverHttps] Loaded 2020-06-09T16:46:52.869Z,1591721212.869 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-06-09T16:46:52.870Z,1591721212.870 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408544E0 2020-06-09T16:46:52.870Z,1591721212.870 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 705 2020-06-09T16:46:52.884Z,1591721212.884 [Depth_Keller] Loaded 2020-06-09T16:46:52.884Z,1591721212.884 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-06-09T16:46:52.889Z,1591721212.889 [DropWeight] Loaded 2020-06-09T16:46:52.889Z,1591721212.889 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread. 2020-06-09T16:46:52.933Z,1591721212.933 [DVL_micro] Loaded 2020-06-09T16:46:52.933Z,1591721212.933 [ComponentRegistry](DEBUG): SyncComponent "DVL_micro" handled in the control thread. 2020-06-09T16:46:53.027Z,1591721213.027 [NAL9602] Loaded 2020-06-09T16:46:53.027Z,1591721213.027 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-06-09T16:46:53.065Z,1591721213.065 [Onboard] Loaded 2020-06-09T16:46:53.066Z,1591721213.066 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread. 2020-06-09T16:46:53.069Z,1591721213.069 [Radio_Surface] Loaded 2020-06-09T16:46:53.069Z,1591721213.069 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-06-09T16:46:53.070Z,1591721213.070 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408844E0 2020-06-09T16:46:53.071Z,1591721213.071 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 706 2020-06-09T16:46:53.200Z,1591721213.200 [DAT] Loaded 2020-06-09T16:46:53.200Z,1591721213.200 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2020-06-09T16:46:54.658Z,1591721214.658 [BPC1] Loaded 2020-06-09T16:46:54.658Z,1591721214.658 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-06-09T16:46:54.658Z,1591721214.658 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-06-09T16:46:54.659Z,1591721214.659 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-06-09T16:46:54.760Z,1591721214.760 [BuoyancyServo] Loaded 2020-06-09T16:46:54.760Z,1591721214.760 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-06-09T16:46:54.771Z,1591721214.771 [ElevatorServo] Loaded 2020-06-09T16:46:54.771Z,1591721214.771 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-06-09T16:46:54.782Z,1591721214.782 [MassServo] Loaded 2020-06-09T16:46:54.782Z,1591721214.782 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-06-09T16:46:54.793Z,1591721214.793 [RudderServo] Loaded 2020-06-09T16:46:54.793Z,1591721214.793 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-06-09T16:46:54.803Z,1591721214.803 [ThrusterServo] Loaded 2020-06-09T16:46:54.804Z,1591721214.804 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-06-09T16:46:54.804Z,1591721214.804 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-06-09T16:46:54.805Z,1591721214.805 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-06-09T16:46:54.884Z,1591721214.884 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2020-06-09T16:46:54.885Z,1591721214.885 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-06-09T16:46:54.910Z,1591721214.910 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-06-09T16:46:54.911Z,1591721214.911 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-06-09T16:46:55.191Z,1591721215.191 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-06-09T16:46:55.191Z,1591721215.191 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-06-09T16:46:55.374Z,1591721215.374 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2020-06-09T16:46:55.379Z,1591721215.379 [CTD_Seabird](INFO): created writer for : sea_water_density 2020-06-09T16:46:55.379Z,1591721215.379 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2020-06-09T16:46:55.384Z,1591721215.384 [CTD_Seabird](INFO): created writer for : depth 2020-06-09T16:46:55.384Z,1591721215.384 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2020-06-09T16:46:55.389Z,1591721215.389 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2020-06-09T16:46:55.390Z,1591721215.390 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2020-06-09T16:46:55.395Z,1591721215.395 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2020-06-09T16:46:55.395Z,1591721215.395 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2020-06-09T16:46:55.400Z,1591721215.400 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2020-06-09T16:46:55.401Z,1591721215.401 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2020-06-09T16:46:55.406Z,1591721215.406 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2020-06-09T16:46:55.407Z,1591721215.407 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2020-06-09T16:46:55.412Z,1591721215.412 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2020-06-09T16:46:55.439Z,1591721215.439 [CTD_Seabird] Loaded 2020-06-09T16:46:55.439Z,1591721215.439 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2020-06-09T16:46:55.440Z,1591721215.440 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A904E0 2020-06-09T16:46:55.440Z,1591721215.440 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 707 2020-06-09T16:46:55.470Z,1591721215.470 [ESPComponent] Loaded 2020-06-09T16:46:55.471Z,1591721215.471 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread. 2020-06-09T16:46:55.484Z,1591721215.484 [PAR_Licor] Loaded 2020-06-09T16:46:55.485Z,1591721215.485 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread. 2020-06-09T16:46:55.491Z,1591721215.491 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2020-06-09T16:46:55.491Z,1591721215.491 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2020-06-09T16:46:55.495Z,1591721215.495 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2020-06-09T16:46:55.495Z,1591721215.495 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2020-06-09T16:46:55.499Z,1591721215.499 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2020-06-09T16:46:55.499Z,1591721215.499 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2020-06-09T16:46:55.504Z,1591721215.504 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2020-06-09T16:46:55.504Z,1591721215.504 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2020-06-09T16:46:55.508Z,1591721215.508 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2020-06-09T16:46:55.508Z,1591721215.508 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2020-06-09T16:46:55.512Z,1591721215.512 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2020-06-09T16:46:55.512Z,1591721215.512 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2020-06-09T16:46:55.516Z,1591721215.516 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2020-06-09T16:46:55.516Z,1591721215.516 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2020-06-09T16:46:55.521Z,1591721215.521 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T16:46:55.525Z,1591721215.525 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T16:46:55.525Z,1591721215.525 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T16:46:55.526Z,1591721215.526 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T16:46:55.530Z,1591721215.530 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T16:46:55.530Z,1591721215.530 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T16:46:55.534Z,1591721215.534 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T16:46:55.534Z,1591721215.534 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-06-09T16:46:55.538Z,1591721215.538 [WetLabsBB2FL] Loaded 2020-06-09T16:46:55.539Z,1591721215.539 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2020-06-09T16:46:55.540Z,1591721215.540 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC04E0 2020-06-09T16:46:55.540Z,1591721215.540 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 708 2020-06-09T16:46:55.541Z,1591721215.541 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-06-09T16:46:55.541Z,1591721215.541 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-06-09T16:46:55.672Z,1591721215.672 [SBIT](DEBUG): Construct Startup Built In Test. 2020-06-09T16:46:55.683Z,1591721215.683 [SBIT] Loaded 2020-06-09T16:46:55.683Z,1591721215.683 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-06-09T16:46:55.684Z,1591721215.684 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-06-09T16:46:55.696Z,1591721215.696 [IBIT] Loaded 2020-06-09T16:46:55.697Z,1591721215.697 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-06-09T16:46:55.700Z,1591721215.700 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-06-09T16:46:55.836Z,1591721215.836 [CBIT] Loaded 2020-06-09T16:46:55.836Z,1591721215.836 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-06-09T16:46:55.836Z,1591721215.836 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-06-09T16:46:55.840Z,1591721215.840 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-06-09T16:46:55.841Z,1591721215.841 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-06-09T16:46:55.848Z,1591721215.848 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-06-09T16:46:55.849Z,1591721215.849 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B2B4E0 2020-06-09T16:46:55.850Z,1591721215.850 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 709 2020-06-09T16:46:55.854Z,1591721215.854 [Supervisor](INFO): Main Thread ID is 451 2020-06-09T16:46:55.854Z,1591721215.854 [Supervisor](DEBUG): Running supervisor. 2020-06-09T16:46:55.855Z,1591721215.855 [CommandLine ThreadHandler](INFO): Handler Thread ID is 710 2020-06-09T16:46:55.857Z,1591721215.857 [controlThread ThreadHandler](INFO): Handler Thread ID is 711 2020-06-09T16:46:55.858Z,1591721215.858 [controlThread](DEBUG): Initializing ControlThread 2020-06-09T16:46:55.859Z,1591721215.859 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-06-09T16:46:55.859Z,1591721215.859 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-06-09T16:46:55.859Z,1591721215.859 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-06-09T16:46:55.860Z,1591721215.860 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-06-09T16:46:55.860Z,1591721215.860 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-06-09T16:46:55.860Z,1591721215.860 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-06-09T16:46:55.861Z,1591721215.861 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-06-09T16:46:55.863Z,1591721215.863 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-06-09T16:46:55.863Z,1591721215.863 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-06-09T16:46:55.864Z,1591721215.864 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-06-09T16:46:55.865Z,1591721215.865 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-06-09T16:46:55.865Z,1591721215.865 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-06-09T16:46:55.877Z,1591721215.877 [SBIT](INFO): Initialize SBIT Component. 2020-06-09T16:46:55.878Z,1591721215.878 [SBIT](IMPORTANT): git: 2020-06-09 2020-06-09T16:46:55.878Z,1591721215.878 [SBIT](INFO): git hash: 492c82351796d8646f9bb5d9c938bbc9efa48549 2020-06-09T16:46:55.878Z,1591721215.878 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-06-09T16:46:55.878Z,1591721215.878 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019 2020-06-09T16:46:55.879Z,1591721215.879 [SBIT](INFO): Beginning SBIT in 59.000000 seconds. 2020-06-09T16:46:55.880Z,1591721215.880 [IBIT](INFO): Initialize IBIT Component. 2020-06-09T16:46:55.881Z,1591721215.881 [CBIT](DEBUG): Initialize CBIT Component. 2020-06-09T16:46:55.882Z,1591721215.882 [logger ThreadHandler](INFO): Handler Thread ID is 712 2020-06-09T16:46:55.893Z,1591721215.893 [CBIT](DEBUG): Initialized mux pins. 2020-06-09T16:46:55.893Z,1591721215.893 [CBIT](DEBUG): Initializing the watchdog timer. 2020-06-09T16:46:55.901Z,1591721215.901 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 713 2020-06-09T16:46:55.902Z,1591721215.902 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-06-09T16:46:55.913Z,1591721215.913 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 714 2020-06-09T16:46:55.917Z,1591721215.917 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2020-06-09T16:46:55.917Z,1591721215.917 [CBIT](DEBUG): Initializing heartbeat. 2020-06-09T16:46:55.925Z,1591721215.925 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 715 2020-06-09T16:46:55.926Z,1591721215.926 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2020-06-09T16:46:55.930Z,1591721215.930 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 717 2020-06-09T16:46:55.931Z,1591721215.931 [WetLabsBB2FL](INFO): Powering down 2020-06-09T16:46:55.966Z,1591721215.966 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 718 2020-06-09T16:46:55.969Z,1591721215.969 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-06-09T16:46:55.969Z,1591721215.969 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-06-09T16:46:55.969Z,1591721215.969 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-06-09T16:46:55.969Z,1591721215.969 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-06-09T16:46:55.970Z,1591721215.970 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-06-09T16:46:55.970Z,1591721215.970 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-06-09T16:46:55.970Z,1591721215.970 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-06-09T16:46:55.970Z,1591721215.970 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-06-09T16:46:55.970Z,1591721215.970 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-06-09T16:46:55.970Z,1591721215.970 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-06-09T16:46:55.971Z,1591721215.971 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-06-09T16:46:55.971Z,1591721215.971 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-06-09T16:46:55.971Z,1591721215.971 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-06-09T16:46:55.971Z,1591721215.971 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-06-09T16:46:55.971Z,1591721215.971 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-06-09T16:46:55.972Z,1591721215.972 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-06-09T16:46:55.989Z,1591721215.989 [CBIT](DEBUG): Deactivating GF circuits. 2020-06-09T16:46:55.989Z,1591721215.989 [CBIT](DEBUG): Deactivating emergency mode. 2020-06-09T16:46:56.025Z,1591721216.025 [CBIT](DEBUG): Backplane powered. 2020-06-09T16:46:56.026Z,1591721216.026 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-06-09T16:46:56.036Z,1591721216.036 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-06-09T16:46:56.046Z,1591721216.046 [MissionManager](DEBUG): 2020-06-09T16:46:56.047Z,1591721216.047 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-06-09T16:46:56.128Z,1591721216.128 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-06-09T16:46:56.130Z,1591721216.130 [Default:A.Wait](DEBUG): Construct Wait. 2020-06-09T16:46:56.131Z,1591721216.131 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-06-09T16:46:56.164Z,1591721216.164 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-06-09T16:46:56.186Z,1591721216.186 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-06-09T16:46:56.192Z,1591721216.192 [Default:E.Execute](DEBUG): Construct Execute. 2020-06-09T16:46:56.211Z,1591721216.211 [MissionManager](DEBUG): 0 Wait a moment to see if the scheduler starts a new mission before starting to actually run Default. 13 Burn on Dropped weight due to communications timeout. 5 Default mission has been running for Restarting logs and Default mission. restart logs 2020-06-09T16:46:56.216Z,1591721216.216 [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-09T16:46:56.233Z,1591721216.233 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-06-09T16:46:56.275Z,1591721216.275 [Depth_Keller](ERROR): Pressure reading out of range: 1829.799438 decibar 2020-06-09T16:46:56.303Z,1591721216.303 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-09T16:46:56.303Z,1591721216.303 [DAT](INFO): Powering up 2020-06-09T16:46:56.303Z,1591721216.303 [DAT](DEBUG): Initializing DAT. 2020-06-09T16:46:56.317Z,1591721216.317 [Radio_Surface](INFO): Powering up 2020-06-09T16:46:56.357Z,1591721216.357 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-09T16:46:56.386Z,1591721216.386 [DepthRateCalculator](ERROR): Depth measurement is not active 2020-06-09T16:46:56.415Z,1591721216.415 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-06-09T16:46:56.425Z,1591721216.425 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-06-09T16:46:56.426Z,1591721216.426 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-06-09T16:46:56.437Z,1591721216.437 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-06-09T16:46:56.438Z,1591721216.438 [MassServo](DEBUG): Initializing EZServoServo. 2020-06-09T16:46:56.449Z,1591721216.449 [MassServo](DEBUG): Initializing MassServo. 2020-06-09T16:46:56.450Z,1591721216.450 [RudderServo](DEBUG): Initializing EZServoServo. 2020-06-09T16:46:56.461Z,1591721216.461 [RudderServo](DEBUG): Initializing RudderServo. 2020-06-09T16:46:56.462Z,1591721216.462 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-06-09T16:46:56.473Z,1591721216.473 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-06-09T16:46:56.671Z,1591721216.671 [DepthRateCalculator](ERROR): Depth measurement is not active 2020-06-09T16:47:02.957Z,1591721222.957 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2020-06-09T16:47:23.307Z,1591721243.307 [NAL9602](INFO): Powering up NAL9602 2020-06-09T16:47:34.220Z,1591721254.220 [NAL9602](INFO): NAL9602 initialized 2020-06-09T16:47:49.570Z,1591721269.570 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:47:49.571Z,1591721269.571 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.7,0000.0,14 2020-06-09T16:47:55.658Z,1591721275.658 [SBIT](IMPORTANT): Beginning Startup BIT 2020-06-09T16:47:55.663Z,1591721275.663 [CBIT](IMPORTANT): Beginning ground fault scan 2020-06-09T16:47:56.479Z,1591721276.479 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2020-06-09T16:47:56.479Z,1591721276.479 [DAT] Communications Fault, FailCount= 1 2020-06-09T16:47:56.479Z,1591721276.479 [DAT](ERROR): Communications Fault 2020-06-09T16:47:56.534Z,1591721276.534 [CBIT](ERROR): Communications Fault in component: DAT 2020-06-09T16:47:56.854Z,1591721276.854 [DAT](INFO): Powering down 2020-06-09T16:47:58.149Z,1591721278.149 [CBIT](INFO): Clearing failed state for component DAT 2020-06-09T16:47:58.149Z,1591721278.149 [DAT] No Fault, FailCount= 1 2020-06-09T16:48:00.206Z,1591721280.206 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-09T16:48:00.206Z,1591721280.206 [DAT](INFO): Powering up 2020-06-09T16:48:00.207Z,1591721280.207 [DAT](DEBUG): Initializing DAT. 2020-06-09T16:48:00.278Z,1591721280.278 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-09T16:48:06.749Z,1591721286.749 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.004427 CHAN A1 (24V): -0.000419 CHAN A2 (12V): -0.000305 CHAN A3 (5V): 0.000016 CHAN B0 (3.3V): 0.000449 CHAN B1 (3.15aV): 0.000757 CHAN B2 (3.15bV): 0.000203 CHAN B3 (GND): 0.000326 OPEN: 0.003820 Full Scale Calc: 4.765 mA, -1.589 mA 2020-06-09T16:48:49.449Z,1591721329.449 [SBIT](IMPORTANT): SBIT PASSED 2020-06-09T16:48:49.450Z,1591721329.450 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2020-06-09T16:48:49.450Z,1591721329.450 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool; 2020-06-09T16:48:49.451Z,1591721329.451 [SBIT](IMPORTANT): ESPComponent.simulateHardware=0 bool; 2020-06-09T16:48:49.451Z,1591721329.451 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=242.907926 cubic_centimeter; 2020-06-09T16:48:49.451Z,1591721329.451 [SBIT](IMPORTANT): VerticalControl.massDefault=9.890285 millimeter; 2020-06-09T16:48:49.871Z,1591721329.871 [MissionManager](IMPORTANT): Started mission Startup 2020-06-09T16:48:49.871Z,1591721329.871 [Startup] Running Loop=1 2020-06-09T16:48:49.871Z,1591721329.871 [Startup](DEBUG): Aggregate::initialize Startup 2020-06-09T16:48:49.871Z,1591721329.871 [Startup:A.GoToSurface] Running Loop=1 2020-06-09T16:48:49.872Z,1591721329.872 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-06-09T16:48:49.872Z,1591721329.872 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-06-09T16:48:49.873Z,1591721329.873 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-06-09T16:48:49.873Z,1591721329.873 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-06-09T16:48:49.874Z,1591721329.874 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-06-09T16:48:49.874Z,1591721329.874 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-06-09T16:48:49.875Z,1591721329.875 [Startup:StartupSatComms] Running Loop=1 2020-06-09T16:48:49.875Z,1591721329.875 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-06-09T16:48:49.876Z,1591721329.876 [Startup:StartupSatComms:A] Running Loop=1 2020-06-09T16:48:50.287Z,1591721330.287 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-06-09T16:49:00.359Z,1591721340.359 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2020-06-09T16:49:00.359Z,1591721340.359 [DAT] Communications Fault, FailCount= 2 2020-06-09T16:49:00.359Z,1591721340.359 [DAT](ERROR): Communications Fault 2020-06-09T16:49:00.403Z,1591721340.403 [CBIT](ERROR): Communications Fault in component: DAT 2020-06-09T16:49:00.771Z,1591721340.771 [DAT](INFO): Powering down 2020-06-09T16:49:01.595Z,1591721341.595 [CBIT](INFO): Clearing failed state for component DAT 2020-06-09T16:49:01.595Z,1591721341.595 [DAT] No Fault, FailCount= 2 2020-06-09T16:49:03.989Z,1591721343.989 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-09T16:49:03.989Z,1591721343.989 [DAT](INFO): Powering up 2020-06-09T16:49:03.989Z,1591721343.989 [DAT](DEBUG): Initializing DAT. 2020-06-09T16:49:04.041Z,1591721344.041 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-09T16:49:23.904Z,1591721363.904 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005201 2020-06-09T16:49:50.046Z,1591721390.046 [Startup:StartupSatComms:A](INFO): Timed out from 2020-06-09T16:48:49.9Z 2020-06-09T16:49:50.047Z,1591721390.047 [Startup:StartupSatComms:A] Stopped 2020-06-09T16:49:50.047Z,1591721390.047 [Startup:StartupSatComms:B] Running Loop=1 2020-06-09T16:49:50.455Z,1591721390.455 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-06-09T16:49:56.109Z,1591721396.109 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-06-09T16:49:56.109Z,1591721396.109 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:49:56.127Z,1591721396.127 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:49:56.570Z,1591721396.570 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:49:56.570Z,1591721396.570 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2020-06-09T16:49:59.360Z,1591721399.360 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20200609T150638/Courier0031.lzma 2020-06-09T16:50:00.363Z,1591721400.363 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Courier0031.lzma.bak 2020-06-09T16:50:00.363Z,1591721400.363 [DataOverHttps](INFO): SBD MOMSN=12374376 2020-06-09T16:50:04.207Z,1591721404.207 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2020-06-09T16:50:04.207Z,1591721404.207 [DAT] Communications Fault, FailCount= 3 2020-06-09T16:50:04.207Z,1591721404.207 [DAT](ERROR): Communications Fault 2020-06-09T16:50:04.254Z,1591721404.254 [CBIT](ERROR): Communications Fault in component: DAT 2020-06-09T16:50:04.601Z,1591721404.601 [DAT](INFO): Powering down 2020-06-09T16:50:05.658Z,1591721405.658 [CBIT](INFO): Clearing failed state for component DAT 2020-06-09T16:50:05.658Z,1591721405.658 [DAT] No Fault, FailCount= 3 2020-06-09T16:50:07.811Z,1591721407.811 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-09T16:50:07.811Z,1591721407.811 [DAT](INFO): Powering up 2020-06-09T16:50:07.811Z,1591721407.811 [DAT](DEBUG): Initializing DAT. 2020-06-09T16:50:07.849Z,1591721407.849 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-09T16:50:18.053Z,1591721418.053 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20200609T164645/Courier0000.lzma 2020-06-09T16:50:19.055Z,1591721419.055 [DataOverHttps](INFO): Moved sent file to Logs/20200609T164645/Courier0000.lzma.bak 2020-06-09T16:50:19.055Z,1591721419.055 [DataOverHttps](INFO): SBD MOMSN=12374378 2020-06-09T16:50:38.801Z,1591721438.801 [DataOverHttps](INFO): Sending 244 bytes from file Logs/20200609T150638/Express0032.lzma 2020-06-09T16:50:39.802Z,1591721439.802 [DataOverHttps](INFO): Moved sent file to Logs/20200609T150638/Express0032.lzma.bak 2020-06-09T16:50:39.803Z,1591721439.803 [DataOverHttps](INFO): SBD MOMSN=12374381 2020-06-09T16:50:50.251Z,1591721450.251 [Startup:StartupSatComms:B](INFO): Timed out from 2020-06-09T16:49:50.0Z 2020-06-09T16:50:50.251Z,1591721450.251 [Startup:StartupSatComms:B] Stopped 2020-06-09T16:50:50.251Z,1591721450.251 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-06-09T16:50:50.251Z,1591721450.251 [Startup:StartupSatComms] Stopped 2020-06-09T16:50:50.251Z,1591721450.251 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-06-09T16:50:50.252Z,1591721450.252 [Startup](INFO): Completed Startup 2020-06-09T16:50:50.252Z,1591721450.252 [MissionManager](INFO): Startup is completed. 2020-06-09T16:50:50.252Z,1591721450.252 [MissionManager](INFO): Uninitializing Mission Startup 2020-06-09T16:50:50.277Z,1591721450.277 [Startup] Stopped 2020-06-09T16:50:50.277Z,1591721450.277 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-06-09T16:50:50.277Z,1591721450.277 [Startup:A.GoToSurface] Stopped 2020-06-09T16:50:50.277Z,1591721450.277 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-06-09T16:50:50.686Z,1591721450.686 [MissionManager](IMPORTANT): Started mission Default 2020-06-09T16:50:50.686Z,1591721450.686 [Default] Running Loop=1 2020-06-09T16:50:50.686Z,1591721450.686 [Default](DEBUG): Aggregate::initialize Default 2020-06-09T16:50:50.686Z,1591721450.686 [Default:B.GoToSurface] Running Loop=1 2020-06-09T16:50:50.686Z,1591721450.686 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-06-09T16:50:50.687Z,1591721450.687 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-06-09T16:50:50.687Z,1591721450.687 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-06-09T16:50:50.687Z,1591721450.687 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-06-09T16:50:50.688Z,1591721450.688 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-06-09T16:50:50.688Z,1591721450.688 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-06-09T16:50:50.688Z,1591721450.688 [Default:A.Wait] Running Loop=1 2020-06-09T16:50:50.688Z,1591721450.688 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-06-09T16:50:59.291Z,1591721459.291 [DataOverHttps](INFO): Sending 865 bytes from file Logs/20200609T164645/Express0001.lzma 2020-06-09T16:51:00.290Z,1591721460.290 [DataOverHttps](INFO): Moved sent file to Logs/20200609T164645/Express0001.lzma.bak 2020-06-09T16:51:00.291Z,1591721460.291 [DataOverHttps](INFO): SBD MOMSN=12374387 2020-06-09T16:51:00.336Z,1591721460.336 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:51:00.336Z,1591721460.336 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.7,0000.0,148 2020-06-09T16:51:04.011Z,1591721464.011 [Default:A.Wait](INFO): Done Waiting. 2020-06-09T16:51:04.011Z,1591721464.011 [Default:A.Wait] Stopped 2020-06-09T16:51:04.011Z,1591721464.011 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T16:51:04.394Z,1591721464.394 [Default:CheckIn] Running Loop=1 2020-06-09T16:51:04.395Z,1591721464.395 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T16:51:04.395Z,1591721464.395 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T16:51:04.794Z,1591721464.794 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-06-09T16:51:08.009Z,1591721468.009 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2020-06-09T16:51:08.009Z,1591721468.009 [DAT] Communications Fault, FailCount= 4 2020-06-09T16:51:08.010Z,1591721468.010 [DAT](ERROR): Communications Fault 2020-06-09T16:51:08.031Z,1591721468.031 [CBIT](ERROR): Communications Fault in component: DAT 2020-06-09T16:51:08.423Z,1591721468.423 [DAT](INFO): Powering down 2020-06-09T16:51:09.254Z,1591721469.254 [CBIT](INFO): Clearing failed state for component DAT 2020-06-09T16:51:09.254Z,1591721469.254 [DAT] No Fault, FailCount= 4 2020-06-09T16:51:11.673Z,1591721471.673 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-09T16:51:11.673Z,1591721471.673 [DAT](INFO): Powering up 2020-06-09T16:51:11.674Z,1591721471.674 [DAT](DEBUG): Initializing DAT. 2020-06-09T16:51:11.729Z,1591721471.729 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-09T16:51:18.105Z,1591721478.105 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:51:18.105Z,1591721478.105 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+20.8,009.0,000 2020-06-09T16:52:01.324Z,1591721521.324 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:52:01.325Z,1591721521.325 [DVL_micro](ERROR): Failed to parse: :TS,000000005.0,+20.8,0000.0,1489.0,000 2020-06-09T16:52:11.855Z,1591721531.855 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2020-06-09T16:52:11.855Z,1591721531.855 [DAT] Communications Fault, FailCount= 5 2020-06-09T16:52:11.856Z,1591721531.856 [DAT](ERROR): Communications Fault 2020-06-09T16:52:11.873Z,1591721531.873 [CBIT](ERROR): Communications Fault in component: DAT 2020-06-09T16:52:12.250Z,1591721532.250 [DAT](INFO): Powering down 2020-06-09T16:52:13.088Z,1591721533.088 [CBIT](INFO): Clearing failed state for component DAT 2020-06-09T16:52:13.088Z,1591721533.088 [DAT] No Fault, FailCount= 5 2020-06-09T16:52:15.503Z,1591721535.503 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-09T16:52:15.504Z,1591721535.504 [DAT](INFO): Powering up 2020-06-09T16:52:15.504Z,1591721535.504 [DAT](DEBUG): Initializing DAT. 2020-06-09T16:52:15.534Z,1591721535.534 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-09T16:52:37.291Z,1591721557.291 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-06-09T16:52:57.114Z,1591721577.114 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2020-06-09T16:52:57.114Z,1591721577.114 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:52:57.124Z,1591721577.124 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:52:57.530Z,1591721577.530 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:52:57.530Z,1591721577.530 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2020-06-09T16:53:02.347Z,1591721582.347 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2020-06-09T16:53:15.692Z,1591721595.692 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2020-06-09T16:53:15.692Z,1591721595.692 [DAT] Communications Fault, FailCount= 6 2020-06-09T16:53:15.692Z,1591721595.692 [DAT](ERROR): Communications Fault 2020-06-09T16:53:15.708Z,1591721595.708 [CBIT](ERROR): Communications Fault in component: DAT 2020-06-09T16:53:16.096Z,1591721596.096 [DAT](INFO): Powering down 2020-06-09T16:53:16.935Z,1591721596.935 [CBIT](INFO): Clearing failed state for component DAT 2020-06-09T16:53:16.935Z,1591721596.935 [DAT] No Fault, FailCount= 6 2020-06-09T16:53:19.331Z,1591721599.331 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-09T16:53:19.332Z,1591721599.332 [DAT](INFO): Powering up 2020-06-09T16:53:19.332Z,1591721599.332 [DAT](DEBUG): Initializing DAT. 2020-06-09T16:53:19.409Z,1591721599.409 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-09T16:54:19.521Z,1591721659.521 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2020-06-09T16:54:19.521Z,1591721659.521 [DAT] Communications Fault, FailCount= 7 2020-06-09T16:54:19.522Z,1591721659.522 [DAT](ERROR): Communications Fault 2020-06-09T16:54:19.538Z,1591721659.538 [CBIT](ERROR): Communications Fault in component: DAT 2020-06-09T16:54:19.928Z,1591721659.928 [DAT](INFO): Powering down 2020-06-09T16:54:20.787Z,1591721660.787 [CBIT](INFO): Clearing failed state for component DAT 2020-06-09T16:54:20.787Z,1591721660.787 [DAT] No Fault, FailCount= 7 2020-06-09T16:54:23.162Z,1591721663.162 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-09T16:54:23.162Z,1591721663.162 [DAT](INFO): Powering up 2020-06-09T16:54:23.163Z,1591721663.163 [DAT](DEBUG): Initializing DAT. 2020-06-09T16:54:23.261Z,1591721663.261 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-09T16:54:28.440Z,1591721668.440 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2020-06-09T16:54:28.441Z,1591721668.441 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6. 2020-06-09T16:54:28.444Z,1591721668.444 [BPC1](INFO): Received data from all battery sticks. 2020-06-09T16:54:46.573Z,1591721686.573 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: -172 2020-06-09T16:54:46.575Z,1591721686.575 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,:RD,+99999.99,+9999.99,+9999.99 2020-06-09T16:55:23.363Z,1591721723.363 [DAT](FAULT): failed to initialize, no bytes available on serial interface 2020-06-09T16:55:23.363Z,1591721723.363 [DAT] Communications Fault, FailCount= 8 2020-06-09T16:55:23.363Z,1591721723.363 [DAT](ERROR): Communications Fault 2020-06-09T16:55:23.400Z,1591721723.400 [CBIT](ERROR): Communications Fault in component: DAT 2020-06-09T16:55:23.400Z,1591721723.400 [CBIT](FAULT): Communications Fault in component: DAT 2020-06-09T16:55:23.757Z,1591721723.757 [DAT](INFO): Powering down 2020-06-09T16:55:29.804Z,1591721729.804 [DVL_micro](ERROR): Failed to parse: :000000000,35.0,+20.8,0000.0,1489.0,000 2020-06-09T16:55:55.252Z,1591721755.252 [DVL_micro](ERROR): only read 2 of 4 data items 2020-06-09T16:55:55.253Z,1591721755.253 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999..99 2020-06-09T16:55:58.103Z,1591721758.103 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2020-06-09T16:55:58.103Z,1591721758.103 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:55:58.113Z,1591721758.113 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:55:58.526Z,1591721758.526 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:55:58.526Z,1591721758.526 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2020-06-09T16:56:04.569Z,1591721764.569 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T16:51:04.4Z 2020-06-09T16:56:04.570Z,1591721764.570 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T16:56:04.570Z,1591721764.570 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T16:56:04.983Z,1591721764.983 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-06-09T16:56:13.034Z,1591721773.034 [DVL_micro](ERROR): DVL BIT error. See manual. Result code: 1059 2020-06-09T16:56:13.036Z,1591721773.036 [DVL_micro](ERROR): Failed to parse: :BD,+00000000.00,+00000000.00,+00000000.00,9999.99,000.00 2020-06-09T16:56:13.552Z,1591721773.552 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20200609T164645/Courier0004.lzma 2020-06-09T16:56:14.554Z,1591721774.554 [DataOverHttps](INFO): Moved sent file to Logs/20200609T164645/Courier0004.lzma.bak 2020-06-09T16:56:14.555Z,1591721774.555 [DataOverHttps](INFO): SBD MOMSN=12374408 2020-06-09T16:56:33.661Z,1591721793.661 [DataOverHttps](INFO): Sending 358 bytes from file Logs/20200609T164645/Express0005.lzma 2020-06-09T16:56:34.662Z,1591721794.662 [DataOverHttps](INFO): Moved sent file to Logs/20200609T164645/Express0005.lzma.bak 2020-06-09T16:56:34.663Z,1591721794.663 [DataOverHttps](INFO): SBD MOMSN=12374410 2020-06-09T16:56:39.350Z,1591721799.350 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T16:56:39.350Z,1591721799.350 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T16:56:39.350Z,1591721799.350 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T16:56:56.264Z,1591721816.264 [DVL_micro](ERROR): only read 0 of 4 data items 2020-06-09T16:56:56.264Z,1591721816.264 [DVL_micro](ERROR): Failed to parse: :RD,,+9999.99,+9999.99,+9999.99 2020-06-09T16:57:37.467Z,1591721857.467 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T16:57:37.467Z,1591721857.467 [NAL9602] Data Fault, FailCount= 1 2020-06-09T16:57:37.467Z,1591721857.467 [NAL9602](ERROR): Data Fault 2020-06-09T16:57:37.520Z,1591721857.520 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T16:57:37.867Z,1591721857.867 [NAL9602](INFO): Powering down 2020-06-09T16:57:38.716Z,1591721858.716 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T16:57:38.717Z,1591721858.717 [NAL9602] No Fault, FailCount= 1 2020-06-09T16:58:08.171Z,1591721888.171 [NAL9602](INFO): Powering up NAL9602 2020-06-09T16:58:19.075Z,1591721899.075 [NAL9602](INFO): NAL9602 initialized 2020-06-09T16:58:40.489Z,1591721920.489 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T16:58:40.489Z,1591721920.489 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+0.0,1489.0,000 2020-06-09T16:58:58.265Z,1591721938.265 [DVL_micro](ERROR): Failed to parse: :WI,+00635,-01763,+01164,+00000,A 2020-06-09T16:58:59.110Z,1591721939.110 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2020-06-09T16:58:59.110Z,1591721939.110 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T16:58:59.120Z,1591721939.120 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T16:58:59.522Z,1591721939.522 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T16:58:59.522Z,1591721939.522 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2020-06-09T16:59:41.501Z,1591721981.501 [DVL_micro](ERROR): only read 1 of 4 data items 2020-06-09T16:59:41.501Z,1591721981.501 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,,+9999.99 2020-06-09T17:00:23.550Z,1591722023.550 [CBIT](INFO): Clearing failed state for component DAT 2020-06-09T17:00:23.550Z,1591722023.550 [DAT] No Fault, FailCount= 8 2020-06-09T17:00:23.927Z,1591722023.927 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-06-09T17:00:23.927Z,1591722023.927 [DAT](INFO): Powering up 2020-06-09T17:00:23.927Z,1591722023.927 [DAT](DEBUG): Initializing DAT. 2020-06-09T17:00:23.955Z,1591722023.955 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-06-09T17:00:38.076Z,1591722038.076 [DAT](INFO): commRate: 800 2020-06-09T17:00:38.077Z,1591722038.077 [DAT](INFO): commRate: 800 2020-06-09T17:00:38.471Z,1591722038.471 [DAT](INFO): entering command mode 2020-06-09T17:00:38.874Z,1591722038.874 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:39.296Z,1591722039.296 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:39.722Z,1591722039.722 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:40.111Z,1591722040.111 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:40.494Z,1591722040.494 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:40.895Z,1591722040.895 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:41.308Z,1591722041.308 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:41.713Z,1591722041.713 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:42.138Z,1591722042.138 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:42.508Z,1591722042.508 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T17:00:42.508Z,1591722042.508 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,39,0000.0,1489.0,000 2020-06-09T17:00:42.535Z,1591722042.535 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:42.936Z,1591722042.936 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:43.314Z,1591722043.314 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:43.729Z,1591722043.729 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:44.131Z,1591722044.131 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:44.553Z,1591722044.553 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:44.952Z,1591722044.952 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:45.360Z,1591722045.360 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:45.759Z,1591722045.759 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:46.167Z,1591722046.167 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:46.562Z,1591722046.562 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:46.964Z,1591722046.964 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:47.371Z,1591722047.371 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:47.770Z,1591722047.770 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:48.179Z,1591722048.179 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:48.586Z,1591722048.586 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:48.999Z,1591722048.999 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:49.380Z,1591722049.380 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:49.803Z,1591722049.803 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:50.186Z,1591722050.186 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:50.590Z,1591722050.590 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:50.998Z,1591722050.998 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:51.415Z,1591722051.415 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:51.825Z,1591722051.825 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:52.229Z,1591722052.229 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:52.624Z,1591722052.624 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:53.019Z,1591722053.019 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:53.418Z,1591722053.418 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:53.825Z,1591722053.825 [DAT](DEBUG): checking for command mode acknowledgment 2020-06-09T17:00:53.825Z,1591722053.825 [DAT](FAULT): failed to enter command mode 2020-06-09T17:00:54.245Z,1591722054.245 [DAT](INFO): entering command mode 2020-06-09T17:00:54.657Z,1591722054.657 [DAT](INFO): setting verbose to 3 2020-06-09T17:00:55.074Z,1591722055.074 [DAT](INFO): set verbose to 3 2020-06-09T17:00:55.075Z,1591722055.075 [DAT](INFO): setting DatVerbose to 27440 2020-06-09T17:00:55.435Z,1591722055.435 [DAT](INFO): set DatVerbose to 27440 2020-06-09T17:00:55.435Z,1591722055.435 [DAT](INFO): setting transmit power to 8 2020-06-09T17:00:55.847Z,1591722055.847 [DAT](INFO): set transmit power to 8 2020-06-09T17:00:55.848Z,1591722055.848 [DAT](INFO): setting local address to 8 2020-06-09T17:00:56.255Z,1591722056.255 [DAT](INFO): set local address to 8 2020-06-09T17:01:18.925Z,1591722078.925 [CommandLine](IMPORTANT): got command failComponent 2020-06-09T17:01:18.926Z,1591722078.926 [CommandLine](IMPORTANT): Failed components: 2020-06-09T17:01:18.926Z,1591722078.926 [CommandLine](IMPORTANT): No failed Components. 2020-06-09T17:01:23.581Z,1591722083.581 [CommandLine](IMPORTANT): got command show stack 2020-06-09T17:01:23.582Z,1591722083.582 [CommandLine](IMPORTANT): Behavior Stack: 2020-06-09T17:01:23.582Z,1591722083.582 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface 2020-06-09T17:01:23.582Z,1591722083.582 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:C.Wait 2020-06-09T17:01:26.894Z,1591722086.894 [CommandLine](IMPORTANT): got command show variable abort 2020-06-09T17:01:27.051Z,1591722087.051 [CommandLine](IMPORTANT): CBIT.abortDepth (meter) 2020-06-09T17:01:27.051Z,1591722087.051 [CommandLine](IMPORTANT): CBIT.abortDepthTimeout (second) 2020-06-09T17:01:31.391Z,1591722091.391 [CommandLine](IMPORTANT): got command get CBIT.abortDepth 2020-06-09T17:01:31.391Z,1591722091.391 [CommandLine](IMPORTANT): CBIT.abortDepth 300.000000 m 2020-06-09T17:01:36.790Z,1591722096.790 [CommandLine](IMPORTANT): got command get CBIT.stopDepth 2020-06-09T17:01:36.791Z,1591722096.791 [CommandLine](IMPORTANT): CBIT.stopDepth 275.000000 m 2020-06-09T17:01:39.903Z,1591722099.903 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T17:01:39.903Z,1591722099.903 [Default:CheckIn:C.Wait] Stopped 2020-06-09T17:01:39.903Z,1591722099.903 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T17:01:39.903Z,1591722099.903 [Default:CheckIn:D] Running Loop=1 2020-06-09T17:01:40.306Z,1591722100.306 [Default:CheckIn:D] Stopped 2020-06-09T17:01:40.306Z,1591722100.306 [Default:CheckIn:E] Running Loop=1 2020-06-09T17:01:40.730Z,1591722100.730 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.826998 min 2020-06-09T17:01:40.730Z,1591722100.730 [Default:CheckIn:E] Stopped 2020-06-09T17:01:40.730Z,1591722100.730 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T17:01:40.731Z,1591722100.731 [Default:CheckIn] Stopped 2020-06-09T17:01:40.731Z,1591722100.731 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T17:01:40.731Z,1591722100.731 [Default:CheckIn](INFO): Running loop #2 2020-06-09T17:01:40.731Z,1591722100.731 [Default:CheckIn] Running Loop=2 2020-06-09T17:01:40.731Z,1591722100.731 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T17:01:40.731Z,1591722100.731 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T17:01:44.806Z,1591722104.806 [CommandLine](IMPORTANT): got command get platform_orientation degree 2020-06-09T17:01:44.806Z,1591722104.806 [CommandLine](IMPORTANT): platform_orientation 215.284066 arcdeg 2020-06-09T17:01:52.123Z,1591722112.123 [CommandLine](IMPORTANT): got command get platform_orientation degree 2020-06-09T17:01:52.123Z,1591722112.123 [CommandLine](IMPORTANT): platform_orientation 215.253384 arcdeg 2020-06-09T17:01:58.718Z,1591722118.718 [CommandLine](IMPORTANT): got command strobe off 2020-06-09T17:01:58.719Z,1591722118.719 [CommandLine](IMPORTANT): Deactivating strobe 2020-06-09T17:02:00.087Z,1591722120.087 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2020-06-09T17:02:00.087Z,1591722120.087 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T17:02:00.097Z,1591722120.097 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T17:02:00.514Z,1591722120.514 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T17:02:00.514Z,1591722120.514 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2020-06-09T17:02:08.968Z,1591722128.968 [DVL_micro](ERROR): only read 2 of 4 data items 2020-06-09T17:02:08.968Z,1591722128.968 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,+9999.99,,+9999.99 2020-06-09T17:02:29.161Z,1591722149.161 [DVL_micro](ERROR): Failed to parse: :SA,-00.92,-06.67,253.3 2020-06-09T17:02:44.511Z,1591722164.511 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T17:02:44.512Z,1591722164.512 [DVL_micro](ERROR): Failed to parse: :BI,+00860,-01348,+0000,I 2020-06-09T17:04:56.629Z,1591722296.629 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T17:04:56.629Z,1591722296.629 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+210,1489.0,000 2020-06-09T17:05:01.180Z,1591722301.180 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2020-06-09T17:05:01.180Z,1591722301.180 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T17:05:01.248Z,1591722301.248 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T17:05:01.570Z,1591722301.570 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T17:05:01.570Z,1591722301.570 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2020-06-09T17:05:57.652Z,1591722357.652 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T17:05:57.653Z,1591722357.653 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.0,0000.0,1489.0,,+01864,-02363,+00459,+00000,A 2020-06-09T17:06:20.678Z,1591722380.678 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T17:06:20.678Z,1591722380.678 [DVL_micro](ERROR): Failed to parse::TS,00000000000000,35.0,+21.0,0000.0,1489.0I,-00038+01354,+00000,A 2020-06-09T17:06:38.443Z,1591722398.443 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T17:06:38.443Z,1591722398.443 [DVL_micro](ERROR): Failed to parse: :BI,+00130,-01561,+0000,I 2020-06-09T17:06:40.899Z,1591722400.899 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T17:01:40.7Z 2020-06-09T17:06:40.899Z,1591722400.899 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T17:06:40.899Z,1591722400.899 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T17:06:51.016Z,1591722411.016 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200609T164645/Courier0007.lzma 2020-06-09T17:06:52.019Z,1591722412.019 [DataOverHttps](INFO): Moved sent file to Logs/20200609T164645/Courier0007.lzma.bak 2020-06-09T17:06:52.019Z,1591722412.019 [DataOverHttps](INFO): SBD MOMSN=12374467 2020-06-09T17:07:13.926Z,1591722433.926 [DataOverHttps](INFO): Sending 560 bytes from file Logs/20200609T164645/Express0008.lzma 2020-06-09T17:07:14.927Z,1591722434.927 [DataOverHttps](INFO): Moved sent file to Logs/20200609T164645/Express0008.lzma.bak 2020-06-09T17:07:14.927Z,1591722434.927 [DataOverHttps](INFO): SBD MOMSN=12374469 2020-06-09T17:07:17.674Z,1591722437.674 [Default:CheckIn:Read_Iridium] Stopped 2020-06-09T17:07:17.674Z,1591722437.674 [Default:CheckIn:C.Wait] Running Loop=1 2020-06-09T17:07:17.674Z,1591722437.674 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-06-09T17:08:02.122Z,1591722482.122 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2020-06-09T17:08:02.122Z,1591722482.122 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T17:08:02.132Z,1591722482.132 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T17:08:02.527Z,1591722482.527 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T17:08:02.527Z,1591722482.527 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2020-06-09T17:08:22.284Z,1591722502.284 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-06-09T17:08:22.284Z,1591722502.284 [NAL9602] Data Fault, FailCount= 2 2020-06-09T17:08:22.284Z,1591722502.284 [NAL9602](ERROR): Data Fault 2020-06-09T17:08:22.346Z,1591722502.346 [CBIT](ERROR): Data Fault in component: NAL9602 2020-06-09T17:08:22.694Z,1591722502.694 [NAL9602](INFO): Powering down 2020-06-09T17:08:23.536Z,1591722503.536 [CBIT](INFO): Clearing failed state for component NAL9602 2020-06-09T17:08:23.536Z,1591722503.536 [NAL9602] No Fault, FailCount= 2 2020-06-09T17:08:30.364Z,1591722510.364 [DVL_micro](ERROR): only read 1 of 4 data items 2020-06-09T17:08:30.364Z,1591722510.364 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,++9999.99,+9999.99 2020-06-09T17:08:52.989Z,1591722532.989 [NAL9602](INFO): Powering up NAL9602 2020-06-09T17:08:58.240Z,1591722538.240 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T17:08:58.241Z,1591722538.241 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0000.0,1489.0,000 2020-06-09T17:09:03.879Z,1591722543.879 [NAL9602](INFO): NAL9602 initialized 2020-06-09T17:09:08.344Z,1591722548.344 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T17:09:08.345Z,1591722548.345 [DVL_micro](ERROR): Failed to parse: :RD,+99999.99,+9999.99,+9999.99 2020-06-09T17:09:43.886Z,1591722583.886 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T17:09:43.886Z,1591722583.886 [DVL_micro](ERROR): Failed to parse: :TS,00000000000000,35.0,+21.0,0000.0,1489:WI,+01342,-01406,+01265,+00000,A 2020-06-09T17:10:57.827Z,1591722657.827 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T17:10:57.827Z,1591722657.827 [DVL_micro](ERROR): Failed to parse: :BI,+02256,-01334,+0080,I 2020-06-09T17:11:03.130Z,1591722663.130 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2020-06-09T17:11:03.130Z,1591722663.130 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T17:11:03.169Z,1591722663.169 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T17:11:03.562Z,1591722663.562 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T17:11:03.562Z,1591722663.562 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2020-06-09T17:11:27.888Z,1591722687.888 [CommandLine](IMPORTANT): got command burn on 2020-06-09T17:11:27.891Z,1591722687.891 [CommandLine](IMPORTANT): Activating dropweight wire 2020-06-09T17:11:28.935Z,1591722688.935 [DropWeight](CRITICAL): DROP WEIGHT MISSING. 2020-06-09T17:11:28.935Z,1591722688.935 [DropWeight] Hardware Fault, FailCount= 1 2020-06-09T17:11:28.935Z,1591722688.935 [DropWeight](ERROR): Hardware Fault 2020-06-09T17:11:29.022Z,1591722689.022 [CommandLine](FAULT): Scheduling is paused 2020-06-09T17:11:29.023Z,1591722689.023 [CBIT](INFO): Critical error at 20200609T171128 2020-06-09T17:11:29.023Z,1591722689.023 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2020-06-09T17:11:29.038Z,1591722689.038 [CBIT](ERROR): Hardware Fault in component: DropWeight 2020-06-09T17:11:29.038Z,1591722689.038 [CBIT](CRITICAL): Hardware Fault in component: DropWeight 2020-06-09T17:11:29.426Z,1591722689.426 [CBIT](INFO): Critical error at 20200609T171129 2020-06-09T17:11:52.741Z,1591722712.741 [CommandLine](IMPORTANT): got command burn off 2020-06-09T17:11:52.742Z,1591722712.742 [CommandLine](IMPORTANT): Deactivating dropweight wire 2020-06-09T17:12:18.274Z,1591722738.274 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-06-09T17:12:18.274Z,1591722738.274 [Default:CheckIn:C.Wait] Stopped 2020-06-09T17:12:18.274Z,1591722738.274 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-06-09T17:12:18.274Z,1591722738.274 [Default:CheckIn:D] Running Loop=1 2020-06-09T17:12:18.691Z,1591722738.691 [Default:CheckIn:D] Stopped 2020-06-09T17:12:18.691Z,1591722738.691 [Default:CheckIn:E] Running Loop=1 2020-06-09T17:12:19.115Z,1591722739.115 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.466748 min 2020-06-09T17:12:19.115Z,1591722739.115 [Default:CheckIn:E] Stopped 2020-06-09T17:12:19.116Z,1591722739.116 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-06-09T17:12:19.116Z,1591722739.116 [Default:CheckIn] Stopped 2020-06-09T17:12:19.116Z,1591722739.116 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-06-09T17:12:19.116Z,1591722739.116 [Default:CheckIn](INFO): Running loop #3 2020-06-09T17:12:19.116Z,1591722739.116 [Default:CheckIn] Running Loop=3 2020-06-09T17:12:19.116Z,1591722739.116 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-06-09T17:12:19.116Z,1591722739.116 [Default:CheckIn:Read_GPS] Running Loop=1 2020-06-09T17:12:42.068Z,1591722762.068 [DVL_micro](ERROR): only read 1 of 4 data items 2020-06-09T17:12:42.073Z,1591722762.073 [DVL_micro](ERROR): Failed to parse: :RD,+9999.99,,+9999.999 2020-06-09T17:13:37.826Z,1591722817.826 [DVL_micro](ERROR): only read 1 of 4 data items 2020-06-09T17:13:37.827Z,1591722817.827 [DVL_micro](ERROR): Failed to parse: :BI,-00202+01373,+00000,I 2020-06-09T17:13:43.078Z,1591722823.078 [DVL_micro](ERROR): only read 0 of 4 data items 2020-06-09T17:13:43.078Z,1591722823.078 [DVL_micro](ERROR): Failed to parse: :BI-01163,+01461,+00000,I 2020-06-09T17:13:58.026Z,1591722838.026 [DVL_micro](ERROR): Failed to parse: :B,-01585,+01516,+00000,I 2020-06-09T17:14:04.153Z,1591722844.153 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2020-06-09T17:14:04.153Z,1591722844.153 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T17:14:04.204Z,1591722844.204 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T17:14:04.566Z,1591722844.566 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T17:14:04.566Z,1591722844.566 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2020-06-09T17:14:44.088Z,1591722884.088 [DVL_micro](ERROR): only read 0 of 1 data item for BIT error 2020-06-09T17:14:44.088Z,1591722884.088 [DVL_micro](ERROR): Failed to parse: :TS0000000,35.0,+21.1,0000.0,1489.0,000 2020-06-09T17:14:48.326Z,1591722888.326 [CommandLine](IMPORTANT): got command failComponent 2020-06-09T17:14:48.326Z,1591722888.326 [CommandLine](IMPORTANT): Failed components: 2020-06-09T17:14:48.327Z,1591722888.327 [CommandLine](IMPORTANT): DropWeight: Hardware Fault 2020-06-09T17:15:52.678Z,1591722952.678 [CommandLine](IMPORTANT): got command failComponent 2020-06-09T17:15:52.678Z,1591722952.678 [CommandLine](IMPORTANT): Failed components: 2020-06-09T17:15:52.678Z,1591722952.678 [CommandLine](IMPORTANT): DropWeight: Hardware Fault 2020-06-09T17:15:59.259Z,1591722959.259 [CommandLine](IMPORTANT): got command failComponent none DropWeight 2020-06-09T17:15:59.260Z,1591722959.260 [DropWeight] No Fault, FailCount= 1 2020-06-09T17:15:59.260Z,1591722959.260 [CommandLine](IMPORTANT): DropWeight failureMode is No Fault 2020-06-09T17:16:02.933Z,1591722962.933 [DVL_micro](ERROR): DVL uart error: serial timeout 2020-06-09T17:16:02.933Z,1591722962.933 [DVL_micro] Communications Fault, FailCount= 1 2020-06-09T17:16:02.933Z,1591722962.933 [DVL_micro](ERROR): Communications Fault 2020-06-09T17:16:02.933Z,1591722962.933 [DVL_micro](ERROR): Failed to parse: 2020-06-09T17:16:03.021Z,1591722963.021 [CBIT](ERROR): Communications Fault in component: DVL_micro 2020-06-09T17:16:03.341Z,1591722963.341 [DVL_micro](INFO): Powering down 2020-06-09T17:16:04.166Z,1591722964.166 [CBIT](INFO): Clearing failed state for component DVL_micro 2020-06-09T17:16:04.166Z,1591722964.166 [DVL_micro] No Fault, FailCount= 1 2020-06-09T17:16:24.072Z,1591722984.072 [CommandLine](IMPORTANT): got command failComponent 2020-06-09T17:16:24.072Z,1591722984.072 [CommandLine](IMPORTANT): Failed components: 2020-06-09T17:16:24.072Z,1591722984.072 [CommandLine](IMPORTANT): No failed Components. 2020-06-09T17:16:44.886Z,1591723004.886 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T17:16:44.887Z,1591723004.887 [DVL_micro](ERROR): Failed to parse: :BI,+01681,-01143,+0110,I 2020-06-09T17:16:54.994Z,1591723014.994 [DVL_micro](ERROR): only read 3 of 4 data items 2020-06-09T17:16:54.995Z,1591723014.995 [DVL_micro](ERROR): Failed to parse: :BI,+00196,-0080,+00000,I 2020-06-09T17:16:56.965Z,1591723016.965 [CommandLine](IMPORTANT): got command failComponent 2020-06-09T17:16:56.966Z,1591723016.966 [CommandLine](IMPORTANT): Failed components: 2020-06-09T17:16:56.966Z,1591723016.966 [CommandLine](IMPORTANT): No failed Components. 2020-06-09T17:17:05.190Z,1591723025.190 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2020-06-09T17:17:05.190Z,1591723025.190 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-06-09T17:17:05.204Z,1591723025.204 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-06-09T17:17:05.564Z,1591723025.564 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-06-09T17:17:05.564Z,1591723025.564 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2020-06-09T17:17:19.275Z,1591723039.275 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-09T17:12:19.1Z 2020-06-09T17:17:19.276Z,1591723039.276 [Default:CheckIn:Read_GPS] Stopped 2020-06-09T17:17:19.276Z,1591723039.276 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-06-09T17:17:31.197Z,1591723051.197 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20200609T164645/Courier0010.lzma 2020-06-09T17:17:32.199Z,1591723052.199 [DataOverHttps](INFO): Moved sent file to Logs/20200609T164645/Courier0010.lzma.bak 2020-06-09T17:17:32.199Z,1591723052.199 [DataOverHttps](INFO): SBD MOMSN=12374501 2020-06-09T17:17:58.174Z,1591723078.174 [DataOverHttps](INFO): Sending 371 bytes from file Logs/20200609T164645/Express0011.lzma 2020-06-09T17:17:59.175Z,1591723079.175 [DataOverHttps](INFO): Moved sent file to Logs/20200609T164645/Express0011.lzma.bak 2020-06-09T17:17:59.175Z,1591723079.175 [Da