2020-08-25T20:25:51.566Z,1598387151.566 [Supervisor](DEBUG): Initializing supervisor. 2020-08-25T20:25:51.569Z,1598387151.569 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-08-25T20:25:51.570Z,1598387151.570 [SyncHandler](INFO): Protected caller Thread ID is 3083 2020-08-25T20:25:51.570Z,1598387151.570 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-08-25T20:25:51.571Z,1598387151.571 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-08-25T20:25:51.572Z,1598387151.572 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3084 2020-08-25T20:25:51.575Z,1598387151.575 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-08-25T20:25:51.588Z,1598387151.588 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-08-25T20:25:51.589Z,1598387151.589 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-08-25T20:25:51.589Z,1598387151.589 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3085 2020-08-25T20:25:51.590Z,1598387151.590 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-08-25T20:25:51.591Z,1598387151.591 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-08-25T20:25:51.591Z,1598387151.591 [logger ThreadHandler](INFO): Protected caller Thread ID is 3086 2020-08-25T20:25:51.593Z,1598387151.593 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-08-25T20:25:51.593Z,1598387151.593 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-08-25T20:25:51.595Z,1598387151.595 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-08-25T20:25:51.756Z,1598387151.756 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-08-25T20:25:51.756Z,1598387151.756 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-08-25T20:25:52.341Z,1598387152.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-08-25T20:25:52.342Z,1598387152.342 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2020-08-25T20:25:52.533Z,1598387152.533 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2020-08-25T20:25:52.534Z,1598387152.534 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-08-25T20:25:52.636Z,1598387152.636 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-08-25T20:25:52.636Z,1598387152.636 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-08-25T20:25:52.740Z,1598387152.740 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-08-25T20:25:52.741Z,1598387152.741 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-08-25T20:25:52.824Z,1598387152.824 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-08-25T20:25:52.963Z,1598387152.963 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-08-25T20:25:52.964Z,1598387152.964 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-08-25T20:25:53.249Z,1598387153.249 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-08-25T20:25:53.249Z,1598387153.249 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-08-25T20:25:53.693Z,1598387153.693 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-08-25T20:25:53.694Z,1598387153.694 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-08-25T20:25:53.838Z,1598387153.838 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-08-25T20:25:53.839Z,1598387153.839 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-08-25T20:25:54.031Z,1598387154.031 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-08-25T20:25:54.031Z,1598387154.031 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-08-25T20:25:54.493Z,1598387154.493 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-08-25T20:25:54.493Z,1598387154.493 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-08-25T20:25:55.123Z,1598387155.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-08-25T20:25:55.123Z,1598387155.123 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-08-25T20:25:55.327Z,1598387155.327 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-08-25T20:25:55.327Z,1598387155.327 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-08-25T20:25:55.728Z,1598387155.728 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-08-25T20:25:55.728Z,1598387155.728 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-08-25T20:25:56.055Z,1598387156.055 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-08-25T20:25:56.057Z,1598387156.057 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2020-08-25T20:25:56.058Z,1598387156.058 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2020-08-25T20:25:56.145Z,1598387156.145 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2020-08-25T20:25:56.303Z,1598387156.303 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2020-08-25T20:25:56.412Z,1598387156.412 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2020-08-25T20:25:56.500Z,1598387156.500 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2020-08-25T20:25:56.596Z,1598387156.596 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2020-08-25T20:25:56.796Z,1598387156.796 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2020-08-25T20:25:57.027Z,1598387157.027 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-08-25T20:25:57.027Z,1598387157.027 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2020-08-25T20:25:57.124Z,1598387157.124 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2020-08-25T20:25:57.224Z,1598387157.224 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2020-08-25T20:25:57.356Z,1598387157.356 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2020-08-25T20:25:57.458Z,1598387157.458 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2020-08-25T20:25:57.472Z,1598387157.472 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2020-08-25T20:25:57.543Z,1598387157.543 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2020-08-25T20:25:57.544Z,1598387157.544 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-08-25T20:25:57.588Z,1598387157.588 [VerticalControl](DEBUG): Construct VerticalControl. 2020-08-25T20:25:57.693Z,1598387157.693 [VerticalControl] Loaded 2020-08-25T20:25:57.694Z,1598387157.694 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-08-25T20:25:57.694Z,1598387157.694 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-08-25T20:25:57.769Z,1598387157.769 [HorizontalControl] Loaded 2020-08-25T20:25:57.770Z,1598387157.770 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-08-25T20:25:57.770Z,1598387157.770 [SpeedControl](DEBUG): Construct SpeedControl. 2020-08-25T20:25:57.775Z,1598387157.775 [SpeedControl] Loaded 2020-08-25T20:25:57.776Z,1598387157.776 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-08-25T20:25:57.776Z,1598387157.776 [LoopControl](DEBUG): Construct LoopControl. 2020-08-25T20:25:57.777Z,1598387157.777 [LoopControl] Loaded 2020-08-25T20:25:57.777Z,1598387157.777 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-08-25T20:25:57.777Z,1598387157.777 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-08-25T20:25:57.778Z,1598387157.778 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-08-25T20:25:57.817Z,1598387157.817 [DepthRateCalculator] Loaded 2020-08-25T20:25:57.817Z,1598387157.817 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-08-25T20:25:57.822Z,1598387157.822 [PitchRateCalculator] Loaded 2020-08-25T20:25:57.822Z,1598387157.822 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-08-25T20:25:57.837Z,1598387157.837 [SpeedCalculator] Loaded 2020-08-25T20:25:57.837Z,1598387157.837 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-08-25T20:25:57.857Z,1598387157.857 [TempGradientCalculator] Loaded 2020-08-25T20:25:57.857Z,1598387157.857 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-08-25T20:25:57.862Z,1598387157.862 [YawRateCalculator] Loaded 2020-08-25T20:25:57.862Z,1598387157.862 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-08-25T20:25:57.889Z,1598387157.889 [ElevatorOffsetCalculator] Loaded 2020-08-25T20:25:57.890Z,1598387157.890 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-08-25T20:25:57.890Z,1598387157.890 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-08-25T20:25:57.891Z,1598387157.891 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-08-25T20:25:57.915Z,1598387157.915 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-08-25T20:25:57.916Z,1598387157.916 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-08-25T20:25:57.997Z,1598387157.997 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components) 2020-08-25T20:25:57.998Z,1598387157.998 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-08-25T20:25:58.267Z,1598387158.267 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-08-25T20:25:58.268Z,1598387158.268 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-08-25T20:25:58.365Z,1598387158.365 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-08-25T20:25:58.366Z,1598387158.366 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-08-25T20:25:58.688Z,1598387158.688 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-08-25T20:25:58.693Z,1598387158.693 [AHRS_M2](INFO): created writer for : platform_orientation 2020-08-25T20:25:58.695Z,1598387158.695 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-08-25T20:25:58.700Z,1598387158.700 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-08-25T20:25:58.700Z,1598387158.700 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-08-25T20:25:58.705Z,1598387158.705 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-08-25T20:25:58.706Z,1598387158.706 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-08-25T20:25:58.711Z,1598387158.711 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-08-25T20:25:58.778Z,1598387158.778 [AHRS_M2] Loaded 2020-08-25T20:25:58.778Z,1598387158.778 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-08-25T20:25:58.852Z,1598387158.852 [DataOverHttps] Loaded 2020-08-25T20:25:58.852Z,1598387158.852 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-08-25T20:25:58.853Z,1598387158.853 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0 2020-08-25T20:25:58.854Z,1598387158.854 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3168 2020-08-25T20:25:58.883Z,1598387158.883 [Depth_Keller] Loaded 2020-08-25T20:25:58.883Z,1598387158.883 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-08-25T20:25:58.995Z,1598387158.995 [NAL9602] Loaded 2020-08-25T20:25:58.995Z,1598387158.995 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-08-25T20:25:59.041Z,1598387159.041 [Onboard] Loaded 2020-08-25T20:25:59.041Z,1598387159.041 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2020-08-25T20:25:59.042Z,1598387159.042 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0 2020-08-25T20:25:59.043Z,1598387159.043 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3169 2020-08-25T20:25:59.061Z,1598387159.061 [Radio_Surface] Loaded 2020-08-25T20:25:59.061Z,1598387159.061 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-08-25T20:25:59.062Z,1598387159.062 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0 2020-08-25T20:25:59.062Z,1598387159.062 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3170 2020-08-25T20:25:59.206Z,1598387159.206 [DAT] Loaded 2020-08-25T20:25:59.206Z,1598387159.206 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2020-08-25T20:26:01.013Z,1598387161.013 [BPC1] Loaded 2020-08-25T20:26:01.013Z,1598387161.013 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-08-25T20:26:01.044Z,1598387161.044 [AMEcho] Loaded 2020-08-25T20:26:01.044Z,1598387161.044 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread. 2020-08-25T20:26:01.045Z,1598387161.045 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-08-25T20:26:01.045Z,1598387161.045 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-08-25T20:26:01.156Z,1598387161.156 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-08-25T20:26:01.156Z,1598387161.156 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-08-25T20:26:01.176Z,1598387161.176 [NavChart] Loaded 2020-08-25T20:26:01.176Z,1598387161.176 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-08-25T20:26:01.180Z,1598387161.180 [UniversalFixResidualReporter] Loaded 2020-08-25T20:26:01.180Z,1598387161.180 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-08-25T20:26:01.181Z,1598387161.181 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-08-25T20:26:01.181Z,1598387161.181 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-08-25T20:26:01.305Z,1598387161.305 [SBIT](DEBUG): Construct Startup Built In Test. 2020-08-25T20:26:01.316Z,1598387161.316 [SBIT] Loaded 2020-08-25T20:26:01.316Z,1598387161.316 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-08-25T20:26:01.317Z,1598387161.317 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-08-25T20:26:01.329Z,1598387161.329 [IBIT] Loaded 2020-08-25T20:26:01.329Z,1598387161.329 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-08-25T20:26:01.333Z,1598387161.332 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-08-25T20:26:01.465Z,1598387161.465 [CBIT] Loaded 2020-08-25T20:26:01.465Z,1598387161.465 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-08-25T20:26:01.465Z,1598387161.465 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-08-25T20:26:01.466Z,1598387161.466 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-08-25T20:26:01.578Z,1598387161.578 [BuoyancyServo] Loaded 2020-08-25T20:26:01.579Z,1598387161.579 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-08-25T20:26:01.606Z,1598387161.606 [ElevatorServo] Loaded 2020-08-25T20:26:01.606Z,1598387161.606 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-08-25T20:26:01.633Z,1598387161.633 [MassServo] Loaded 2020-08-25T20:26:01.633Z,1598387161.633 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-08-25T20:26:01.659Z,1598387161.659 [RudderServo] Loaded 2020-08-25T20:26:01.659Z,1598387161.659 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-08-25T20:26:01.685Z,1598387161.685 [ThrusterServo] Loaded 2020-08-25T20:26:01.685Z,1598387161.685 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-08-25T20:26:01.685Z,1598387161.685 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-08-25T20:26:01.686Z,1598387161.686 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-08-25T20:26:01.703Z,1598387161.703 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-08-25T20:26:01.704Z,1598387161.704 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-08-25T20:26:01.927Z,1598387161.927 [BackSeatDriver] Loaded 2020-08-25T20:26:01.927Z,1598387161.927 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread. 2020-08-25T20:26:01.929Z,1598387161.929 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0 2020-08-25T20:26:01.929Z,1598387161.929 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 3171 2020-08-25T20:26:01.956Z,1598387161.956 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2020-08-25T20:26:01.961Z,1598387161.961 [CTD_Seabird](INFO): created writer for : sea_water_density 2020-08-25T20:26:01.962Z,1598387161.962 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2020-08-25T20:26:01.966Z,1598387161.966 [CTD_Seabird](INFO): created writer for : depth 2020-08-25T20:26:01.967Z,1598387161.967 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2020-08-25T20:26:01.973Z,1598387161.973 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2020-08-25T20:26:01.973Z,1598387161.973 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2020-08-25T20:26:01.978Z,1598387161.978 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2020-08-25T20:26:01.979Z,1598387161.979 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2020-08-25T20:26:01.984Z,1598387161.984 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2020-08-25T20:26:01.984Z,1598387161.984 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2020-08-25T20:26:01.989Z,1598387161.989 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2020-08-25T20:26:01.990Z,1598387161.990 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2020-08-25T20:26:01.995Z,1598387161.995 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2020-08-25T20:26:02.021Z,1598387162.021 [CTD_Seabird] Loaded 2020-08-25T20:26:02.022Z,1598387162.022 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2020-08-25T20:26:02.023Z,1598387162.023 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B334E0 2020-08-25T20:26:02.023Z,1598387162.023 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3172 2020-08-25T20:26:02.044Z,1598387162.044 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2020-08-25T20:26:02.044Z,1598387162.044 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2020-08-25T20:26:02.048Z,1598387162.048 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2020-08-25T20:26:02.049Z,1598387162.049 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2020-08-25T20:26:02.052Z,1598387162.052 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2020-08-25T20:26:02.053Z,1598387162.053 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2020-08-25T20:26:02.057Z,1598387162.057 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2020-08-25T20:26:02.057Z,1598387162.057 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2020-08-25T20:26:02.061Z,1598387162.061 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2020-08-25T20:26:02.061Z,1598387162.061 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2020-08-25T20:26:02.065Z,1598387162.065 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2020-08-25T20:26:02.065Z,1598387162.065 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2020-08-25T20:26:02.069Z,1598387162.069 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2020-08-25T20:26:02.069Z,1598387162.069 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2020-08-25T20:26:02.073Z,1598387162.073 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2020-08-25T20:26:02.078Z,1598387162.078 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2020-08-25T20:26:02.078Z,1598387162.078 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-08-25T20:26:02.078Z,1598387162.078 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-08-25T20:26:02.082Z,1598387162.082 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-08-25T20:26:02.082Z,1598387162.082 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-08-25T20:26:02.086Z,1598387162.086 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-08-25T20:26:02.087Z,1598387162.087 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-08-25T20:26:02.091Z,1598387162.091 [WetLabsBB2FL] Loaded 2020-08-25T20:26:02.091Z,1598387162.091 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2020-08-25T20:26:02.092Z,1598387162.092 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B634E0 2020-08-25T20:26:02.092Z,1598387162.092 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3173 2020-08-25T20:26:02.093Z,1598387162.093 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-08-25T20:26:02.097Z,1598387162.097 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-08-25T20:26:02.097Z,1598387162.097 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-08-25T20:26:02.104Z,1598387162.104 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-08-25T20:26:02.105Z,1598387162.105 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B934E0 2020-08-25T20:26:02.105Z,1598387162.105 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3174 2020-08-25T20:26:02.110Z,1598387162.110 [Supervisor](INFO): Main Thread ID is 715 2020-08-25T20:26:02.110Z,1598387162.110 [Supervisor](DEBUG): Running supervisor. 2020-08-25T20:26:02.110Z,1598387162.110 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3175 2020-08-25T20:26:02.113Z,1598387162.113 [controlThread ThreadHandler](INFO): Handler Thread ID is 3176 2020-08-25T20:26:02.113Z,1598387162.113 [controlThread](DEBUG): Initializing ControlThread 2020-08-25T20:26:02.114Z,1598387162.114 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-08-25T20:26:02.116Z,1598387162.116 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-08-25T20:26:02.116Z,1598387162.116 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-08-25T20:26:02.117Z,1598387162.117 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-08-25T20:26:02.117Z,1598387162.117 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-08-25T20:26:02.118Z,1598387162.118 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-08-25T20:26:02.118Z,1598387162.118 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-08-25T20:26:02.118Z,1598387162.118 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-08-25T20:26:02.119Z,1598387162.119 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-08-25T20:26:02.119Z,1598387162.119 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-08-25T20:26:02.124Z,1598387162.124 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-08-25T20:26:02.124Z,1598387162.124 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-08-25T20:26:02.125Z,1598387162.125 [SBIT](INFO): Initialize SBIT Component. 2020-08-25T20:26:02.125Z,1598387162.125 [SBIT](IMPORTANT): git: 2020-08-18a-28-g0d8891e 2020-08-25T20:26:02.125Z,1598387162.125 [SBIT](INFO): git hash: 0d8891e4c136abd7dd8b76b3c91e52f720a234d8 2020-08-25T20:26:02.125Z,1598387162.125 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-08-25T20:26:02.127Z,1598387162.127 [SBIT](INFO): Kernel Reporting Different Version From Configuration. Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019 Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020 2020-08-25T20:26:02.128Z,1598387162.128 [SBIT](INFO): Beginning SBIT in 65.000000 seconds. 2020-08-25T20:26:02.128Z,1598387162.128 [IBIT](INFO): Initialize IBIT Component. 2020-08-25T20:26:02.129Z,1598387162.129 [CBIT](DEBUG): Initialize CBIT Component. 2020-08-25T20:26:02.130Z,1598387162.130 [logger ThreadHandler](INFO): Handler Thread ID is 3177 2020-08-25T20:26:02.142Z,1598387162.142 [CBIT](DEBUG): Initialized mux pins. 2020-08-25T20:26:02.143Z,1598387162.143 [CBIT](DEBUG): Initializing the watchdog timer. 2020-08-25T20:26:02.147Z,1598387162.147 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3178 2020-08-25T20:26:02.148Z,1598387162.148 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-08-25T20:26:02.155Z,1598387162.155 [Onboard ThreadHandler](INFO): Handler Thread ID is 3179 2020-08-25T20:26:02.166Z,1598387162.166 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2020-08-25T20:26:02.166Z,1598387162.166 [CBIT](DEBUG): Initializing heartbeat. 2020-08-25T20:26:02.172Z,1598387162.172 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3180 2020-08-25T20:26:02.191Z,1598387162.191 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 3181 2020-08-25T20:26:02.203Z,1598387162.203 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3182 2020-08-25T20:26:02.203Z,1598387162.203 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2020-08-25T20:26:02.208Z,1598387162.208 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3184 2020-08-25T20:26:02.209Z,1598387162.209 [WetLabsBB2FL](INFO): Powering down 2020-08-25T20:26:02.235Z,1598387162.235 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3185 2020-08-25T20:26:02.238Z,1598387162.238 [CBIT](DEBUG): Deactivating GF circuits. 2020-08-25T20:26:02.239Z,1598387162.239 [CBIT](DEBUG): Deactivating emergency mode. 2020-08-25T20:26:02.241Z,1598387162.241 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-08-25T20:26:02.241Z,1598387162.241 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-08-25T20:26:02.242Z,1598387162.242 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-08-25T20:26:02.242Z,1598387162.242 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-08-25T20:26:02.242Z,1598387162.242 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-08-25T20:26:02.242Z,1598387162.242 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-08-25T20:26:02.242Z,1598387162.242 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-08-25T20:26:02.242Z,1598387162.242 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-08-25T20:26:02.243Z,1598387162.243 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-08-25T20:26:02.243Z,1598387162.243 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-08-25T20:26:02.243Z,1598387162.243 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-08-25T20:26:02.243Z,1598387162.243 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-08-25T20:26:02.243Z,1598387162.243 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-08-25T20:26:02.243Z,1598387162.243 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-08-25T20:26:02.244Z,1598387162.244 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-08-25T20:26:02.244Z,1598387162.244 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-08-25T20:26:02.274Z,1598387162.274 [CBIT](DEBUG): Backplane powered. 2020-08-25T20:26:02.276Z,1598387162.276 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-08-25T20:26:02.288Z,1598387162.288 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-08-25T20:26:02.306Z,1598387162.306 [MissionManager](DEBUG): 2020-08-25T20:26:02.307Z,1598387162.307 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-08-25T20:26:02.380Z,1598387162.380 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-08-25T20:26:02.381Z,1598387162.381 [Default:A.Wait](DEBUG): Construct Wait. 2020-08-25T20:26:02.383Z,1598387162.383 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-08-25T20:26:02.429Z,1598387162.429 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-08-25T20:26:02.432Z,1598387162.432 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-08-25T20:26:02.446Z,1598387162.446 [Default:E.Execute](DEBUG): Construct Execute. 2020-08-25T20:26:02.457Z,1598387162.457 [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-08-25T20:26:02.461Z,1598387162.461 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,DAT,BPC1,AMEcho,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter, 2020-08-25T20:26:02.481Z,1598387162.481 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-08-25T20:26:02.523Z,1598387162.523 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar 2020-08-25T20:26:02.526Z,1598387162.526 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-08-25T20:26:02.527Z,1598387162.527 [DAT](INFO): Powering up 2020-08-25T20:26:02.527Z,1598387162.527 [DAT](DEBUG): Initializing DAT. 2020-08-25T20:26:02.575Z,1598387162.575 [AMEcho](INFO): Powering up 2020-08-25T20:26:02.595Z,1598387162.595 [Radio_Surface](INFO): Powering up 2020-08-25T20:26:02.596Z,1598387162.596 [DepthRateCalculator](ERROR): Depth measurement is not active 2020-08-25T20:26:02.612Z,1598387162.612 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-08-25T20:26:02.615Z,1598387162.615 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-08-25T20:26:02.631Z,1598387162.631 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-08-25T20:26:02.633Z,1598387162.633 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-08-25T20:26:02.643Z,1598387162.643 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-08-25T20:26:02.644Z,1598387162.644 [MassServo](DEBUG): Initializing EZServoServo. 2020-08-25T20:26:02.655Z,1598387162.655 [MassServo](DEBUG): Initializing MassServo. 2020-08-25T20:26:02.656Z,1598387162.656 [RudderServo](DEBUG): Initializing EZServoServo. 2020-08-25T20:26:02.675Z,1598387162.675 [RudderServo](DEBUG): Initializing RudderServo. 2020-08-25T20:26:02.676Z,1598387162.676 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-08-25T20:26:02.691Z,1598387162.691 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-08-25T20:26:03.059Z,1598387163.059 [AMEcho](INFO): Powering down 2020-08-25T20:26:03.598Z,1598387163.598 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2020-08-25T20:26:03.599Z,1598387163.599 [RudderServo](FAULT): Rudder failed to initialize 2020-08-25T20:26:03.599Z,1598387163.599 [RudderServo] Communications Fault, FailCount= 1 2020-08-25T20:26:03.599Z,1598387163.599 [RudderServo](ERROR): Communications Fault 2020-08-25T20:26:03.710Z,1598387163.710 [CBIT](ERROR): Communications Fault in component: RudderServo 2020-08-25T20:26:03.859Z,1598387163.859 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-08-25T20:26:03.860Z,1598387163.860 [RudderServo](INFO): Powering down 2020-08-25T20:26:04.538Z,1598387164.538 [RudderServo](DEBUG): Initializing EZServoServo. 2020-08-25T20:26:04.655Z,1598387164.655 [RudderServo](DEBUG): Initializing RudderServo. 2020-08-25T20:26:04.659Z,1598387164.659 [CBIT](INFO): Clearing failed state for component RudderServo 2020-08-25T20:26:04.659Z,1598387164.659 [RudderServo] No Fault, FailCount= 1 2020-08-25T20:26:09.235Z,1598387169.235 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2020-08-25T20:26:13.016Z,1598387173.016 [DAT](INFO): DAT read: 2020-08-25T20:26:13.018Z,1598387173.018 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2020-08-25T20:26:14.228Z,1598387174.228 [DAT](INFO): DAT read: MF Frequency Band 2020-08-25T20:26:14.229Z,1598387174.229 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21 2020-08-25T20:26:14.230Z,1598387174.230 [DAT](INFO): DAT read: Aug 25 2020 20:25:50 2020-08-25T20:26:15.036Z,1598387175.036 [DAT](INFO): DAT read: Features enabled [Bearing] 2020-08-25T20:26:15.038Z,1598387175.038 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2020-08-25T20:26:15.038Z,1598387175.038 [DAT](INFO): commRate: 800 2020-08-25T20:26:15.038Z,1598387175.038 [DAT](INFO): commRate: 800 2020-08-25T20:26:15.440Z,1598387175.440 [DAT](INFO): entering command mode 2020-08-25T20:26:15.844Z,1598387175.844 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:16.256Z,1598387176.256 [DAT](INFO): DAT read: 2020-08-25T20:26:16.256Z,1598387176.256 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:16.652Z,1598387176.652 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:17.056Z,1598387177.056 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:17.460Z,1598387177.460 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:17.864Z,1598387177.864 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:18.268Z,1598387178.268 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:18.672Z,1598387178.672 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:19.076Z,1598387179.076 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:19.480Z,1598387179.480 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:19.884Z,1598387179.884 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:20.288Z,1598387180.288 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:20.692Z,1598387180.692 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:21.096Z,1598387181.096 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:21.500Z,1598387181.500 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:21.908Z,1598387181.908 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:22.308Z,1598387182.308 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:22.712Z,1598387182.712 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:23.116Z,1598387183.116 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:23.520Z,1598387183.520 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:23.924Z,1598387183.924 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:24.328Z,1598387184.328 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:24.732Z,1598387184.732 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:25.136Z,1598387185.136 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:25.540Z,1598387185.540 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:25.944Z,1598387185.944 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:26.354Z,1598387186.354 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:26.752Z,1598387186.752 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:27.156Z,1598387187.156 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:27.564Z,1598387187.564 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:27.964Z,1598387187.964 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:28.364Z,1598387188.364 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:28.776Z,1598387188.776 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:29.176Z,1598387189.176 [NAL9602](INFO): Powering up NAL9602 2020-08-25T20:26:29.177Z,1598387189.177 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:29.580Z,1598387189.580 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:29.984Z,1598387189.984 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:30.388Z,1598387190.388 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:30.792Z,1598387190.792 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-25T20:26:30.792Z,1598387190.792 [DAT](FAULT): failed to enter command mode 2020-08-25T20:26:31.196Z,1598387191.196 [DAT](INFO): entering command mode 2020-08-25T20:26:31.600Z,1598387191.600 [DAT](INFO): DAT read: user:1> 2020-08-25T20:26:31.601Z,1598387191.601 [DAT](INFO): DAT read: Command '+++' not found 2020-08-25T20:26:31.601Z,1598387191.601 [DAT](INFO): DAT read: Error 2020-08-25T20:26:31.601Z,1598387191.601 [DAT](INFO): setting verbose to 3 2020-08-25T20:26:32.000Z,1598387192.000 [DAT](INFO): DAT read: user:2> 2020-08-25T20:26:32.001Z,1598387192.001 [DAT](INFO): DAT read: Verbose | 3 2020-08-25T20:26:32.001Z,1598387192.001 [DAT](INFO): set verbose to 3 2020-08-25T20:26:32.002Z,1598387192.002 [DAT](INFO): setting DatVerbose to 27440 2020-08-25T20:26:32.408Z,1598387192.408 [DAT](INFO): DAT read: user:3> 2020-08-25T20:26:32.409Z,1598387192.409 [DAT](INFO): DAT read: DatVerbose | 27440 2020-08-25T20:26:32.409Z,1598387192.409 [DAT](INFO): set DatVerbose to 27440 2020-08-25T20:26:32.410Z,1598387192.410 [DAT](INFO): setting transmit power to 8 2020-08-25T20:26:32.812Z,1598387192.812 [DAT](INFO): DAT read: user:4> 2020-08-25T20:26:32.813Z,1598387192.813 [DAT](INFO): DAT read: TxPower | 8 (Max) 2020-08-25T20:26:32.813Z,1598387192.813 [DAT](INFO): set transmit power to 8 2020-08-25T20:26:32.814Z,1598387192.814 [DAT](INFO): setting local address to 9 2020-08-25T20:26:33.212Z,1598387193.212 [DAT](INFO): DAT read: user:5> 2020-08-25T20:26:33.213Z,1598387193.213 [DAT](INFO): DAT read: LocalAddr | 9 2020-08-25T20:26:33.213Z,1598387193.213 [DAT](INFO): set local address to 9 2020-08-25T20:26:40.089Z,1598387200.089 [NAL9602](INFO): NAL9602 initialized 2020-08-25T20:27:07.588Z,1598387227.588 [SBIT](IMPORTANT): Beginning Startup BIT 2020-08-25T20:27:07.592Z,1598387227.592 [CBIT](IMPORTANT): Beginning ground fault scan 2020-08-25T20:27:18.590Z,1598387238.590 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.009927 CHAN A1 (24V): -0.000846 CHAN A2 (12V): -0.007168 CHAN A3 (5V): -0.001986 CHAN B0 (3.3V): 0.000765 CHAN B1 (3.15aV): -0.000098 CHAN B2 (3.15bV): -0.000042 CHAN B3 (GND): 0.002721 OPEN: 0.005620 Full Scale Calc: 4.765 mA, -1.589 mA 2020-08-25T20:28:01.332Z,1598387281.332 [SBIT](IMPORTANT): SBIT PASSED 2020-08-25T20:28:01.332Z,1598387281.332 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2020-08-25T20:28:01.333Z,1598387281.333 [SBIT](IMPORTANT): BackSeatDriver.loadAtStartup=1 bool; 2020-08-25T20:28:01.333Z,1598387281.333 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere; 2020-08-25T20:28:01.333Z,1598387281.333 [SBIT](IMPORTANT): DAT.sbdAddress=6 enum; 2020-08-25T20:28:01.334Z,1598387281.334 [SBIT](IMPORTANT): DAT.surfaceThreshold=-1 meter; 2020-08-25T20:28:01.334Z,1598387281.334 [SBIT](IMPORTANT): DAT.verbosity=3 count; 2020-08-25T20:28:01.334Z,1598387281.334 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2020-08-25T20:28:01.334Z,1598387281.334 [SBIT](IMPORTANT): Express none ThrusterServo.component_avgCurrent; 2020-08-25T20:28:01.334Z,1598387281.334 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second; 2020-08-25T20:28:01.334Z,1598387281.334 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter; 2020-08-25T20:28:01.335Z,1598387281.335 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool; 2020-08-25T20:28:01.335Z,1598387281.335 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=344.685708 cubic_centimeter; 2020-08-25T20:28:01.335Z,1598387281.335 [SBIT](IMPORTANT): VerticalControl.massDefault=11.293600 millimeter; 2020-08-25T20:28:01.335Z,1598387281.335 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=0 bool; 2020-08-25T20:28:01.715Z,1598387281.715 [MissionManager](IMPORTANT): Started mission Startup 2020-08-25T20:28:01.716Z,1598387281.716 [Startup] Running Loop=1 2020-08-25T20:28:01.716Z,1598387281.716 [Startup](DEBUG): Aggregate::initialize Startup 2020-08-25T20:28:01.716Z,1598387281.716 [Startup:A.GoToSurface] Running Loop=1 2020-08-25T20:28:01.716Z,1598387281.716 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-08-25T20:28:01.717Z,1598387281.717 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-08-25T20:28:01.717Z,1598387281.717 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-08-25T20:28:01.717Z,1598387281.717 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-08-25T20:28:01.718Z,1598387281.718 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-08-25T20:28:01.718Z,1598387281.718 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-08-25T20:28:01.720Z,1598387281.720 [Startup:StartupSatComms] Running Loop=1 2020-08-25T20:28:01.720Z,1598387281.720 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-08-25T20:28:01.720Z,1598387281.720 [Startup:StartupSatComms:A] Running Loop=1 2020-08-25T20:28:02.132Z,1598387282.132 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-08-25T20:28:02.524Z,1598387282.524 [AMEcho](INFO): Powering up 2020-08-25T20:28:15.837Z,1598387295.837 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:28:15.838Z,1598387295.838 [AMEcho] Communications Fault, FailCount= 1 2020-08-25T20:28:15.838Z,1598387295.838 [AMEcho](ERROR): Communications Fault 2020-08-25T20:28:15.852Z,1598387295.852 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:28:16.407Z,1598387296.407 [AMEcho](INFO): Powering down 2020-08-25T20:28:17.084Z,1598387297.084 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:28:17.084Z,1598387297.084 [AMEcho] No Fault, FailCount= 1 2020-08-25T20:28:17.460Z,1598387297.460 [AMEcho](INFO): Powering up 2020-08-25T20:28:22.379Z,1598387302.379 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-25T20:28:29.898Z,1598387309.898 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005420 2020-08-25T20:28:30.781Z,1598387310.781 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:28:30.781Z,1598387310.781 [AMEcho] Communications Fault, FailCount= 2 2020-08-25T20:28:30.781Z,1598387310.781 [AMEcho](ERROR): Communications Fault 2020-08-25T20:28:30.823Z,1598387310.823 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:28:31.355Z,1598387311.355 [AMEcho](INFO): Powering down 2020-08-25T20:28:32.012Z,1598387312.012 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:28:32.013Z,1598387312.013 [AMEcho] No Fault, FailCount= 2 2020-08-25T20:28:32.397Z,1598387312.397 [AMEcho](INFO): Powering up 2020-08-25T20:28:45.733Z,1598387325.733 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:28:45.733Z,1598387325.733 [AMEcho] Communications Fault, FailCount= 3 2020-08-25T20:28:45.733Z,1598387325.733 [AMEcho](ERROR): Communications Fault 2020-08-25T20:28:45.776Z,1598387325.776 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:28:45.776Z,1598387325.776 [CBIT](CRITICAL): Communications Fault in component: AMEcho 2020-08-25T20:28:46.295Z,1598387326.295 [AMEcho](INFO): Powering down 2020-08-25T20:28:46.314Z,1598387326.314 [CommandLine](FAULT): Scheduling is paused 2020-08-25T20:28:46.314Z,1598387326.314 [CBIT](INFO): Critical error at 20200825T202845 2020-08-25T20:28:46.315Z,1598387326.315 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2020-08-25T20:29:01.904Z,1598387341.904 [Startup:StartupSatComms:A](INFO): Timed out from 2020-08-25T20:28:01.7Z 2020-08-25T20:29:01.904Z,1598387341.904 [Startup:StartupSatComms:A] Stopped 2020-08-25T20:29:01.904Z,1598387341.904 [Startup:StartupSatComms:B] Running Loop=1 2020-08-25T20:29:02.442Z,1598387342.442 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-08-25T20:29:02.442Z,1598387342.442 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-25T20:29:02.444Z,1598387342.444 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-08-25T20:29:02.453Z,1598387342.453 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-25T20:29:03.011Z,1598387343.011 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-25T20:29:03.011Z,1598387343.011 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2020-08-25T20:29:04.382Z,1598387344.382 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200825T181443/Courier0060.lzma 2020-08-25T20:29:04.516Z,1598387344.516 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Courier0060.lzma.bak 2020-08-25T20:29:04.517Z,1598387344.517 [DataOverHttps](INFO): SBD MOMSN=12616254 2020-08-25T20:29:05.000Z,1598387345.000 [DAT](INFO): #Outgoing data=1 2020-08-25T20:29:05.001Z,1598387345.001 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-25T20:29:05.119Z,1598387345.119 [DAT](INFO): setting remote address to 6 2020-08-25T20:29:05.455Z,1598387345.455 [DAT](INFO): DAT read: user:6> 2020-08-25T20:29:05.456Z,1598387345.456 [DAT](INFO): DAT read: RemoteAddr | 6 2020-08-25T20:29:05.456Z,1598387345.456 [DAT](INFO): set remote address to 6 2020-08-25T20:29:05.457Z,1598387345.457 [DAT](INFO): entering online mode 2020-08-25T20:29:05.859Z,1598387345.859 [DAT](INFO): DAT read: user:7> 2020-08-25T20:29:05.860Z,1598387345.860 [DAT](INFO): DAT read: 2020-08-25T20:29:05.861Z,1598387345.861 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2020-08-25T20:29:05.861Z,1598387345.861 [DAT](INFO): commRate: 800 2020-08-25T20:29:05.861Z,1598387345.861 [DAT](INFO): online mode acknowledged 2020-08-25T20:29:05.862Z,1598387345.862 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-25T20:29:09.485Z,1598387349.485 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:28:49.5384 2020-08-25T20:29:09.485Z,1598387349.485 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-25T20:29:22.386Z,1598387362.386 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20200825T202551/Courier0000.lzma 2020-08-25T20:29:23.388Z,1598387363.388 [DataOverHttps](INFO): Moved sent file to Logs/20200825T202551/Courier0000.lzma.bak 2020-08-25T20:29:23.388Z,1598387363.388 [DataOverHttps](INFO): SBD MOMSN=12616256 2020-08-25T20:29:24.090Z,1598387364.090 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-25T20:29:26.063Z,1598387366.063 [DAT](FAULT): Ack receipt timeout failure. 2020-08-25T20:29:26.063Z,1598387366.063 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2020-08-25T20:29:27.172Z,1598387367.172 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-25T20:29:27.179Z,1598387367.179 [Startup:StartupSatComms:B] Stopped 2020-08-25T20:29:27.179Z,1598387367.179 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-08-25T20:29:27.179Z,1598387367.179 [Startup:StartupSatComms] Stopped 2020-08-25T20:29:27.179Z,1598387367.179 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-08-25T20:29:27.180Z,1598387367.180 [Startup](INFO): Completed Startup 2020-08-25T20:29:27.180Z,1598387367.180 [MissionManager](INFO): Startup is completed. 2020-08-25T20:29:27.180Z,1598387367.180 [MissionManager](INFO): Uninitializing Mission Startup 2020-08-25T20:29:27.180Z,1598387367.180 [Startup] Stopped 2020-08-25T20:29:27.180Z,1598387367.180 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-08-25T20:29:27.180Z,1598387367.180 [Startup:A.GoToSurface] Stopped 2020-08-25T20:29:27.180Z,1598387367.180 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-08-25T20:29:27.290Z,1598387367.290 [MissionManager](IMPORTANT): Started mission Default 2020-08-25T20:29:27.291Z,1598387367.291 [Default] Running Loop=1 2020-08-25T20:29:27.291Z,1598387367.291 [Default](DEBUG): Aggregate::initialize Default 2020-08-25T20:29:27.291Z,1598387367.291 [Default:B.GoToSurface] Running Loop=1 2020-08-25T20:29:27.291Z,1598387367.291 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-08-25T20:29:27.291Z,1598387367.291 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-08-25T20:29:27.291Z,1598387367.291 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-08-25T20:29:27.292Z,1598387367.292 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-08-25T20:29:27.292Z,1598387367.292 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-08-25T20:29:27.292Z,1598387367.292 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-08-25T20:29:27.293Z,1598387367.293 [Default:A.Wait] Running Loop=1 2020-08-25T20:29:27.293Z,1598387367.293 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-08-25T20:29:40.315Z,1598387380.315 [DataOverHttps](INFO): Sending 360 bytes from file Logs/20200825T181443/Express0061.lzma 2020-08-25T20:29:40.605Z,1598387380.605 [Default:A.Wait](INFO): Done Waiting. 2020-08-25T20:29:40.606Z,1598387380.606 [Default:A.Wait] Stopped 2020-08-25T20:29:40.606Z,1598387380.606 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-08-25T20:29:40.953Z,1598387380.953 [Default:CheckIn] Running Loop=1 2020-08-25T20:29:40.953Z,1598387380.953 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-25T20:29:40.953Z,1598387380.953 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-25T20:29:41.316Z,1598387381.316 [DataOverHttps](INFO): Moved sent file to Logs/20200825T181443/Express0061.lzma.bak 2020-08-25T20:29:41.316Z,1598387381.316 [DataOverHttps](INFO): SBD MOMSN=12616260 2020-08-25T20:29:41.385Z,1598387381.385 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-08-25T20:30:33.915Z,1598387433.915 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-25T20:30:39.344Z,1598387439.344 [CommandLine](IMPORTANT): got command failComponent 2020-08-25T20:30:39.344Z,1598387439.344 [CommandLine](IMPORTANT): Failed components: 2020-08-25T20:30:39.344Z,1598387439.344 [CommandLine](IMPORTANT): AMEcho: Communications Fault 2020-08-25T20:31:42.952Z,1598387502.952 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-08-25T20:31:45.862Z,1598387505.862 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:31:45.862Z,1598387505.862 [AMEcho] No Fault, FailCount= 3 2020-08-25T20:31:46.213Z,1598387506.213 [AMEcho](INFO): Powering up 2020-08-25T20:31:59.642Z,1598387519.642 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:31:59.642Z,1598387519.642 [AMEcho] Communications Fault, FailCount= 1 2020-08-25T20:31:59.642Z,1598387519.642 [AMEcho](ERROR): Communications Fault 2020-08-25T20:31:59.709Z,1598387519.709 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:32:00.090Z,1598387520.090 [AMEcho](INFO): Powering down 2020-08-25T20:32:00.753Z,1598387520.753 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:32:00.753Z,1598387520.753 [AMEcho] No Fault, FailCount= 1 2020-08-25T20:32:01.142Z,1598387521.142 [AMEcho](INFO): Powering up 2020-08-25T20:32:03.558Z,1598387523.558 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2020-08-25T20:32:03.558Z,1598387523.558 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-25T20:32:03.568Z,1598387523.568 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-25T20:32:03.991Z,1598387523.991 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-25T20:32:03.991Z,1598387523.991 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2020-08-25T20:32:14.466Z,1598387534.466 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:32:14.466Z,1598387534.466 [AMEcho] Communications Fault, FailCount= 2 2020-08-25T20:32:14.466Z,1598387534.466 [AMEcho](ERROR): Communications Fault 2020-08-25T20:32:14.508Z,1598387534.508 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:32:15.035Z,1598387535.035 [AMEcho](INFO): Powering down 2020-08-25T20:32:15.712Z,1598387535.712 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:32:15.712Z,1598387535.712 [AMEcho] No Fault, FailCount= 2 2020-08-25T20:32:16.092Z,1598387536.092 [AMEcho](INFO): Powering up 2020-08-25T20:32:29.415Z,1598387549.415 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:32:29.415Z,1598387549.415 [AMEcho] Communications Fault, FailCount= 3 2020-08-25T20:32:29.415Z,1598387549.415 [AMEcho](ERROR): Communications Fault 2020-08-25T20:32:29.429Z,1598387549.429 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:32:29.430Z,1598387549.430 [CBIT](CRITICAL): Communications Fault in component: AMEcho 2020-08-25T20:32:29.979Z,1598387549.979 [AMEcho](INFO): Powering down 2020-08-25T20:32:29.992Z,1598387549.992 [CBIT](INFO): Critical error at 20200825T203229 2020-08-25T20:32:39.586Z,1598387559.586 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-08-25T20:32:50.886Z,1598387570.886 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-25T20:33:20.734Z,1598387600.734 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-08-25T20:33:20.737Z,1598387600.737 [BPC1](INFO): Received data from all battery sticks. 2020-08-25T20:34:41.144Z,1598387681.144 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-25T20:29:40.0Z 2020-08-25T20:34:41.144Z,1598387681.144 [Default:CheckIn:Read_GPS] Stopped 2020-08-25T20:34:41.144Z,1598387681.144 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-08-25T20:34:41.537Z,1598387681.537 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-08-25T20:34:43.162Z,1598387683.162 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-25T20:34:46.804Z,1598387686.804 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:34:26.8372 2020-08-25T20:34:46.804Z,1598387686.804 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-25T20:34:47.690Z,1598387687.690 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20200825T202551/Courier0004.lzma 2020-08-25T20:34:48.692Z,1598387688.692 [DataOverHttps](INFO): Moved sent file to Logs/20200825T202551/Courier0004.lzma.bak 2020-08-25T20:34:48.692Z,1598387688.692 [DataOverHttps](INFO): SBD MOMSN=12616294 2020-08-25T20:35:03.379Z,1598387703.379 [DAT](FAULT): Ack receipt timeout failure. 2020-08-25T20:35:03.379Z,1598387703.379 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2020-08-25T20:35:05.120Z,1598387705.120 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-25T20:35:05.125Z,1598387705.125 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2020-08-25T20:35:05.125Z,1598387705.125 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-25T20:35:05.126Z,1598387705.126 [Default:CheckIn:Read_Iridium] Stopped 2020-08-25T20:35:05.126Z,1598387705.126 [Default:CheckIn:C.Wait] Running Loop=1 2020-08-25T20:35:05.126Z,1598387705.126 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-08-25T20:35:05.136Z,1598387705.136 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-25T20:35:05.232Z,1598387705.232 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-25T20:35:05.232Z,1598387705.232 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2020-08-25T20:35:06.104Z,1598387706.104 [DataOverHttps](INFO): Sending 1074 bytes from file Logs/20200825T202551/Express0001.lzma 2020-08-25T20:35:07.104Z,1598387707.104 [DataOverHttps](INFO): Moved sent file to Logs/20200825T202551/Express0001.lzma.bak 2020-08-25T20:35:07.104Z,1598387707.104 [DataOverHttps](INFO): SBD MOMSN=12616297 2020-08-25T20:35:29.441Z,1598387729.441 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:35:29.441Z,1598387729.441 [AMEcho] No Fault, FailCount= 3 2020-08-25T20:35:29.807Z,1598387729.807 [AMEcho](INFO): Powering up 2020-08-25T20:35:41.344Z,1598387741.344 [CommandLine](IMPORTANT): got command configSet AMEcho.enabled 0.000000 bool 2020-08-25T20:35:41.535Z,1598387741.535 [AMEcho](ERROR): Setting 'enabled' to 0 2020-08-25T20:35:42.098Z,1598387742.098 [AMEcho](INFO): Powering down 2020-08-25T20:35:45.344Z,1598387745.344 [CommandLine](IMPORTANT): got command failComponent 2020-08-25T20:35:45.344Z,1598387745.344 [CommandLine](IMPORTANT): Failed components: 2020-08-25T20:35:45.344Z,1598387745.344 [CommandLine](IMPORTANT): No failed Components. 2020-08-25T20:35:53.040Z,1598387753.040 [CommandLine](IMPORTANT): got command configSet AMEcho.enabled 1.000000 bool 2020-08-25T20:35:53.230Z,1598387753.230 [AMEcho](ERROR): Setting 'enabled' to 1 2020-08-25T20:35:53.637Z,1598387753.637 [AMEcho](INFO): Powering up 2020-08-25T20:36:06.978Z,1598387766.978 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:36:06.979Z,1598387766.979 [AMEcho] Communications Fault, FailCount= 1 2020-08-25T20:36:06.979Z,1598387766.979 [AMEcho](ERROR): Communications Fault 2020-08-25T20:36:06.000Z,1598387767.000 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:36:07.535Z,1598387767.535 [AMEcho](INFO): Powering down 2020-08-25T20:36:08.196Z,1598387768.196 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:36:08.196Z,1598387768.196 [AMEcho] No Fault, FailCount= 1 2020-08-25T20:36:08.581Z,1598387768.581 [AMEcho](INFO): Powering up 2020-08-25T20:36:21.920Z,1598387781.920 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:36:21.920Z,1598387781.920 [AMEcho] Communications Fault, FailCount= 2 2020-08-25T20:36:21.920Z,1598387781.920 [AMEcho](ERROR): Communications Fault 2020-08-25T20:36:21.976Z,1598387781.976 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:36:22.482Z,1598387782.482 [AMEcho](INFO): Powering down 2020-08-25T20:36:23.155Z,1598387783.155 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:36:23.155Z,1598387783.155 [AMEcho] No Fault, FailCount= 2 2020-08-25T20:36:23.528Z,1598387783.528 [AMEcho](INFO): Powering up 2020-08-25T20:36:36.875Z,1598387796.875 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:36:36.875Z,1598387796.875 [AMEcho] Communications Fault, FailCount= 3 2020-08-25T20:36:36.875Z,1598387796.875 [AMEcho](ERROR): Communications Fault 2020-08-25T20:36:36.919Z,1598387796.919 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:36:36.920Z,1598387796.920 [CBIT](CRITICAL): Communications Fault in component: AMEcho 2020-08-25T20:36:37.427Z,1598387797.427 [AMEcho](INFO): Powering down 2020-08-25T20:36:37.442Z,1598387797.442 [CBIT](INFO): Critical error at 20200825T203636 2020-08-25T20:36:42.109Z,1598387802.109 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-08-25T20:36:42.109Z,1598387802.109 [NAL9602] Data Fault, FailCount= 1 2020-08-25T20:36:42.109Z,1598387802.109 [NAL9602](ERROR): Data Fault 2020-08-25T20:36:42.124Z,1598387802.124 [CBIT](ERROR): Data Fault in component: NAL9602 2020-08-25T20:36:42.511Z,1598387802.511 [NAL9602](INFO): Powering down 2020-08-25T20:36:43.338Z,1598387803.338 [CBIT](INFO): Clearing failed state for component NAL9602 2020-08-25T20:36:43.338Z,1598387803.338 [NAL9602] No Fault, FailCount= 1 2020-08-25T20:37:12.816Z,1598387832.816 [NAL9602](INFO): Powering up NAL9602 2020-08-25T20:37:23.732Z,1598387843.732 [NAL9602](INFO): NAL9602 initialized 2020-08-25T20:38:05.775Z,1598387885.775 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2020-08-25T20:38:05.775Z,1598387885.775 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-25T20:38:05.785Z,1598387885.785 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-25T20:38:06.195Z,1598387886.195 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-25T20:38:06.196Z,1598387886.196 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2020-08-25T20:39:37.064Z,1598387977.064 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:39:37.064Z,1598387977.064 [AMEcho] No Fault, FailCount= 3 2020-08-25T20:39:37.455Z,1598387977.455 [AMEcho](INFO): Powering up 2020-08-25T20:39:50.782Z,1598387990.782 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:39:50.782Z,1598387990.782 [AMEcho] Communications Fault, FailCount= 1 2020-08-25T20:39:50.782Z,1598387990.782 [AMEcho](ERROR): Communications Fault 2020-08-25T20:39:50.822Z,1598387990.822 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:39:51.355Z,1598387991.355 [AMEcho](INFO): Powering down 2020-08-25T20:39:52.027Z,1598387992.027 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:39:52.028Z,1598387992.028 [AMEcho] No Fault, FailCount= 1 2020-08-25T20:39:52.415Z,1598387992.415 [AMEcho](INFO): Powering up 2020-08-25T20:40:05.349Z,1598388005.349 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-08-25T20:40:05.349Z,1598388005.349 [Default:CheckIn:C.Wait] Stopped 2020-08-25T20:40:05.349Z,1598388005.349 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-08-25T20:40:05.349Z,1598388005.349 [Default:CheckIn:D] Running Loop=1 2020-08-25T20:40:05.739Z,1598388005.739 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:40:05.739Z,1598388005.739 [AMEcho] Communications Fault, FailCount= 2 2020-08-25T20:40:05.739Z,1598388005.739 [AMEcho](ERROR): Communications Fault 2020-08-25T20:40:05.752Z,1598388005.752 [Default:CheckIn:D] Stopped 2020-08-25T20:40:05.752Z,1598388005.752 [Default:CheckIn:E] Running Loop=1 2020-08-25T20:40:05.760Z,1598388005.760 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:40:06.303Z,1598388006.303 [AMEcho](INFO): Powering down 2020-08-25T20:40:06.316Z,1598388006.316 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.641016 min 2020-08-25T20:40:06.317Z,1598388006.317 [Default:CheckIn:E] Stopped 2020-08-25T20:40:06.317Z,1598388006.317 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-08-25T20:40:06.317Z,1598388006.317 [Default:CheckIn] Stopped 2020-08-25T20:40:06.317Z,1598388006.317 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-25T20:40:06.317Z,1598388006.317 [Default:CheckIn](INFO): Running loop #2 2020-08-25T20:40:06.317Z,1598388006.317 [Default:CheckIn] Running Loop=2 2020-08-25T20:40:06.317Z,1598388006.317 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-25T20:40:06.317Z,1598388006.317 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-25T20:40:06.959Z,1598388006.959 [CBIT](INFO): Clearing failed state for component AMEcho 2020-08-25T20:40:06.959Z,1598388006.959 [AMEcho] No Fault, FailCount= 2 2020-08-25T20:40:07.348Z,1598388007.348 [AMEcho](INFO): Powering up 2020-08-25T20:40:20.692Z,1598388020.692 [AMEcho](ERROR): No EchoSounder communication! Re-initializing 2020-08-25T20:40:20.692Z,1598388020.692 [AMEcho] Communications Fault, FailCount= 3 2020-08-25T20:40:20.692Z,1598388020.692 [AMEcho](ERROR): Communications Fault 2020-08-25T20:40:20.741Z,1598388020.741 [CBIT](ERROR): Communications Fault in component: AMEcho 2020-08-25T20:40:20.741Z,1598388020.741 [CBIT](CRITICAL): Communications Fault in component: AMEcho 2020-08-25T20:40:21.266Z,1598388021.266 [AMEcho](INFO): Powering down 2020-08-25T20:40:21.292Z,1598388021.292 [CBIT](INFO): Critical error at 20200825T204020 2020-08-25T20:40:37.283Z,1598388037.283 [CommandLine](IMPORTANT): got command configSet AMEcho.enabled 0.000000 bool 2020-08-25T20:40:45.343Z,1598388045.343 [CommandLine](IMPORTANT): got command failComponent 2020-08-25T20:40:45.343Z,1598388045.343 [CommandLine](IMPORTANT): Failed components: 2020-08-25T20:40:45.343Z,1598388045.343 [CommandLine](IMPORTANT): AMEcho: Communications Fault 2020-08-25T20:40:49.904Z,1598388049.904 [CommandLine](IMPORTANT): got command failComponent none AMEcho 2020-08-25T20:40:49.904Z,1598388049.904 [AMEcho] No Fault, FailCount= 3 2020-08-25T20:40:49.905Z,1598388049.905 [CommandLine](IMPORTANT): AMEcho failureMode is No Fault 2020-08-25T20:40:50.184Z,1598388050.184 [AMEcho](INFO): Powering up 2020-08-25T20:40:53.827Z,1598388053.827 [AMEcho](ERROR): Setting 'enabled' to 0 2020-08-25T20:40:54.391Z,1598388054.391 [AMEcho](INFO): Powering down 2020-08-25T20:41:06.770Z,1598388066.770 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2020-08-25T20:41:06.770Z,1598388066.770 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-25T20:41:06.781Z,1598388066.781 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-25T20:41:07.195Z,1598388067.195 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-25T20:41:07.196Z,1598388067.196 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2020-08-25T20:44:07.775Z,1598388247.775 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2020-08-25T20:44:07.775Z,1598388247.775 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-25T20:44:07.785Z,1598388247.785 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-25T20:44:08.199Z,1598388248.199 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-25T20:44:08.199Z,1598388248.199 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2020-08-25T20:45:06.339Z,1598388306.339 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-25T20:40:06.3Z 2020-08-25T20:45:06.339Z,1598388306.339 [Default:CheckIn:Read_GPS] Stopped 2020-08-25T20:45:06.339Z,1598388306.339 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-08-25T20:45:08.349Z,1598388308.349 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-25T20:45:11.992Z,1598388311.992 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:44:52.0348 2020-08-25T20:45:11.992Z,1598388311.992 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-25T20:45:13.755Z,1598388313.755 [DataOverHttps](INFO): Sending 94 bytes from file Logs/20200825T202551/Courier0007.lzma 2020-08-25T20:45:14.756Z,1598388314.756 [DataOverHttps](INFO): Moved sent file to Logs/20200825T202551/Courier0007.lzma.bak 2020-08-25T20:45:14.756Z,1598388314.756 [DataOverHttps](INFO): SBD MOMSN=12616357 2020-08-25T20:45:28.619Z,1598388328.619 [DAT](FAULT): Ack receipt timeout failure. 2020-08-25T20:45:28.619Z,1598388328.619 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2020-08-25T20:45:31.261Z,1598388331.261 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-25T20:45:31.316Z,1598388331.316 [Default:CheckIn:Read_Iridium] Stopped 2020-08-25T20:45:31.316Z,1598388331.316 [Default:CheckIn:C.Wait] Running Loop=1 2020-08-25T20:45:31.317Z,1598388331.317 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-08-25T20:45:35.939Z,1598388335.939 [DataOverHttps](INFO): Sending 275 bytes from file Logs/20200825T202551/Express0005.lzma 2020-08-25T20:45:36.940Z,1598388336.940 [DataOverHttps](INFO): Moved sent file to Logs/20200825T202551/Express0005.lzma.bak 2020-08-25T20:45:36.940Z,1598388336.940 [DataOverHttps](INFO): SBD MOMSN=12616361 2020-08-25T20:47:08.750Z,1598388428.750 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2020-08-25T20:47:08.750Z,1598388428.750 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-25T20:47:08.760Z,1598388428.760 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-25T20:47:09.149Z,1598388429.149 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-25T20:47:09.149Z,1598388429.149 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2020-08-25T20:47:26.900Z,1598388446.900 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-08-25T20:47:26.900Z,1598388446.900 [NAL9602] Data Fault, FailCount= 2 2020-08-25T20:47:26.900Z,1598388446.900 [NAL9602](ERROR): Data Fault 2020-08-25T20:47:26.916Z,1598388446.916 [CBIT](ERROR): Data Fault in component: NAL9602 2020-08-25T20:47:27.307Z,1598388447.307 [NAL9602](INFO): Powering down 2020-08-25T20:47:28.183Z,1598388448.183 [CBIT](INFO): Clearing failed state for component NAL9602 2020-08-25T20:47:28.183Z,1598388448.183 [NAL9602] No Fault, FailCount= 2 2020-08-25T20:47:57.606Z,1598388477.606 [NAL9602](INFO): Powering up NAL9602 2020-08-25T20:48:08.520Z,1598388488.520 [NAL9602](INFO): NAL9602 initialized 2020-08-25T20:50:09.734Z,1598388609.734 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2020-08-25T20:50:09.734Z,1598388609.734 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-25T20:50:09.744Z,1598388609.744 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-25T20:50:10.159Z,1598388610.159 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-25T20:50:10.159Z,1598388610.159 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2020-08-25T20:50:31.583Z,1598388631.583 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-08-25T20:50:31.583Z,1598388631.583 [Default:CheckIn:C.Wait] Stopped 2020-08-25T20:50:31.583Z,1598388631.583 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-08-25T20:50:31.583Z,1598388631.583 [Default:CheckIn:D] Running Loop=1 2020-08-25T20:50:31.999Z,1598388631.999 [Default:CheckIn:D] Stopped 2020-08-25T20:50:31.999Z,1598388631.999 [Default:CheckIn:E] Running Loop=1 2020-08-25T20:50:32.388Z,1598388632.388 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.078471 min 2020-08-25T20:50:32.388Z,1598388632.388 [Default:CheckIn:E] Stopped 2020-08-25T20:50:32.388Z,1598388632.388 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-08-25T20:50:32.388Z,1598388632.388 [Default:CheckIn] Stopped 2020-08-25T20:50:32.388Z,1598388632.388 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-25T20:50:32.388Z,1598388632.388 [Default:CheckIn](INFO): Running loop #3 2020-08-25T20:50:32.388Z,1598388632.388 [Default:CheckIn] Running Loop=3 2020-08-25T20:50:32.388Z,1598388632.388 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-25T20:50:32.388Z,1598388632.388 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-25T20:51:56.492Z,1598388716.492 [CommandLine](IMPORTANT): got command restart application 2020-08-25T20:51:57.499Z,1598388717.499 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-25T20:51:57.499Z,1598388717.499 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:57.638Z,1598388717.638 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2020-08-25T20:51:57.639Z,1598388717.639 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:57.639Z,1598388717.639 [CommandLine](INFO): Join timeout helper Thread ID is 3251 2020-08-25T20:51:57.640Z,1598388717.640 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2020-08-25T20:51:57.640Z,1598388717.640 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:57.640Z,1598388717.640 [NavChartDb](INFO): Join timeout helper Thread ID is 3252 2020-08-25T20:51:57.974Z,1598388717.974 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-25T20:51:57.975Z,1598388717.975 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:57.986Z,1598388717.986 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2020-08-25T20:51:57.986Z,1598388717.986 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:57.987Z,1598388717.987 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3253 2020-08-25T20:51:58.175Z,1598388718.175 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-25T20:51:58.175Z,1598388718.175 [WetLabsBB2FL](INFO): Powering down 2020-08-25T20:51:58.176Z,1598388718.176 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:58.178Z,1598388718.178 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2020-08-25T20:51:58.178Z,1598388718.178 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:58.179Z,1598388718.179 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3254 2020-08-25T20:51:58.755Z,1598388718.755 [CTD_Seabird](INFO): Powering down 2020-08-25T20:51:58.766Z,1598388718.766 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-25T20:51:58.767Z,1598388718.767 [CTD_Seabird](INFO): Powering down 2020-08-25T20:51:58.778Z,1598388718.778 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:58.782Z,1598388718.782 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler 2020-08-25T20:51:58.782Z,1598388718.782 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:58.783Z,1598388718.783 [BackSeatDriver](INFO): Join timeout helper Thread ID is 3255 2020-08-25T20:51:59.047Z,1598388719.047 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-25T20:51:59.047Z,1598388719.047 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:59.067Z,1598388719.067 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2020-08-25T20:51:59.067Z,1598388719.067 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:59.068Z,1598388719.068 [Radio_Surface](INFO): Join timeout helper Thread ID is 3256 2020-08-25T20:51:59.450Z,1598388719.450 [Radio_Surface](INFO): Powering down 2020-08-25T20:51:59.451Z,1598388719.451 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-25T20:51:59.452Z,1598388719.452 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:59.474Z,1598388719.474 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2020-08-25T20:51:59.474Z,1598388719.474 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:51:59.474Z,1598388719.474 [Onboard](INFO): Join timeout helper Thread ID is 3257 2020-08-25T20:51:59.903Z,1598388719.903 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2020-08-25T20:52:03.454Z,1598388723.454 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-25T20:52:03.455Z,1598388723.455 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:03.463Z,1598388723.463 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2020-08-25T20:52:03.463Z,1598388723.463 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:03.464Z,1598388723.464 [DataOverHttps](INFO): Join timeout helper Thread ID is 3258 2020-08-25T20:52:03.725Z,1598388723.725 [CBIT](FAULT): Humidity exceeds 50% of running average: Humidity:2285304 %. Average:303240.156250 2020-08-25T20:52:03.918Z,1598388723.918 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-25T20:52:03.919Z,1598388723.919 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:03.935Z,1598388723.935 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2020-08-25T20:52:03.935Z,1598388723.935 [logger ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:03.936Z,1598388723.936 [logger](INFO): Join timeout helper Thread ID is 3259 2020-08-25T20:52:03.950Z,1598388723.950 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-25T20:52:03.951Z,1598388723.951 [logger ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:03.955Z,1598388723.955 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2020-08-25T20:52:03.955Z,1598388723.955 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:03.955Z,1598388723.955 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2020-08-25T20:52:03.955Z,1598388723.955 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:03.956Z,1598388723.956 [controlThread](INFO): Join timeout helper Thread ID is 3260 2020-08-25T20:52:04.082Z,1598388724.082 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-25T20:52:04.083Z,1598388724.083 [controlThread](DEBUG): Uninitializing ControlThread 2020-08-25T20:52:04.083Z,1598388724.083 [AHRS_M2](INFO): Powering down 2020-08-25T20:52:04.155Z,1598388724.155 [NAL9602](INFO): Powering down 2020-08-25T20:52:04.156Z,1598388724.156 [DAT](INFO): Powering down 2020-08-25T20:52:04.275Z,1598388724.275 [AMEcho](INFO): Powering down 2020-08-25T20:52:04.276Z,1598388724.276 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2020-08-25T20:52:04.277Z,1598388724.277 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2020-08-25T20:52:04.277Z,1598388724.277 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2020-08-25T20:52:04.278Z,1598388724.278 [MissionManager](INFO): Uninitializing Mission Default 2020-08-25T20:52:04.278Z,1598388724.278 [Default] Stopped 2020-08-25T20:52:04.278Z,1598388724.278 [Default](DEBUG): Aggregate::uninitialize Default 2020-08-25T20:52:04.278Z,1598388724.278 [Default:B.GoToSurface] Stopped 2020-08-25T20:52:04.278Z,1598388724.278 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-08-25T20:52:04.278Z,1598388724.278 [Default:CheckIn] Stopped 2020-08-25T20:52:04.278Z,1598388724.278 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-25T20:52:04.279Z,1598388724.279 [Default:CheckIn:Read_GPS] Stopped 2020-08-25T20:52:04.281Z,1598388724.281 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2020-08-25T20:52:04.281Z,1598388724.281 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2020-08-25T20:52:04.281Z,1598388724.281 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2020-08-25T20:52:04.282Z,1598388724.282 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2020-08-25T20:52:04.282Z,1598388724.282 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2020-08-25T20:52:04.282Z,1598388724.282 [BuoyancyServo](INFO): Powering down 2020-08-25T20:52:04.294Z,1598388724.294 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2020-08-25T20:52:04.295Z,1598388724.295 [ElevatorServo](INFO): Powering down 2020-08-25T20:52:04.295Z,1598388724.295 [MassServo](DEBUG): Uninitialize Mass Servo. 2020-08-25T20:52:04.296Z,1598388724.296 [MassServo](INFO): Powering down 2020-08-25T20:52:04.296Z,1598388724.296 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-08-25T20:52:04.296Z,1598388724.296 [RudderServo](INFO): Powering down 2020-08-25T20:52:04.297Z,1598388724.297 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2020-08-25T20:52:04.297Z,1598388724.297 [ThrusterServo](INFO): Powering down 2020-08-25T20:52:04.298Z,1598388724.298 [SBIT](DEBUG): Uninitialize SBIT Component. 2020-08-25T20:52:04.299Z,1598388724.299 [IBIT](DEBUG): Uninitialize IBIT Component. 2020-08-25T20:52:04.299Z,1598388724.299 [CBIT](DEBUG): Uninitialize CBIT Component. 2020-08-25T20:52:04.299Z,1598388724.299 [CBIT](DEBUG): Powering off loads. 2020-08-25T20:52:04.310Z,1598388724.310 [CBIT](DEBUG): Disabling WDT. 2020-08-25T20:52:04.322Z,1598388724.322 [CBIT](DEBUG): Opening all GF detection circuits. 2020-08-25T20:52:04.323Z,1598388724.323 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:04.434Z,1598388724.434 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:04.436Z,1598388724.436 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:04.442Z,1598388724.442 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:04.514Z,1598388724.514 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:04.517Z,1598388724.517 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:04.520Z,1598388724.520 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:04.534Z,1598388724.534 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-08-25T20:52:04.598Z,1598388724.598 [logger ThreadHandler](INFO): Thread cancelled.