2020-08-26T16:22:53.101Z,1598458973.101 [Supervisor](DEBUG): Initializing supervisor. 2020-08-26T16:22:53.105Z,1598458973.105 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0 2020-08-26T16:22:53.106Z,1598458973.106 [SyncHandler](INFO): Protected caller Thread ID is 2410 2020-08-26T16:22:53.106Z,1598458973.106 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread. 2020-08-26T16:22:53.107Z,1598458973.107 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0 2020-08-26T16:22:53.107Z,1598458973.107 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 2411 2020-08-26T16:22:53.112Z,1598458973.112 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread. 2020-08-26T16:22:53.126Z,1598458973.126 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread. 2020-08-26T16:22:53.127Z,1598458973.127 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0 2020-08-26T16:22:53.128Z,1598458973.128 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 2412 2020-08-26T16:22:53.128Z,1598458973.128 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread. 2020-08-26T16:22:53.129Z,1598458973.129 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0 2020-08-26T16:22:53.130Z,1598458973.130 [logger ThreadHandler](INFO): Protected caller Thread ID is 2413 2020-08-26T16:22:53.132Z,1598458973.132 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread. 2020-08-26T16:22:53.132Z,1598458973.132 [Supervisor](INFO): Looking for Config files in directory: Config/ 2020-08-26T16:22:53.134Z,1598458973.134 [Supervisor](INFO): Opening Config file at: Config/secure.cfg 2020-08-26T16:22:53.295Z,1598458973.295 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure 2020-08-26T16:22:53.296Z,1598458973.296 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg 2020-08-26T16:22:53.929Z,1598458973.929 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor 2020-08-26T16:22:53.930Z,1598458973.930 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg 2020-08-26T16:22:54.134Z,1598458974.134 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock 2020-08-26T16:22:54.135Z,1598458974.135 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg 2020-08-26T16:22:54.235Z,1598458974.235 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample 2020-08-26T16:22:54.236Z,1598458974.236 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg 2020-08-26T16:22:54.341Z,1598458974.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite 2020-08-26T16:22:54.341Z,1598458974.341 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg 2020-08-26T16:22:54.423Z,1598458974.423 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg 2020-08-26T16:22:54.565Z,1598458974.565 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation 2020-08-26T16:22:54.566Z,1598458974.566 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg 2020-08-26T16:22:54.870Z,1598458974.870 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo 2020-08-26T16:22:54.870Z,1598458974.870 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg 2020-08-26T16:22:55.346Z,1598458975.346 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator 2020-08-26T16:22:55.346Z,1598458975.346 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg 2020-08-26T16:22:55.496Z,1598458975.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation 2020-08-26T16:22:55.497Z,1598458975.497 [Supervisor](INFO): Opening Config file at: Config/logger.cfg 2020-08-26T16:22:55.703Z,1598458975.703 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger 2020-08-26T16:22:55.703Z,1598458975.703 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg 2020-08-26T16:22:56.195Z,1598458976.195 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle 2020-08-26T16:22:56.195Z,1598458976.195 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg 2020-08-26T16:22:56.421Z,1598458976.421 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation 2020-08-26T16:22:56.422Z,1598458976.422 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg 2020-08-26T16:22:56.633Z,1598458976.633 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT 2020-08-26T16:22:56.634Z,1598458976.634 [Supervisor](INFO): Opening Config file at: Config/Science.cfg 2020-08-26T16:22:57.180Z,1598458977.180 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science 2020-08-26T16:22:57.181Z,1598458977.181 [Supervisor](INFO): Opening Config file at: Config/Control.cfg 2020-08-26T16:22:57.962Z,1598458977.962 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control 2020-08-26T16:22:57.964Z,1598458977.964 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/ 2020-08-26T16:22:57.966Z,1598458977.966 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg 2020-08-26T16:22:58.051Z,1598458978.051 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg 2020-08-26T16:22:58.216Z,1598458978.216 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg 2020-08-26T16:22:58.326Z,1598458978.326 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg 2020-08-26T16:22:58.412Z,1598458978.412 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg 2020-08-26T16:22:58.508Z,1598458978.508 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg 2020-08-26T16:22:58.720Z,1598458978.720 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg 2020-08-26T16:22:58.956Z,1598458978.956 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery 2020-08-26T16:22:58.957Z,1598458978.957 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg 2020-08-26T16:22:59.053Z,1598458979.053 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg 2020-08-26T16:22:59.153Z,1598458979.153 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg 2020-08-26T16:22:59.289Z,1598458979.289 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg 2020-08-26T16:22:59.391Z,1598458979.391 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/ 2020-08-26T16:22:59.392Z,1598458979.392 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg 2020-08-26T16:22:59.406Z,1598458979.406 [Module Loader](DEBUG): Loading Module at Modules/Dock.so 2020-08-26T16:22:59.504Z,1598458979.504 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking) 2020-08-26T16:22:59.504Z,1598458979.504 [Module Loader](DEBUG): Loading Module at Modules/Control.so 2020-08-26T16:22:59.567Z,1598458979.567 [VerticalControl](DEBUG): Construct VerticalControl. 2020-08-26T16:22:59.683Z,1598458979.683 [VerticalControl] Loaded 2020-08-26T16:22:59.683Z,1598458979.683 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread. 2020-08-26T16:22:59.684Z,1598458979.684 [HorizontalControl](DEBUG): Construct HorizontalControl. 2020-08-26T16:22:59.766Z,1598458979.766 [HorizontalControl] Loaded 2020-08-26T16:22:59.766Z,1598458979.766 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread. 2020-08-26T16:22:59.767Z,1598458979.767 [SpeedControl](DEBUG): Construct SpeedControl. 2020-08-26T16:22:59.772Z,1598458979.772 [SpeedControl] Loaded 2020-08-26T16:22:59.773Z,1598458979.773 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread. 2020-08-26T16:22:59.773Z,1598458979.773 [LoopControl](DEBUG): Construct LoopControl. 2020-08-26T16:22:59.774Z,1598458979.774 [LoopControl] Loaded 2020-08-26T16:22:59.774Z,1598458979.774 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread. 2020-08-26T16:22:59.775Z,1598458979.775 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control) 2020-08-26T16:22:59.775Z,1598458979.775 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so 2020-08-26T16:22:59.832Z,1598458979.832 [DepthRateCalculator] Loaded 2020-08-26T16:22:59.832Z,1598458979.832 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread. 2020-08-26T16:22:59.837Z,1598458979.837 [PitchRateCalculator] Loaded 2020-08-26T16:22:59.837Z,1598458979.837 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread. 2020-08-26T16:22:59.853Z,1598458979.853 [SpeedCalculator] Loaded 2020-08-26T16:22:59.854Z,1598458979.854 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread. 2020-08-26T16:22:59.876Z,1598458979.876 [TempGradientCalculator] Loaded 2020-08-26T16:22:59.876Z,1598458979.876 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread. 2020-08-26T16:22:59.881Z,1598458979.881 [YawRateCalculator] Loaded 2020-08-26T16:22:59.881Z,1598458979.881 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread. 2020-08-26T16:22:59.911Z,1598458979.911 [ElevatorOffsetCalculator] Loaded 2020-08-26T16:22:59.911Z,1598458979.911 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread. 2020-08-26T16:22:59.912Z,1598458979.912 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components) 2020-08-26T16:22:59.912Z,1598458979.912 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so 2020-08-26T16:22:59.954Z,1598458979.954 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions) 2020-08-26T16:22:59.954Z,1598458979.954 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so 2020-08-26T16:23:00.024Z,1598458980.024 [Module Loader](ERROR): Cannot load library: Modules/Estimation.so: undefined symbol: _ZN9Component15executeRunStateEv 2020-08-26T16:23:00.024Z,1598458980.024 [Module Loader](ERROR): Could not load the module at Modules/Estimation.so 2020-08-26T16:23:00.025Z,1598458980.025 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so 2020-08-26T16:23:00.367Z,1598458980.367 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands) 2020-08-26T16:23:00.367Z,1598458980.367 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so 2020-08-26T16:23:00.491Z,1598458980.491 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator) 2020-08-26T16:23:00.492Z,1598458980.492 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so 2020-08-26T16:23:00.933Z,1598458980.933 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation 2020-08-26T16:23:00.938Z,1598458980.938 [AHRS_M2](INFO): created writer for : platform_orientation 2020-08-26T16:23:00.940Z,1598458980.940 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation 2020-08-26T16:23:00.945Z,1598458980.945 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation 2020-08-26T16:23:00.946Z,1598458980.946 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle 2020-08-26T16:23:00.951Z,1598458980.951 [AHRS_M2](INFO): created writer for : platform_pitch_angle 2020-08-26T16:23:00.952Z,1598458980.952 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle 2020-08-26T16:23:00.957Z,1598458980.957 [AHRS_M2](INFO): created writer for : platform_roll_angle 2020-08-26T16:23:01.030Z,1598458981.030 [AHRS_M2] Loaded 2020-08-26T16:23:01.030Z,1598458981.030 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread. 2020-08-26T16:23:01.108Z,1598458981.108 [DataOverHttps] Loaded 2020-08-26T16:23:01.109Z,1598458981.109 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread. 2020-08-26T16:23:01.110Z,1598458981.110 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408AF4E0 2020-08-26T16:23:01.110Z,1598458981.110 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 2495 2020-08-26T16:23:01.141Z,1598458981.141 [Depth_Keller] Loaded 2020-08-26T16:23:01.141Z,1598458981.141 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread. 2020-08-26T16:23:01.258Z,1598458981.258 [NAL9602] Loaded 2020-08-26T16:23:01.259Z,1598458981.259 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread. 2020-08-26T16:23:01.308Z,1598458981.308 [Onboard] Loaded 2020-08-26T16:23:01.308Z,1598458981.308 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread. 2020-08-26T16:23:01.309Z,1598458981.309 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408DF4E0 2020-08-26T16:23:01.310Z,1598458981.310 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 2496 2020-08-26T16:23:01.330Z,1598458981.330 [Radio_Surface] Loaded 2020-08-26T16:23:01.330Z,1598458981.330 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread. 2020-08-26T16:23:01.331Z,1598458981.331 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4090F4E0 2020-08-26T16:23:01.332Z,1598458981.332 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 2497 2020-08-26T16:23:01.486Z,1598458981.486 [DAT] Loaded 2020-08-26T16:23:01.487Z,1598458981.487 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread. 2020-08-26T16:23:03.011Z,1598458983.011 [BPC1] Loaded 2020-08-26T16:23:03.012Z,1598458983.012 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread. 2020-08-26T16:23:03.044Z,1598458983.044 [AMEcho] Loaded 2020-08-26T16:23:03.045Z,1598458983.045 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread. 2020-08-26T16:23:03.045Z,1598458983.045 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components) 2020-08-26T16:23:03.046Z,1598458983.046 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so 2020-08-26T16:23:03.575Z,1598458983.575 [DeadReckonUsingMultipleVelocitySources] Loaded 2020-08-26T16:23:03.575Z,1598458983.575 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread. 2020-08-26T16:23:03.596Z,1598458983.596 [NavChart] Loaded 2020-08-26T16:23:03.597Z,1598458983.597 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread. 2020-08-26T16:23:03.601Z,1598458983.601 [UniversalFixResidualReporter] Loaded 2020-08-26T16:23:03.601Z,1598458983.601 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread. 2020-08-26T16:23:03.602Z,1598458983.602 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components) 2020-08-26T16:23:03.602Z,1598458983.602 [Module Loader](DEBUG): Loading Module at Modules/BIT.so 2020-08-26T16:23:03.952Z,1598458983.952 [SBIT](DEBUG): Construct Startup Built In Test. 2020-08-26T16:23:03.963Z,1598458983.963 [SBIT] Loaded 2020-08-26T16:23:03.964Z,1598458983.964 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread. 2020-08-26T16:23:03.964Z,1598458983.964 [IBIT](DEBUG): Construct Initiated Built In Test. 2020-08-26T16:23:03.977Z,1598458983.977 [IBIT] Loaded 2020-08-26T16:23:03.978Z,1598458983.978 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread. 2020-08-26T16:23:03.981Z,1598458983.981 [CBIT](DEBUG): Construct Continuous Built In Test. 2020-08-26T16:23:04.124Z,1598458984.124 [CBIT] Loaded 2020-08-26T16:23:04.124Z,1598458984.124 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread. 2020-08-26T16:23:04.124Z,1598458984.124 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test) 2020-08-26T16:23:04.125Z,1598458984.125 [Module Loader](DEBUG): Loading Module at Modules/Servo.so 2020-08-26T16:23:04.273Z,1598458984.273 [BuoyancyServo] Loaded 2020-08-26T16:23:04.274Z,1598458984.274 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread. 2020-08-26T16:23:04.303Z,1598458984.303 [ElevatorServo] Loaded 2020-08-26T16:23:04.303Z,1598458984.303 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread. 2020-08-26T16:23:04.332Z,1598458984.332 [MassServo] Loaded 2020-08-26T16:23:04.332Z,1598458984.332 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread. 2020-08-26T16:23:04.360Z,1598458984.360 [RudderServo] Loaded 2020-08-26T16:23:04.360Z,1598458984.360 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread. 2020-08-26T16:23:04.388Z,1598458984.388 [ThrusterServo] Loaded 2020-08-26T16:23:04.388Z,1598458984.388 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread. 2020-08-26T16:23:04.388Z,1598458984.388 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers) 2020-08-26T16:23:04.389Z,1598458984.389 [Module Loader](DEBUG): Loading Module at Modules/Sample.so 2020-08-26T16:23:04.419Z,1598458984.419 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components) 2020-08-26T16:23:04.420Z,1598458984.420 [Module Loader](DEBUG): Loading Module at Modules/Science.so 2020-08-26T16:23:04.741Z,1598458984.741 [BackSeatDriver] Loaded 2020-08-26T16:23:04.742Z,1598458984.742 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread. 2020-08-26T16:23:04.743Z,1598458984.743 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40AA54E0 2020-08-26T16:23:04.743Z,1598458984.743 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 2498 2020-08-26T16:23:04.773Z,1598458984.773 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density 2020-08-26T16:23:04.778Z,1598458984.778 [CTD_Seabird](INFO): created writer for : sea_water_density 2020-08-26T16:23:04.778Z,1598458984.778 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth 2020-08-26T16:23:04.783Z,1598458984.783 [CTD_Seabird](INFO): created writer for : depth 2020-08-26T16:23:04.784Z,1598458984.784 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure 2020-08-26T16:23:04.790Z,1598458984.790 [CTD_Seabird](INFO): created writer for : sea_water_pressure 2020-08-26T16:23:04.790Z,1598458984.790 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity 2020-08-26T16:23:04.796Z,1598458984.796 [CTD_Seabird](INFO): created writer for : sea_water_salinity 2020-08-26T16:23:04.796Z,1598458984.796 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature 2020-08-26T16:23:04.801Z,1598458984.801 [CTD_Seabird](INFO): created writer for : sea_water_temperature 2020-08-26T16:23:04.802Z,1598458984.802 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity 2020-08-26T16:23:04.808Z,1598458984.808 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity 2020-08-26T16:23:04.808Z,1598458984.808 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water 2020-08-26T16:23:04.814Z,1598458984.814 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water 2020-08-26T16:23:04.842Z,1598458984.842 [CTD_Seabird] Loaded 2020-08-26T16:23:04.842Z,1598458984.842 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread. 2020-08-26T16:23:04.843Z,1598458984.843 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AD54E0 2020-08-26T16:23:04.844Z,1598458984.844 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 2499 2020-08-26T16:23:04.866Z,1598458984.866 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470 2020-08-26T16:23:04.867Z,1598458984.867 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470 2020-08-26T16:23:04.871Z,1598458984.871 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650 2020-08-26T16:23:04.871Z,1598458984.871 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650 2020-08-26T16:23:04.876Z,1598458984.876 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl 2020-08-26T16:23:04.876Z,1598458984.876 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl 2020-08-26T16:23:04.880Z,1598458984.880 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm 2020-08-26T16:23:04.880Z,1598458984.880 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm 2020-08-26T16:23:04.885Z,1598458984.885 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm 2020-08-26T16:23:04.885Z,1598458984.885 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm 2020-08-26T16:23:04.890Z,1598458984.890 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm 2020-08-26T16:23:04.890Z,1598458984.890 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm 2020-08-26T16:23:04.894Z,1598458984.894 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm 2020-08-26T16:23:04.894Z,1598458984.894 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm 2020-08-26T16:23:04.899Z,1598458984.899 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water 2020-08-26T16:23:04.903Z,1598458984.903 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water 2020-08-26T16:23:04.904Z,1598458984.904 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-08-26T16:23:04.904Z,1598458984.904 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water 2020-08-26T16:23:04.908Z,1598458984.908 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-08-26T16:23:04.908Z,1598458984.908 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water 2020-08-26T16:23:04.913Z,1598458984.913 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-08-26T16:23:04.913Z,1598458984.913 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water 2020-08-26T16:23:04.917Z,1598458984.917 [WetLabsBB2FL] Loaded 2020-08-26T16:23:04.917Z,1598458984.917 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread. 2020-08-26T16:23:04.919Z,1598458984.919 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B054E0 2020-08-26T16:23:04.919Z,1598458984.919 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 2500 2020-08-26T16:23:04.920Z,1598458984.920 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components) 2020-08-26T16:23:04.924Z,1598458984.924 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread. 2020-08-26T16:23:04.925Z,1598458984.925 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread. 2020-08-26T16:23:04.932Z,1598458984.932 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread. 2020-08-26T16:23:04.933Z,1598458984.933 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B354E0 2020-08-26T16:23:04.933Z,1598458984.933 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 2501 2020-08-26T16:23:04.938Z,1598458984.938 [Supervisor](INFO): Main Thread ID is 2080 2020-08-26T16:23:04.938Z,1598458984.938 [Supervisor](DEBUG): Running supervisor. 2020-08-26T16:23:04.939Z,1598458984.939 [CommandLine ThreadHandler](INFO): Handler Thread ID is 2502 2020-08-26T16:23:04.941Z,1598458984.941 [controlThread ThreadHandler](INFO): Handler Thread ID is 2503 2020-08-26T16:23:04.942Z,1598458984.942 [controlThread](DEBUG): Initializing ControlThread 2020-08-26T16:23:04.943Z,1598458984.943 [VerticalControl](DEBUG): Initialize VerticalControlComponent. 2020-08-26T16:23:04.944Z,1598458984.944 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent. 2020-08-26T16:23:04.945Z,1598458984.945 [SpeedControl](DEBUG): Initialize SpeedControlComponent. 2020-08-26T16:23:04.945Z,1598458984.945 [LoopControl](DEBUG): Initialize LoopControlComponent. 2020-08-26T16:23:04.946Z,1598458984.946 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator. 2020-08-26T16:23:04.946Z,1598458984.946 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator. 2020-08-26T16:23:04.947Z,1598458984.947 [SpeedCalculator](DEBUG): Initializing SpeedCalculator. 2020-08-26T16:23:04.947Z,1598458984.947 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator. 2020-08-26T16:23:04.947Z,1598458984.947 [YawRateCalculator](DEBUG): Initializing YawRateCalculator. 2020-08-26T16:23:04.948Z,1598458984.948 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator. 2020-08-26T16:23:04.952Z,1598458984.952 [NavChart](DEBUG): Initialize NavChart Navigation. 2020-08-26T16:23:04.952Z,1598458984.952 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component. 2020-08-26T16:23:04.952Z,1598458984.952 [SBIT](INFO): Initialize SBIT Component. 2020-08-26T16:23:04.953Z,1598458984.953 [SBIT](IMPORTANT): git: 2020-08-18a-32-gaaad966 2020-08-26T16:23:04.953Z,1598458984.953 [SBIT](INFO): git hash: aaad9665165668190e0d3f81a990339c7737e6b1 2020-08-26T16:23:04.953Z,1598458984.953 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8 2020-08-26T16:23:04.955Z,1598458984.955 [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-26T16:23:04.956Z,1598458984.956 [SBIT](INFO): Beginning SBIT in 65.000000 seconds. 2020-08-26T16:23:04.956Z,1598458984.956 [IBIT](INFO): Initialize IBIT Component. 2020-08-26T16:23:04.957Z,1598458984.957 [CBIT](DEBUG): Initialize CBIT Component. 2020-08-26T16:23:04.958Z,1598458984.958 [logger ThreadHandler](INFO): Handler Thread ID is 2504 2020-08-26T16:23:04.970Z,1598458984.970 [CBIT](DEBUG): Initialized mux pins. 2020-08-26T16:23:04.971Z,1598458984.971 [CBIT](DEBUG): Initializing the watchdog timer. 2020-08-26T16:23:04.975Z,1598458984.975 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 2505 2020-08-26T16:23:04.976Z,1598458984.976 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP 2020-08-26T16:23:04.983Z,1598458984.983 [Onboard ThreadHandler](INFO): Handler Thread ID is 2506 2020-08-26T16:23:04.995Z,1598458984.995 [CBIT](INFO): Last reboot was NOT due to watchdog timer. 2020-08-26T16:23:04.996Z,1598458984.996 [CBIT](DEBUG): Initializing heartbeat. 2020-08-26T16:23:05.005Z,1598458985.005 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 2507 2020-08-26T16:23:05.027Z,1598458985.027 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 2508 2020-08-26T16:23:05.039Z,1598458985.039 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 2509 2020-08-26T16:23:05.039Z,1598458985.039 [CTD_Seabird](DEBUG): Initializing CTD_Seabird. 2020-08-26T16:23:05.044Z,1598458985.044 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 2511 2020-08-26T16:23:05.045Z,1598458985.045 [WetLabsBB2FL](INFO): Powering down 2020-08-26T16:23:05.066Z,1598458985.066 [CBIT](DEBUG): Deactivating GF circuits. 2020-08-26T16:23:05.066Z,1598458985.066 [CBIT](DEBUG): Deactivating emergency mode. 2020-08-26T16:23:05.079Z,1598458985.079 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 2512 2020-08-26T16:23:05.087Z,1598458985.087 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000 2020-08-26T16:23:05.088Z,1598458985.088 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000 2020-08-26T16:23:05.088Z,1598458985.088 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000 2020-08-26T16:23:05.088Z,1598458985.088 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000 2020-08-26T16:23:05.088Z,1598458985.088 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000 2020-08-26T16:23:05.088Z,1598458985.088 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000 2020-08-26T16:23:05.089Z,1598458985.089 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000 2020-08-26T16:23:05.089Z,1598458985.089 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000 2020-08-26T16:23:05.089Z,1598458985.089 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000 2020-08-26T16:23:05.089Z,1598458985.089 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000 2020-08-26T16:23:05.089Z,1598458985.089 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000 2020-08-26T16:23:05.089Z,1598458985.089 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000 2020-08-26T16:23:05.090Z,1598458985.090 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000 2020-08-26T16:23:05.090Z,1598458985.090 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000 2020-08-26T16:23:05.090Z,1598458985.090 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000 2020-08-26T16:23:05.090Z,1598458985.090 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000 2020-08-26T16:23:05.102Z,1598458985.102 [CBIT](DEBUG): Backplane powered. 2020-08-26T16:23:05.104Z,1598458985.104 [MissionManager](INFO): Loading Mission: Missions/Startup.xml 2020-08-26T16:23:05.124Z,1598458985.124 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface. 2020-08-26T16:23:05.136Z,1598458985.136 [MissionManager](DEBUG): 2020-08-26T16:23:05.136Z,1598458985.136 [MissionManager](INFO): Loading Mission: Missions/Default.xml 2020-08-26T16:23:05.194Z,1598458985.194 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-08-26T16:23:05.210Z,1598458985.210 [Default:A.Wait](DEBUG): Construct Wait. 2020-08-26T16:23:05.212Z,1598458985.212 [Default:B.GoToSurface](DEBUG): Construct GoToSurface. 2020-08-26T16:23:05.276Z,1598458985.276 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-08-26T16:23:05.279Z,1598458985.279 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-08-26T16:23:05.297Z,1598458985.297 [Default:E.Execute](DEBUG): Construct Execute. 2020-08-26T16:23:05.300Z,1598458985.300 [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-26T16:23:05.310Z,1598458985.310 [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-26T16:23:05.331Z,1598458985.331 [AHRS_M2](DEBUG): Initializing AHRS_M2. 2020-08-26T16:23:05.366Z,1598458985.366 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar 2020-08-26T16:23:05.369Z,1598458985.369 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2 2020-08-26T16:23:05.369Z,1598458985.369 [DAT](INFO): Powering up 2020-08-26T16:23:05.369Z,1598458985.369 [DAT](DEBUG): Initializing DAT. 2020-08-26T16:23:05.410Z,1598458985.410 [Radio_Surface](INFO): Powering up 2020-08-26T16:23:05.415Z,1598458985.415 [AMEcho](INFO): Powering up 2020-08-26T16:23:05.431Z,1598458985.431 [DepthRateCalculator](ERROR): Depth measurement is not active 2020-08-26T16:23:05.442Z,1598458985.442 [BuoyancyServo](DEBUG): Initializing EZServoServo. 2020-08-26T16:23:05.443Z,1598458985.443 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2 2020-08-26T16:23:05.479Z,1598458985.479 [BuoyancyServo](DEBUG): Initializing BuoyancyServo. 2020-08-26T16:23:05.480Z,1598458985.480 [ElevatorServo](DEBUG): Initializing EZServoServo. 2020-08-26T16:23:05.495Z,1598458985.495 [ElevatorServo](DEBUG): Initializing ElevatorServo. 2020-08-26T16:23:05.496Z,1598458985.496 [MassServo](DEBUG): Initializing EZServoServo. 2020-08-26T16:23:05.507Z,1598458985.507 [MassServo](DEBUG): Initializing MassServo. 2020-08-26T16:23:05.508Z,1598458985.508 [RudderServo](DEBUG): Initializing EZServoServo. 2020-08-26T16:23:05.519Z,1598458985.519 [RudderServo](DEBUG): Initializing RudderServo. 2020-08-26T16:23:05.520Z,1598458985.520 [ThrusterServo](DEBUG): Initializing EZServoServo. 2020-08-26T16:23:05.531Z,1598458985.531 [ThrusterServo](DEBUG): Initializing ThrusterServo. 2020-08-26T16:23:05.906Z,1598458985.906 [AMEcho](INFO): Powering down 2020-08-26T16:23:06.446Z,1598458986.446 [RudderServo](ERROR): Rudder initialization uart error serial timeout 2020-08-26T16:23:06.447Z,1598458986.447 [RudderServo](FAULT): Rudder failed to initialize 2020-08-26T16:23:06.447Z,1598458986.447 [RudderServo] Communications Fault, FailCount= 1 2020-08-26T16:23:06.447Z,1598458986.447 [RudderServo](ERROR): Communications Fault 2020-08-26T16:23:06.558Z,1598458986.558 [CBIT](ERROR): Communications Fault in component: RudderServo 2020-08-26T16:23:06.703Z,1598458986.703 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-08-26T16:23:06.704Z,1598458986.704 [RudderServo](INFO): Powering down 2020-08-26T16:23:07.387Z,1598458987.387 [RudderServo](DEBUG): Initializing EZServoServo. 2020-08-26T16:23:07.507Z,1598458987.507 [RudderServo](DEBUG): Initializing RudderServo. 2020-08-26T16:23:07.511Z,1598458987.511 [CBIT](INFO): Clearing failed state for component RudderServo 2020-08-26T16:23:07.511Z,1598458987.511 [RudderServo] No Fault, FailCount= 1 2020-08-26T16:23:12.071Z,1598458992.071 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit. 2020-08-26T16:23:15.864Z,1598458995.864 [DAT](INFO): DAT read: 2020-08-26T16:23:15.866Z,1598458995.866 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2020-08-26T16:23:17.076Z,1598458997.076 [DAT](INFO): DAT read: MF Frequency Band 2020-08-26T16:23:17.077Z,1598458997.077 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21 2020-08-26T16:23:17.078Z,1598458997.078 [DAT](INFO): DAT read: Aug 26 2020 16:22:53 2020-08-26T16:23:17.884Z,1598458997.884 [DAT](INFO): DAT read: Features enabled [Bearing] 2020-08-26T16:23:17.886Z,1598458997.886 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2020-08-26T16:23:17.886Z,1598458997.886 [DAT](INFO): commRate: 800 2020-08-26T16:23:17.886Z,1598458997.886 [DAT](INFO): commRate: 800 2020-08-26T16:23:18.288Z,1598458998.288 [DAT](INFO): entering command mode 2020-08-26T16:23:18.692Z,1598458998.692 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:19.100Z,1598458999.100 [DAT](INFO): DAT read: 2020-08-26T16:23:19.100Z,1598458999.100 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:19.500Z,1598458999.500 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:19.904Z,1598458999.904 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:20.308Z,1598459000.308 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:20.712Z,1598459000.712 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:21.116Z,1598459001.116 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:21.520Z,1598459001.520 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:21.924Z,1598459001.924 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:22.328Z,1598459002.328 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:22.732Z,1598459002.732 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:23.136Z,1598459003.136 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:23.540Z,1598459003.540 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:23.940Z,1598459003.940 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:24.348Z,1598459004.348 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:24.752Z,1598459004.752 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:25.156Z,1598459005.156 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:25.560Z,1598459005.560 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:25.964Z,1598459005.964 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:26.368Z,1598459006.368 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:26.772Z,1598459006.772 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:27.184Z,1598459007.184 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:27.576Z,1598459007.576 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:27.984Z,1598459007.984 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:28.388Z,1598459008.388 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:28.793Z,1598459008.793 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:29.196Z,1598459009.196 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:29.600Z,1598459009.600 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:29.000Z,1598459010.000 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:30.412Z,1598459010.412 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:30.833Z,1598459010.833 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:31.212Z,1598459011.212 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:31.624Z,1598459011.624 [NAL9602](INFO): Powering up NAL9602 2020-08-26T16:23:31.625Z,1598459011.625 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:32.024Z,1598459012.024 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:32.428Z,1598459012.428 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:32.832Z,1598459012.832 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:33.236Z,1598459013.236 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:33.640Z,1598459013.640 [DAT](DEBUG): checking for command mode acknowledgment 2020-08-26T16:23:33.640Z,1598459013.640 [DAT](FAULT): failed to enter command mode 2020-08-26T16:23:34.050Z,1598459014.050 [DAT](INFO): entering command mode 2020-08-26T16:23:34.448Z,1598459014.448 [DAT](INFO): DAT read: user:1> 2020-08-26T16:23:34.449Z,1598459014.449 [DAT](INFO): DAT read: Command '+++' not found 2020-08-26T16:23:34.449Z,1598459014.449 [DAT](INFO): DAT read: Error 2020-08-26T16:23:34.450Z,1598459014.450 [DAT](INFO): setting verbose to 3 2020-08-26T16:23:34.852Z,1598459014.852 [DAT](INFO): DAT read: user:2> 2020-08-26T16:23:34.853Z,1598459014.853 [DAT](INFO): DAT read: Verbose | 3 2020-08-26T16:23:34.853Z,1598459014.853 [DAT](INFO): set verbose to 3 2020-08-26T16:23:34.854Z,1598459014.854 [DAT](INFO): setting DatVerbose to 27440 2020-08-26T16:23:35.252Z,1598459015.252 [DAT](INFO): DAT read: user:3> 2020-08-26T16:23:35.253Z,1598459015.253 [DAT](INFO): DAT read: DatVerbose | 27440 2020-08-26T16:23:35.254Z,1598459015.254 [DAT](INFO): set DatVerbose to 27440 2020-08-26T16:23:35.254Z,1598459015.254 [DAT](INFO): setting transmit power to 8 2020-08-26T16:23:35.660Z,1598459015.660 [DAT](INFO): DAT read: user:4> 2020-08-26T16:23:35.661Z,1598459015.661 [DAT](INFO): DAT read: TxPower | 8 (Max) 2020-08-26T16:23:35.661Z,1598459015.661 [DAT](INFO): set transmit power to 8 2020-08-26T16:23:35.662Z,1598459015.662 [DAT](INFO): setting local address to 9 2020-08-26T16:23:36.065Z,1598459016.065 [DAT](INFO): DAT read: user:5> 2020-08-26T16:23:36.066Z,1598459016.066 [DAT](INFO): DAT read: LocalAddr | 9 2020-08-26T16:23:36.066Z,1598459016.066 [DAT](INFO): set local address to 9 2020-08-26T16:23:42.530Z,1598459022.530 [NAL9602](INFO): NAL9602 initialized 2020-08-26T16:24:10.412Z,1598459050.412 [SBIT](IMPORTANT): Beginning Startup BIT 2020-08-26T16:24:10.416Z,1598459050.416 [CBIT](IMPORTANT): Beginning ground fault scan 2020-08-26T16:24:21.442Z,1598459061.442 [CBIT](IMPORTANT): No ground fault detected mA: CHAN A0 (Batt): -0.010750 CHAN A1 (24V): -0.001396 CHAN A2 (12V): -0.007112 CHAN A3 (5V): -0.002030 CHAN B0 (3.3V): 0.000134 CHAN B1 (3.15aV): -0.000045 CHAN B2 (3.15bV): 0.000095 CHAN B3 (GND): 0.001666 OPEN: 0.005470 Full Scale Calc: 4.765 mA, -1.589 mA 2020-08-26T16:24:32.332Z,1598459072.332 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T16:25:04.164Z,1598459104.164 [SBIT](IMPORTANT): SBIT PASSED 2020-08-26T16:25:04.164Z,1598459104.164 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg 2020-08-26T16:25:04.165Z,1598459104.165 [SBIT](IMPORTANT): BackSeatDriver.loadAtStartup=1 bool; 2020-08-26T16:25:04.165Z,1598459104.165 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere; 2020-08-26T16:25:04.166Z,1598459104.166 [SBIT](IMPORTANT): DAT.sbdAddress=6 enum; 2020-08-26T16:25:04.166Z,1598459104.166 [SBIT](IMPORTANT): DAT.surfaceThreshold=-1 meter; 2020-08-26T16:25:04.166Z,1598459104.166 [SBIT](IMPORTANT): DAT.verbosity=3 count; 2020-08-26T16:25:04.166Z,1598459104.166 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool; 2020-08-26T16:25:04.166Z,1598459104.166 [SBIT](IMPORTANT): Express none ThrusterServo.component_avgCurrent; 2020-08-26T16:25:04.166Z,1598459104.166 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second; 2020-08-26T16:25:04.167Z,1598459104.167 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter; 2020-08-26T16:25:04.167Z,1598459104.167 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool; 2020-08-26T16:25:04.167Z,1598459104.167 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=344.685708 cubic_centimeter; 2020-08-26T16:25:04.167Z,1598459104.167 [SBIT](IMPORTANT): VerticalControl.massDefault=11.293600 millimeter; 2020-08-26T16:25:04.167Z,1598459104.167 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=0 bool; 2020-08-26T16:25:04.576Z,1598459104.576 [MissionManager](IMPORTANT): Started mission Startup 2020-08-26T16:25:04.576Z,1598459104.576 [Startup] Running Loop=1 2020-08-26T16:25:04.576Z,1598459104.576 [Startup](DEBUG): Aggregate::initialize Startup 2020-08-26T16:25:04.576Z,1598459104.576 [Startup:A.GoToSurface] Running Loop=1 2020-08-26T16:25:04.576Z,1598459104.576 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-08-26T16:25:04.577Z,1598459104.577 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-08-26T16:25:04.578Z,1598459104.578 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-08-26T16:25:04.578Z,1598459104.578 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-08-26T16:25:04.578Z,1598459104.578 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-08-26T16:25:04.579Z,1598459104.579 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-08-26T16:25:04.580Z,1598459104.580 [Startup:StartupSatComms] Running Loop=1 2020-08-26T16:25:04.580Z,1598459104.580 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms 2020-08-26T16:25:04.580Z,1598459104.580 [Startup:StartupSatComms:A] Running Loop=1 2020-08-26T16:25:04.976Z,1598459104.976 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix 2020-08-26T16:25:05.349Z,1598459105.349 [AMEcho](INFO): Powering up 2020-08-26T16:25:36.334Z,1598459136.334 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005500 2020-08-26T16:26:04.743Z,1598459164.743 [Startup:StartupSatComms:A](INFO): Timed out from 2020-08-26T16:25:04.6Z 2020-08-26T16:26:04.744Z,1598459164.744 [Startup:StartupSatComms:A] Stopped 2020-08-26T16:26:04.744Z,1598459164.744 [Startup:StartupSatComms:B] Running Loop=1 2020-08-26T16:26:05.175Z,1598459165.175 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1 2020-08-26T16:26:05.175Z,1598459165.175 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:26:05.177Z,1598459165.177 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-08-26T16:26:05.207Z,1598459165.207 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:26:06.280Z,1598459166.280 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:26:06.280Z,1598459166.280 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1 2020-08-26T16:26:08.877Z,1598459168.877 [DAT](INFO): #Outgoing data=1 2020-08-26T16:26:08.877Z,1598459168.877 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-26T16:26:09.243Z,1598459169.243 [DAT](INFO): setting remote address to 6 2020-08-26T16:26:09.578Z,1598459169.578 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200826T151826/Courier0022.lzma 2020-08-26T16:26:09.613Z,1598459169.613 [DAT](INFO): DAT read: user:6> 2020-08-26T16:26:09.613Z,1598459169.613 [DAT](INFO): DAT read: RemoteAddr | 6 2020-08-26T16:26:09.614Z,1598459169.614 [DAT](INFO): set remote address to 6 2020-08-26T16:26:09.615Z,1598459169.615 [DAT](INFO): entering online mode 2020-08-26T16:26:10.013Z,1598459170.013 [DAT](INFO): DAT read: user:7> 2020-08-26T16:26:10.013Z,1598459170.013 [DAT](INFO): DAT read: 2020-08-26T16:26:10.015Z,1598459170.015 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2020-08-26T16:26:10.015Z,1598459170.015 [DAT](INFO): commRate: 800 2020-08-26T16:26:10.015Z,1598459170.015 [DAT](INFO): online mode acknowledged 2020-08-26T16:26:10.016Z,1598459170.016 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-26T16:26:10.584Z,1598459170.584 [DataOverHttps](INFO): Moved sent file to Logs/20200826T151826/Courier0022.lzma.bak 2020-08-26T16:26:10.584Z,1598459170.584 [DataOverHttps](INFO): SBD MOMSN=12620304 2020-08-26T16:26:13.243Z,1598459173.243 [DAT](INFO): DAT read: Forwarding Delay UpTx time:16:25:53.5453 2020-08-26T16:26:13.243Z,1598459173.243 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-26T16:26:22.267Z,1598459182.267 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T16:26:26.127Z,1598459186.127 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200826T162253/Courier0000.lzma 2020-08-26T16:26:27.124Z,1598459187.124 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Courier0000.lzma.bak 2020-08-26T16:26:27.124Z,1598459187.124 [DataOverHttps](INFO): SBD MOMSN=12620306 2020-08-26T16:26:30.221Z,1598459190.221 [DAT](FAULT): Ack receipt timeout failure. 2020-08-26T16:26:30.221Z,1598459190.221 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2020-08-26T16:26:31.401Z,1598459191.401 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-26T16:26:31.415Z,1598459191.415 [Startup:StartupSatComms:B] Stopped 2020-08-26T16:26:31.416Z,1598459191.416 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms 2020-08-26T16:26:31.416Z,1598459191.416 [Startup:StartupSatComms] Stopped 2020-08-26T16:26:31.416Z,1598459191.416 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms 2020-08-26T16:26:31.416Z,1598459191.416 [Startup](INFO): Completed Startup 2020-08-26T16:26:31.417Z,1598459191.417 [MissionManager](INFO): Startup is completed. 2020-08-26T16:26:31.417Z,1598459191.417 [MissionManager](INFO): Uninitializing Mission Startup 2020-08-26T16:26:31.417Z,1598459191.417 [Startup] Stopped 2020-08-26T16:26:31.417Z,1598459191.417 [Startup](DEBUG): Aggregate::uninitialize Startup 2020-08-26T16:26:31.417Z,1598459191.417 [Startup:A.GoToSurface] Stopped 2020-08-26T16:26:31.417Z,1598459191.417 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-08-26T16:26:31.520Z,1598459191.520 [MissionManager](IMPORTANT): Started mission Default 2020-08-26T16:26:31.520Z,1598459191.520 [Default] Running Loop=1 2020-08-26T16:26:31.520Z,1598459191.520 [Default](DEBUG): Aggregate::initialize Default 2020-08-26T16:26:31.520Z,1598459191.520 [Default:B.GoToSurface] Running Loop=1 2020-08-26T16:26:31.521Z,1598459191.521 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-08-26T16:26:31.521Z,1598459191.521 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-08-26T16:26:31.521Z,1598459191.521 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-08-26T16:26:31.521Z,1598459191.521 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-08-26T16:26:31.522Z,1598459191.522 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-08-26T16:26:31.522Z,1598459191.522 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-08-26T16:26:31.526Z,1598459191.526 [Default:A.Wait] Running Loop=1 2020-08-26T16:26:31.527Z,1598459191.527 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-08-26T16:26:32.010Z,1598459192.010 [AMEcho](INFO): Powering down 2020-08-26T16:26:33.068Z,1598459193.068 [AMEcho](INFO): Powering up 2020-08-26T16:26:44.040Z,1598459204.040 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20200826T151826/Express0011.lzma 2020-08-26T16:26:44.781Z,1598459204.781 [Default:A.Wait](INFO): Done Waiting. 2020-08-26T16:26:44.781Z,1598459204.781 [Default:A.Wait] Stopped 2020-08-26T16:26:44.781Z,1598459204.781 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T16:26:45.040Z,1598459205.040 [DataOverHttps](INFO): Moved sent file to Logs/20200826T151826/Express0011.lzma.bak 2020-08-26T16:26:45.040Z,1598459205.040 [DataOverHttps](INFO): SBD MOMSN=12620309 2020-08-26T16:26:45.225Z,1598459205.225 [Default:CheckIn] Running Loop=1 2020-08-26T16:26:45.226Z,1598459205.226 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-26T16:26:45.226Z,1598459205.226 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-26T16:26:45.596Z,1598459205.596 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-08-26T16:28:36.346Z,1598459316.346 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T16:28:45.568Z,1598459325.568 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2020-08-26T16:29:05.828Z,1598459345.828 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-08-26T16:29:07.012Z,1598459347.012 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2 2020-08-26T16:29:07.012Z,1598459347.012 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:29:07.021Z,1598459347.021 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:29:07.408Z,1598459347.408 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:29:07.408Z,1598459347.408 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2 2020-08-26T16:29:26.428Z,1598459366.428 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T16:29:32.100Z,1598459372.100 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-08-26T16:29:55.476Z,1598459395.476 [CommandLine](IMPORTANT): got command run ./Missions/bsd.xml 2020-08-26T16:29:55.476Z,1598459395.476 [MissionManager](INFO): Loading Mission: ./Missions/bsd.xml 2020-08-26T16:29:55.561Z,1598459395.561 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-08-26T16:29:55.562Z,1598459395.562 [Default:A.Wait](DEBUG): Construct Wait. 2020-08-26T16:29:55.566Z,1598459395.566 [Default:C.GoToSurface](DEBUG): Construct GoToSurface. 2020-08-26T16:29:55.577Z,1598459395.577 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-08-26T16:29:55.579Z,1598459395.579 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-08-26T16:29:55.584Z,1598459395.584 [Default:F.Execute](DEBUG): Construct Execute. 2020-08-26T16:29:55.588Z,1598459395.588 [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-26T16:29:55.591Z,1598459395.591 [CommandLine](IMPORTANT): Running ./Missions/bsd.xml 2020-08-26T16:29:55.935Z,1598459395.935 [Default] Stopped 2020-08-26T16:29:55.935Z,1598459395.935 [Default](DEBUG): Aggregate::uninitialize Default 2020-08-26T16:29:55.936Z,1598459395.936 [Default:B.GoToSurface] Stopped 2020-08-26T16:29:55.936Z,1598459395.936 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-08-26T16:29:55.936Z,1598459395.936 [Default:CheckIn] Stopped 2020-08-26T16:29:55.936Z,1598459395.936 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-26T16:29:55.936Z,1598459395.936 [Default:CheckIn:Read_GPS] Stopped 2020-08-26T16:29:55.936Z,1598459395.936 [MissionManager](IMPORTANT): Started mission Default 2020-08-26T16:29:55.936Z,1598459395.936 [Default] Running Loop=1 2020-08-26T16:29:55.936Z,1598459395.936 [Default](DEBUG): Aggregate::initialize Default 2020-08-26T16:29:55.936Z,1598459395.936 [Default:B] Running Loop=1 2020-08-26T16:29:55.936Z,1598459395.936 [Default:C.GoToSurface] Running Loop=1 2020-08-26T16:29:55.937Z,1598459395.937 [Default:C.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-08-26T16:29:55.937Z,1598459395.937 [Default:C.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-08-26T16:29:55.937Z,1598459395.937 [Default:C.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-08-26T16:29:55.937Z,1598459395.937 [Default:C.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-08-26T16:29:55.938Z,1598459395.938 [Default:C.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-08-26T16:29:55.938Z,1598459395.938 [Default:C.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-08-26T16:29:55.938Z,1598459395.938 [Default:A.Wait] Running Loop=1 2020-08-26T16:29:55.939Z,1598459395.939 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-08-26T16:29:55.939Z,1598459395.939 [Default:B] Running Loop=1 2020-08-26T16:29:55.940Z,1598459395.940 [Default:B](DEBUG): Initialize ReadDataComponent to sense BackSeatDriver.power_back_seat_driver 2020-08-26T16:29:55.963Z,1598459395.963 [BackSeatDriver](INFO): Powering up 2020-08-26T16:29:55.963Z,1598459395.963 [BackSeatDriver](INFO): Subscribing to LCM channel: BackSeatDriverStatus 2020-08-26T16:29:56.309Z,1598459396.309 [BackSeatDriver](INFO): Subscribing to LCM channel: BioLumProxies 2020-08-26T16:30:09.239Z,1598459409.239 [Default:A.Wait](INFO): Done Waiting. 2020-08-26T16:30:09.240Z,1598459409.240 [Default:A.Wait] Stopped 2020-08-26T16:30:09.240Z,1598459409.240 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T16:30:09.648Z,1598459409.648 [Default:CheckIn] Running Loop=1 2020-08-26T16:30:09.648Z,1598459409.648 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-26T16:30:09.648Z,1598459409.648 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-26T16:30:10.101Z,1598459410.101 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-08-26T16:30:59.390Z,1598459459.390 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-08-26T16:31:26.411Z,1598459486.411 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-08-26T16:31:26.414Z,1598459486.414 [BPC1](INFO): Received data from all battery sticks. 2020-08-26T16:32:08.042Z,1598459528.042 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3 2020-08-26T16:32:08.042Z,1598459528.042 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:32:08.052Z,1598459528.052 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:32:08.465Z,1598459528.465 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:32:08.465Z,1598459528.465 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3 2020-08-26T16:33:45.780Z,1598459625.780 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-08-26T16:33:45.780Z,1598459625.780 [NAL9602] Data Fault, FailCount= 1 2020-08-26T16:33:45.780Z,1598459625.780 [NAL9602](ERROR): Data Fault 2020-08-26T16:33:45.808Z,1598459625.808 [CBIT](ERROR): Data Fault in component: NAL9602 2020-08-26T16:33:46.172Z,1598459626.172 [NAL9602](INFO): Powering down 2020-08-26T16:33:47.008Z,1598459627.008 [CBIT](INFO): Clearing failed state for component NAL9602 2020-08-26T16:33:47.008Z,1598459627.008 [NAL9602] No Fault, FailCount= 1 2020-08-26T16:34:16.479Z,1598459656.479 [NAL9602](INFO): Powering up NAL9602 2020-08-26T16:34:27.388Z,1598459667.388 [NAL9602](INFO): NAL9602 initialized 2020-08-26T16:35:09.005Z,1598459709.005 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4 2020-08-26T16:35:09.005Z,1598459709.005 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:35:09.015Z,1598459709.015 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:35:09.431Z,1598459709.431 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:35:09.431Z,1598459709.431 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4 2020-08-26T16:35:09.835Z,1598459709.835 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T16:30:09.6Z 2020-08-26T16:35:09.835Z,1598459709.835 [Default:CheckIn:Read_GPS] Stopped 2020-08-26T16:35:09.835Z,1598459709.835 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-08-26T16:35:10.236Z,1598459710.236 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-08-26T16:35:11.730Z,1598459711.730 [BackSeatDriver](FAULT): Failed to receive device response within the specified timeout. 2020-08-26T16:35:11.730Z,1598459711.730 [BackSeatDriver] Communications Fault, FailCount= 1 2020-08-26T16:35:11.730Z,1598459711.730 [BackSeatDriver](ERROR): Communications Fault 2020-08-26T16:35:11.826Z,1598459711.826 [DAT](INFO): DAT read: Rx Time:16:29:27.9014 2020-08-26T16:35:11.826Z,1598459711.826 [DAT](INFO): received an acoustic signal 2020-08-26T16:35:11.826Z,1598459711.826 [DAT](INFO): DAT read: 2020-08-26T16:35:11.827Z,1598459711.827 [DAT](INFO): DAT read: DATA(0002):~~ 2020-08-26T16:35:11.827Z,1598459711.827 [DAT](INFO): Got DATA 2 2020-08-26T16:35:11.829Z,1598459711.829 [DAT](INFO): DAT read: Source:006 Destination:009 2020-08-26T16:35:11.829Z,1598459711.829 [DAT](INFO): Got Src/Dest after DATA 2020-08-26T16:35:11.829Z,1598459711.829 [DAT](INFO): DATA Src=6, Dst=9 2020-08-26T16:35:11.860Z,1598459711.860 [DAT](INFO): DAT read: CRC:Pass MPD:12.1 PSNR:15.3 AGC:76 SPD:+00.0 CCERR:011 2020-08-26T16:35:11.860Z,1598459711.860 [DAT](INFO): Got CRC:Pass 2020-08-26T16:35:11.860Z,1598459711.860 [DAT](INFO): Got CRC:Pass 2020-08-26T16:35:11.860Z,1598459711.860 [DAT](INFO): Incoming data is intended for us 2020-08-26T16:35:11.860Z,1598459711.860 [DAT](INFO): Got ack 2020-08-26T16:35:11.860Z,1598459711.860 [DAT](INFO): DAT read: 2020-08-26T16:35:11.861Z,1598459711.861 [DAT](INFO): DAT read: 2020-08-26T16:35:11.862Z,1598459711.862 [DAT](INFO): DAT read: Rx Time:16:29:49.3516 2020-08-26T16:35:11.862Z,1598459711.862 [DAT](INFO): received an acoustic signal 2020-08-26T16:35:11.863Z,1598459711.863 [DAT](INFO): DAT read: 2020-08-26T16:35:11.864Z,1598459711.864 [DAT](INFO): DAT read: DATA(0031):set _.humidity 7.703577 percent 2020-08-26T16:35:11.864Z,1598459711.864 [DAT](INFO): Got DATA 31 2020-08-26T16:35:11.865Z,1598459711.865 [DAT](INFO): DAT read: Source:006 Destination:009 2020-08-26T16:35:11.865Z,1598459711.865 [DAT](INFO): Got Src/Dest after DATA 2020-08-26T16:35:11.866Z,1598459711.866 [DAT](INFO): DATA Src=6, Dst=9 2020-08-26T16:35:11.871Z,1598459711.871 [DAT](INFO): DAT read: CRC:Pass MPD:12.1 PSNR:12.3 AGC:76 SPD:-00.3 CCERR:009 2020-08-26T16:35:11.871Z,1598459711.871 [DAT](INFO): Got CRC:Pass 2020-08-26T16:35:11.871Z,1598459711.871 [DAT](INFO): Got CRC:Pass 2020-08-26T16:35:11.872Z,1598459711.872 [DAT](INFO): Incoming data is intended for us 2020-08-26T16:35:11.872Z,1598459711.872 [DAT](INFO): Received command:set _.humidity 7.703577 percent 2020-08-26T16:35:12.136Z,1598459712.136 [BackSeatDriver](INFO): Sent LCM shutdown request. 2020-08-26T16:35:12.728Z,1598459712.728 [CommandLine](IMPORTANT): got command set _.humidity 7.703577 percent 2020-08-26T16:35:12.738Z,1598459712.738 [DAT](INFO): Sending ack 2020-08-26T16:35:12.739Z,1598459712.739 [DAT](INFO): DAT read: 2020-08-26T16:35:12.739Z,1598459712.739 [DAT](INFO): DAT read: 2020-08-26T16:35:12.778Z,1598459712.778 [CBIT](ERROR): Communications Fault in component: BackSeatDriver 2020-08-26T16:35:16.040Z,1598459716.040 [DAT](INFO): DAT read: Forwarding Delay UpTx time:16:34:56.2424 2020-08-26T16:35:16.040Z,1598459716.040 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-26T16:35:19.280Z,1598459719.280 [DAT](INFO): DAT read: Forwarding Delay UpTx time:16:34:59.5924 2020-08-26T16:35:19.280Z,1598459719.280 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-26T16:35:20.170Z,1598459720.170 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20200826T162253/Courier0004.lzma 2020-08-26T16:35:21.172Z,1598459721.172 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Courier0004.lzma.bak 2020-08-26T16:35:21.173Z,1598459721.173 [DataOverHttps](INFO): SBD MOMSN=12620343 2020-08-26T16:35:27.487Z,1598459727.487 [BackSeatDriver](INFO): Powering down 2020-08-26T16:35:27.891Z,1598459727.891 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BackSeatDriverStatus 2020-08-26T16:35:27.891Z,1598459727.891 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BioLumProxies 2020-08-26T16:35:28.295Z,1598459728.295 [BackSeatDriver](INFO): Powering up 2020-08-26T16:35:28.295Z,1598459728.295 [BackSeatDriver](INFO): Subscribing to LCM channel: BackSeatDriverStatus 2020-08-26T16:35:28.296Z,1598459728.296 [BackSeatDriver](INFO): Subscribing to LCM channel: BioLumProxies 2020-08-26T16:35:28.577Z,1598459728.577 [CBIT](INFO): Clearing failed state for component BackSeatDriver 2020-08-26T16:35:28.578Z,1598459728.578 [BackSeatDriver] No Fault, FailCount= 1 2020-08-26T16:35:36.224Z,1598459736.224 [DAT](FAULT): Ack receipt timeout failure. 2020-08-26T16:35:36.224Z,1598459736.224 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2020-08-26T16:35:39.057Z,1598459739.057 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-26T16:35:39.073Z,1598459739.073 [Default:CheckIn:Read_Iridium] Stopped 2020-08-26T16:35:39.073Z,1598459739.073 [Default:CheckIn:C.Wait] Running Loop=1 2020-08-26T16:35:39.073Z,1598459739.073 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-08-26T16:35:41.804Z,1598459741.804 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20200826T151826/Express0014.lzma 2020-08-26T16:35:42.814Z,1598459742.814 [DataOverHttps](INFO): Moved sent file to Logs/20200826T151826/Express0014.lzma.bak 2020-08-26T16:35:42.814Z,1598459742.814 [DataOverHttps](INFO): SBD MOMSN=12620345 2020-08-26T16:38:09.289Z,1598459889.289 [CommandLine](IMPORTANT): got command stop 2020-08-26T16:38:09.289Z,1598459889.289 [CommandLine](IMPORTANT): Scheduling is paused 2020-08-26T16:38:09.289Z,1598459889.289 [Supervisor](INFO): Stop Mission called by CommandLine::commandStop 2020-08-26T16:38:09.428Z,1598459889.428 [MissionManager](INFO): MissionManager is completed. 2020-08-26T16:38:09.428Z,1598459889.428 [MissionManager](INFO): Uninitializing Mission Default 2020-08-26T16:38:09.428Z,1598459889.428 [Default] Stopped 2020-08-26T16:38:09.428Z,1598459889.428 [Default](DEBUG): Aggregate::uninitialize Default 2020-08-26T16:38:09.428Z,1598459889.428 [Default:B] Stopped 2020-08-26T16:38:09.428Z,1598459889.428 [Default:C.GoToSurface] Stopped 2020-08-26T16:38:09.428Z,1598459889.428 [Default:C.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-08-26T16:38:09.429Z,1598459889.429 [Default:CheckIn] Stopped 2020-08-26T16:38:09.429Z,1598459889.429 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-26T16:38:09.429Z,1598459889.429 [Default:CheckIn:C.Wait] Stopped 2020-08-26T16:38:09.429Z,1598459889.429 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T16:38:09.832Z,1598459889.832 [MissionManager](IMPORTANT): Started mission Default 2020-08-26T16:38:09.832Z,1598459889.832 [Default] Running Loop=1 2020-08-26T16:38:09.832Z,1598459889.832 [Default](DEBUG): Aggregate::initialize Default 2020-08-26T16:38:09.832Z,1598459889.832 [Default:B.GoToSurface] Running Loop=1 2020-08-26T16:38:09.832Z,1598459889.832 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-08-26T16:38:09.833Z,1598459889.833 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-08-26T16:38:09.833Z,1598459889.833 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-08-26T16:38:09.833Z,1598459889.833 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-08-26T16:38:09.833Z,1598459889.833 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-08-26T16:38:09.834Z,1598459889.834 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-08-26T16:38:09.834Z,1598459889.834 [Default:A.Wait] Running Loop=1 2020-08-26T16:38:09.834Z,1598459889.834 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-08-26T16:38:10.234Z,1598459890.234 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5 2020-08-26T16:38:10.234Z,1598459890.234 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:38:10.268Z,1598459890.268 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:38:10.676Z,1598459890.676 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:38:10.676Z,1598459890.676 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5 2020-08-26T16:38:11.559Z,1598459891.559 [BackSeatDriver](INFO): Sent LCM shutdown request. 2020-08-26T16:38:23.184Z,1598459903.184 [Default:A.Wait](INFO): Done Waiting. 2020-08-26T16:38:23.184Z,1598459903.184 [Default:A.Wait] Stopped 2020-08-26T16:38:23.184Z,1598459903.184 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T16:38:23.578Z,1598459903.578 [Default:CheckIn] Running Loop=1 2020-08-26T16:38:23.578Z,1598459903.578 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-26T16:38:23.578Z,1598459903.578 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-26T16:38:26.911Z,1598459906.911 [BackSeatDriver](INFO): Powering down 2020-08-26T16:38:27.314Z,1598459907.314 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BackSeatDriverStatus 2020-08-26T16:38:27.315Z,1598459907.315 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BioLumProxies 2020-08-26T16:39:55.239Z,1598459995.239 [CommandLine](IMPORTANT): got command show variable BackSeat 2020-08-26T16:39:55.453Z,1598459995.453 [CommandLine](IMPORTANT): BackSeatDriver.loadControl (none) 2020-08-26T16:39:55.454Z,1598459995.454 [CommandLine](IMPORTANT): BackSeatDriver.uart (none) 2020-08-26T16:39:55.478Z,1598459995.478 [CommandLine](IMPORTANT): BackSeatDriver.baud (bit_per_second) 2020-08-26T16:39:55.500Z,1598459995.500 [CommandLine](IMPORTANT): BackSeatDriver.loadAtStartup (bool) 2020-08-26T16:39:55.501Z,1598459995.501 [CommandLine](IMPORTANT): BackSeatDriver.simulateHardware (bool) 2020-08-26T16:39:55.501Z,1598459995.501 [CommandLine](IMPORTANT): BackSeatDriver.lcmListenChannelName (none) 2020-08-26T16:39:55.501Z,1598459995.501 [CommandLine](IMPORTANT): BackSeatDriver.shutdownCmd (none) 2020-08-26T16:39:55.502Z,1598459995.502 [CommandLine](IMPORTANT): BackSeatDriver.lcmListenerTimeout (second) 2020-08-26T16:39:55.502Z,1598459995.502 [CommandLine](IMPORTANT): BackSeatDriver.verbosity (count) 2020-08-26T16:39:55.630Z,1598459995.630 [CommandLine](IMPORTANT): BackSeatDriver.component_voltage (volt) 2020-08-26T16:39:55.630Z,1598459995.630 [CommandLine](IMPORTANT): BackSeatDriver.component_avgVoltage (volt) 2020-08-26T16:39:55.643Z,1598459995.643 [CommandLine](IMPORTANT): BackSeatDriver.component_current (milliampere) 2020-08-26T16:39:55.643Z,1598459995.643 [CommandLine](IMPORTANT): BackSeatDriver.component_avgCurrent (milliampere) 2020-08-26T16:39:55.643Z,1598459995.643 [CommandLine](IMPORTANT): BackSeatDriver.power_back_seat_driver (bool) 2020-08-26T16:39:55.644Z,1598459995.644 [CommandLine](IMPORTANT): BackSeatDriver.biolum_dinoflagellate_proxy (none) 2020-08-26T16:39:55.644Z,1598459995.644 [CommandLine](IMPORTANT): BackSeatDriver.biolum_larvacean_proxy (none) 2020-08-26T16:39:55.644Z,1598459995.644 [CommandLine](IMPORTANT): BackSeatDriver.biolum_jelly_proxy (none) 2020-08-26T16:39:55.645Z,1598459995.645 [CommandLine](IMPORTANT): BackSeatDriver.biolum_copepod_proxy (none) 2020-08-26T16:39:55.645Z,1598459995.645 [CommandLine](IMPORTANT): BackSeatDriver.biolum_adino_proxy (none) 2020-08-26T16:39:55.645Z,1598459995.645 [CommandLine](IMPORTANT): BackSeatDriver.biolum_hdino_proxy (none) 2020-08-26T16:39:55.646Z,1598459995.646 [CommandLine](IMPORTANT): BackSeatDriver.biolum_aother_proxy (none) 2020-08-26T16:40:10.380Z,1598460010.380 [CommandLine](IMPORTANT): got command report touch BackSeatDriver.component_avgCurrent 2020-08-26T16:40:25.464Z,1598460025.464 [CommandLine](IMPORTANT): got command run ./Missions/bsd.xml 2020-08-26T16:40:25.465Z,1598460025.465 [MissionManager](INFO): Loading Mission: ./Missions/bsd.xml 2020-08-26T16:40:25.508Z,1598460025.508 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min 2020-08-26T16:40:25.509Z,1598460025.509 [Default:A.Wait](DEBUG): Construct Wait. 2020-08-26T16:40:25.511Z,1598460025.511 [Default:C.GoToSurface](DEBUG): Construct GoToSurface. 2020-08-26T16:40:25.519Z,1598460025.519 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute. 2020-08-26T16:40:25.521Z,1598460025.521 [Default:CheckIn:C.Wait](DEBUG): Construct Wait. 2020-08-26T16:40:25.525Z,1598460025.525 [Default:F.Execute](DEBUG): Construct Execute. 2020-08-26T16:40:25.544Z,1598460025.544 [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-26T16:40:25.546Z,1598460025.546 [CommandLine](IMPORTANT): Running ./Missions/bsd.xml 2020-08-26T16:40:25.603Z,1598460025.603 [Default] Stopped 2020-08-26T16:40:25.603Z,1598460025.603 [Default](DEBUG): Aggregate::uninitialize Default 2020-08-26T16:40:25.603Z,1598460025.603 [Default:B.GoToSurface] Stopped 2020-08-26T16:40:25.603Z,1598460025.603 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-08-26T16:40:25.603Z,1598460025.603 [Default:CheckIn] Stopped 2020-08-26T16:40:25.603Z,1598460025.603 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-26T16:40:25.603Z,1598460025.603 [Default:CheckIn:Read_GPS] Stopped 2020-08-26T16:40:25.603Z,1598460025.603 [MissionManager](IMPORTANT): Started mission Default 2020-08-26T16:40:25.604Z,1598460025.604 [Default] Running Loop=1 2020-08-26T16:40:25.604Z,1598460025.604 [Default](DEBUG): Aggregate::initialize Default 2020-08-26T16:40:25.604Z,1598460025.604 [Default:B] Running Loop=1 2020-08-26T16:40:25.604Z,1598460025.604 [Default:C.GoToSurface] Running Loop=1 2020-08-26T16:40:25.604Z,1598460025.604 [Default:C.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-08-26T16:40:25.604Z,1598460025.604 [Default:C.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-08-26T16:40:25.605Z,1598460025.605 [Default:C.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-08-26T16:40:25.605Z,1598460025.605 [Default:C.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-08-26T16:40:25.605Z,1598460025.605 [Default:C.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-08-26T16:40:25.605Z,1598460025.605 [Default:C.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-08-26T16:40:25.606Z,1598460025.606 [Default:A.Wait] Running Loop=1 2020-08-26T16:40:25.606Z,1598460025.606 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-08-26T16:40:25.607Z,1598460025.607 [Default:B] Running Loop=1 2020-08-26T16:40:25.607Z,1598460025.607 [Default:B](DEBUG): Initialize ReadDataComponent to sense BackSeatDriver.power_back_seat_driver 2020-08-26T16:40:25.711Z,1598460025.711 [BackSeatDriver](INFO): Powering up 2020-08-26T16:40:25.711Z,1598460025.711 [BackSeatDriver](INFO): Subscribing to LCM channel: BackSeatDriverStatus 2020-08-26T16:40:25.712Z,1598460025.712 [BackSeatDriver](INFO): Subscribing to LCM channel: BioLumProxies 2020-08-26T16:40:38.912Z,1598460038.912 [Default:A.Wait](INFO): Done Waiting. 2020-08-26T16:40:38.912Z,1598460038.912 [Default:A.Wait] Stopped 2020-08-26T16:40:38.912Z,1598460038.912 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T16:40:39.330Z,1598460039.330 [Default:CheckIn] Running Loop=1 2020-08-26T16:40:39.331Z,1598460039.331 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-26T16:40:39.331Z,1598460039.331 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-26T16:40:39.745Z,1598460039.745 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix 2020-08-26T16:40:51.859Z,1598460051.859 [Reporter](INFO): BackSeatDriver.component_avgCurrent 517.470032 mA 2020-08-26T16:41:01.562Z,1598460061.562 [Reporter](INFO): BackSeatDriver.component_avgCurrent 675.280029 mA 2020-08-26T16:41:11.230Z,1598460071.230 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6 2020-08-26T16:41:11.230Z,1598460071.230 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:41:11.264Z,1598460071.264 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:41:11.666Z,1598460071.666 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:41:11.666Z,1598460071.666 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6 2020-08-26T16:41:11.668Z,1598460071.668 [Reporter](INFO): BackSeatDriver.component_avgCurrent 693.630005 mA 2020-08-26T16:41:21.755Z,1598460081.755 [Reporter](INFO): BackSeatDriver.component_avgCurrent 642.250000 mA 2020-08-26T16:41:31.857Z,1598460091.857 [Reporter](INFO): BackSeatDriver.component_avgCurrent 576.190002 mA 2020-08-26T16:41:41.595Z,1598460101.595 [Reporter](INFO): BackSeatDriver.component_avgCurrent 565.179993 mA 2020-08-26T16:41:51.653Z,1598460111.653 [Reporter](INFO): BackSeatDriver.component_avgCurrent 576.190002 mA 2020-08-26T16:42:01.749Z,1598460121.749 [Reporter](INFO): BackSeatDriver.component_avgCurrent 576.190002 mA 2020-08-26T16:42:11.845Z,1598460131.845 [Reporter](INFO): BackSeatDriver.component_avgCurrent 656.929993 mA 2020-08-26T16:42:21.552Z,1598460141.552 [Reporter](INFO): BackSeatDriver.component_avgCurrent 686.290039 mA 2020-08-26T16:42:31.641Z,1598460151.641 [Reporter](INFO): BackSeatDriver.component_avgCurrent 664.270020 mA 2020-08-26T16:42:41.764Z,1598460161.764 [Reporter](INFO): BackSeatDriver.component_avgCurrent 660.600037 mA 2020-08-26T16:42:51.837Z,1598460171.837 [Reporter](INFO): BackSeatDriver.component_avgCurrent 620.230042 mA 2020-08-26T16:43:01.577Z,1598460181.577 [Reporter](INFO): BackSeatDriver.component_avgCurrent 620.230042 mA 2020-08-26T16:43:11.648Z,1598460191.648 [Reporter](INFO): BackSeatDriver.component_avgCurrent 616.559998 mA 2020-08-26T16:43:21.753Z,1598460201.753 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:43:31.837Z,1598460211.837 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:43:41.544Z,1598460221.544 [Reporter](INFO): BackSeatDriver.component_avgCurrent 598.210022 mA 2020-08-26T16:43:51.645Z,1598460231.645 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:44:01.751Z,1598460241.751 [Reporter](INFO): BackSeatDriver.component_avgCurrent 568.850037 mA 2020-08-26T16:44:11.857Z,1598460251.857 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:44:12.241Z,1598460252.241 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7 2020-08-26T16:44:12.241Z,1598460252.241 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:44:12.251Z,1598460252.251 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:44:12.639Z,1598460252.639 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:44:12.639Z,1598460252.639 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7 2020-08-26T16:44:21.563Z,1598460261.563 [Reporter](INFO): BackSeatDriver.component_avgCurrent 568.850037 mA 2020-08-26T16:44:30.405Z,1598460270.405 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-08-26T16:44:30.405Z,1598460270.405 [NAL9602] Data Fault, FailCount= 2 2020-08-26T16:44:30.405Z,1598460270.405 [NAL9602](ERROR): Data Fault 2020-08-26T16:44:30.422Z,1598460270.422 [CBIT](ERROR): Data Fault in component: NAL9602 2020-08-26T16:44:30.799Z,1598460270.799 [NAL9602](INFO): Powering down 2020-08-26T16:44:31.628Z,1598460271.628 [CBIT](INFO): Clearing failed state for component NAL9602 2020-08-26T16:44:31.628Z,1598460271.628 [NAL9602] No Fault, FailCount= 2 2020-08-26T16:44:31.629Z,1598460271.629 [Reporter](INFO): BackSeatDriver.component_avgCurrent 568.850037 mA 2020-08-26T16:44:41.733Z,1598460281.733 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:44:51.831Z,1598460291.831 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:45:01.103Z,1598460301.103 [NAL9602](INFO): Powering up NAL9602 2020-08-26T16:45:01.524Z,1598460301.524 [Reporter](INFO): BackSeatDriver.component_avgCurrent 568.850037 mA 2020-08-26T16:45:11.637Z,1598460311.637 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T16:45:12.012Z,1598460312.012 [NAL9602](INFO): NAL9602 initialized 2020-08-26T16:45:21.757Z,1598460321.757 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:45:31.846Z,1598460331.846 [Reporter](INFO): BackSeatDriver.component_avgCurrent 576.190002 mA 2020-08-26T16:45:39.491Z,1598460339.491 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T16:40:39.3Z 2020-08-26T16:45:39.491Z,1598460339.491 [Default:CheckIn:Read_GPS] Stopped 2020-08-26T16:45:39.492Z,1598460339.492 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-08-26T16:45:39.908Z,1598460339.908 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-08-26T16:45:41.478Z,1598460341.478 [BackSeatDriver](FAULT): Failed to receive device response within the specified timeout. 2020-08-26T16:45:41.478Z,1598460341.478 [BackSeatDriver] Communications Fault, FailCount= 2 2020-08-26T16:45:41.479Z,1598460341.479 [BackSeatDriver](ERROR): Communications Fault 2020-08-26T16:45:41.555Z,1598460341.555 [DAT](INFO): DAT read: Rx Time:16:40:01.7105 2020-08-26T16:45:41.555Z,1598460341.555 [DAT](INFO): received an acoustic signal 2020-08-26T16:45:41.590Z,1598460341.590 [DAT](INFO): DAT read: 16:40:01.7105 LVL= 13680, 18753, 22418, 32755, AGC= 72, IDX= 292,-0.41, 0.047,-0.702, 0.290, 0.747, PHS=-0.666,-1.420,-0.385, RAW= 165.2, 43.3, CAL= 167.5, 50.8, ROT= 327.5, -50.8 2020-08-26T16:45:41.592Z,1598460341.592 [DAT](INFO): got valid direction response: 16:40:01.7105 LVL= 13680, 18753, 22418, 32755, AGC= 72, IDX= 292,-0.41, 0.047,-0.702, 0.290, 0.747, PHS=-0.666,-1.420,-0.385, RAW= 165.2, 43.3, CAL= 167.5, 50.8, ROT= 327.5, -50.8 2020-08-26T16:45:41.592Z,1598460341.592 [DAT](INFO): DAT read: 2020-08-26T16:45:41.593Z,1598460341.593 [DAT](INFO): DAT read: DATA(0002):~~ 2020-08-26T16:45:41.593Z,1598460341.593 [DAT](INFO): Got DATA 2 2020-08-26T16:45:41.594Z,1598460341.594 [DAT](INFO): DAT read: Source:006 Destination:009 2020-08-26T16:45:41.594Z,1598460341.594 [DAT](INFO): Got Src/Dest after DATA 2020-08-26T16:45:41.606Z,1598460341.606 [DAT](INFO): DATA Src=6, Dst=9 2020-08-26T16:45:41.608Z,1598460341.608 [DAT](INFO): DAT read: CRC:Pass MPD:13.6 PSNR:13.0 AGC:76 SPD:-00.3 CCERR:010 2020-08-26T16:45:41.608Z,1598460341.608 [DAT](INFO): Got CRC:Pass 2020-08-26T16:45:41.608Z,1598460341.608 [DAT](INFO): Got CRC:Pass 2020-08-26T16:45:41.608Z,1598460341.608 [DAT](INFO): Incoming data is intended for us 2020-08-26T16:45:41.608Z,1598460341.608 [DAT](INFO): Got ack 2020-08-26T16:45:41.608Z,1598460341.608 [DAT](INFO): DAT read: 2020-08-26T16:45:41.609Z,1598460341.609 [DAT](INFO): DAT read: 2020-08-26T16:45:41.610Z,1598460341.610 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-26T16:45:41.662Z,1598460341.662 [DAT](INFO): Read direction message, but no range. 2020-08-26T16:45:41.703Z,1598460341.703 [CBIT](ERROR): Communications Fault in component: BackSeatDriver 2020-08-26T16:45:41.884Z,1598460341.884 [BackSeatDriver](INFO): Sent LCM shutdown request. 2020-08-26T16:45:45.148Z,1598460345.148 [DAT](INFO): DAT read: Forwarding Delay UpTx time:16:45:25.1395 2020-08-26T16:45:45.148Z,1598460345.148 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-26T16:45:50.650Z,1598460350.650 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200826T162253/Courier0007.lzma 2020-08-26T16:45:51.652Z,1598460351.652 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Courier0007.lzma.bak 2020-08-26T16:45:51.652Z,1598460351.652 [DataOverHttps](INFO): SBD MOMSN=12620387 2020-08-26T16:45:57.235Z,1598460357.235 [BackSeatDriver](INFO): Powering down 2020-08-26T16:45:57.313Z,1598460357.313 [Reporter](INFO): BackSeatDriver.component_avgCurrent no_value 2020-08-26T16:45:57.639Z,1598460357.639 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BackSeatDriverStatus 2020-08-26T16:45:57.639Z,1598460357.639 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BioLumProxies 2020-08-26T16:45:58.043Z,1598460358.043 [BackSeatDriver](INFO): Powering up 2020-08-26T16:45:58.043Z,1598460358.043 [BackSeatDriver](INFO): Subscribing to LCM channel: BackSeatDriverStatus 2020-08-26T16:45:58.044Z,1598460358.044 [BackSeatDriver](INFO): Subscribing to LCM channel: BioLumProxies 2020-08-26T16:45:58.140Z,1598460358.140 [CBIT](INFO): Clearing failed state for component BackSeatDriver 2020-08-26T16:45:58.140Z,1598460358.140 [BackSeatDriver] No Fault, FailCount= 2 2020-08-26T16:46:01.704Z,1598460361.704 [DAT](FAULT): Ack receipt timeout failure. 2020-08-26T16:46:01.705Z,1598460361.705 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2020-08-26T16:46:02.824Z,1598460362.824 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-26T16:46:02.831Z,1598460362.831 [Default:CheckIn:Read_Iridium] Stopped 2020-08-26T16:46:02.831Z,1598460362.831 [Default:CheckIn:C.Wait] Running Loop=1 2020-08-26T16:46:02.831Z,1598460362.831 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-08-26T16:46:08.655Z,1598460368.655 [DataOverHttps](INFO): Sending 177 bytes from file Logs/20200826T151826/Express0017.lzma 2020-08-26T16:46:09.656Z,1598460369.656 [DataOverHttps](INFO): Moved sent file to Logs/20200826T151826/Express0017.lzma.bak 2020-08-26T16:46:09.656Z,1598460369.656 [DataOverHttps](INFO): SBD MOMSN=12620389 2020-08-26T16:46:23.893Z,1598460383.893 [Reporter](INFO): BackSeatDriver.component_avgCurrent 513.799988 mA 2020-08-26T16:46:33.995Z,1598460393.995 [Reporter](INFO): BackSeatDriver.component_avgCurrent 678.950012 mA 2020-08-26T16:46:44.093Z,1598460404.093 [Reporter](INFO): BackSeatDriver.component_avgCurrent 708.309998 mA 2020-08-26T16:46:54.184Z,1598460414.184 [Reporter](INFO): BackSeatDriver.component_avgCurrent 631.239990 mA 2020-08-26T16:47:03.889Z,1598460423.889 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:47:13.168Z,1598460433.168 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8 2020-08-26T16:47:13.168Z,1598460433.168 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:47:13.179Z,1598460433.179 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:47:13.590Z,1598460433.590 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:47:13.590Z,1598460433.590 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8 2020-08-26T16:47:13.986Z,1598460433.986 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:47:24.069Z,1598460444.069 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:47:34.177Z,1598460454.177 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:47:43.885Z,1598460463.885 [Reporter](INFO): BackSeatDriver.component_avgCurrent 664.270020 mA 2020-08-26T16:47:53.989Z,1598460473.989 [Reporter](INFO): BackSeatDriver.component_avgCurrent 697.299988 mA 2020-08-26T16:48:04.069Z,1598460484.069 [Reporter](INFO): BackSeatDriver.component_avgCurrent 667.940002 mA 2020-08-26T16:48:14.195Z,1598460494.195 [Reporter](INFO): BackSeatDriver.component_avgCurrent 634.910034 mA 2020-08-26T16:48:23.884Z,1598460503.884 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:48:33.987Z,1598460513.987 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:48:44.061Z,1598460524.061 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:48:54.192Z,1598460534.192 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:49:03.928Z,1598460543.928 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T16:49:13.991Z,1598460553.991 [Reporter](INFO): BackSeatDriver.component_avgCurrent 576.190002 mA 2020-08-26T16:49:24.073Z,1598460564.073 [Reporter](INFO): BackSeatDriver.component_avgCurrent 576.190002 mA 2020-08-26T16:49:34.180Z,1598460574.180 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:49:43.872Z,1598460583.872 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:49:53.985Z,1598460593.985 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:50:04.065Z,1598460604.065 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:50:14.174Z,1598460614.174 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9 2020-08-26T16:50:14.175Z,1598460614.175 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:50:14.189Z,1598460614.189 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:50:14.238Z,1598460614.238 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:50:14.613Z,1598460614.613 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:50:14.613Z,1598460614.613 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9 2020-08-26T16:50:23.879Z,1598460623.879 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:50:33.979Z,1598460633.979 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:50:44.065Z,1598460644.065 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:50:54.183Z,1598460654.183 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:51:03.071Z,1598460663.071 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-08-26T16:51:03.071Z,1598460663.071 [Default:CheckIn:C.Wait] Stopped 2020-08-26T16:51:03.072Z,1598460663.072 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T16:51:03.072Z,1598460663.072 [Default:CheckIn:D] Running Loop=1 2020-08-26T16:51:03.464Z,1598460663.464 [Default:CheckIn:D] Stopped 2020-08-26T16:51:03.464Z,1598460663.464 [Default:CheckIn:E] Running Loop=1 2020-08-26T16:51:03.876Z,1598460663.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.631006 min 2020-08-26T16:51:03.876Z,1598460663.876 [Default:CheckIn:E] Stopped 2020-08-26T16:51:03.876Z,1598460663.876 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-08-26T16:51:03.876Z,1598460663.876 [Default:CheckIn] Stopped 2020-08-26T16:51:03.876Z,1598460663.876 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-26T16:51:03.876Z,1598460663.876 [Default:CheckIn](INFO): Running loop #2 2020-08-26T16:51:03.876Z,1598460663.876 [Default:CheckIn] Running Loop=2 2020-08-26T16:51:03.877Z,1598460663.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-26T16:51:03.877Z,1598460663.877 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-26T16:51:03.887Z,1598460663.887 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T16:51:13.830Z,1598460673.830 [BackSeatDriver](FAULT): Failed to receive device response within the specified timeout. 2020-08-26T16:51:13.830Z,1598460673.830 [BackSeatDriver] Communications Fault, FailCount= 3 2020-08-26T16:51:13.830Z,1598460673.830 [BackSeatDriver](ERROR): Communications Fault 2020-08-26T16:51:13.984Z,1598460673.984 [CBIT](ERROR): Communications Fault in component: BackSeatDriver 2020-08-26T16:51:14.235Z,1598460674.235 [BackSeatDriver](INFO): Sent LCM shutdown request. 2020-08-26T16:51:29.586Z,1598460689.586 [BackSeatDriver](INFO): Powering down 2020-08-26T16:51:29.717Z,1598460689.717 [Reporter](INFO): BackSeatDriver.component_avgCurrent no_value 2020-08-26T16:51:29.990Z,1598460689.990 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BackSeatDriverStatus 2020-08-26T16:51:29.991Z,1598460689.991 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BioLumProxies 2020-08-26T16:51:30.395Z,1598460690.395 [BackSeatDriver](INFO): Powering up 2020-08-26T16:51:30.395Z,1598460690.395 [BackSeatDriver](INFO): Subscribing to LCM channel: BackSeatDriverStatus 2020-08-26T16:51:30.396Z,1598460690.396 [BackSeatDriver](INFO): Subscribing to LCM channel: BioLumProxies 2020-08-26T16:51:30.536Z,1598460690.536 [CBIT](INFO): Clearing failed state for component BackSeatDriver 2020-08-26T16:51:30.536Z,1598460690.536 [BackSeatDriver] No Fault, FailCount= 3 2020-08-26T16:51:56.407Z,1598460716.407 [Reporter](INFO): BackSeatDriver.component_avgCurrent 521.140015 mA 2020-08-26T16:52:06.545Z,1598460726.545 [Reporter](INFO): BackSeatDriver.component_avgCurrent 675.280029 mA 2020-08-26T16:52:16.183Z,1598460736.183 [Reporter](INFO): BackSeatDriver.component_avgCurrent 715.650024 mA 2020-08-26T16:52:26.313Z,1598460746.313 [Reporter](INFO): BackSeatDriver.component_avgCurrent 649.590027 mA 2020-08-26T16:52:36.386Z,1598460756.386 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:52:46.477Z,1598460766.477 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:52:56.177Z,1598460776.177 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:53:06.293Z,1598460786.293 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:53:15.166Z,1598460795.166 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10 2020-08-26T16:53:15.166Z,1598460795.166 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:53:15.176Z,1598460795.176 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:53:15.591Z,1598460795.591 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:53:15.591Z,1598460795.591 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10 2020-08-26T16:53:16.376Z,1598460796.376 [Reporter](INFO): BackSeatDriver.component_avgCurrent 671.609985 mA 2020-08-26T16:53:26.477Z,1598460806.477 [Reporter](INFO): BackSeatDriver.component_avgCurrent 711.980042 mA 2020-08-26T16:53:36.170Z,1598460816.170 [Reporter](INFO): BackSeatDriver.component_avgCurrent 675.280029 mA 2020-08-26T16:53:46.305Z,1598460826.305 [Reporter](INFO): BackSeatDriver.component_avgCurrent 631.239990 mA 2020-08-26T16:53:56.373Z,1598460836.373 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T16:54:06.470Z,1598460846.470 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T16:54:16.169Z,1598460856.169 [Reporter](INFO): BackSeatDriver.component_avgCurrent 612.890015 mA 2020-08-26T16:54:26.301Z,1598460866.301 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:54:36.368Z,1598460876.368 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:54:46.485Z,1598460886.485 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:54:56.189Z,1598460896.189 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:55:06.272Z,1598460906.272 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T16:55:15.136Z,1598460915.136 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-08-26T16:55:15.136Z,1598460915.136 [NAL9602] Data Fault, FailCount= 3 2020-08-26T16:55:15.136Z,1598460915.136 [NAL9602](ERROR): Data Fault 2020-08-26T16:55:15.151Z,1598460915.151 [CBIT](ERROR): Data Fault in component: NAL9602 2020-08-26T16:55:15.536Z,1598460915.536 [NAL9602](INFO): Powering down 2020-08-26T16:55:16.375Z,1598460916.375 [CBIT](INFO): Clearing failed state for component NAL9602 2020-08-26T16:55:16.375Z,1598460916.375 [NAL9602] No Fault, FailCount= 3 2020-08-26T16:55:16.377Z,1598460916.377 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T16:55:26.469Z,1598460926.469 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:55:36.158Z,1598460936.158 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:55:45.836Z,1598460945.836 [NAL9602](INFO): Powering up NAL9602 2020-08-26T16:55:46.261Z,1598460946.261 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T16:55:56.386Z,1598460956.386 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:55:56.744Z,1598460956.744 [NAL9602](INFO): NAL9602 initialized 2020-08-26T16:56:04.027Z,1598460964.027 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T16:51:03.9Z 2020-08-26T16:56:04.027Z,1598460964.027 [Default:CheckIn:Read_GPS] Stopped 2020-08-26T16:56:04.027Z,1598460964.027 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-08-26T16:56:06.056Z,1598460966.056 [DAT](INFO): DAT read: Rx Time:16:50:32.1199 2020-08-26T16:56:06.056Z,1598460966.056 [DAT](INFO): received an acoustic signal 2020-08-26T16:56:06.056Z,1598460966.056 [DAT](INFO): DAT read: 2020-08-26T16:56:06.057Z,1598460966.057 [DAT](INFO): DAT read: DATA(0006):~~+++ 2020-08-26T16:56:06.057Z,1598460966.057 [DAT](INFO): Got DATA 6 2020-08-26T16:56:06.058Z,1598460966.058 [DAT](INFO): DAT read: Source:006 Destination:009 2020-08-26T16:56:06.058Z,1598460966.058 [DAT](INFO): Got Src/Dest after DATA 2020-08-26T16:56:06.059Z,1598460966.059 [DAT](INFO): DATA Src=6, Dst=9 2020-08-26T16:56:06.060Z,1598460966.060 [DAT](INFO): DAT read: CRC:Pass MPD:30.0 PSNR:14.4 AGC:66 SPD:+00.0 CCERR:010 2020-08-26T16:56:06.060Z,1598460966.060 [DAT](INFO): Got CRC:Pass 2020-08-26T16:56:06.060Z,1598460966.060 [DAT](INFO): Got CRC:Pass 2020-08-26T16:56:06.060Z,1598460966.060 [DAT](INFO): Incoming data is intended for us 2020-08-26T16:56:06.060Z,1598460966.060 [DAT](INFO): Got ack 2020-08-26T16:56:06.062Z,1598460966.062 [DAT](INFO): Received command:+++ 2020-08-26T16:56:06.066Z,1598460966.066 [DAT](INFO): Sending ack 2020-08-26T16:56:06.066Z,1598460966.066 [DAT](INFO): DAT read: 2020-08-26T16:56:06.071Z,1598460966.071 [DAT](INFO): DAT read: 2020-08-26T16:56:06.484Z,1598460966.484 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T16:56:09.284Z,1598460969.284 [DAT](INFO): DAT read: Forwarding Delay UpTx time:16:55:49.5364 2020-08-26T16:56:09.284Z,1598460969.284 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-26T16:56:10.830Z,1598460970.830 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200826T162253/Courier0010.lzma 2020-08-26T16:56:11.832Z,1598460971.832 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Courier0010.lzma.bak 2020-08-26T16:56:11.832Z,1598460971.832 [DataOverHttps](INFO): SBD MOMSN=12620432 2020-08-26T16:56:12.911Z,1598460972.911 [DAT](INFO): DAT read: Forwarding Delay UpTx time:16:55:52.8364 2020-08-26T16:56:12.911Z,1598460972.911 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-26T16:56:16.149Z,1598460976.149 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11 2020-08-26T16:56:16.149Z,1598460976.149 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:56:16.160Z,1598460976.160 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:56:16.161Z,1598460976.161 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:56:16.572Z,1598460976.572 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:56:16.572Z,1598460976.572 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11 2020-08-26T16:56:26.277Z,1598460986.277 [Reporter](INFO): BackSeatDriver.component_avgCurrent 598.210022 mA 2020-08-26T16:56:28.798Z,1598460988.798 [DataOverHttps](INFO): Sending 327 bytes from file Logs/20200826T151826/Express0020.lzma 2020-08-26T16:56:29.478Z,1598460989.478 [DAT](FAULT): Ack receipt timeout failure. 2020-08-26T16:56:29.478Z,1598460989.478 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2020-08-26T16:56:29.800Z,1598460989.800 [DataOverHttps](INFO): Moved sent file to Logs/20200826T151826/Express0020.lzma.bak 2020-08-26T16:56:29.800Z,1598460989.800 [DataOverHttps](INFO): SBD MOMSN=12620434 2020-08-26T16:56:29.891Z,1598460989.891 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER 2020-08-26T16:56:31.267Z,1598460991.267 [Default:CheckIn:Read_Iridium] Stopped 2020-08-26T16:56:31.267Z,1598460991.267 [Default:CheckIn:C.Wait] Running Loop=1 2020-08-26T16:56:31.267Z,1598460991.267 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-08-26T16:56:36.185Z,1598460996.185 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T16:56:46.150Z,1598461006.150 [BackSeatDriver](FAULT): Failed to receive device response within the specified timeout. 2020-08-26T16:56:46.150Z,1598461006.150 [BackSeatDriver] Communications Fault, FailCount= 4 2020-08-26T16:56:46.150Z,1598461006.150 [BackSeatDriver](ERROR): Communications Fault 2020-08-26T16:56:46.267Z,1598461006.267 [CBIT](ERROR): Communications Fault in component: BackSeatDriver 2020-08-26T16:56:46.556Z,1598461006.556 [BackSeatDriver](INFO): Sent LCM shutdown request. 2020-08-26T16:57:01.906Z,1598461021.907 [BackSeatDriver](INFO): Powering down 2020-08-26T16:57:02.044Z,1598461022.044 [Reporter](INFO): BackSeatDriver.component_avgCurrent no_value 2020-08-26T16:57:02.310Z,1598461022.310 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BackSeatDriverStatus 2020-08-26T16:57:02.311Z,1598461022.311 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BioLumProxies 2020-08-26T16:57:02.714Z,1598461022.714 [BackSeatDriver](INFO): Powering up 2020-08-26T16:57:02.715Z,1598461022.715 [BackSeatDriver](INFO): Subscribing to LCM channel: BackSeatDriverStatus 2020-08-26T16:57:02.716Z,1598461022.716 [BackSeatDriver](INFO): Subscribing to LCM channel: BioLumProxies 2020-08-26T16:57:02.844Z,1598461022.844 [CBIT](INFO): Clearing failed state for component BackSeatDriver 2020-08-26T16:57:02.844Z,1598461022.844 [BackSeatDriver] No Fault, FailCount= 4 2020-08-26T16:57:14.586Z,1598461034.586 [DataOverHttps](INFO): Sending 284 bytes from file Logs/20200826T151826/Express0023.lzma 2020-08-26T16:57:15.588Z,1598461035.588 [DataOverHttps](INFO): Moved sent file to Logs/20200826T151826/Express0023.lzma.bak 2020-08-26T16:57:15.588Z,1598461035.588 [DataOverHttps](INFO): SBD MOMSN=12620443 2020-08-26T16:57:28.688Z,1598461048.688 [Reporter](INFO): BackSeatDriver.component_avgCurrent 524.809998 mA 2020-08-26T16:57:38.801Z,1598461058.801 [Reporter](INFO): BackSeatDriver.component_avgCurrent 689.960022 mA 2020-08-26T16:57:48.478Z,1598461068.478 [Reporter](INFO): BackSeatDriver.component_avgCurrent 715.650024 mA 2020-08-26T16:57:58.609Z,1598461078.609 [Reporter](INFO): BackSeatDriver.component_avgCurrent 645.920044 mA 2020-08-26T16:58:08.700Z,1598461088.700 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T16:58:18.806Z,1598461098.806 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T16:58:28.490Z,1598461108.490 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T16:58:38.601Z,1598461118.601 [Reporter](INFO): BackSeatDriver.component_avgCurrent 616.559998 mA 2020-08-26T16:58:48.681Z,1598461128.681 [Reporter](INFO): BackSeatDriver.component_avgCurrent 678.950012 mA 2020-08-26T16:58:58.793Z,1598461138.793 [Reporter](INFO): BackSeatDriver.component_avgCurrent 704.640015 mA 2020-08-26T16:59:08.503Z,1598461148.503 [Reporter](INFO): BackSeatDriver.component_avgCurrent 682.619995 mA 2020-08-26T16:59:16.963Z,1598461156.963 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12 2020-08-26T16:59:16.963Z,1598461156.963 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T16:59:16.973Z,1598461156.973 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T16:59:17.383Z,1598461157.383 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T16:59:17.383Z,1598461157.383 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12 2020-08-26T16:59:18.577Z,1598461158.577 [Reporter](INFO): BackSeatDriver.component_avgCurrent 623.900024 mA 2020-08-26T16:59:28.679Z,1598461168.679 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T16:59:38.795Z,1598461178.795 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T16:59:48.488Z,1598461188.488 [Reporter](INFO): BackSeatDriver.component_avgCurrent 609.220032 mA 2020-08-26T16:59:58.573Z,1598461198.573 [Reporter](INFO): BackSeatDriver.component_avgCurrent 620.230042 mA 2020-08-26T17:00:08.685Z,1598461208.685 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:00:18.785Z,1598461218.785 [Reporter](INFO): BackSeatDriver.component_avgCurrent 576.190002 mA 2020-08-26T17:00:28.480Z,1598461228.480 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T17:00:38.581Z,1598461238.581 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T17:00:48.689Z,1598461248.689 [Reporter](INFO): BackSeatDriver.component_avgCurrent 576.190002 mA 2020-08-26T17:00:58.785Z,1598461258.785 [Reporter](INFO): BackSeatDriver.component_avgCurrent 576.190002 mA 2020-08-26T17:01:08.480Z,1598461268.480 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:01:18.581Z,1598461278.581 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T17:01:28.679Z,1598461288.679 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:01:31.484Z,1598461291.484 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-08-26T17:01:31.484Z,1598461291.484 [Default:CheckIn:C.Wait] Stopped 2020-08-26T17:01:31.484Z,1598461291.484 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T17:01:31.484Z,1598461291.484 [Default:CheckIn:D] Running Loop=1 2020-08-26T17:01:31.907Z,1598461291.907 [Default:CheckIn:D] Stopped 2020-08-26T17:01:31.908Z,1598461291.908 [Default:CheckIn:E] Running Loop=1 2020-08-26T17:01:32.311Z,1598461292.311 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.105062 min 2020-08-26T17:01:32.312Z,1598461292.312 [Default:CheckIn:E] Stopped 2020-08-26T17:01:32.312Z,1598461292.312 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-08-26T17:01:32.312Z,1598461292.312 [Default:CheckIn] Stopped 2020-08-26T17:01:32.312Z,1598461292.312 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-26T17:01:32.312Z,1598461292.312 [Default:CheckIn](INFO): Running loop #3 2020-08-26T17:01:32.312Z,1598461292.312 [Default:CheckIn] Running Loop=3 2020-08-26T17:01:32.312Z,1598461292.312 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-26T17:01:32.312Z,1598461292.312 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-26T17:01:38.782Z,1598461298.782 [Reporter](INFO): BackSeatDriver.component_avgCurrent 601.880005 mA 2020-08-26T17:01:48.478Z,1598461308.478 [Reporter](INFO): BackSeatDriver.component_avgCurrent 598.210022 mA 2020-08-26T17:01:58.562Z,1598461318.562 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T17:02:08.675Z,1598461328.675 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:02:17.961Z,1598461337.961 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13 2020-08-26T17:02:17.961Z,1598461337.961 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:02:17.972Z,1598461337.972 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:02:18.388Z,1598461338.388 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:02:18.388Z,1598461338.388 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13 2020-08-26T17:02:18.470Z,1598461338.470 [BackSeatDriver](FAULT): Failed to receive device response within the specified timeout. 2020-08-26T17:02:18.470Z,1598461338.470 [BackSeatDriver] Communications Fault, FailCount= 5 2020-08-26T17:02:18.470Z,1598461338.470 [BackSeatDriver](ERROR): Communications Fault 2020-08-26T17:02:18.772Z,1598461338.772 [CBIT](ERROR): Communications Fault in component: BackSeatDriver 2020-08-26T17:02:18.772Z,1598461338.772 [CBIT](FAULT): Communications Fault in component: BackSeatDriver 2020-08-26T17:02:18.875Z,1598461338.875 [BackSeatDriver](INFO): Sent LCM shutdown request. 2020-08-26T17:02:34.227Z,1598461354.227 [BackSeatDriver](INFO): Powering down 2020-08-26T17:02:34.516Z,1598461354.516 [Reporter](INFO): BackSeatDriver.component_avgCurrent no_value 2020-08-26T17:02:34.631Z,1598461354.631 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BackSeatDriverStatus 2020-08-26T17:02:34.631Z,1598461354.631 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BioLumProxies 2020-08-26T17:02:35.034Z,1598461355.034 [BackSeatDriver](INFO): Powering up 2020-08-26T17:02:35.035Z,1598461355.035 [BackSeatDriver](INFO): Subscribing to LCM channel: BackSeatDriverStatus 2020-08-26T17:02:35.036Z,1598461355.036 [BackSeatDriver](INFO): Subscribing to LCM channel: BioLumProxies 2020-08-26T17:04:48.656Z,1598461488.656 [CBIT](INFO): Clearing failed state for component BackSeatDriver 2020-08-26T17:04:48.656Z,1598461488.656 [BackSeatDriver] No Fault, FailCount= 5 2020-08-26T17:04:59.571Z,1598461499.571 [Reporter](INFO): BackSeatDriver.component_avgCurrent 620.230042 mA 2020-08-26T17:05:09.269Z,1598461509.269 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T17:05:18.933Z,1598461518.933 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14 2020-08-26T17:05:18.933Z,1598461518.933 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:05:18.971Z,1598461518.971 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:05:19.339Z,1598461519.339 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:05:19.339Z,1598461519.339 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14 2020-08-26T17:05:19.341Z,1598461519.341 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T17:05:29.471Z,1598461529.471 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T17:05:39.576Z,1598461539.576 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:05:49.252Z,1598461549.252 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T17:05:57.708Z,1598461557.708 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-08-26T17:05:57.708Z,1598461557.708 [NAL9602] Data Fault, FailCount= 4 2020-08-26T17:05:57.708Z,1598461557.708 [NAL9602](ERROR): Data Fault 2020-08-26T17:05:57.752Z,1598461557.752 [CBIT](ERROR): Data Fault in component: NAL9602 2020-08-26T17:05:58.112Z,1598461558.112 [NAL9602](INFO): Powering down 2020-08-26T17:05:58.944Z,1598461558.944 [CBIT](INFO): Clearing failed state for component NAL9602 2020-08-26T17:05:58.944Z,1598461558.944 [NAL9602] No Fault, FailCount= 4 2020-08-26T17:05:59.364Z,1598461559.364 [Reporter](INFO): BackSeatDriver.component_avgCurrent 605.549988 mA 2020-08-26T17:06:09.455Z,1598461569.455 [Reporter](INFO): BackSeatDriver.component_avgCurrent 620.230042 mA 2020-08-26T17:06:19.552Z,1598461579.552 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:06:28.408Z,1598461588.408 [NAL9602](INFO): Powering up NAL9602 2020-08-26T17:06:29.235Z,1598461589.235 [Reporter](INFO): BackSeatDriver.component_avgCurrent 576.190002 mA 2020-08-26T17:06:32.464Z,1598461592.464 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T17:01:32.3Z 2020-08-26T17:06:32.464Z,1598461592.464 [Default:CheckIn:Read_GPS] Stopped 2020-08-26T17:06:32.464Z,1598461592.464 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-08-26T17:06:34.478Z,1598461594.478 [DAT](INFO): DAT read: Rx Time:17:01:03.6289 2020-08-26T17:06:34.479Z,1598461594.479 [DAT](INFO): received an acoustic signal 2020-08-26T17:06:34.479Z,1598461594.479 [DAT](INFO): DAT read: 2020-08-26T17:06:34.480Z,1598461594.480 [DAT](INFO): DAT read: $Packet for address 0 2020-08-26T17:06:34.480Z,1598461594.480 [DAT](INFO): received a packet notification 2020-08-26T17:06:35.307Z,1598461595.307 [DAT](INFO): #Outgoing data=1 2020-08-26T17:06:35.307Z,1598461595.307 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-26T17:06:35.402Z,1598461595.402 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-26T17:06:38.992Z,1598461598.992 [DAT](INFO): DAT read: Forwarding Delay UpTx time:17:06:18.9328 2020-08-26T17:06:38.992Z,1598461598.992 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-26T17:06:39.392Z,1598461599.392 [NAL9602](INFO): NAL9602 initialized 2020-08-26T17:06:39.537Z,1598461599.537 [Reporter](INFO): BackSeatDriver.component_avgCurrent 572.520020 mA 2020-08-26T17:06:40.380Z,1598461600.380 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200826T162253/Courier0013.lzma 2020-08-26T17:06:40.916Z,1598461600.916 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Courier0013.lzma.bak 2020-08-26T17:06:40.916Z,1598461600.916 [DataOverHttps](INFO): SBD MOMSN=12620499 2020-08-26T17:06:49.503Z,1598461609.503 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T17:06:55.537Z,1598461615.537 [DAT](FAULT): Ack receipt timeout failure. 2020-08-26T17:06:55.537Z,1598461615.537 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2020-08-26T17:06:55.941Z,1598461615.941 [DAT](INFO): Sent 39 bytes from file Logs/20200826T162253/Courier0013.lzma.parts 2020-08-26T17:06:55.941Z,1598461615.941 [DAT](INFO): Packets left to send: 0 2020-08-26T17:06:55.943Z,1598461615.943 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2020-08-26T17:06:56.860Z,1598461616.860 [DataOverHttps](INFO): Sending 1040 bytes from file Logs/20200826T162253/Express0001.lzma 2020-08-26T17:06:57.119Z,1598461617.119 [Default:CheckIn:Read_Iridium] Stopped 2020-08-26T17:06:57.119Z,1598461617.119 [Default:CheckIn:C.Wait] Running Loop=1 2020-08-26T17:06:57.119Z,1598461617.119 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-08-26T17:06:57.860Z,1598461617.860 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Express0001.lzma.bak 2020-08-26T17:06:57.860Z,1598461617.860 [DataOverHttps](INFO): SBD MOMSN=12620501 2020-08-26T17:06:59.211Z,1598461619.211 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:07:09.307Z,1598461629.307 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T17:07:19.397Z,1598461639.397 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T17:07:29.485Z,1598461649.485 [Reporter](INFO): BackSeatDriver.component_avgCurrent 598.210022 mA 2020-08-26T17:07:39.214Z,1598461659.214 [Reporter](INFO): BackSeatDriver.component_avgCurrent 598.210022 mA 2020-08-26T17:07:49.306Z,1598461669.306 [Reporter](INFO): BackSeatDriver.component_avgCurrent 601.880005 mA 2020-08-26T17:07:59.377Z,1598461679.377 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T17:08:09.497Z,1598461689.497 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T17:08:19.183Z,1598461699.183 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:08:19.970Z,1598461699.970 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15 2020-08-26T17:08:19.970Z,1598461699.970 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:08:19.981Z,1598461699.981 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:08:20.391Z,1598461700.391 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:08:20.391Z,1598461700.391 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15 2020-08-26T17:08:29.293Z,1598461709.293 [Reporter](INFO): BackSeatDriver.component_avgCurrent 634.910034 mA 2020-08-26T17:08:39.389Z,1598461719.389 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T17:08:49.506Z,1598461729.506 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T17:08:59.188Z,1598461739.188 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T17:09:09.293Z,1598461749.293 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T17:09:19.384Z,1598461759.384 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T17:09:29.498Z,1598461769.498 [Reporter](INFO): BackSeatDriver.component_avgCurrent 605.549988 mA 2020-08-26T17:09:39.183Z,1598461779.183 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T17:09:49.166Z,1598461789.166 [BackSeatDriver](FAULT): Failed to receive device response within the specified timeout. 2020-08-26T17:09:49.166Z,1598461789.166 [BackSeatDriver] Communications Fault, FailCount= 1 2020-08-26T17:09:49.166Z,1598461789.166 [BackSeatDriver](ERROR): Communications Fault 2020-08-26T17:09:49.291Z,1598461789.291 [CBIT](ERROR): Communications Fault in component: BackSeatDriver 2020-08-26T17:09:49.571Z,1598461789.571 [BackSeatDriver](INFO): Sent LCM shutdown request. 2020-08-26T17:10:04.924Z,1598461804.924 [BackSeatDriver](INFO): Powering down 2020-08-26T17:10:05.026Z,1598461805.026 [Reporter](INFO): BackSeatDriver.component_avgCurrent no_value 2020-08-26T17:10:05.330Z,1598461805.330 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BackSeatDriverStatus 2020-08-26T17:10:05.331Z,1598461805.331 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BioLumProxies 2020-08-26T17:10:05.735Z,1598461805.735 [BackSeatDriver](INFO): Powering up 2020-08-26T17:10:05.735Z,1598461805.735 [BackSeatDriver](INFO): Subscribing to LCM channel: BackSeatDriverStatus 2020-08-26T17:10:05.736Z,1598461805.736 [BackSeatDriver](INFO): Subscribing to LCM channel: BioLumProxies 2020-08-26T17:10:05.836Z,1598461805.836 [CBIT](INFO): Clearing failed state for component BackSeatDriver 2020-08-26T17:10:05.836Z,1598461805.836 [BackSeatDriver] No Fault, FailCount= 1 2020-08-26T17:10:31.714Z,1598461831.714 [Reporter](INFO): BackSeatDriver.component_avgCurrent 521.140015 mA 2020-08-26T17:10:41.785Z,1598461841.785 [Reporter](INFO): BackSeatDriver.component_avgCurrent 686.290039 mA 2020-08-26T17:10:51.501Z,1598461851.501 [Reporter](INFO): BackSeatDriver.component_avgCurrent 715.650024 mA 2020-08-26T17:11:01.610Z,1598461861.610 [Reporter](INFO): BackSeatDriver.component_avgCurrent 660.600037 mA 2020-08-26T17:11:11.689Z,1598461871.689 [Reporter](INFO): BackSeatDriver.component_avgCurrent 612.890015 mA 2020-08-26T17:11:20.970Z,1598461880.970 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16 2020-08-26T17:11:20.970Z,1598461880.970 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:11:20.980Z,1598461880.980 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:11:21.395Z,1598461881.395 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:11:21.395Z,1598461881.395 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16 2020-08-26T17:11:21.804Z,1598461881.804 [Reporter](INFO): BackSeatDriver.component_avgCurrent 612.890015 mA 2020-08-26T17:11:31.503Z,1598461891.503 [Reporter](INFO): BackSeatDriver.component_avgCurrent 616.559998 mA 2020-08-26T17:11:41.599Z,1598461901.599 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T17:11:51.685Z,1598461911.685 [Reporter](INFO): BackSeatDriver.component_avgCurrent 667.940002 mA 2020-08-26T17:11:57.345Z,1598461917.345 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-08-26T17:11:57.345Z,1598461917.345 [Default:CheckIn:C.Wait] Stopped 2020-08-26T17:11:57.345Z,1598461917.345 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T17:11:57.345Z,1598461917.345 [Default:CheckIn:D] Running Loop=1 2020-08-26T17:11:57.739Z,1598461917.739 [Default:CheckIn:D] Stopped 2020-08-26T17:11:57.739Z,1598461917.739 [Default:CheckIn:E] Running Loop=1 2020-08-26T17:11:58.146Z,1598461918.146 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.535590 min 2020-08-26T17:11:58.146Z,1598461918.146 [Default:CheckIn:E] Stopped 2020-08-26T17:11:58.147Z,1598461918.147 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-08-26T17:11:58.147Z,1598461918.147 [Default:CheckIn] Stopped 2020-08-26T17:11:58.147Z,1598461918.147 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-26T17:11:58.147Z,1598461918.147 [Default:CheckIn](INFO): Running loop #4 2020-08-26T17:11:58.147Z,1598461918.147 [Default:CheckIn] Running Loop=4 2020-08-26T17:11:58.147Z,1598461918.147 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-26T17:11:58.147Z,1598461918.147 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-26T17:12:01.801Z,1598461921.801 [Reporter](INFO): BackSeatDriver.component_avgCurrent 704.640015 mA 2020-08-26T17:12:11.898Z,1598461931.898 [Reporter](INFO): BackSeatDriver.component_avgCurrent 682.619995 mA 2020-08-26T17:12:21.593Z,1598461941.593 [Reporter](INFO): BackSeatDriver.component_avgCurrent 645.920044 mA 2020-08-26T17:12:31.687Z,1598461951.687 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:12:41.788Z,1598461961.788 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T17:12:51.892Z,1598461971.892 [Reporter](INFO): BackSeatDriver.component_avgCurrent 601.880005 mA 2020-08-26T17:13:01.592Z,1598461981.592 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:13:11.707Z,1598461991.707 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:13:21.799Z,1598462001.799 [Reporter](INFO): BackSeatDriver.component_avgCurrent 609.220032 mA 2020-08-26T17:13:31.508Z,1598462011.508 [Reporter](INFO): BackSeatDriver.component_avgCurrent 583.530029 mA 2020-08-26T17:13:41.589Z,1598462021.589 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T17:13:51.689Z,1598462031.689 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:14:01.793Z,1598462041.793 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T17:14:11.495Z,1598462051.495 [Reporter](INFO): BackSeatDriver.component_avgCurrent 590.869995 mA 2020-08-26T17:14:21.581Z,1598462061.581 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T17:14:21.964Z,1598462061.964 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17 2020-08-26T17:14:21.964Z,1598462061.964 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:14:21.986Z,1598462061.986 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:14:22.379Z,1598462062.379 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:14:22.379Z,1598462062.379 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17 2020-08-26T17:14:31.689Z,1598462071.689 [Reporter](INFO): BackSeatDriver.component_avgCurrent 579.859985 mA 2020-08-26T17:14:41.793Z,1598462081.793 [Reporter](INFO): BackSeatDriver.component_avgCurrent 587.200012 mA 2020-08-26T17:14:51.890Z,1598462091.890 [Reporter](INFO): BackSeatDriver.component_avgCurrent 594.540039 mA 2020-08-26T17:15:01.572Z,1598462101.572 [Reporter](INFO): BackSeatDriver.component_avgCurrent 601.880005 mA 2020-08-26T17:15:11.672Z,1598462111.672 [Reporter](INFO): BackSeatDriver.component_avgCurrent 601.880005 mA 2020-08-26T17:15:21.490Z,1598462121.490 [BackSeatDriver](FAULT): Failed to receive device response within the specified timeout. 2020-08-26T17:15:21.490Z,1598462121.490 [BackSeatDriver] Communications Fault, FailCount= 2 2020-08-26T17:15:21.490Z,1598462121.490 [BackSeatDriver](ERROR): Communications Fault 2020-08-26T17:15:21.784Z,1598462121.784 [CBIT](ERROR): Communications Fault in component: BackSeatDriver 2020-08-26T17:15:21.895Z,1598462121.895 [BackSeatDriver](INFO): Sent LCM shutdown request. 2020-08-26T17:15:37.247Z,1598462137.247 [BackSeatDriver](INFO): Powering down 2020-08-26T17:15:37.569Z,1598462137.569 [Reporter](INFO): BackSeatDriver.component_avgCurrent no_value 2020-08-26T17:15:37.651Z,1598462137.651 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BackSeatDriverStatus 2020-08-26T17:15:37.651Z,1598462137.651 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BioLumProxies 2020-08-26T17:15:38.055Z,1598462138.055 [BackSeatDriver](INFO): Powering up 2020-08-26T17:15:38.055Z,1598462138.055 [BackSeatDriver](INFO): Subscribing to LCM channel: BackSeatDriverStatus 2020-08-26T17:15:38.056Z,1598462138.056 [BackSeatDriver](INFO): Subscribing to LCM channel: BioLumProxies 2020-08-26T17:15:38.354Z,1598462138.354 [CBIT](INFO): Clearing failed state for component BackSeatDriver 2020-08-26T17:15:38.354Z,1598462138.354 [BackSeatDriver] No Fault, FailCount= 2 2020-08-26T17:16:04.214Z,1598462164.214 [Reporter](INFO): BackSeatDriver.component_avgCurrent 528.479980 mA 2020-08-26T17:16:13.892Z,1598462173.892 [Reporter](INFO): BackSeatDriver.component_avgCurrent 675.280029 mA 2020-08-26T17:16:24.025Z,1598462184.025 [Reporter](INFO): BackSeatDriver.component_avgCurrent 726.660034 mA 2020-08-26T17:16:34.096Z,1598462194.096 [Reporter](INFO): BackSeatDriver.component_avgCurrent 678.950012 mA 2020-08-26T17:16:41.348Z,1598462201.348 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-08-26T17:16:41.348Z,1598462201.348 [NAL9602] Data Fault, FailCount= 5 2020-08-26T17:16:41.348Z,1598462201.348 [NAL9602](ERROR): Data Fault 2020-08-26T17:16:41.387Z,1598462201.387 [CBIT](ERROR): Data Fault in component: NAL9602 2020-08-26T17:16:41.387Z,1598462201.387 [CBIT](CRITICAL): Data Fault in component: NAL9602 2020-08-26T17:16:41.748Z,1598462201.748 [NAL9602](INFO): Powering down 2020-08-26T17:16:41.766Z,1598462201.766 [CommandLine](FAULT): Scheduling is paused 2020-08-26T17:16:41.767Z,1598462201.767 [CBIT](INFO): Critical error at 20200826T171641 2020-08-26T17:16:41.767Z,1598462201.767 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals 2020-08-26T17:16:42.168Z,1598462202.168 [MissionManager](INFO): MissionManager is completed. 2020-08-26T17:16:42.168Z,1598462202.168 [MissionManager](INFO): Uninitializing Mission Default 2020-08-26T17:16:42.168Z,1598462202.168 [Default] Stopped 2020-08-26T17:16:42.168Z,1598462202.168 [Default](DEBUG): Aggregate::uninitialize Default 2020-08-26T17:16:42.169Z,1598462202.169 [Default:B] Stopped 2020-08-26T17:16:42.169Z,1598462202.169 [Default:C.GoToSurface] Stopped 2020-08-26T17:16:42.169Z,1598462202.169 [Default:C.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-08-26T17:16:42.169Z,1598462202.169 [Default:CheckIn] Stopped 2020-08-26T17:16:42.169Z,1598462202.169 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-26T17:16:42.169Z,1598462202.169 [Default:CheckIn:Read_GPS] Stopped 2020-08-26T17:16:42.567Z,1598462202.567 [MissionManager](IMPORTANT): Started mission Default 2020-08-26T17:16:42.567Z,1598462202.567 [Default] Running Loop=1 2020-08-26T17:16:42.568Z,1598462202.568 [Default](DEBUG): Aggregate::initialize Default 2020-08-26T17:16:42.568Z,1598462202.568 [Default:B.GoToSurface] Running Loop=1 2020-08-26T17:16:42.568Z,1598462202.568 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2020-08-26T17:16:42.568Z,1598462202.568 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2020-08-26T17:16:42.568Z,1598462202.568 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2020-08-26T17:16:42.569Z,1598462202.569 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2020-08-26T17:16:42.569Z,1598462202.569 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2020-08-26T17:16:42.569Z,1598462202.569 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2020-08-26T17:16:42.570Z,1598462202.570 [Default:A.Wait] Running Loop=1 2020-08-26T17:16:42.570Z,1598462202.570 [Default:A.Wait](DEBUG): Initialize Wait Component. 2020-08-26T17:16:43.811Z,1598462203.811 [BackSeatDriver](INFO): Sent LCM shutdown request. 2020-08-26T17:16:55.891Z,1598462215.891 [Default:A.Wait](INFO): Done Waiting. 2020-08-26T17:16:55.891Z,1598462215.891 [Default:A.Wait] Stopped 2020-08-26T17:16:55.891Z,1598462215.891 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T17:16:56.304Z,1598462216.304 [Default:CheckIn] Running Loop=1 2020-08-26T17:16:56.305Z,1598462216.305 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-26T17:16:56.305Z,1598462216.305 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-26T17:16:59.162Z,1598462219.162 [BackSeatDriver](INFO): Powering down 2020-08-26T17:16:59.544Z,1598462219.544 [Reporter](INFO): BackSeatDriver.component_avgCurrent no_value 2020-08-26T17:16:59.567Z,1598462219.567 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BackSeatDriverStatus 2020-08-26T17:16:59.567Z,1598462219.567 [BackSeatDriver](INFO): Unsubscribing from LCM channel: BioLumProxies 2020-08-26T17:17:22.970Z,1598462242.970 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18 2020-08-26T17:17:22.970Z,1598462242.970 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:17:22.981Z,1598462242.981 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:17:23.391Z,1598462243.391 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:17:23.391Z,1598462243.391 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18 2020-08-26T17:18:41.757Z,1598462321.757 [CBIT](INFO): Clearing failed state for component NAL9602 2020-08-26T17:18:41.757Z,1598462321.757 [NAL9602] No Fault, FailCount= 5 2020-08-26T17:18:42.147Z,1598462322.147 [NAL9602](INFO): Powering up NAL9602 2020-08-26T17:18:53.048Z,1598462333.048 [NAL9602](INFO): NAL9602 initialized 2020-08-26T17:20:23.970Z,1598462423.970 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19 2020-08-26T17:20:23.970Z,1598462423.970 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:20:23.980Z,1598462423.980 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:20:24.400Z,1598462424.400 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:20:24.400Z,1598462424.400 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19 2020-08-26T17:21:56.475Z,1598462516.475 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T17:16:56.3Z 2020-08-26T17:21:56.475Z,1598462516.475 [Default:CheckIn:Read_GPS] Stopped 2020-08-26T17:21:56.475Z,1598462516.475 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-08-26T17:21:56.880Z,1598462516.880 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2020-08-26T17:21:58.504Z,1598462518.504 [DAT](INFO): DAT read: Rx Time:17:11:31.7882 2020-08-26T17:21:58.504Z,1598462518.504 [DAT](INFO): received an acoustic signal 2020-08-26T17:21:58.505Z,1598462518.505 [DAT](INFO): DAT read: 2020-08-26T17:21:58.506Z,1598462518.506 [DAT](INFO): DAT read: DATA(0002):~~ 2020-08-26T17:21:58.506Z,1598462518.506 [DAT](INFO): Got DATA 2 2020-08-26T17:21:58.507Z,1598462518.507 [DAT](INFO): DAT read: Source:006 Destination:009 2020-08-26T17:21:58.507Z,1598462518.507 [DAT](INFO): Got Src/Dest after DATA 2020-08-26T17:21:58.508Z,1598462518.508 [DAT](INFO): DATA Src=6, Dst=9 2020-08-26T17:21:58.510Z,1598462518.510 [DAT](INFO): DAT read: CRC:Pass MPD:13.2 PSNR:15.7 AGC:73 SPD:-00.1 CCERR:011 2020-08-26T17:21:58.510Z,1598462518.510 [DAT](INFO): Got CRC:Pass 2020-08-26T17:21:58.510Z,1598462518.510 [DAT](INFO): Got CRC:Pass 2020-08-26T17:21:58.510Z,1598462518.510 [DAT](INFO): Incoming data is intended for us 2020-08-26T17:21:58.510Z,1598462518.510 [DAT](INFO): Got ack 2020-08-26T17:21:58.511Z,1598462518.511 [DAT](INFO): DAT read: 2020-08-26T17:21:58.511Z,1598462518.511 [DAT](INFO): DAT read: 2020-08-26T17:21:58.512Z,1598462518.512 [DAT](INFO): DAT read: Rx Time:17:11:35.8883 2020-08-26T17:21:58.513Z,1598462518.513 [DAT](INFO): received an acoustic signal 2020-08-26T17:21:58.513Z,1598462518.513 [DAT](INFO): DAT read: 2020-08-26T17:21:58.514Z,1598462518.514 [DAT](INFO): DAT read: DATA(0004):+++ 2020-08-26T17:21:58.514Z,1598462518.514 [DAT](INFO): Got DATA 4 2020-08-26T17:21:58.551Z,1598462518.551 [DAT](INFO): DAT read: Source:006 Destination:009 2020-08-26T17:21:58.551Z,1598462518.551 [DAT](INFO): Got Src/Dest after DATA 2020-08-26T17:21:58.552Z,1598462518.552 [DAT](INFO): DATA Src=6, Dst=9 2020-08-26T17:21:58.553Z,1598462518.553 [DAT](INFO): DAT read: CRC:Pass MPD:12.4 PSNR:10.7 AGC:77 SPD:+00.1 CCERR:008 2020-08-26T17:21:58.553Z,1598462518.553 [DAT](INFO): Got CRC:Pass 2020-08-26T17:21:58.553Z,1598462518.553 [DAT](INFO): Got CRC:Pass 2020-08-26T17:21:58.553Z,1598462518.553 [DAT](INFO): Incoming data is intended for us 2020-08-26T17:21:58.558Z,1598462518.558 [DAT](INFO): Received command:+++ 2020-08-26T17:21:58.559Z,1598462518.559 [DAT](INFO): Sending ack 2020-08-26T17:21:58.560Z,1598462518.560 [DAT](INFO): DAT read: 2020-08-26T17:21:58.560Z,1598462518.560 [DAT](INFO): DAT read: 2020-08-26T17:21:59.893Z,1598462519.893 [DAT](INFO): #Outgoing data=1 2020-08-26T17:21:59.893Z,1598462519.893 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-26T17:22:01.976Z,1598462521.976 [DAT](INFO): DAT read: Forwarding Delay UpTx time:17:21:42.0282 2020-08-26T17:22:01.977Z,1598462521.977 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-26T17:22:03.902Z,1598462523.902 [DataOverHttps](INFO): Sending 105 bytes from file Logs/20200826T162253/Courier0016.lzma 2020-08-26T17:22:04.904Z,1598462524.904 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Courier0016.lzma.bak 2020-08-26T17:22:04.904Z,1598462524.904 [DataOverHttps](INFO): SBD MOMSN=12620566 2020-08-26T17:22:05.620Z,1598462525.620 [DAT](INFO): DAT read: Forwarding Delay UpTx time:17:21:45.5782 2020-08-26T17:22:05.620Z,1598462525.620 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-26T17:22:20.964Z,1598462540.964 [DAT](INFO): DAT read: Rx Time:17:22:00.4476 2020-08-26T17:22:20.964Z,1598462540.964 [DAT](INFO): received an acoustic signal 2020-08-26T17:22:21.375Z,1598462541.375 [DAT](INFO): DAT read: 2020-08-26T17:22:21.376Z,1598462541.376 [DAT](INFO): DAT read: $Packet for address 0 2020-08-26T17:22:21.376Z,1598462541.376 [DAT](INFO): received a packet notification 2020-08-26T17:22:22.154Z,1598462542.154 [DataOverHttps](INFO): Sending 287 bytes from file Logs/20200826T162253/Express0005.lzma 2020-08-26T17:22:22.165Z,1598462542.165 [DAT](FAULT): Ack receipt timeout failure. 2020-08-26T17:22:22.165Z,1598462542.165 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2020-08-26T17:22:22.573Z,1598462542.573 [DAT](INFO): Sent 105 bytes from file Logs/20200826T162253/Courier0016.lzma.parts 2020-08-26T17:22:22.573Z,1598462542.573 [DAT](INFO): Packets left to send: 0 2020-08-26T17:22:22.575Z,1598462542.575 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2020-08-26T17:22:23.152Z,1598462543.152 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Express0005.lzma.bak 2020-08-26T17:22:23.152Z,1598462543.152 [DataOverHttps](INFO): SBD MOMSN=12620571 2020-08-26T17:22:23.739Z,1598462543.739 [Default:CheckIn:Read_Iridium] Stopped 2020-08-26T17:22:23.739Z,1598462543.739 [Default:CheckIn:C.Wait] Running Loop=1 2020-08-26T17:22:23.739Z,1598462543.739 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-08-26T17:23:25.186Z,1598462605.186 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20 2020-08-26T17:23:25.186Z,1598462605.186 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:23:25.196Z,1598462605.196 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:23:25.609Z,1598462605.609 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:23:25.610Z,1598462605.610 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20 2020-08-26T17:26:26.169Z,1598462786.169 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21 2020-08-26T17:26:26.169Z,1598462786.169 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:26:26.207Z,1598462786.207 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:26:26.584Z,1598462786.584 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:26:26.584Z,1598462786.584 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21 2020-08-26T17:27:23.953Z,1598462843.953 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-08-26T17:27:23.953Z,1598462843.953 [Default:CheckIn:C.Wait] Stopped 2020-08-26T17:27:23.953Z,1598462843.953 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T17:27:23.953Z,1598462843.953 [Default:CheckIn:D] Running Loop=1 2020-08-26T17:27:24.367Z,1598462844.367 [Default:CheckIn:D] Stopped 2020-08-26T17:27:24.368Z,1598462844.368 [Default:CheckIn:E] Running Loop=1 2020-08-26T17:27:24.762Z,1598462844.762 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.696664 min 2020-08-26T17:27:24.762Z,1598462844.762 [Default:CheckIn:E] Stopped 2020-08-26T17:27:24.762Z,1598462844.762 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-08-26T17:27:24.762Z,1598462844.762 [Default:CheckIn] Stopped 2020-08-26T17:27:24.763Z,1598462844.763 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-26T17:27:24.763Z,1598462844.763 [Default:CheckIn](INFO): Running loop #2 2020-08-26T17:27:24.763Z,1598462844.763 [Default:CheckIn] Running Loop=2 2020-08-26T17:27:24.763Z,1598462844.763 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-26T17:27:24.763Z,1598462844.763 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-26T17:28:55.236Z,1598462935.236 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-08-26T17:28:55.236Z,1598462935.236 [NAL9602] Data Fault, FailCount= 1 2020-08-26T17:28:55.236Z,1598462935.236 [NAL9602](ERROR): Data Fault 2020-08-26T17:28:55.252Z,1598462935.252 [CBIT](ERROR): Data Fault in component: NAL9602 2020-08-26T17:28:55.639Z,1598462935.639 [NAL9602](INFO): Powering down 2020-08-26T17:28:56.484Z,1598462936.484 [CBIT](INFO): Clearing failed state for component NAL9602 2020-08-26T17:28:56.484Z,1598462936.484 [NAL9602] No Fault, FailCount= 1 2020-08-26T17:29:25.940Z,1598462965.940 [NAL9602](INFO): Powering up NAL9602 2020-08-26T17:29:27.161Z,1598462967.161 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22 2020-08-26T17:29:27.161Z,1598462967.161 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:29:27.199Z,1598462967.199 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:29:27.568Z,1598462967.568 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:29:27.568Z,1598462967.568 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22 2020-08-26T17:29:36.857Z,1598462976.857 [NAL9602](INFO): NAL9602 initialized 2020-08-26T17:32:24.920Z,1598463144.920 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T17:27:24.8Z 2020-08-26T17:32:24.920Z,1598463144.920 [Default:CheckIn:Read_GPS] Stopped 2020-08-26T17:32:24.920Z,1598463144.920 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-08-26T17:32:28.321Z,1598463148.321 [DAT](INFO): #Outgoing data=1 2020-08-26T17:32:28.321Z,1598463148.321 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-26T17:32:28.366Z,1598463148.366 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23 2020-08-26T17:32:28.366Z,1598463148.366 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:32:28.376Z,1598463148.376 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:32:28.433Z,1598463148.433 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-26T17:32:28.522Z,1598463148.522 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:32:28.522Z,1598463148.522 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23 2020-08-26T17:32:32.040Z,1598463152.040 [DAT](INFO): DAT read: Forwarding Delay UpTx time:17:32:11.9749 2020-08-26T17:32:32.040Z,1598463152.040 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-26T17:32:32.566Z,1598463152.566 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200826T162253/Courier0019.lzma 2020-08-26T17:32:33.568Z,1598463153.568 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Courier0019.lzma.bak 2020-08-26T17:32:33.568Z,1598463153.568 [DataOverHttps](INFO): SBD MOMSN=12620614 2020-08-26T17:32:36.499Z,1598463156.499 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T17:32:43.355Z,1598463163.355 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T17:32:48.592Z,1598463168.592 [DAT](FAULT): Ack receipt timeout failure. 2020-08-26T17:32:48.592Z,1598463168.592 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2020-08-26T17:32:48.993Z,1598463168.993 [DAT](INFO): Sent 39 bytes from file Logs/20200826T162253/Courier0019.lzma.parts 2020-08-26T17:32:48.994Z,1598463168.994 [DAT](INFO): Packets left to send: 0 2020-08-26T17:32:48.996Z,1598463168.996 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2020-08-26T17:32:49.408Z,1598463169.408 [DAT](INFO): DAT read: Rx Time:17:32:29.1572 2020-08-26T17:32:49.409Z,1598463169.409 [DAT](INFO): received an acoustic signal 2020-08-26T17:32:50.572Z,1598463170.572 [Default:CheckIn:Read_Iridium] Stopped 2020-08-26T17:32:50.573Z,1598463170.573 [Default:CheckIn:C.Wait] Running Loop=1 2020-08-26T17:32:50.573Z,1598463170.573 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-08-26T17:32:51.219Z,1598463171.219 [DataOverHttps](INFO): Sending 688 bytes from file Logs/20200826T162253/Express0008.lzma 2020-08-26T17:32:52.220Z,1598463172.220 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Express0008.lzma.bak 2020-08-26T17:32:52.220Z,1598463172.220 [DataOverHttps](INFO): SBD MOMSN=12620619 2020-08-26T17:34:17.527Z,1598463257.527 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T17:35:28.989Z,1598463328.989 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24 2020-08-26T17:35:28.989Z,1598463328.989 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:35:29.008Z,1598463329.008 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:35:29.416Z,1598463329.416 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:35:29.416Z,1598463329.416 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24 2020-08-26T17:35:52.230Z,1598463352.230 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T17:36:16.285Z,1598463376.285 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T17:36:28.037Z,1598463388.037 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T17:37:17.318Z,1598463437.318 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2020-08-26T17:37:50.827Z,1598463470.827 [Default:CheckIn:C.Wait](INFO): Done Waiting. 2020-08-26T17:37:50.827Z,1598463470.827 [Default:CheckIn:C.Wait] Stopped 2020-08-26T17:37:50.827Z,1598463470.827 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T17:37:50.828Z,1598463470.828 [Default:CheckIn:D] Running Loop=1 2020-08-26T17:37:51.207Z,1598463471.207 [Default:CheckIn:D] Stopped 2020-08-26T17:37:51.207Z,1598463471.207 [Default:CheckIn:E] Running Loop=1 2020-08-26T17:37:51.620Z,1598463471.620 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.143990 min 2020-08-26T17:37:51.620Z,1598463471.620 [Default:CheckIn:E] Stopped 2020-08-26T17:37:51.620Z,1598463471.620 [Default:CheckIn](INFO): Completed Default:CheckIn 2020-08-26T17:37:51.620Z,1598463471.620 [Default:CheckIn] Stopped 2020-08-26T17:37:51.620Z,1598463471.620 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-26T17:37:51.620Z,1598463471.620 [Default:CheckIn](INFO): Running loop #3 2020-08-26T17:37:51.620Z,1598463471.620 [Default:CheckIn] Running Loop=3 2020-08-26T17:37:51.621Z,1598463471.621 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2020-08-26T17:37:51.621Z,1598463471.621 [Default:CheckIn:Read_GPS] Running Loop=1 2020-08-26T17:38:29.636Z,1598463509.636 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size. 2020-08-26T17:38:30.027Z,1598463510.027 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 25 2020-08-26T17:38:30.027Z,1598463510.027 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:38:30.037Z,1598463510.037 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:38:30.447Z,1598463510.447 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:38:30.447Z,1598463510.447 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 25 2020-08-26T17:38:32.017Z,1598463512.017 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6. 2020-08-26T17:38:32.019Z,1598463512.019 [BPC1](INFO): Received data from all battery sticks. 2020-08-26T17:39:37.856Z,1598463577.856 [NAL9602](FAULT): GPS failed to acquire within timeout. 2020-08-26T17:39:37.856Z,1598463577.856 [NAL9602] Data Fault, FailCount= 2 2020-08-26T17:39:37.856Z,1598463577.856 [NAL9602](ERROR): Data Fault 2020-08-26T17:39:37.872Z,1598463577.872 [CBIT](ERROR): Data Fault in component: NAL9602 2020-08-26T17:39:38.252Z,1598463578.252 [NAL9602](INFO): Powering down 2020-08-26T17:39:39.083Z,1598463579.083 [CBIT](INFO): Clearing failed state for component NAL9602 2020-08-26T17:39:39.083Z,1598463579.083 [NAL9602] No Fault, FailCount= 2 2020-08-26T17:40:08.557Z,1598463608.557 [NAL9602](INFO): Powering up NAL9602 2020-08-26T17:40:19.472Z,1598463619.472 [NAL9602](INFO): NAL9602 initialized 2020-08-26T17:41:30.989Z,1598463690.989 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 26 2020-08-26T17:41:30.989Z,1598463690.989 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:41:31.022Z,1598463691.022 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:41:31.403Z,1598463691.403 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:41:31.404Z,1598463691.404 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 26 2020-08-26T17:42:51.804Z,1598463771.804 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T17:37:51.6Z 2020-08-26T17:42:51.804Z,1598463771.804 [Default:CheckIn:Read_GPS] Stopped 2020-08-26T17:42:51.804Z,1598463771.804 [Default:CheckIn:Read_Iridium] Running Loop=1 2020-08-26T17:42:54.471Z,1598463774.471 [DAT](INFO): DAT read: 2020-08-26T17:42:54.472Z,1598463774.472 [DAT](INFO): DAT read: DATA(0002):~~ 2020-08-26T17:42:54.473Z,1598463774.473 [DAT](INFO): Got DATA 2 2020-08-26T17:42:54.474Z,1598463774.474 [DAT](INFO): DAT read: Source:006 Destination:009 2020-08-26T17:42:54.474Z,1598463774.474 [DAT](INFO): Got Src/Dest after DATA 2020-08-26T17:42:54.511Z,1598463774.511 [DAT](INFO): DATA Src=6, Dst=9 2020-08-26T17:42:54.512Z,1598463774.512 [DAT](INFO): DAT read: CRC:Pass MPD:11.5 PSNR:15.1 AGC:76 SPD:+00.0 CCERR:010 2020-08-26T17:42:54.513Z,1598463774.513 [DAT](INFO): Got CRC:Pass 2020-08-26T17:42:54.513Z,1598463774.513 [DAT](INFO): Got CRC:Pass 2020-08-26T17:42:54.513Z,1598463774.513 [DAT](INFO): Incoming data is intended for us 2020-08-26T17:42:54.513Z,1598463774.513 [DAT](INFO): Got ack 2020-08-26T17:42:54.513Z,1598463774.513 [DAT](INFO): DAT read: 2020-08-26T17:42:54.514Z,1598463774.514 [DAT](INFO): DAT read: 2020-08-26T17:42:54.523Z,1598463774.523 [DAT](INFO): DAT read: Rx Time:17:32:33.2586 2020-08-26T17:42:54.523Z,1598463774.523 [DAT](INFO): received an acoustic signal 2020-08-26T17:42:54.524Z,1598463774.524 [DAT](INFO): DAT read: 2020-08-26T17:42:54.524Z,1598463774.524 [DAT](INFO): DAT read: DATA(0004):+++ 2020-08-26T17:42:54.525Z,1598463774.525 [DAT](INFO): Got DATA 4 2020-08-26T17:42:54.525Z,1598463774.525 [DAT](INFO): DAT read: Source:006 Destination:009 2020-08-26T17:42:54.526Z,1598463774.526 [DAT](INFO): Got Src/Dest after DATA 2020-08-26T17:42:54.526Z,1598463774.526 [DAT](INFO): DATA Src=6, Dst=9 2020-08-26T17:42:54.536Z,1598463774.536 [DAT](INFO): DAT read: CRC:Pass MPD:13.3 PSNR:15.0 AGC:77 SPD:+00.0 CCERR:011 2020-08-26T17:42:54.536Z,1598463774.536 [DAT](INFO): Got CRC:Pass 2020-08-26T17:42:54.536Z,1598463774.536 [DAT](INFO): Got CRC:Pass 2020-08-26T17:42:54.536Z,1598463774.536 [DAT](INFO): Incoming data is intended for us 2020-08-26T17:42:54.537Z,1598463774.537 [DAT](INFO): Received command:+++ 2020-08-26T17:42:54.538Z,1598463774.538 [DAT](INFO): Sending ack 2020-08-26T17:42:54.558Z,1598463774.558 [DAT](INFO): DAT read: 2020-08-26T17:42:54.559Z,1598463774.559 [DAT](INFO): DAT read: 2020-08-26T17:42:57.465Z,1598463777.465 [DAT](INFO): #Outgoing data=1 2020-08-26T17:42:57.465Z,1598463777.465 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2020-08-26T17:42:57.946Z,1598463777.946 [DAT](INFO): DAT read: Forwarding Delay UpTx time:17:42:38.0214 2020-08-26T17:42:57.946Z,1598463777.946 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2020-08-26T17:43:01.178Z,1598463781.178 [DAT](INFO): DAT read: Forwarding Delay UpTx time:17:42:41.4714 2020-08-26T17:43:01.178Z,1598463781.178 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING 2020-08-26T17:43:09.689Z,1598463789.689 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20200826T162253/Courier0022.lzma 2020-08-26T17:43:10.736Z,1598463790.736 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Courier0022.lzma.bak 2020-08-26T17:43:10.736Z,1598463790.736 [DataOverHttps](INFO): SBD MOMSN=12620732 2020-08-26T17:43:18.176Z,1598463798.176 [DAT](FAULT): Ack receipt timeout failure. 2020-08-26T17:43:18.176Z,1598463798.176 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED 2020-08-26T17:43:18.551Z,1598463798.551 [DAT](INFO): DAT read: Rx Time:17:42:58.3170 2020-08-26T17:43:18.551Z,1598463798.551 [DAT](INFO): received an acoustic signal 2020-08-26T17:43:18.551Z,1598463798.551 [DAT](INFO): Sent 50 bytes from file Logs/20200826T162253/Courier0022.lzma.parts 2020-08-26T17:43:18.552Z,1598463798.552 [DAT](INFO): Packets left to send: 0 2020-08-26T17:43:18.554Z,1598463798.554 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER 2020-08-26T17:43:22.210Z,1598463802.210 [Default:CheckIn:Read_Iridium] Stopped 2020-08-26T17:43:22.211Z,1598463802.211 [Default:CheckIn:C.Wait] Running Loop=1 2020-08-26T17:43:22.211Z,1598463802.211 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2020-08-26T17:44:21.824Z,1598463861.824 [DataOverHttps](INFO): Sending 254 bytes from file Logs/20200826T162253/Express0011.lzma 2020-08-26T17:44:22.824Z,1598463862.824 [DataOverHttps](INFO): Moved sent file to Logs/20200826T162253/Express0011.lzma.bak 2020-08-26T17:44:22.824Z,1598463862.824 [DataOverHttps](INFO): SBD MOMSN=12620741 2020-08-26T17:44:31.881Z,1598463871.881 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 27 2020-08-26T17:44:31.881Z,1598463871.881 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2020-08-26T17:44:31.891Z,1598463871.891 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2020-08-26T17:44:32.307Z,1598463872.307 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2020-08-26T17:44:32.307Z,1598463872.307 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 27 2020-08-26T17:45:33.512Z,1598463933.512 [DataOverHttps](IMPORTANT): SBD MTMSN=20200826T174532 2020-08-26T17:45:43.343Z,1598463943.343 [DataOverHttps](INFO): Received command:restart app 2020-08-26T17:45:43.380Z,1598463943.380 [CommandLine](IMPORTANT): got command restart application 2020-08-26T17:45:44.415Z,1598463944.415 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-26T17:45:44.415Z,1598463944.415 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:44.554Z,1598463944.554 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2020-08-26T17:45:44.555Z,1598463944.555 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:44.555Z,1598463944.555 [CommandLine](INFO): Join timeout helper Thread ID is 2667 2020-08-26T17:45:44.556Z,1598463944.556 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2020-08-26T17:45:44.556Z,1598463944.556 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:44.557Z,1598463944.557 [NavChartDb](INFO): Join timeout helper Thread ID is 2668 2020-08-26T17:45:44.951Z,1598463944.951 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-26T17:45:44.951Z,1598463944.951 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:44.958Z,1598463944.958 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2020-08-26T17:45:44.958Z,1598463944.958 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:44.959Z,1598463944.959 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2669 2020-08-26T17:45:45.111Z,1598463945.111 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-26T17:45:45.111Z,1598463945.111 [WetLabsBB2FL](INFO): Powering down 2020-08-26T17:45:45.112Z,1598463945.112 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:45.118Z,1598463945.118 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2020-08-26T17:45:45.118Z,1598463945.118 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:45.119Z,1598463945.119 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2670 2020-08-26T17:45:45.599Z,1598463945.599 [CTD_Seabird](INFO): Powering down 2020-08-26T17:45:45.610Z,1598463945.610 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-26T17:45:45.611Z,1598463945.611 [CTD_Seabird](INFO): Powering down 2020-08-26T17:45:45.623Z,1598463945.623 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:45.623Z,1598463945.623 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler 2020-08-26T17:45:45.623Z,1598463945.623 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:45.623Z,1598463945.623 [BackSeatDriver](INFO): Join timeout helper Thread ID is 2671 2020-08-26T17:45:45.719Z,1598463945.719 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-26T17:45:45.719Z,1598463945.719 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:45.724Z,1598463945.724 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2020-08-26T17:45:45.724Z,1598463945.724 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:45.725Z,1598463945.725 [Radio_Surface](INFO): Join timeout helper Thread ID is 2672 2020-08-26T17:45:46.126Z,1598463946.126 [Radio_Surface](INFO): Powering down 2020-08-26T17:45:46.127Z,1598463946.127 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-26T17:45:46.128Z,1598463946.128 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:46.139Z,1598463946.139 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2020-08-26T17:45:46.139Z,1598463946.139 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:46.140Z,1598463946.140 [Onboard](INFO): Join timeout helper Thread ID is 2673 2020-08-26T17:45:46.351Z,1598463946.351 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2020-08-26T17:45:49.251Z,1598463949.251 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-26T17:45:49.251Z,1598463949.251 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:49.258Z,1598463949.258 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2020-08-26T17:45:49.259Z,1598463949.259 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:49.259Z,1598463949.259 [DataOverHttps](INFO): Join timeout helper Thread ID is 2674 2020-08-26T17:45:49.363Z,1598463949.363 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-26T17:45:49.363Z,1598463949.363 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:49.379Z,1598463949.379 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2020-08-26T17:45:49.379Z,1598463949.379 [logger ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:49.380Z,1598463949.380 [logger](INFO): Join timeout helper Thread ID is 2675 2020-08-26T17:45:49.411Z,1598463949.411 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-26T17:45:49.411Z,1598463949.411 [logger ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:49.419Z,1598463949.419 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2020-08-26T17:45:49.419Z,1598463949.419 [CommandLine ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:49.419Z,1598463949.419 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2020-08-26T17:45:49.419Z,1598463949.419 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:49.420Z,1598463949.420 [controlThread](INFO): Join timeout helper Thread ID is 2676 2020-08-26T17:45:49.426Z,1598463949.426 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2020-08-26T17:45:49.427Z,1598463949.427 [controlThread](DEBUG): Uninitializing ControlThread 2020-08-26T17:45:49.427Z,1598463949.427 [AHRS_M2](INFO): Powering down 2020-08-26T17:45:49.499Z,1598463949.499 [NAL9602](INFO): Powering down 2020-08-26T17:45:49.500Z,1598463949.500 [DAT](INFO): Powering down 2020-08-26T17:45:49.786Z,1598463949.786 [AMEcho](INFO): Powering down 2020-08-26T17:45:49.788Z,1598463949.788 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2020-08-26T17:45:49.788Z,1598463949.788 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2020-08-26T17:45:49.789Z,1598463949.789 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2020-08-26T17:45:49.789Z,1598463949.789 [MissionManager](INFO): Uninitializing Mission Default 2020-08-26T17:45:49.790Z,1598463949.790 [Default] Stopped 2020-08-26T17:45:49.790Z,1598463949.790 [Default](DEBUG): Aggregate::uninitialize Default 2020-08-26T17:45:49.790Z,1598463949.790 [Default:B.GoToSurface] Stopped 2020-08-26T17:45:49.790Z,1598463949.790 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2020-08-26T17:45:49.790Z,1598463949.790 [Default:CheckIn] Stopped 2020-08-26T17:45:49.790Z,1598463949.790 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2020-08-26T17:45:49.790Z,1598463949.790 [Default:CheckIn:C.Wait] Stopped 2020-08-26T17:45:49.790Z,1598463949.790 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2020-08-26T17:45:49.793Z,1598463949.793 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2020-08-26T17:45:49.793Z,1598463949.793 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2020-08-26T17:45:49.793Z,1598463949.793 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2020-08-26T17:45:49.794Z,1598463949.794 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2020-08-26T17:45:49.794Z,1598463949.794 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2020-08-26T17:45:49.794Z,1598463949.794 [BuoyancyServo](INFO): Powering down 2020-08-26T17:45:49.806Z,1598463949.806 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2020-08-26T17:45:49.807Z,1598463949.807 [ElevatorServo](INFO): Powering down 2020-08-26T17:45:49.807Z,1598463949.807 [MassServo](DEBUG): Uninitialize Mass Servo. 2020-08-26T17:45:49.807Z,1598463949.807 [MassServo](INFO): Powering down 2020-08-26T17:45:49.808Z,1598463949.808 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2020-08-26T17:45:49.808Z,1598463949.808 [RudderServo](INFO): Powering down 2020-08-26T17:45:49.809Z,1598463949.809 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2020-08-26T17:45:49.809Z,1598463949.809 [ThrusterServo](INFO): Powering down 2020-08-26T17:45:49.810Z,1598463949.810 [SBIT](DEBUG): Uninitialize SBIT Component. 2020-08-26T17:45:49.810Z,1598463949.810 [IBIT](DEBUG): Uninitialize IBIT Component. 2020-08-26T17:45:49.811Z,1598463949.811 [CBIT](DEBUG): Uninitialize CBIT Component. 2020-08-26T17:45:49.811Z,1598463949.811 [CBIT](DEBUG): Powering off loads. 2020-08-26T17:45:49.822Z,1598463949.822 [CBIT](DEBUG): Disabling WDT. 2020-08-26T17:45:49.834Z,1598463949.834 [CBIT](DEBUG): Opening all GF detection circuits. 2020-08-26T17:45:49.835Z,1598463949.835 [controlThread ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:49.946Z,1598463949.946 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:49.949Z,1598463949.949 [Onboard ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:49.954Z,1598463949.954 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:50.027Z,1598463950.027 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:50.030Z,1598463950.030 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:50.033Z,1598463950.033 [BackSeatDriver ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:50.049Z,1598463950.049 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2020-08-26T17:45:50.112Z,1598463950.112 [logger ThreadHandler](INFO): Thread cancelled.