2020-08-25T15:36:01.142Z,1598369761.142 [Supervisor](DEBUG): Initializing supervisor.
2020-08-25T15:36:01.145Z,1598369761.145 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-08-25T15:36:01.145Z,1598369761.145 [SyncHandler](INFO): Protected caller Thread ID is 1388
2020-08-25T15:36:01.145Z,1598369761.145 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-08-25T15:36:01.146Z,1598369761.146 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-08-25T15:36:01.147Z,1598369761.147 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1389
2020-08-25T15:36:01.149Z,1598369761.149 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-08-25T15:36:01.162Z,1598369761.162 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-08-25T15:36:01.163Z,1598369761.163 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-08-25T15:36:01.163Z,1598369761.163 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1390
2020-08-25T15:36:01.164Z,1598369761.164 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-08-25T15:36:01.165Z,1598369761.165 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-08-25T15:36:01.165Z,1598369761.165 [logger ThreadHandler](INFO): Protected caller Thread ID is 1391
2020-08-25T15:36:01.167Z,1598369761.167 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-08-25T15:36:01.168Z,1598369761.168 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-08-25T15:36:01.169Z,1598369761.169 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-08-25T15:36:01.264Z,1598369761.264 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-08-25T15:36:01.265Z,1598369761.265 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-08-25T15:36:01.846Z,1598369761.846 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-08-25T15:36:01.846Z,1598369761.846 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-08-25T15:36:02.037Z,1598369762.037 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-08-25T15:36:02.037Z,1598369762.037 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-08-25T15:36:02.137Z,1598369762.137 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-08-25T15:36:02.138Z,1598369762.138 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-08-25T15:36:02.247Z,1598369762.247 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-08-25T15:36:02.248Z,1598369762.248 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-08-25T15:36:02.416Z,1598369762.416 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-08-25T15:36:02.687Z,1598369762.687 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-08-25T15:36:02.688Z,1598369762.688 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-08-25T15:36:02.972Z,1598369762.972 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-08-25T15:36:02.973Z,1598369762.973 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-08-25T15:36:03.417Z,1598369763.417 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-08-25T15:36:03.418Z,1598369763.418 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-08-25T15:36:03.560Z,1598369763.560 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-08-25T15:36:03.561Z,1598369763.561 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-08-25T15:36:03.745Z,1598369763.745 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-08-25T15:36:03.746Z,1598369763.746 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-08-25T15:36:04.204Z,1598369764.204 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-08-25T15:36:04.204Z,1598369764.204 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-08-25T15:36:04.417Z,1598369764.417 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-08-25T15:36:04.418Z,1598369764.418 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-08-25T15:36:04.618Z,1598369764.618 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-08-25T15:36:04.619Z,1598369764.619 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-08-25T15:36:05.020Z,1598369765.020 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-08-25T15:36:05.021Z,1598369765.021 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-08-25T15:36:05.346Z,1598369765.346 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-08-25T15:36:05.348Z,1598369765.348 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-08-25T15:36:05.349Z,1598369765.349 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-08-25T15:36:05.432Z,1598369765.432 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-08-25T15:36:05.589Z,1598369765.589 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-08-25T15:36:05.696Z,1598369765.696 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-08-25T15:36:05.782Z,1598369765.782 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-08-25T15:36:05.876Z,1598369765.876 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-08-25T15:36:06.075Z,1598369766.075 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-08-25T15:36:06.306Z,1598369766.306 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-08-25T15:36:06.306Z,1598369766.306 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-08-25T15:36:06.401Z,1598369766.401 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-08-25T15:36:06.500Z,1598369766.500 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-08-25T15:36:06.630Z,1598369766.630 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-08-25T15:36:06.730Z,1598369766.730 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-08-25T15:36:06.740Z,1598369766.740 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-08-25T15:36:06.815Z,1598369766.815 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-08-25T15:36:06.816Z,1598369766.816 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-08-25T15:36:06.862Z,1598369766.862 [VerticalControl](DEBUG): Construct VerticalControl.
2020-08-25T15:36:06.970Z,1598369766.970 [VerticalControl] Loaded
2020-08-25T15:36:06.971Z,1598369766.971 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-08-25T15:36:06.971Z,1598369766.971 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-08-25T15:36:07.048Z,1598369767.048 [HorizontalControl] Loaded
2020-08-25T15:36:07.048Z,1598369767.048 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-08-25T15:36:07.049Z,1598369767.049 [SpeedControl](DEBUG): Construct SpeedControl.
2020-08-25T15:36:07.054Z,1598369767.054 [SpeedControl] Loaded
2020-08-25T15:36:07.054Z,1598369767.054 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-08-25T15:36:07.055Z,1598369767.055 [LoopControl](DEBUG): Construct LoopControl.
2020-08-25T15:36:07.055Z,1598369767.055 [LoopControl] Loaded
2020-08-25T15:36:07.055Z,1598369767.055 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-08-25T15:36:07.056Z,1598369767.056 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-08-25T15:36:07.056Z,1598369767.056 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-08-25T15:36:07.096Z,1598369767.096 [DepthRateCalculator] Loaded
2020-08-25T15:36:07.096Z,1598369767.096 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-08-25T15:36:07.101Z,1598369767.101 [PitchRateCalculator] Loaded
2020-08-25T15:36:07.101Z,1598369767.101 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-08-25T15:36:07.116Z,1598369767.116 [SpeedCalculator] Loaded
2020-08-25T15:36:07.117Z,1598369767.117 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-08-25T15:36:07.137Z,1598369767.137 [TempGradientCalculator] Loaded
2020-08-25T15:36:07.137Z,1598369767.137 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-08-25T15:36:07.142Z,1598369767.142 [YawRateCalculator] Loaded
2020-08-25T15:36:07.142Z,1598369767.142 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-08-25T15:36:07.170Z,1598369767.170 [ElevatorOffsetCalculator] Loaded
2020-08-25T15:36:07.170Z,1598369767.170 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-08-25T15:36:07.171Z,1598369767.171 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-08-25T15:36:07.171Z,1598369767.171 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-08-25T15:36:07.196Z,1598369767.196 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-08-25T15:36:07.197Z,1598369767.197 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-08-25T15:36:07.278Z,1598369767.278 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-08-25T15:36:07.278Z,1598369767.278 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-08-25T15:36:07.921Z,1598369767.921 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-08-25T15:36:07.922Z,1598369767.922 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-08-25T15:36:08.038Z,1598369768.038 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-08-25T15:36:08.039Z,1598369768.039 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-08-25T15:36:08.372Z,1598369768.372 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-08-25T15:36:08.377Z,1598369768.377 [AHRS_M2](INFO): created writer for : platform_orientation
2020-08-25T15:36:08.379Z,1598369768.379 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-08-25T15:36:08.384Z,1598369768.384 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-08-25T15:36:08.384Z,1598369768.384 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-08-25T15:36:08.389Z,1598369768.389 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-08-25T15:36:08.390Z,1598369768.390 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-08-25T15:36:08.395Z,1598369768.395 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-08-25T15:36:08.464Z,1598369768.464 [AHRS_M2] Loaded
2020-08-25T15:36:08.464Z,1598369768.464 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-08-25T15:36:08.541Z,1598369768.541 [DataOverHttps] Loaded
2020-08-25T15:36:08.541Z,1598369768.541 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-08-25T15:36:08.542Z,1598369768.542 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0
2020-08-25T15:36:08.543Z,1598369768.543 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1473
2020-08-25T15:36:08.572Z,1598369768.572 [Depth_Keller] Loaded
2020-08-25T15:36:08.572Z,1598369768.572 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-08-25T15:36:08.681Z,1598369768.681 [NAL9602] Loaded
2020-08-25T15:36:08.682Z,1598369768.682 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-08-25T15:36:08.729Z,1598369768.729 [Onboard] Loaded
2020-08-25T15:36:08.729Z,1598369768.729 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-08-25T15:36:08.730Z,1598369768.730 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0
2020-08-25T15:36:08.730Z,1598369768.730 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1474
2020-08-25T15:36:08.749Z,1598369768.749 [Radio_Surface] Loaded
2020-08-25T15:36:08.749Z,1598369768.749 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-08-25T15:36:08.750Z,1598369768.750 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2020-08-25T15:36:08.751Z,1598369768.751 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1475
2020-08-25T15:36:08.774Z,1598369768.774 [DAT](CRITICAL): No configuration setting for: DAT.maxAckTimeouts
2020-08-25T15:36:08.903Z,1598369768.903 [DAT] Loaded
2020-08-25T15:36:08.903Z,1598369768.903 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-08-25T15:36:10.364Z,1598369770.364 [BPC1] Loaded
2020-08-25T15:36:10.364Z,1598369770.364 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-08-25T15:36:10.395Z,1598369770.395 [AMEcho] Loaded
2020-08-25T15:36:10.396Z,1598369770.396 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread.
2020-08-25T15:36:10.396Z,1598369770.396 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-08-25T15:36:10.397Z,1598369770.397 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-08-25T15:36:10.509Z,1598369770.509 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-08-25T15:36:10.509Z,1598369770.509 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-08-25T15:36:10.529Z,1598369770.529 [NavChart] Loaded
2020-08-25T15:36:10.529Z,1598369770.529 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-08-25T15:36:10.533Z,1598369770.533 [UniversalFixResidualReporter] Loaded
2020-08-25T15:36:10.534Z,1598369770.534 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-08-25T15:36:10.534Z,1598369770.534 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-08-25T15:36:10.535Z,1598369770.535 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-08-25T15:36:10.665Z,1598369770.665 [SBIT](DEBUG): Construct Startup Built In Test.
2020-08-25T15:36:10.676Z,1598369770.676 [SBIT] Loaded
2020-08-25T15:36:10.676Z,1598369770.676 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-08-25T15:36:10.677Z,1598369770.677 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-08-25T15:36:10.689Z,1598369770.689 [IBIT] Loaded
2020-08-25T15:36:10.689Z,1598369770.689 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-08-25T15:36:10.692Z,1598369770.692 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-08-25T15:36:10.827Z,1598369770.827 [CBIT] Loaded
2020-08-25T15:36:10.827Z,1598369770.827 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-08-25T15:36:10.827Z,1598369770.827 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-08-25T15:36:10.828Z,1598369770.828 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-08-25T15:36:10.946Z,1598369770.946 [BuoyancyServo] Loaded
2020-08-25T15:36:10.946Z,1598369770.946 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-08-25T15:36:10.973Z,1598369770.973 [ElevatorServo] Loaded
2020-08-25T15:36:10.974Z,1598369770.974 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-08-25T15:36:11.001Z,1598369771.001 [MassServo] Loaded
2020-08-25T15:36:11.001Z,1598369771.001 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-08-25T15:36:11.028Z,1598369771.028 [RudderServo] Loaded
2020-08-25T15:36:11.028Z,1598369771.028 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-08-25T15:36:11.054Z,1598369771.054 [ThrusterServo] Loaded
2020-08-25T15:36:11.054Z,1598369771.054 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-08-25T15:36:11.055Z,1598369771.055 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-08-25T15:36:11.055Z,1598369771.055 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-08-25T15:36:11.073Z,1598369771.073 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-08-25T15:36:11.074Z,1598369771.074 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-08-25T15:36:11.304Z,1598369771.304 [BackSeatDriver] Loaded
2020-08-25T15:36:11.304Z,1598369771.304 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2020-08-25T15:36:11.305Z,1598369771.305 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2020-08-25T15:36:11.306Z,1598369771.306 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 1476
2020-08-25T15:36:11.333Z,1598369771.333 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-08-25T15:36:11.339Z,1598369771.339 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-08-25T15:36:11.339Z,1598369771.339 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-08-25T15:36:11.344Z,1598369771.344 [CTD_Seabird](INFO): created writer for : depth
2020-08-25T15:36:11.344Z,1598369771.344 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-08-25T15:36:11.349Z,1598369771.349 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-08-25T15:36:11.350Z,1598369771.350 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-08-25T15:36:11.355Z,1598369771.355 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-08-25T15:36:11.355Z,1598369771.355 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-08-25T15:36:11.361Z,1598369771.361 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-08-25T15:36:11.362Z,1598369771.362 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-08-25T15:36:11.367Z,1598369771.367 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-08-25T15:36:11.368Z,1598369771.368 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-08-25T15:36:11.373Z,1598369771.373 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-08-25T15:36:11.399Z,1598369771.399 [CTD_Seabird] Loaded
2020-08-25T15:36:11.400Z,1598369771.400 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-08-25T15:36:11.401Z,1598369771.401 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B334E0
2020-08-25T15:36:11.401Z,1598369771.401 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1477
2020-08-25T15:36:11.423Z,1598369771.423 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-08-25T15:36:11.423Z,1598369771.423 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-08-25T15:36:11.427Z,1598369771.427 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-08-25T15:36:11.427Z,1598369771.427 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-08-25T15:36:11.431Z,1598369771.431 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-08-25T15:36:11.431Z,1598369771.431 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-08-25T15:36:11.435Z,1598369771.435 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-08-25T15:36:11.436Z,1598369771.436 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-08-25T15:36:11.440Z,1598369771.440 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-08-25T15:36:11.440Z,1598369771.440 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-08-25T15:36:11.444Z,1598369771.444 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-08-25T15:36:11.444Z,1598369771.444 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-08-25T15:36:11.448Z,1598369771.448 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-08-25T15:36:11.448Z,1598369771.448 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-08-25T15:36:11.453Z,1598369771.453 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:36:11.457Z,1598369771.457 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:36:11.458Z,1598369771.458 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:36:11.458Z,1598369771.458 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:36:11.462Z,1598369771.462 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:36:11.462Z,1598369771.462 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:36:11.466Z,1598369771.466 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:36:11.466Z,1598369771.466 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T15:36:11.470Z,1598369771.470 [WetLabsBB2FL] Loaded
2020-08-25T15:36:11.471Z,1598369771.471 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-08-25T15:36:11.472Z,1598369771.472 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B634E0
2020-08-25T15:36:11.472Z,1598369771.472 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1478
2020-08-25T15:36:11.473Z,1598369771.473 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-08-25T15:36:11.476Z,1598369771.476 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-08-25T15:36:11.477Z,1598369771.477 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-08-25T15:36:11.484Z,1598369771.484 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-08-25T15:36:11.485Z,1598369771.485 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B934E0
2020-08-25T15:36:11.485Z,1598369771.485 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1479
2020-08-25T15:36:11.489Z,1598369771.489 [Supervisor](INFO): Main Thread ID is 715
2020-08-25T15:36:11.489Z,1598369771.489 [Supervisor](DEBUG): Running supervisor.
2020-08-25T15:36:11.490Z,1598369771.490 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1480
2020-08-25T15:36:11.493Z,1598369771.493 [controlThread ThreadHandler](INFO): Handler Thread ID is 1481
2020-08-25T15:36:11.494Z,1598369771.494 [controlThread](DEBUG): Initializing ControlThread
2020-08-25T15:36:11.495Z,1598369771.495 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-08-25T15:36:11.496Z,1598369771.496 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-08-25T15:36:11.497Z,1598369771.497 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-08-25T15:36:11.497Z,1598369771.497 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-08-25T15:36:11.498Z,1598369771.498 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-08-25T15:36:11.498Z,1598369771.498 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-08-25T15:36:11.499Z,1598369771.499 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-08-25T15:36:11.499Z,1598369771.499 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-08-25T15:36:11.499Z,1598369771.499 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-08-25T15:36:11.500Z,1598369771.500 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-08-25T15:36:11.504Z,1598369771.504 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-08-25T15:36:11.504Z,1598369771.504 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-08-25T15:36:11.504Z,1598369771.504 [SBIT](INFO): Initialize SBIT Component.
2020-08-25T15:36:11.505Z,1598369771.505 [SBIT](IMPORTANT): git: 2020-08-18a-31-gbd628322e
2020-08-25T15:36:11.505Z,1598369771.505 [SBIT](INFO): git hash: bd628322e6debfac9e6880a33269f73ad5816ff1
2020-08-25T15:36:11.505Z,1598369771.505 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-08-25T15:36:11.507Z,1598369771.507 [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-25T15:36:11.508Z,1598369771.508 [SBIT](INFO): Beginning SBIT in 65.000000 seconds.
2020-08-25T15:36:11.508Z,1598369771.508 [IBIT](INFO): Initialize IBIT Component.
2020-08-25T15:36:11.509Z,1598369771.509 [CBIT](DEBUG): Initialize CBIT Component.
2020-08-25T15:36:11.510Z,1598369771.510 [logger ThreadHandler](INFO): Handler Thread ID is 1482
2020-08-25T15:36:11.522Z,1598369771.522 [CBIT](DEBUG): Initialized mux pins.
2020-08-25T15:36:11.523Z,1598369771.523 [CBIT](DEBUG): Initializing the watchdog timer.
2020-08-25T15:36:11.527Z,1598369771.527 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1483
2020-08-25T15:36:11.528Z,1598369771.528 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-08-25T15:36:11.535Z,1598369771.535 [Onboard ThreadHandler](INFO): Handler Thread ID is 1484
2020-08-25T15:36:11.547Z,1598369771.547 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-08-25T15:36:11.547Z,1598369771.547 [CBIT](DEBUG): Initializing heartbeat.
2020-08-25T15:36:11.557Z,1598369771.557 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1485
2020-08-25T15:36:11.579Z,1598369771.579 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 1486
2020-08-25T15:36:11.591Z,1598369771.591 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1487
2020-08-25T15:36:11.591Z,1598369771.591 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-08-25T15:36:11.596Z,1598369771.596 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1489
2020-08-25T15:36:11.597Z,1598369771.597 [WetLabsBB2FL](INFO): Powering down
2020-08-25T15:36:11.618Z,1598369771.618 [CBIT](DEBUG): Deactivating GF circuits.
2020-08-25T15:36:11.618Z,1598369771.618 [CBIT](DEBUG): Deactivating emergency mode.
2020-08-25T15:36:11.631Z,1598369771.631 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1490
2020-08-25T15:36:11.634Z,1598369771.634 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-08-25T15:36:11.634Z,1598369771.634 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-08-25T15:36:11.634Z,1598369771.634 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-08-25T15:36:11.634Z,1598369771.634 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-08-25T15:36:11.635Z,1598369771.635 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-08-25T15:36:11.635Z,1598369771.635 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-08-25T15:36:11.635Z,1598369771.635 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-08-25T15:36:11.635Z,1598369771.635 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-08-25T15:36:11.635Z,1598369771.635 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-08-25T15:36:11.635Z,1598369771.635 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-08-25T15:36:11.635Z,1598369771.635 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-08-25T15:36:11.636Z,1598369771.636 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-08-25T15:36:11.636Z,1598369771.636 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-08-25T15:36:11.636Z,1598369771.636 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-08-25T15:36:11.636Z,1598369771.636 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-08-25T15:36:11.636Z,1598369771.636 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-08-25T15:36:11.654Z,1598369771.654 [CBIT](DEBUG): Backplane powered.
2020-08-25T15:36:11.656Z,1598369771.656 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-08-25T15:36:11.666Z,1598369771.666 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-25T15:36:11.676Z,1598369771.676 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2020-08-25T15:36:11.677Z,1598369771.677 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-08-25T15:36:11.745Z,1598369771.745 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-08-25T15:36:11.762Z,1598369771.762 [Default:A.Wait](DEBUG): Construct Wait.
2020-08-25T15:36:11.764Z,1598369771.764 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-25T15:36:11.807Z,1598369771.807 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-08-25T15:36:11.809Z,1598369771.809 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-08-25T15:36:11.842Z,1598369771.842 [Default:E.Execute](DEBUG): Construct Execute.
2020-08-25T15:36:11.845Z,1598369771.845 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2020-08-25T15:36:11.866Z,1598369771.866 [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-25T15:36:11.887Z,1598369771.887 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-08-25T15:36:11.963Z,1598369771.963 [Radio_Surface](INFO): Powering up
2020-08-25T15:36:12.020Z,1598369772.020 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-08-25T15:36:12.020Z,1598369772.020 [DAT](INFO): Powering up
2020-08-25T15:36:12.020Z,1598369772.020 [DAT](DEBUG): Initializing DAT.
2020-08-25T15:36:12.071Z,1598369772.071 [AMEcho](INFO): Powering up
2020-08-25T15:36:12.091Z,1598369772.091 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-08-25T15:36:12.136Z,1598369772.136 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:36:12.143Z,1598369772.143 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-08-25T15:36:12.144Z,1598369772.144 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:36:12.155Z,1598369772.155 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-08-25T15:36:12.156Z,1598369772.156 [MassServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:36:12.167Z,1598369772.167 [MassServo](DEBUG): Initializing MassServo.
2020-08-25T15:36:12.168Z,1598369772.168 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:36:12.179Z,1598369772.179 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-25T15:36:12.180Z,1598369772.180 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:36:12.191Z,1598369772.191 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-08-25T15:36:12.193Z,1598369772.193 [CommandLine](FAULT): Scheduling is paused
2020-08-25T15:36:12.193Z,1598369772.193 [CBIT](INFO): Critical error at 20200825T153608
2020-08-25T15:36:12.194Z,1598369772.194 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-08-25T15:36:12.990Z,1598369772.990 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-08-25T15:36:12.991Z,1598369772.991 [RudderServo](FAULT): Rudder failed to initialize
2020-08-25T15:36:12.991Z,1598369772.991 [RudderServo] Communications Fault, FailCount= 1
2020-08-25T15:36:12.991Z,1598369772.991 [RudderServo](ERROR): Communications Fault
2020-08-25T15:36:13.126Z,1598369773.126 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-08-25T15:36:13.275Z,1598369773.275 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-08-25T15:36:13.276Z,1598369773.276 [RudderServo](INFO): Powering down
2020-08-25T15:36:13.993Z,1598369773.993 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-25T15:36:14.115Z,1598369774.115 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-25T15:36:14.119Z,1598369774.119 [CBIT](INFO): Clearing failed state for component RudderServo
2020-08-25T15:36:14.119Z,1598369774.119 [RudderServo] No Fault, FailCount= 1
2020-08-25T15:36:24.453Z,1598369784.453 [DAT](INFO): commRate: 800
2020-08-25T15:36:24.454Z,1598369784.454 [DAT](INFO): commRate: 800
2020-08-25T15:36:24.856Z,1598369784.856 [DAT](INFO): entering command mode
2020-08-25T15:36:25.264Z,1598369785.264 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:25.431Z,1598369785.431 [AMEcho](INFO): Powering down
2020-08-25T15:36:25.664Z,1598369785.664 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:26.068Z,1598369786.068 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:26.472Z,1598369786.472 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:26.876Z,1598369786.876 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:27.280Z,1598369787.280 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:27.684Z,1598369787.684 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:28.088Z,1598369788.088 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:28.492Z,1598369788.492 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:28.896Z,1598369788.896 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:29.300Z,1598369789.300 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:29.704Z,1598369789.704 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:30.108Z,1598369790.108 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:30.512Z,1598369790.512 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:30.916Z,1598369790.916 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:31.320Z,1598369791.320 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:31.724Z,1598369791.724 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:32.128Z,1598369792.128 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:32.532Z,1598369792.532 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:32.936Z,1598369792.936 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:33.340Z,1598369793.340 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:33.752Z,1598369793.752 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:34.149Z,1598369794.149 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:34.552Z,1598369794.552 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:34.956Z,1598369794.956 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:35.356Z,1598369795.356 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:35.768Z,1598369795.768 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:36.168Z,1598369796.168 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:36.572Z,1598369796.572 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:36.976Z,1598369796.976 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:37.380Z,1598369797.380 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:37.783Z,1598369797.783 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:38.192Z,1598369798.192 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:38.592Z,1598369798.592 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:38.996Z,1598369798.996 [NAL9602](INFO): Powering up NAL9602
2020-08-25T15:36:38.997Z,1598369798.997 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:39.406Z,1598369799.406 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:39.804Z,1598369799.804 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:40.204Z,1598369800.204 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T15:36:40.204Z,1598369800.204 [DAT](FAULT): failed to enter command mode
2020-08-25T15:36:40.612Z,1598369800.612 [DAT](INFO): entering command mode
2020-08-25T15:36:41.029Z,1598369801.029 [DAT](INFO): setting verbose to 3
2020-08-25T15:36:41.417Z,1598369801.417 [DAT](INFO): set verbose to 3
2020-08-25T15:36:41.417Z,1598369801.417 [DAT](INFO): setting DatVerbose to 27440
2020-08-25T15:36:41.825Z,1598369801.825 [DAT](INFO): set DatVerbose to 27440
2020-08-25T15:36:41.825Z,1598369801.825 [DAT](INFO): setting transmit power to 8
2020-08-25T15:36:42.237Z,1598369802.237 [DAT](INFO): set transmit power to 8
2020-08-25T15:36:42.237Z,1598369802.237 [DAT](INFO): setting local address to 9
2020-08-25T15:36:42.635Z,1598369802.635 [DAT](INFO): set local address to 9
2020-08-25T15:36:49.900Z,1598369809.900 [NAL9602](INFO): NAL9602 initialized
2020-08-25T15:37:16.987Z,1598369836.987 [SBIT](IMPORTANT): Beginning Startup BIT
2020-08-25T15:37:17.019Z,1598369837.019 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-25T15:37:27.994Z,1598369847.994 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.009231
CHAN A1 (24V): 0.000145
CHAN A2 (12V): -0.006714
CHAN A3 (5V): -0.001710
CHAN B0 (3.3V): -0.000239
CHAN B1 (3.15aV): -0.000693
CHAN B2 (3.15bV): 0.000037
CHAN B3 (GND): 0.002348
OPEN: 0.005611
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-25T15:38:10.736Z,1598369890.736 [SBIT](IMPORTANT): SBIT PASSED
2020-08-25T15:38:10.736Z,1598369890.736 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-08-25T15:38:10.737Z,1598369890.737 [SBIT](IMPORTANT): BackSeatDriver.loadAtStartup=1 bool;

2020-08-25T15:38:10.737Z,1598369890.737 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere;

2020-08-25T15:38:10.737Z,1598369890.737 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2020-08-25T15:38:10.737Z,1598369890.737 [SBIT](IMPORTANT): Express none ThrusterServo.component_avgCurrent;

2020-08-25T15:38:10.738Z,1598369890.738 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second;

2020-08-25T15:38:10.738Z,1598369890.738 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2020-08-25T15:38:10.738Z,1598369890.738 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool;

2020-08-25T15:38:10.738Z,1598369890.738 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=344.685708 cubic_centimeter;

2020-08-25T15:38:10.738Z,1598369890.738 [SBIT](IMPORTANT): VerticalControl.massDefault=11.293600 millimeter;

2020-08-25T15:38:10.738Z,1598369890.738 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=0 bool;

2020-08-25T15:38:11.143Z,1598369891.143 [MissionManager](IMPORTANT): Started mission Startup
2020-08-25T15:38:11.143Z,1598369891.143 [Startup] Running Loop=1
2020-08-25T15:38:11.143Z,1598369891.143 [Startup](DEBUG): Aggregate::initialize Startup
2020-08-25T15:38:11.144Z,1598369891.144 [Startup:A.GoToSurface] Running Loop=1
2020-08-25T15:38:11.144Z,1598369891.144 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-25T15:38:11.144Z,1598369891.144 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-25T15:38:11.145Z,1598369891.145 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-25T15:38:11.145Z,1598369891.145 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-25T15:38:11.145Z,1598369891.145 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-25T15:38:11.146Z,1598369891.146 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-25T15:38:11.147Z,1598369891.147 [Startup:StartupSatComms] Running Loop=1
2020-08-25T15:38:11.147Z,1598369891.147 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-08-25T15:38:11.147Z,1598369891.147 [Startup:StartupSatComms:A] Running Loop=1
2020-08-25T15:38:11.524Z,1598369891.524 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-08-25T15:38:11.917Z,1598369891.917 [AMEcho](INFO): Powering up
2020-08-25T15:39:11.340Z,1598369951.340 [Startup:StartupSatComms:A](INFO): Timed out from 2020-08-25T15:38:11.1Z
2020-08-25T15:39:11.340Z,1598369951.340 [Startup:StartupSatComms:A] Stopped
2020-08-25T15:39:11.340Z,1598369951.340 [Startup:StartupSatComms:B] Running Loop=1
2020-08-25T15:39:11.742Z,1598369951.742 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-08-25T15:39:11.742Z,1598369951.742 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-25T15:39:11.745Z,1598369951.745 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-25T15:39:11.758Z,1598369951.758 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-25T15:39:12.137Z,1598369952.137 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-25T15:39:12.137Z,1598369952.137 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-08-25T15:39:36.086Z,1598369976.086 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004727
2020-08-25T15:39:43.318Z,1598369983.318 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200825T153007/Courier0004.lzma
2020-08-25T15:39:44.320Z,1598369984.320 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153007/Courier0004.lzma.bak
2020-08-25T15:39:44.320Z,1598369984.320 [DataOverHttps](INFO): SBD MOMSN=12614070
2020-08-25T15:39:55.389Z,1598369995.389 [CommandLine](IMPORTANT): got command report mod AMEcho.altitude
2020-08-25T15:39:55.399Z,1598369995.399 [Reporter](INFO): AMEcho.altitude 20.830000 m
2020-08-25T15:40:00.476Z,1598370000.476 [DataOverHttps](INFO): Sending 215 bytes from file Logs/20200825T153601/Courier0000.lzma
2020-08-25T15:40:01.476Z,1598370001.476 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0000.lzma.bak
2020-08-25T15:40:01.477Z,1598370001.477 [DataOverHttps](INFO): SBD MOMSN=12614072
2020-08-25T15:40:09.408Z,1598370009.408 [CommandLine](IMPORTANT): got command configSet AMEcho.enabled 0.000000 bool
2020-08-25T15:40:09.508Z,1598370009.508 [AMEcho](ERROR): Setting 'enabled' to 0
2020-08-25T15:40:09.536Z,1598370009.536 [Reporter](INFO): AMEcho.altitude no_value
2020-08-25T15:40:10.063Z,1598370010.063 [AMEcho](INFO): Powering down
2020-08-25T15:40:11.558Z,1598370011.558 [Startup:StartupSatComms:B](INFO): Timed out from 2020-08-25T15:39:11.3Z
2020-08-25T15:40:11.558Z,1598370011.558 [Startup:StartupSatComms:B] Stopped
2020-08-25T15:40:11.558Z,1598370011.558 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-08-25T15:40:11.558Z,1598370011.558 [Startup:StartupSatComms] Stopped
2020-08-25T15:40:11.559Z,1598370011.559 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-08-25T15:40:11.559Z,1598370011.559 [Startup](INFO): Completed Startup
2020-08-25T15:40:11.559Z,1598370011.559 [MissionManager](INFO): Startup is completed.
2020-08-25T15:40:11.560Z,1598370011.560 [MissionManager](INFO): Uninitializing Mission Startup
2020-08-25T15:40:11.560Z,1598370011.560 [Startup] Stopped
2020-08-25T15:40:11.560Z,1598370011.560 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-08-25T15:40:11.560Z,1598370011.560 [Startup:A.GoToSurface] Stopped
2020-08-25T15:40:11.560Z,1598370011.560 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-25T15:40:11.956Z,1598370011.956 [MissionManager](IMPORTANT): Started mission Default
2020-08-25T15:40:11.956Z,1598370011.956 [Default] Running Loop=1
2020-08-25T15:40:11.956Z,1598370011.956 [Default](DEBUG): Aggregate::initialize Default
2020-08-25T15:40:11.956Z,1598370011.956 [Default:B.GoToSurface] Running Loop=1
2020-08-25T15:40:11.957Z,1598370011.957 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-25T15:40:11.957Z,1598370011.957 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-25T15:40:11.957Z,1598370011.957 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-25T15:40:11.957Z,1598370011.957 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-25T15:40:11.958Z,1598370011.958 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-25T15:40:11.958Z,1598370011.958 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-25T15:40:11.959Z,1598370011.959 [Default:A.Wait] Running Loop=1
2020-08-25T15:40:11.959Z,1598370011.959 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-08-25T15:40:19.102Z,1598370019.102 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20200825T151723/Express0008.lzma
2020-08-25T15:40:20.104Z,1598370020.104 [DataOverHttps](INFO): Moved sent file to Logs/20200825T151723/Express0008.lzma.bak
2020-08-25T15:40:20.104Z,1598370020.104 [DataOverHttps](INFO): SBD MOMSN=12614076
2020-08-25T15:40:23.602Z,1598370023.602 [CommandLine](IMPORTANT): got command configSet AMEcho.enabled 1.000000 bool
2020-08-25T15:40:23.656Z,1598370023.656 [AMEcho](ERROR): Setting 'enabled' to 1
2020-08-25T15:40:24.056Z,1598370024.056 [AMEcho](INFO): Powering up
2020-08-25T15:40:25.308Z,1598370025.308 [Default:A.Wait](INFO): Done Waiting.
2020-08-25T15:40:25.308Z,1598370025.308 [Default:A.Wait] Stopped
2020-08-25T15:40:25.308Z,1598370025.308 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T15:40:25.752Z,1598370025.752 [Default:CheckIn] Running Loop=1
2020-08-25T15:40:25.752Z,1598370025.752 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T15:40:25.752Z,1598370025.752 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T15:40:26.076Z,1598370026.076 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-08-25T15:40:36.209Z,1598370036.209 [Reporter](INFO): AMEcho.altitude 20.830000 m
2020-08-25T15:40:41.461Z,1598370041.461 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:40:45.887Z,1598370045.887 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:40:55.657Z,1598370055.657 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T15:40:57.177Z,1598370057.177 [NAL9602](INFO): SBD MO Status=2, MOMSN=8109, MT Status=2, MTMSN=0
2020-08-25T15:40:57.177Z,1598370057.177 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T15:40:58.835Z,1598370058.835 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:40:59.627Z,1598370059.627 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:41:00.829Z,1598370060.829 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T15:41:02.853Z,1598370062.853 [Reporter](INFO): AMEcho.altitude 11.230000 m
2020-08-25T15:41:03.680Z,1598370063.680 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:41:33.977Z,1598370093.977 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:41:48.923Z,1598370108.923 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:41:52.929Z,1598370112.929 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T15:41:58.590Z,1598370118.590 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154158.00,A,3648.15417,N,12147.28504,W,0.467,333.74,250820,,,A*7D
2020-08-25T15:41:58.598Z,1598370118.598 [NAL9602](INFO): GPS fix at 20200825T154158: (36.802569, -121.788084)
2020-08-25T15:41:58.698Z,1598370118.698 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T15:41:58.698Z,1598370118.698 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T15:41:59.046Z,1598370119.046 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-25T15:42:08.566Z,1598370128.566 [DataOverHttps](INFO): Sending 224 bytes from file Logs/20200825T153601/Courier0004.lzma
2020-08-25T15:42:09.568Z,1598370129.568 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0004.lzma.bak
2020-08-25T15:42:09.568Z,1598370129.568 [DataOverHttps](INFO): SBD MOMSN=12614106
2020-08-25T15:42:14.767Z,1598370134.767 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:42:17.641Z,1598370137.641 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:42:31.315Z,1598370151.315 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T15:42:32.707Z,1598370152.707 [DataOverHttps](INFO): Sending 1015 bytes from file Logs/20200825T152347/Express0001.lzma
2020-08-25T15:42:33.708Z,1598370153.708 [DataOverHttps](INFO): Moved sent file to Logs/20200825T152347/Express0001.lzma.bak
2020-08-25T15:42:33.708Z,1598370153.708 [DataOverHttps](INFO): SBD MOMSN=12614109
2020-08-25T15:42:50.745Z,1598370170.745 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:42:51.175Z,1598370171.174 [DataOverHttps](INFO): Sending 430 bytes from file Logs/20200825T152347/Express0005.lzma
2020-08-25T15:42:52.177Z,1598370172.177 [DataOverHttps](INFO): Moved sent file to Logs/20200825T152347/Express0005.lzma.bak
2020-08-25T15:42:52.177Z,1598370172.177 [DataOverHttps](INFO): SBD MOMSN=12614134
2020-08-25T15:42:54.791Z,1598370174.791 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:42:57.667Z,1598370177.667 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:43:10.266Z,1598370190.266 [DataOverHttps](INFO): Sending 183 bytes from file Logs/20200825T152347/Express0008.lzma
2020-08-25T15:43:10.512Z,1598370190.512 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-25T15:43:10.545Z,1598370190.545 [BPC1](INFO): Received data from all battery sticks.
2020-08-25T15:43:11.268Z,1598370191.268 [DataOverHttps](INFO): Moved sent file to Logs/20200825T152347/Express0008.lzma.bak
2020-08-25T15:43:11.269Z,1598370191.269 [DataOverHttps](INFO): SBD MOMSN=12614143
2020-08-25T15:43:30.303Z,1598370210.303 [DataOverHttps](INFO): Sending 1013 bytes from file Logs/20200825T153007/Express0001.lzma
2020-08-25T15:43:31.292Z,1598370211.292 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153007/Express0001.lzma.bak
2020-08-25T15:43:31.292Z,1598370211.292 [DataOverHttps](INFO): SBD MOMSN=12614147
2020-08-25T15:43:48.662Z,1598370228.662 [DataOverHttps](INFO): Sending 348 bytes from file Logs/20200825T153007/Express0005.lzma
2020-08-25T15:43:49.886Z,1598370229.886 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153007/Express0005.lzma.bak
2020-08-25T15:43:49.886Z,1598370229.886 [DataOverHttps](INFO): SBD MOMSN=12614172
2020-08-25T15:44:06.791Z,1598370246.791 [DataOverHttps](INFO): Sending 1007 bytes from file Logs/20200825T153601/Express0001.lzma
2020-08-25T15:44:07.792Z,1598370247.792 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0001.lzma.bak
2020-08-25T15:44:07.792Z,1598370247.792 [DataOverHttps](INFO): SBD MOMSN=12614181
2020-08-25T15:44:18.824Z,1598370258.824 [Reporter](INFO): AMEcho.altitude 11.230000 m
2020-08-25T15:44:19.620Z,1598370259.620 [Reporter](INFO): AMEcho.altitude 12.130000 m
2020-08-25T15:44:20.824Z,1598370260.824 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:44:21.688Z,1598370261.688 [Reporter](INFO): AMEcho.altitude 11.230000 m
2020-08-25T15:44:22.940Z,1598370262.940 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:44:29.075Z,1598370269.075 [DataOverHttps](INFO): Sending 397 bytes from file Logs/20200825T153601/Express0005.lzma
2020-08-25T15:44:30.076Z,1598370270.076 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0005.lzma.bak
2020-08-25T15:44:30.076Z,1598370270.076 [DataOverHttps](INFO): SBD MOMSN=12614206
2020-08-25T15:44:30.940Z,1598370270.940 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T15:44:32.949Z,1598370272.949 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T15:44:32.949Z,1598370272.949 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T15:44:32.949Z,1598370272.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T15:44:34.988Z,1598370274.988 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:44:35.801Z,1598370275.801 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T15:44:37.047Z,1598370277.047 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:44:38.646Z,1598370278.646 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:44:39.841Z,1598370279.841 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:44:41.841Z,1598370281.841 [Reporter](INFO): AMEcho.altitude 12.800000 m
2020-08-25T15:44:50.068Z,1598370290.068 [Reporter](INFO): AMEcho.altitude 12.730000 m
2020-08-25T15:44:50.805Z,1598370290.805 [Reporter](INFO): AMEcho.altitude 12.650000 m
2020-08-25T15:44:52.074Z,1598370292.074 [Reporter](INFO): AMEcho.altitude 12.730000 m
2020-08-25T15:44:56.883Z,1598370296.883 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:44:57.674Z,1598370297.674 [Reporter](INFO): AMEcho.altitude 9.950000 m
2020-08-25T15:44:58.867Z,1598370298.867 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:44:59.698Z,1598370299.698 [Reporter](INFO): AMEcho.altitude 9.800000 m
2020-08-25T15:45:02.904Z,1598370302.904 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:45:03.715Z,1598370303.715 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T15:45:04.924Z,1598370304.924 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T15:45:05.751Z,1598370305.751 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T15:45:09.077Z,1598370309.077 [Reporter](INFO): AMEcho.altitude 13.480000 m
2020-08-25T15:45:09.775Z,1598370309.775 [Reporter](INFO): AMEcho.altitude 12.730000 m
2020-08-25T15:45:10.990Z,1598370310.990 [Reporter](INFO): AMEcho.altitude 13.400000 m
2020-08-25T15:45:11.804Z,1598370311.804 [Reporter](INFO): AMEcho.altitude 12.650000 m
2020-08-25T15:45:22.734Z,1598370322.734 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:45:30.003Z,1598370330.003 [Reporter](INFO): AMEcho.altitude 11.150000 m
2020-08-25T15:45:30.825Z,1598370330.825 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:45:32.824Z,1598370332.824 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:45:36.876Z,1598370336.876 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:45:39.703Z,1598370339.703 [Reporter](INFO): AMEcho.altitude 11.530000 m
2020-08-25T15:45:47.792Z,1598370347.792 [Reporter](INFO): AMEcho.altitude 11.600000 m
2020-08-25T15:45:52.644Z,1598370352.644 [Reporter](INFO): AMEcho.altitude 11.750000 m
2020-08-25T15:45:53.835Z,1598370353.835 [Reporter](INFO): AMEcho.altitude 11.680000 m
2020-08-25T15:45:55.888Z,1598370355.888 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T15:46:01.915Z,1598370361.915 [Reporter](INFO): AMEcho.altitude 22.030001 m
2020-08-25T15:46:09.998Z,1598370369.998 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:46:21.735Z,1598370381.735 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:46:26.963Z,1598370386.963 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:46:45.969Z,1598370405.969 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:46:46.756Z,1598370406.756 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:47:23.954Z,1598370443.954 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T15:47:24.734Z,1598370444.734 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:47:26.772Z,1598370446.772 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T15:47:27.967Z,1598370447.967 [Reporter](INFO): AMEcho.altitude 21.430000 m
2020-08-25T15:47:28.806Z,1598370448.806 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:47:30.793Z,1598370450.793 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T15:47:32.035Z,1598370452.035 [Reporter](INFO): AMEcho.altitude 21.730000 m
2020-08-25T15:47:32.815Z,1598370452.815 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:47:33.654Z,1598370453.654 [Reporter](INFO): AMEcho.altitude 21.430000 m
2020-08-25T15:47:35.644Z,1598370455.644 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:47:38.872Z,1598370458.872 [Reporter](INFO): AMEcho.altitude 21.430000 m
2020-08-25T15:47:39.694Z,1598370459.694 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:47:43.767Z,1598370463.767 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T15:47:45.747Z,1598370465.747 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:47:46.964Z,1598370466.964 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T15:47:56.656Z,1598370476.656 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:47:57.889Z,1598370477.889 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T15:48:00.704Z,1598370480.704 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:48:04.735Z,1598370484.735 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T15:48:05.967Z,1598370485.967 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:48:07.960Z,1598370487.960 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:48:12.010Z,1598370492.010 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:48:14.834Z,1598370494.834 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:48:15.655Z,1598370495.655 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:48:19.693Z,1598370499.693 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:48:20.893Z,1598370500.893 [Reporter](INFO): AMEcho.altitude 22.100000 m
2020-08-25T15:48:22.915Z,1598370502.915 [Reporter](INFO): AMEcho.altitude 20.980000 m
2020-08-25T15:48:23.740Z,1598370503.740 [Reporter](INFO): AMEcho.altitude 20.830000 m
2020-08-25T15:48:25.766Z,1598370505.766 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T15:48:26.962Z,1598370506.962 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T15:48:27.757Z,1598370507.757 [Reporter](INFO): AMEcho.altitude 22.030001 m
2020-08-25T15:48:29.008Z,1598370509.008 [Reporter](INFO): AMEcho.altitude 20.750000 m
2020-08-25T15:48:29.795Z,1598370509.795 [Reporter](INFO): AMEcho.altitude 20.830000 m
2020-08-25T15:48:30.991Z,1598370510.991 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:48:36.667Z,1598370516.667 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T15:48:38.688Z,1598370518.688 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:48:39.892Z,1598370519.892 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T15:48:40.685Z,1598370520.685 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T15:48:42.710Z,1598370522.710 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:48:44.746Z,1598370524.746 [Reporter](INFO): AMEcho.altitude 20.980000 m
2020-08-25T15:48:47.977Z,1598370527.977 [Reporter](INFO): AMEcho.altitude 22.480000 m
2020-08-25T15:48:48.770Z,1598370528.770 [Reporter](INFO): AMEcho.altitude 21.430000 m
2020-08-25T15:48:50.007Z,1598370530.007 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:48:51.998Z,1598370531.998 [Reporter](INFO): AMEcho.altitude 21.430000 m
2020-08-25T15:48:55.685Z,1598370535.685 [Reporter](INFO): AMEcho.altitude 21.280001 m
2020-08-25T15:48:56.851Z,1598370536.851 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:48:58.867Z,1598370538.867 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T15:49:01.694Z,1598370541.694 [Reporter](INFO): AMEcho.altitude 21.430000 m
2020-08-25T15:49:03.715Z,1598370543.715 [Reporter](INFO): AMEcho.altitude 21.350000 m
2020-08-25T15:49:04.951Z,1598370544.951 [Reporter](INFO): AMEcho.altitude 21.430000 m
2020-08-25T15:49:06.944Z,1598370546.944 [Reporter](INFO): AMEcho.altitude 20.450001 m
2020-08-25T15:49:07.755Z,1598370547.755 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:49:09.772Z,1598370549.772 [Reporter](INFO): AMEcho.altitude 21.430000 m
2020-08-25T15:49:11.013Z,1598370551.013 [Reporter](INFO): AMEcho.altitude 21.500000 m
2020-08-25T15:49:19.875Z,1598370559.875 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T15:49:26.740Z,1598370566.740 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:49:27.974Z,1598370567.974 [Reporter](INFO): AMEcho.altitude 20.900000 m
2020-08-25T15:49:28.775Z,1598370568.775 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T15:49:32.827Z,1598370572.827 [Reporter](INFO): AMEcho.altitude 21.129999 m
2020-08-25T15:49:33.606Z,1598370573.606 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T15:49:33.606Z,1598370573.606 [Default:CheckIn:C.Wait] Stopped
2020-08-25T15:49:33.606Z,1598370573.606 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T15:49:33.606Z,1598370573.606 [Default:CheckIn:D] Running Loop=1
2020-08-25T15:49:34.012Z,1598370574.012 [Default:CheckIn:D] Stopped
2020-08-25T15:49:34.012Z,1598370574.012 [Default:CheckIn:E] Running Loop=1
2020-08-25T15:49:34.428Z,1598370574.428 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 9.367587 min 
2020-08-25T15:49:34.428Z,1598370574.428 [Default:CheckIn:E] Stopped
2020-08-25T15:49:34.428Z,1598370574.428 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T15:49:34.428Z,1598370574.428 [Default:CheckIn] Stopped
2020-08-25T15:49:34.428Z,1598370574.428 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T15:49:34.429Z,1598370574.429 [Default:CheckIn](INFO): Running loop #2
2020-08-25T15:49:34.429Z,1598370574.429 [Default:CheckIn] Running Loop=2
2020-08-25T15:49:34.429Z,1598370574.429 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T15:49:34.429Z,1598370574.429 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T15:49:36.421Z,1598370576.421 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154936.00,A,3648.16749,N,12147.28476,W,1.458,351.54,250820,,,A*79
2020-08-25T15:49:36.423Z,1598370576.423 [NAL9602](INFO): GPS fix at 20200825T154936: (36.802791, -121.788079)
2020-08-25T15:49:36.437Z,1598370576.437 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T15:49:36.437Z,1598370576.437 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T15:49:38.871Z,1598370578.871 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:49:44.010Z,1598370584.010 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20200825T153601/Courier0007.lzma
2020-08-25T15:49:45.012Z,1598370585.012 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0007.lzma.bak
2020-08-25T15:49:45.012Z,1598370585.012 [DataOverHttps](INFO): SBD MOMSN=12614220
2020-08-25T15:49:49.811Z,1598370589.811 [Reporter](INFO): AMEcho.altitude 20.900000 m
2020-08-25T15:49:53.017Z,1598370593.017 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:50:02.306Z,1598370602.306 [DataOverHttps](INFO): Sending 159 bytes from file Logs/20200825T153601/Express0008.lzma
2020-08-25T15:50:02.708Z,1598370602.708 [Reporter](INFO): AMEcho.altitude 22.030001 m
2020-08-25T15:50:03.309Z,1598370603.309 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0008.lzma.bak
2020-08-25T15:50:03.309Z,1598370603.309 [DataOverHttps](INFO): SBD MOMSN=12614223
2020-08-25T15:50:03.915Z,1598370603.915 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:50:05.939Z,1598370605.939 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T15:50:05.940Z,1598370605.940 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T15:50:05.940Z,1598370605.940 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T15:50:07.123Z,1598370607.123 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-25T15:50:07.202Z,1598370607.202 [NAL9602](FAULT): received: 
+CSQ:0

OK09, 2, 0, 0, 0

OK
2020-08-25T15:50:07.203Z,1598370607.203 [NAL9602] Data Fault, FailCount= 1
2020-08-25T15:50:07.203Z,1598370607.203 [NAL9602](ERROR): Data Fault
2020-08-25T15:50:07.327Z,1598370607.327 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T15:50:07.527Z,1598370607.527 [NAL9602](INFO): Powering down
2020-08-25T15:50:08.356Z,1598370608.356 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T15:50:08.356Z,1598370608.356 [NAL9602] No Fault, FailCount= 1
2020-08-25T15:50:37.827Z,1598370637.827 [NAL9602](INFO): Powering up NAL9602
2020-08-25T15:50:48.739Z,1598370648.739 [NAL9602](INFO): NAL9602 initialized
2020-08-25T15:51:19.843Z,1598370679.843 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T15:51:34.001Z,1598370694.001 [Reporter](INFO): AMEcho.altitude 20.980000 m
2020-08-25T15:51:38.849Z,1598370698.849 [Reporter](INFO): AMEcho.altitude 21.049999 m
2020-08-25T15:51:39.673Z,1598370699.673 [Reporter](INFO): AMEcho.altitude 20.980000 m
2020-08-25T15:53:50.991Z,1598370830.991 [Reporter](INFO): AMEcho.altitude 20.900000 m
2020-08-25T15:53:53.797Z,1598370833.797 [Reporter](INFO): AMEcho.altitude 20.980000 m
2020-08-25T15:53:55.819Z,1598370835.819 [Reporter](INFO): AMEcho.altitude 20.900000 m
2020-08-25T15:54:12.785Z,1598370852.785 [Reporter](INFO): AMEcho.altitude 20.750000 m
2020-08-25T15:54:14.022Z,1598370854.022 [Reporter](INFO): AMEcho.altitude 20.830000 m
2020-08-25T15:54:14.814Z,1598370854.814 [Reporter](INFO): AMEcho.altitude 20.900000 m
2020-08-25T15:55:00.951Z,1598370900.951 [Reporter](INFO): AMEcho.altitude 20.830000 m
2020-08-25T15:55:02.983Z,1598370902.983 [Reporter](INFO): AMEcho.altitude 20.900000 m
2020-08-25T15:55:06.560Z,1598370906.560 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T15:55:06.560Z,1598370906.560 [Default:CheckIn:C.Wait] Stopped
2020-08-25T15:55:06.560Z,1598370906.560 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T15:55:06.560Z,1598370906.560 [Default:CheckIn:D] Running Loop=1
2020-08-25T15:55:06.976Z,1598370906.976 [Default:CheckIn:D] Stopped
2020-08-25T15:55:06.977Z,1598370906.977 [Default:CheckIn:E] Running Loop=1
2020-08-25T15:55:07.372Z,1598370907.372 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.917001 min 
2020-08-25T15:55:07.372Z,1598370907.372 [Default:CheckIn:E] Stopped
2020-08-25T15:55:07.372Z,1598370907.372 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T15:55:07.372Z,1598370907.372 [Default:CheckIn] Stopped
2020-08-25T15:55:07.372Z,1598370907.372 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T15:55:07.372Z,1598370907.372 [Default:CheckIn](INFO): Running loop #3
2020-08-25T15:55:07.373Z,1598370907.373 [Default:CheckIn] Running Loop=3
2020-08-25T15:55:07.373Z,1598370907.373 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T15:55:07.373Z,1598370907.373 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T15:55:11.019Z,1598370911.019 [Reporter](INFO): AMEcho.altitude 20.830000 m
2020-08-25T15:55:11.807Z,1598370911.807 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T15:55:12.669Z,1598370912.669 [Reporter](INFO): AMEcho.altitude 20.900000 m
2020-08-25T15:55:16.685Z,1598370916.685 [Reporter](INFO): AMEcho.altitude 20.830000 m
2020-08-25T15:55:20.726Z,1598370920.726 [Reporter](INFO): AMEcho.altitude 20.900000 m
2020-08-25T15:55:22.747Z,1598370922.747 [Reporter](INFO): AMEcho.altitude 20.830000 m
2020-08-25T15:55:25.983Z,1598370925.983 [Reporter](INFO): AMEcho.altitude 20.900000 m
2020-08-25T15:55:26.782Z,1598370926.782 [Reporter](INFO): AMEcho.altitude 20.830000 m
2020-08-25T15:55:35.685Z,1598370935.685 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:55:41.735Z,1598370941.735 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T15:55:43.761Z,1598370943.761 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T15:55:44.949Z,1598370944.949 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T15:55:45.770Z,1598370945.770 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T15:55:46.987Z,1598370946.987 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:55:49.003Z,1598370949.003 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T15:55:51.823Z,1598370951.823 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T15:55:53.075Z,1598370953.075 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T15:55:55.887Z,1598370955.887 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T15:55:56.677Z,1598370956.677 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:55:59.899Z,1598370959.899 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T15:56:00.735Z,1598370960.735 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:56:03.955Z,1598370963.955 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T15:56:04.772Z,1598370964.772 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:56:06.780Z,1598370966.780 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T15:56:08.811Z,1598370968.811 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:56:10.014Z,1598370970.014 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:56:10.850Z,1598370970.850 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:56:13.673Z,1598370973.673 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:56:14.864Z,1598370974.864 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T15:56:15.656Z,1598370975.656 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:56:18.887Z,1598370978.887 [Reporter](INFO): AMEcho.altitude 11.750000 m
2020-08-25T15:56:19.714Z,1598370979.714 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:56:23.752Z,1598370983.752 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:56:25.773Z,1598370985.773 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155625.00,A,3648.16212,N,12147.28004,W,0.778,0.00,250820,,,A*79
2020-08-25T15:56:25.775Z,1598370985.775 [NAL9602](INFO): GPS fix at 20200825T155625: (36.802702, -121.788001)
2020-08-25T15:56:25.798Z,1598370985.798 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T15:56:25.798Z,1598370985.798 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T15:56:27.878Z,1598370987.878 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:56:29.041Z,1598370989.041 [Reporter](INFO): AMEcho.altitude 9.950000 m
2020-08-25T15:56:30.656Z,1598370990.656 [Reporter](INFO): AMEcho.altitude 11.680000 m
2020-08-25T15:56:32.743Z,1598370992.743 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:56:35.622Z,1598370995.622 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0010.lzma
2020-08-25T15:56:36.624Z,1598370996.624 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0010.lzma.bak
2020-08-25T15:56:36.624Z,1598370996.624 [DataOverHttps](INFO): SBD MOMSN=12614263
2020-08-25T15:56:50.861Z,1598371010.861 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T15:56:51.686Z,1598371011.686 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T15:56:53.669Z,1598371013.669 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T15:56:54.684Z,1598371014.684 [DataOverHttps](INFO): Sending 246 bytes from file Logs/20200825T153601/Express0011.lzma
2020-08-25T15:56:54.976Z,1598371014.976 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0011.lzma.bak
2020-08-25T15:56:54.976Z,1598371014.976 [DataOverHttps](INFO): SBD MOMSN=12614266
2020-08-25T15:56:55.700Z,1598371015.700 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T15:56:58.091Z,1598371018.091 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T15:56:58.140Z,1598371018.140 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T15:56:58.140Z,1598371018.140 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T15:56:58.140Z,1598371018.140 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T15:57:01.794Z,1598371021.794 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T15:57:02.958Z,1598371022.958 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:57:13.897Z,1598371033.897 [Reporter](INFO): AMEcho.altitude 11.750000 m
2020-08-25T15:57:18.741Z,1598371038.741 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:57:20.735Z,1598371040.735 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T15:57:21.971Z,1598371041.971 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:57:35.685Z,1598371055.685 [Reporter](INFO): AMEcho.altitude 11.680000 m
2020-08-25T15:57:37.711Z,1598371057.711 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T15:57:38.922Z,1598371058.922 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T15:57:40.949Z,1598371060.949 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T15:57:42.958Z,1598371062.958 [Reporter](INFO): AMEcho.altitude 11.150000 m
2020-08-25T15:57:43.770Z,1598371063.770 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:58:02.765Z,1598371082.765 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:58:06.004Z,1598371086.004 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:58:08.007Z,1598371088.007 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:58:08.817Z,1598371088.817 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:58:12.056Z,1598371092.056 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:58:18.931Z,1598371098.931 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:58:21.750Z,1598371101.750 [Reporter](INFO): AMEcho.altitude 11.680000 m
2020-08-25T15:58:23.821Z,1598371103.821 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:58:33.884Z,1598371113.884 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T15:58:36.698Z,1598371116.698 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:58:37.905Z,1598371117.905 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:58:38.777Z,1598371118.777 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T15:58:40.738Z,1598371120.738 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:58:48.034Z,1598371128.034 [Reporter](INFO): AMEcho.altitude 11.600000 m
2020-08-25T15:58:48.815Z,1598371128.815 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:58:50.025Z,1598371130.025 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:58:53.665Z,1598371133.665 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:58:55.741Z,1598371135.741 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:58:56.948Z,1598371136.948 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T15:58:57.771Z,1598371137.771 [Reporter](INFO): AMEcho.altitude 11.750000 m
2020-08-25T15:58:58.923Z,1598371138.923 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T15:58:59.724Z,1598371139.724 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:59:00.933Z,1598371140.933 [Reporter](INFO): AMEcho.altitude 11.150000 m
2020-08-25T15:59:01.750Z,1598371141.750 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T15:59:02.955Z,1598371142.955 [Reporter](INFO): AMEcho.altitude 11.300000 m
2020-08-25T15:59:03.790Z,1598371143.790 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:59:05.781Z,1598371145.781 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T15:59:09.834Z,1598371149.834 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:59:13.065Z,1598371153.065 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T15:59:13.871Z,1598371153.871 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T15:59:17.917Z,1598371157.917 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:59:23.963Z,1598371163.963 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:59:36.894Z,1598371176.894 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T15:59:41.738Z,1598371181.738 [Reporter](INFO): AMEcho.altitude 11.380000 m
2020-08-25T15:59:42.975Z,1598371182.975 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T15:59:45.817Z,1598371185.817 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T15:59:47.012Z,1598371187.012 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T15:59:47.858Z,1598371187.858 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T15:59:52.656Z,1598371192.656 [Reporter](INFO): AMEcho.altitude 10.930000 m
2020-08-25T15:59:53.862Z,1598371193.862 [Reporter](INFO): AMEcho.altitude 11.150000 m
2020-08-25T15:59:55.886Z,1598371195.886 [Reporter](INFO): AMEcho.altitude 11.680000 m
2020-08-25T15:59:57.913Z,1598371197.913 [Reporter](INFO): AMEcho.altitude 11.750000 m
2020-08-25T15:59:59.945Z,1598371199.945 [Reporter](INFO): AMEcho.altitude 10.780000 m
2020-08-25T16:00:02.745Z,1598371202.745 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:00:03.966Z,1598371203.966 [Reporter](INFO): AMEcho.altitude 11.450000 m
2020-08-25T16:00:08.002Z,1598371208.002 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:00:08.835Z,1598371208.835 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:00:12.051Z,1598371212.051 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:00:16.903Z,1598371216.903 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:00:17.700Z,1598371217.700 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:00:19.717Z,1598371219.717 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:00:33.071Z,1598371233.071 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:00:37.917Z,1598371237.917 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:00:39.957Z,1598371239.957 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:00:43.984Z,1598371243.984 [Reporter](INFO): AMEcho.altitude 9.950000 m
2020-08-25T16:00:46.002Z,1598371246.002 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:00:52.898Z,1598371252.898 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:00:54.948Z,1598371254.948 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:01:00.929Z,1598371260.929 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:01:01.746Z,1598371261.746 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:01:03.765Z,1598371263.765 [Reporter](INFO): AMEcho.altitude 9.950000 m
2020-08-25T16:01:04.993Z,1598371264.993 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:01:09.826Z,1598371269.826 [Reporter](INFO): AMEcho.altitude 11.680000 m
2020-08-25T16:01:11.038Z,1598371271.038 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:01:11.837Z,1598371271.837 [Reporter](INFO): AMEcho.altitude 11.080000 m
2020-08-25T16:01:13.064Z,1598371273.064 [Reporter](INFO): AMEcho.altitude 9.800000 m
2020-08-25T16:01:15.890Z,1598371275.890 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:01:20.734Z,1598371280.734 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:01:21.943Z,1598371281.943 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:01:22.751Z,1598371282.751 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:01:25.989Z,1598371285.989 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:01:28.023Z,1598371288.023 [Reporter](INFO): AMEcho.altitude 13.480000 m
2020-08-25T16:01:32.875Z,1598371292.875 [Reporter](INFO): AMEcho.altitude 13.330000 m
2020-08-25T16:01:38.915Z,1598371298.915 [Reporter](INFO): AMEcho.altitude 13.250000 m
2020-08-25T16:01:39.716Z,1598371299.716 [Reporter](INFO): AMEcho.altitude 13.330000 m
2020-08-25T16:01:47.798Z,1598371307.798 [Reporter](INFO): AMEcho.altitude 13.400000 m
2020-08-25T16:01:51.853Z,1598371311.853 [Reporter](INFO): AMEcho.altitude 13.250000 m
2020-08-25T16:01:53.055Z,1598371313.055 [Reporter](INFO): AMEcho.altitude 13.400000 m
2020-08-25T16:01:58.698Z,1598371318.698 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:01:58.698Z,1598371318.698 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:01:58.698Z,1598371318.698 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:01:58.698Z,1598371318.698 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:01:59.094Z,1598371319.094 [Default:CheckIn:D] Stopped
2020-08-25T16:01:59.094Z,1598371319.094 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:01:59.508Z,1598371319.508 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.785620 min 
2020-08-25T16:01:59.508Z,1598371319.508 [Default:CheckIn:E] Stopped
2020-08-25T16:01:59.508Z,1598371319.508 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:01:59.508Z,1598371319.508 [Default:CheckIn] Stopped
2020-08-25T16:01:59.508Z,1598371319.508 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:01:59.508Z,1598371319.508 [Default:CheckIn](INFO): Running loop #4
2020-08-25T16:01:59.509Z,1598371319.509 [Default:CheckIn] Running Loop=4
2020-08-25T16:01:59.509Z,1598371319.509 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:01:59.509Z,1598371319.509 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:02:01.513Z,1598371321.513 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160201.00,A,3648.16760,N,12147.28496,W,0.058,220.54,250820,,,A*76
2020-08-25T16:02:01.516Z,1598371321.516 [NAL9602](INFO): GPS fix at 20200825T160201: (36.802793, -121.788083)
2020-08-25T16:02:01.549Z,1598371321.549 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:02:01.549Z,1598371321.549 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:02:06.001Z,1598371326.001 [Reporter](INFO): AMEcho.altitude 13.180000 m
2020-08-25T16:02:11.018Z,1598371331.018 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0013.lzma
2020-08-25T16:02:12.020Z,1598371332.020 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0013.lzma.bak
2020-08-25T16:02:12.020Z,1598371332.020 [DataOverHttps](INFO): SBD MOMSN=12614278
2020-08-25T16:02:23.024Z,1598371343.024 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:02:25.042Z,1598371345.042 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:02:27.871Z,1598371347.871 [Reporter](INFO): AMEcho.altitude 11.000000 m
2020-08-25T16:02:29.852Z,1598371349.852 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:02:31.100Z,1598371351.100 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:02:31.856Z,1598371351.856 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:02:33.070Z,1598371353.070 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:02:35.879Z,1598371355.879 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:02:39.955Z,1598371359.954 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:02:41.082Z,1598371361.082 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20200825T153601/Express0014.lzma
2020-08-25T16:02:41.976Z,1598371361.976 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:02:42.085Z,1598371362.085 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0014.lzma.bak
2020-08-25T16:02:42.085Z,1598371362.085 [DataOverHttps](INFO): SBD MOMSN=12614304
2020-08-25T16:02:42.756Z,1598371362.756 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:02:44.778Z,1598371364.778 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:02:44.778Z,1598371364.778 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:02:44.778Z,1598371364.778 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T16:02:50.853Z,1598371370.853 [Reporter](INFO): AMEcho.altitude 13.100000 m
2020-08-25T16:03:19.923Z,1598371399.923 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:03:20.753Z,1598371400.753 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:03:21.948Z,1598371401.948 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:03:23.979Z,1598371403.979 [Reporter](INFO): AMEcho.altitude 13.180000 m
2020-08-25T16:03:35.677Z,1598371415.677 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:03:37.693Z,1598371417.693 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:03:38.932Z,1598371418.932 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:03:39.732Z,1598371419.732 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:03:41.756Z,1598371421.756 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:03:44.987Z,1598371424.987 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:03:49.840Z,1598371429.840 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:03:51.041Z,1598371431.041 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:03:53.074Z,1598371433.074 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:03:53.859Z,1598371433.859 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:03:55.099Z,1598371435.099 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:03:56.686Z,1598371436.686 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:03:57.911Z,1598371437.911 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:03:58.707Z,1598371438.707 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:03:59.915Z,1598371439.915 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:04:04.763Z,1598371444.763 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:04:05.992Z,1598371445.992 [Reporter](INFO): AMEcho.altitude 9.950000 m
2020-08-25T16:04:12.054Z,1598371452.054 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:04:14.860Z,1598371454.860 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:04:16.103Z,1598371456.103 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:04:17.693Z,1598371457.693 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:04:18.914Z,1598371458.914 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:04:20.919Z,1598371460.919 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:04:21.745Z,1598371461.745 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:04:23.778Z,1598371463.778 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:04:25.770Z,1598371465.770 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:04:27.017Z,1598371467.017 [Reporter](INFO): AMEcho.altitude 10.850000 m
2020-08-25T16:04:27.819Z,1598371467.819 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:04:29.811Z,1598371469.811 [Reporter](INFO): AMEcho.altitude 11.150000 m
2020-08-25T16:04:31.064Z,1598371471.064 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:04:31.893Z,1598371471.893 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:04:33.093Z,1598371473.093 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:04:38.713Z,1598371478.713 [Reporter](INFO): AMEcho.altitude 10.850000 m
2020-08-25T16:04:39.915Z,1598371479.915 [Reporter](INFO): AMEcho.altitude 10.930000 m
2020-08-25T16:04:40.733Z,1598371480.733 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:04:46.007Z,1598371486.007 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:04:46.789Z,1598371486.789 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:04:48.819Z,1598371488.819 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:04:50.821Z,1598371490.821 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:04:52.039Z,1598371492.039 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:04:52.859Z,1598371492.859 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:04:54.076Z,1598371494.076 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:04:56.881Z,1598371496.881 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:05:02.944Z,1598371502.944 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:05:03.766Z,1598371503.766 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:05:04.966Z,1598371504.966 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:05:05.762Z,1598371505.762 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:05:07.003Z,1598371507.003 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:05:09.009Z,1598371509.009 [Reporter](INFO): AMEcho.altitude 10.850000 m
2020-08-25T16:05:09.832Z,1598371509.832 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:05:11.026Z,1598371511.026 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:05:15.875Z,1598371515.875 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:05:17.924Z,1598371517.924 [Reporter](INFO): AMEcho.altitude 10.850000 m
2020-08-25T16:05:18.745Z,1598371518.745 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:05:21.931Z,1598371521.931 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:05:24.787Z,1598371524.787 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:05:25.989Z,1598371525.989 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:05:27.987Z,1598371527.987 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:05:28.805Z,1598371528.805 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:05:30.837Z,1598371530.837 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:05:32.835Z,1598371532.835 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:05:34.876Z,1598371534.876 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:05:36.888Z,1598371536.888 [Reporter](INFO): AMEcho.altitude 10.780000 m
2020-08-25T16:05:37.685Z,1598371537.685 [Reporter](INFO): AMEcho.altitude 13.400000 m
2020-08-25T16:05:46.970Z,1598371546.970 [Reporter](INFO): AMEcho.altitude 13.330000 m
2020-08-25T16:05:47.797Z,1598371547.797 [Reporter](INFO): AMEcho.altitude 13.400000 m
2020-08-25T16:05:48.998Z,1598371548.998 [Reporter](INFO): AMEcho.altitude 13.330000 m
2020-08-25T16:05:51.046Z,1598371551.046 [Reporter](INFO): AMEcho.altitude 13.250000 m
2020-08-25T16:06:10.011Z,1598371570.011 [Reporter](INFO): AMEcho.altitude 13.180000 m
2020-08-25T16:06:12.841Z,1598371572.841 [Reporter](INFO): AMEcho.altitude 13.250000 m
2020-08-25T16:06:19.721Z,1598371579.721 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:06:20.919Z,1598371580.919 [Reporter](INFO): AMEcho.altitude 13.250000 m
2020-08-25T16:06:21.721Z,1598371581.721 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:06:24.945Z,1598371584.945 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:06:25.769Z,1598371585.769 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:06:27.019Z,1598371587.019 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:06:35.064Z,1598371595.064 [Reporter](INFO): AMEcho.altitude 10.780000 m
2020-08-25T16:06:38.729Z,1598371598.729 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:06:42.742Z,1598371602.742 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:06:43.956Z,1598371603.956 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:06:44.749Z,1598371604.749 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:06:46.767Z,1598371606.767 [Reporter](INFO): AMEcho.altitude 10.850000 m
2020-08-25T16:06:49.996Z,1598371609.996 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:06:52.826Z,1598371612.826 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:06:54.059Z,1598371614.059 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:06:54.863Z,1598371614.863 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:06:56.872Z,1598371616.872 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:07:00.951Z,1598371620.951 [Reporter](INFO): AMEcho.altitude 10.100000 m
2020-08-25T16:07:02.931Z,1598371622.931 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:07:04.116Z,1598371624.116 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T16:07:04.959Z,1598371624.959 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:07:05.784Z,1598371625.784 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:07:06.992Z,1598371626.992 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:07:07.771Z,1598371627.771 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:07:13.036Z,1598371633.036 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:07:13.976Z,1598371633.976 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:07:15.064Z,1598371635.064 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:07:15.855Z,1598371635.855 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:07:19.920Z,1598371639.920 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:07:22.740Z,1598371642.740 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:07:23.967Z,1598371643.967 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:07:26.759Z,1598371646.759 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:07:29.989Z,1598371649.989 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:07:32.846Z,1598371652.846 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:07:34.818Z,1598371654.818 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T16:07:34.839Z,1598371654.839 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:07:38.890Z,1598371658.890 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:07:39.709Z,1598371659.709 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:07:45.341Z,1598371665.341 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:07:45.341Z,1598371665.341 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:07:45.342Z,1598371665.342 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:07:45.342Z,1598371665.342 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:07:45.742Z,1598371665.742 [Default:CheckIn:D] Stopped
2020-08-25T16:07:45.742Z,1598371665.742 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:07:45.772Z,1598371665.772 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:07:46.144Z,1598371666.144 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.563086 min 
2020-08-25T16:07:46.144Z,1598371666.144 [Default:CheckIn:E] Stopped
2020-08-25T16:07:46.144Z,1598371666.144 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:07:46.144Z,1598371666.144 [Default:CheckIn] Stopped
2020-08-25T16:07:46.144Z,1598371666.144 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:07:46.144Z,1598371666.144 [Default:CheckIn](INFO): Running loop #5
2020-08-25T16:07:46.144Z,1598371666.144 [Default:CheckIn] Running Loop=5
2020-08-25T16:07:46.144Z,1598371666.144 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:07:46.145Z,1598371666.145 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:07:48.153Z,1598371668.153 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160747.00,A,3648.17337,N,12147.28520,W,0.136,30.76,250820,,,A*40
2020-08-25T16:07:48.155Z,1598371668.155 [NAL9602](INFO): GPS fix at 20200825T160747: (36.802889, -121.788087)
2020-08-25T16:07:48.164Z,1598371668.164 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:07:48.164Z,1598371668.164 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:07:56.290Z,1598371676.290 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T153601/Courier0016.lzma
2020-08-25T16:07:57.292Z,1598371677.292 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0016.lzma.bak
2020-08-25T16:07:57.292Z,1598371677.292 [DataOverHttps](INFO): SBD MOMSN=12614315
2020-08-25T16:08:14.522Z,1598371694.522 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20200825T153601/Express0017.lzma
2020-08-25T16:08:15.525Z,1598371695.525 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0017.lzma.bak
2020-08-25T16:08:15.525Z,1598371695.525 [DataOverHttps](INFO): SBD MOMSN=12614318
2020-08-25T16:08:18.458Z,1598371698.458 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:08:18.458Z,1598371698.458 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:08:18.458Z,1598371698.458 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T16:08:18.851Z,1598371698.851 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-25T16:08:18.930Z,1598371698.930 [NAL9602](FAULT): received: 
+CSQ:0

OK09, 2, 0, 0, 0

OK
2020-08-25T16:08:18.931Z,1598371698.931 [NAL9602] Data Fault, FailCount= 1
2020-08-25T16:08:18.931Z,1598371698.931 [NAL9602](ERROR): Data Fault
2020-08-25T16:08:18.959Z,1598371698.959 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T16:08:19.255Z,1598371699.255 [NAL9602](INFO): Powering down
2020-08-25T16:08:20.088Z,1598371700.088 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T16:08:20.089Z,1598371700.089 [NAL9602] No Fault, FailCount= 1
2020-08-25T16:08:49.563Z,1598371729.563 [NAL9602](INFO): Powering up NAL9602
2020-08-25T16:08:58.871Z,1598371738.871 [Reporter](INFO): AMEcho.altitude 21.730000 m
2020-08-25T16:09:00.467Z,1598371740.467 [NAL9602](INFO): NAL9602 initialized
2020-08-25T16:09:02.924Z,1598371742.924 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:09:08.997Z,1598371748.997 [Reporter](INFO): AMEcho.altitude 21.730000 m
2020-08-25T16:09:09.779Z,1598371749.779 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:09:31.575Z,1598371771.575 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T16:09:45.733Z,1598371785.733 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T16:09:47.760Z,1598371787.760 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:09:49.778Z,1598371789.778 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T16:09:55.834Z,1598371795.834 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:10:14.820Z,1598371814.820 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T16:10:16.072Z,1598371816.072 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:10:18.049Z,1598371818.049 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T16:11:45.752Z,1598371905.752 [Reporter](INFO): AMEcho.altitude 21.799999 m
2020-08-25T16:11:49.782Z,1598371909.782 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T16:12:37.058Z,1598371957.058 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:12:44.739Z,1598371964.739 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T16:12:48.768Z,1598371968.768 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:12:52.836Z,1598371972.836 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T16:12:54.826Z,1598371974.826 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:12:56.037Z,1598371976.037 [Reporter](INFO): AMEcho.altitude 21.580000 m
2020-08-25T16:12:56.854Z,1598371976.854 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:13:17.057Z,1598371997.057 [Reporter](INFO): AMEcho.altitude 21.730000 m
2020-08-25T16:13:19.055Z,1598371999.055 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:13:19.055Z,1598371999.055 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:13:19.055Z,1598371999.055 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:13:19.055Z,1598371999.055 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:13:19.468Z,1598371999.468 [Default:CheckIn:D] Stopped
2020-08-25T16:13:19.468Z,1598371999.468 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:13:19.871Z,1598371999.871 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.125189 min 
2020-08-25T16:13:19.871Z,1598371999.871 [Default:CheckIn:E] Stopped
2020-08-25T16:13:19.871Z,1598371999.871 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:13:19.871Z,1598371999.871 [Default:CheckIn] Stopped
2020-08-25T16:13:19.872Z,1598371999.872 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:13:19.872Z,1598371999.872 [Default:CheckIn](INFO): Running loop #6
2020-08-25T16:13:19.872Z,1598371999.872 [Default:CheckIn] Running Loop=6
2020-08-25T16:13:19.872Z,1598371999.872 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:13:19.872Z,1598371999.872 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:13:23.894Z,1598372003.894 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T16:13:42.918Z,1598372022.918 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:13:59.071Z,1598372039.071 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:14:03.131Z,1598372043.131 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:14:03.514Z,1598372043.514 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161402.00,A,3648.16136,N,12147.28430,W,0.058,223.01,250820,,,A*78
2020-08-25T16:14:03.516Z,1598372043.516 [NAL9602](INFO): GPS fix at 20200825T161402: (36.802689, -121.788072)
2020-08-25T16:14:03.551Z,1598372043.551 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:14:03.552Z,1598372043.552 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:14:05.948Z,1598372045.948 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:14:10.016Z,1598372050.016 [Reporter](INFO): AMEcho.altitude 10.850000 m
2020-08-25T16:14:10.789Z,1598372050.789 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:14:11.346Z,1598372051.346 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T153601/Courier0019.lzma
2020-08-25T16:14:12.348Z,1598372052.348 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0019.lzma.bak
2020-08-25T16:14:12.348Z,1598372052.348 [DataOverHttps](INFO): SBD MOMSN=12614356
2020-08-25T16:14:16.036Z,1598372056.036 [Reporter](INFO): AMEcho.altitude 9.950000 m
2020-08-25T16:14:16.873Z,1598372056.873 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:14:20.881Z,1598372060.881 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:14:29.001Z,1598372069.001 [Reporter](INFO): AMEcho.altitude 3.310000 m
2020-08-25T16:14:32.055Z,1598372072.055 [DataOverHttps](INFO): Sending 245 bytes from file Logs/20200825T153601/Express0020.lzma
2020-08-25T16:14:33.056Z,1598372073.056 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0020.lzma.bak
2020-08-25T16:14:33.056Z,1598372073.056 [DataOverHttps](INFO): SBD MOMSN=12614359
2020-08-25T16:14:35.821Z,1598372075.821 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:14:35.821Z,1598372075.821 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:14:35.821Z,1598372075.821 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T16:14:36.219Z,1598372076.219 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T16:14:43.115Z,1598372083.115 [Reporter](INFO): AMEcho.altitude 3.300000 m
2020-08-25T16:14:43.909Z,1598372083.909 [Reporter](INFO): AMEcho.altitude 3.310000 m
2020-08-25T16:14:46.776Z,1598372086.776 [Reporter](INFO): AMEcho.altitude 3.300000 m
2020-08-25T16:14:48.796Z,1598372088.796 [Reporter](INFO): AMEcho.altitude 3.310000 m
2020-08-25T16:14:56.030Z,1598372096.030 [Reporter](INFO): AMEcho.altitude 10.780000 m
2020-08-25T16:15:04.144Z,1598372104.144 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:15:04.932Z,1598372104.932 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:15:09.778Z,1598372109.778 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:15:15.050Z,1598372115.050 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:15:17.043Z,1598372117.043 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:15:19.059Z,1598372119.059 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:15:19.893Z,1598372119.893 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:15:26.764Z,1598372126.764 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T16:15:27.954Z,1598372127.954 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:15:29.981Z,1598372129.981 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:15:32.017Z,1598372132.017 [Reporter](INFO): AMEcho.altitude 9.950000 m
2020-08-25T16:15:38.069Z,1598372138.069 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:15:38.863Z,1598372138.863 [Reporter](INFO): AMEcho.altitude 10.330000 m
2020-08-25T16:15:40.070Z,1598372140.070 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:15:40.875Z,1598372140.875 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:15:44.919Z,1598372144.919 [Reporter](INFO): AMEcho.altitude 9.950000 m
2020-08-25T16:15:45.748Z,1598372145.748 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T16:15:52.995Z,1598372152.995 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:16:35.041Z,1598372195.041 [Reporter](INFO): AMEcho.altitude 21.730000 m
2020-08-25T16:16:51.994Z,1598372211.994 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:18:07.951Z,1598372287.951 [Reporter](INFO): AMEcho.altitude 21.950001 m
2020-08-25T16:18:10.774Z,1598372290.774 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:18:35.834Z,1598372315.834 [Reporter](INFO): AMEcho.altitude 21.730000 m
2020-08-25T16:18:41.929Z,1598372321.929 [Reporter](INFO): AMEcho.altitude 21.650000 m
2020-08-25T16:18:47.962Z,1598372327.962 [Reporter](INFO): AMEcho.altitude 21.730000 m
2020-08-25T16:19:36.429Z,1598372376.429 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:19:36.429Z,1598372376.429 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:19:36.429Z,1598372376.429 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:19:36.429Z,1598372376.429 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:19:36.862Z,1598372376.862 [Default:CheckIn:D] Stopped
2020-08-25T16:19:36.862Z,1598372376.862 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:19:37.226Z,1598372377.226 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.415096 min 
2020-08-25T16:19:37.226Z,1598372377.226 [Default:CheckIn:E] Stopped
2020-08-25T16:19:37.227Z,1598372377.227 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:19:37.227Z,1598372377.227 [Default:CheckIn] Stopped
2020-08-25T16:19:37.227Z,1598372377.227 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:19:37.227Z,1598372377.227 [Default:CheckIn](INFO): Running loop #7
2020-08-25T16:19:37.227Z,1598372377.227 [Default:CheckIn] Running Loop=7
2020-08-25T16:19:37.227Z,1598372377.227 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:19:37.227Z,1598372377.227 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:19:39.245Z,1598372379.245 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161938.00,A,3648.17071,N,12147.28287,W,0.136,277.56,250820,,,A*7F
2020-08-25T16:19:39.247Z,1598372379.247 [NAL9602](INFO): GPS fix at 20200825T161938: (36.802845, -121.788048)
2020-08-25T16:19:39.256Z,1598372379.256 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:19:39.256Z,1598372379.256 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:19:47.674Z,1598372387.674 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0022.lzma
2020-08-25T16:19:48.676Z,1598372388.676 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0022.lzma.bak
2020-08-25T16:19:48.676Z,1598372388.676 [DataOverHttps](INFO): SBD MOMSN=12614371
2020-08-25T16:20:06.006Z,1598372406.006 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20200825T153601/Express0023.lzma
2020-08-25T16:20:07.008Z,1598372407.008 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0023.lzma.bak
2020-08-25T16:20:07.008Z,1598372407.008 [DataOverHttps](INFO): SBD MOMSN=12614374
2020-08-25T16:20:09.965Z,1598372409.965 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:20:09.966Z,1598372409.966 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:20:09.966Z,1598372409.966 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T16:20:16.031Z,1598372416.031 [Reporter](INFO): AMEcho.altitude 21.799999 m
2020-08-25T16:21:44.918Z,1598372504.918 [Reporter](INFO): AMEcho.altitude 21.730000 m
2020-08-25T16:21:55.851Z,1598372515.851 [Reporter](INFO): AMEcho.altitude 21.799999 m
2020-08-25T16:21:57.050Z,1598372517.050 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:22:03.948Z,1598372523.948 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:22:05.930Z,1598372525.930 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:22:18.059Z,1598372538.059 [Reporter](INFO): AMEcho.altitude 10.250000 m
2020-08-25T16:22:20.096Z,1598372540.096 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:22:22.148Z,1598372542.148 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:22:43.994Z,1598372563.994 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:22:56.868Z,1598372576.868 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:23:10.998Z,1598372590.998 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:23:13.026Z,1598372593.026 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:23:15.067Z,1598372595.067 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:23:15.851Z,1598372595.851 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:23:16.636Z,1598372596.636 [NAL9602](INFO): SBD MO Status=2, MOMSN=8109, MT Status=2, MTMSN=0
2020-08-25T16:23:16.637Z,1598372596.637 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T16:23:17.861Z,1598372597.861 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:23:47.793Z,1598372627.793 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:23:53.824Z,1598372633.824 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:23:59.087Z,1598372639.087 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:23:59.865Z,1598372639.865 [NAL9602](INFO): SBD MO Status=2, MOMSN=8109, MT Status=2, MTMSN=0
2020-08-25T16:23:59.865Z,1598372639.865 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T16:24:12.029Z,1598372652.029 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:24:14.068Z,1598372654.068 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:24:35.063Z,1598372675.063 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:24:38.260Z,1598372678.260 [NAL9602](INFO): SBD MO Status=0, MOMSN=8109, MT Status=0, MTMSN=0
2020-08-25T16:24:38.261Z,1598372678.261 [NAL9602](INFO): No messages in MT queue
2020-08-25T16:25:08.965Z,1598372708.965 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T16:25:10.582Z,1598372710.582 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:25:10.590Z,1598372710.590 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:25:10.590Z,1598372710.590 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:25:10.590Z,1598372710.590 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:25:10.992Z,1598372710.992 [Default:CheckIn:D] Stopped
2020-08-25T16:25:10.993Z,1598372710.993 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:25:11.392Z,1598372711.392 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.983936 min 
2020-08-25T16:25:11.392Z,1598372711.392 [Default:CheckIn:E] Stopped
2020-08-25T16:25:11.392Z,1598372711.392 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:25:11.392Z,1598372711.392 [Default:CheckIn] Stopped
2020-08-25T16:25:11.393Z,1598372711.393 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:25:11.393Z,1598372711.393 [Default:CheckIn](INFO): Running loop #8
2020-08-25T16:25:11.393Z,1598372711.393 [Default:CheckIn] Running Loop=8
2020-08-25T16:25:11.393Z,1598372711.393 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:25:11.393Z,1598372711.393 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:25:13.411Z,1598372713.411 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162512.00,A,3648.16270,N,12147.28053,W,0.136,357.64,250820,,,A*73
2020-08-25T16:25:13.413Z,1598372713.413 [NAL9602](INFO): GPS fix at 20200825T162512: (36.802712, -121.788009)
2020-08-25T16:25:13.430Z,1598372713.430 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:25:13.430Z,1598372713.430 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:25:22.022Z,1598372722.022 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T153601/Courier0025.lzma
2020-08-25T16:25:23.024Z,1598372723.024 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0025.lzma.bak
2020-08-25T16:25:23.024Z,1598372723.024 [DataOverHttps](INFO): SBD MOMSN=12614403
2020-08-25T16:25:34.815Z,1598372734.815 [NAL9602](INFO): SBD MO Status=0, MOMSN=8110, MT Status=0, MTMSN=0
2020-08-25T16:25:34.815Z,1598372734.815 [NAL9602](INFO): No messages in MT queue
2020-08-25T16:25:34.860Z,1598372734.860 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:25:36.065Z,1598372736.065 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:25:36.893Z,1598372736.893 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:25:40.894Z,1598372740.894 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:25:41.214Z,1598372741.214 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20200825T153601/Express0026.lzma
2020-08-25T16:25:42.217Z,1598372742.217 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0026.lzma.bak
2020-08-25T16:25:42.217Z,1598372742.217 [DataOverHttps](INFO): SBD MOMSN=12614411
2020-08-25T16:25:44.933Z,1598372744.933 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:25:44.933Z,1598372744.933 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:25:44.933Z,1598372744.933 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T16:26:05.524Z,1598372765.524 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T16:26:09.983Z,1598372769.983 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:26:41.906Z,1598372801.906 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:26:52.012Z,1598372812.012 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:27:04.122Z,1598372824.122 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:27:06.152Z,1598372826.152 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:27:09.790Z,1598372829.790 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:27:15.842Z,1598372835.842 [Reporter](INFO): AMEcho.altitude 10.030000 m
2020-08-25T16:27:25.945Z,1598372845.945 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:27:34.823Z,1598372854.823 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:27:38.872Z,1598372858.872 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:27:42.950Z,1598372862.950 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:28:24.111Z,1598372904.111 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:28:43.915Z,1598372923.915 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:29:19.072Z,1598372959.072 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:30:07.955Z,1598373007.955 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:30:41.903Z,1598373041.903 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:30:45.523Z,1598373045.523 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:30:45.523Z,1598373045.523 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:30:45.524Z,1598373045.524 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:30:45.524Z,1598373045.524 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:30:45.934Z,1598373045.934 [Default:CheckIn:D] Stopped
2020-08-25T16:30:45.934Z,1598373045.934 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:30:46.323Z,1598373046.323 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.566284 min 
2020-08-25T16:30:46.323Z,1598373046.323 [Default:CheckIn:E] Stopped
2020-08-25T16:30:46.323Z,1598373046.323 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:30:46.323Z,1598373046.323 [Default:CheckIn] Stopped
2020-08-25T16:30:46.323Z,1598373046.323 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:30:46.323Z,1598373046.323 [Default:CheckIn](INFO): Running loop #9
2020-08-25T16:30:46.323Z,1598373046.323 [Default:CheckIn] Running Loop=9
2020-08-25T16:30:46.323Z,1598373046.323 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:30:46.324Z,1598373046.324 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:30:48.335Z,1598373048.335 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163047.00,A,3648.16477,N,12147.28215,W,0.622,357.64,250820,,,A*74
2020-08-25T16:30:48.337Z,1598373048.337 [NAL9602](INFO): GPS fix at 20200825T163047: (36.802746, -121.788036)
2020-08-25T16:30:48.347Z,1598373048.347 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:30:48.347Z,1598373048.347 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:30:57.330Z,1598373057.330 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0028.lzma
2020-08-25T16:30:58.332Z,1598373058.332 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0028.lzma.bak
2020-08-25T16:30:58.332Z,1598373058.332 [DataOverHttps](INFO): SBD MOMSN=12614419
2020-08-25T16:31:15.634Z,1598373075.634 [DataOverHttps](INFO): Sending 129 bytes from file Logs/20200825T153601/Express0029.lzma
2020-08-25T16:31:16.636Z,1598373076.636 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0029.lzma.bak
2020-08-25T16:31:16.636Z,1598373076.636 [DataOverHttps](INFO): SBD MOMSN=12614423
2020-08-25T16:31:19.725Z,1598373079.725 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:31:19.726Z,1598373079.726 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:31:19.726Z,1598373079.726 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T16:31:29.880Z,1598373089.880 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:31:41.146Z,1598373101.146 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:31:57.697Z,1598373117.697 [NAL9602](INFO): SBD MO Status=2, MOMSN=8111, MT Status=2, MTMSN=0
2020-08-25T16:31:57.697Z,1598373117.697 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T16:33:06.789Z,1598373186.789 [NAL9602](INFO): SBD MO Status=2, MOMSN=8111, MT Status=2, MTMSN=0
2020-08-25T16:33:06.789Z,1598373186.789 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T16:33:12.900Z,1598373192.900 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:33:51.233Z,1598373231.233 [NAL9602](INFO): SBD MO Status=0, MOMSN=8111, MT Status=0, MTMSN=0
2020-08-25T16:33:51.233Z,1598373231.233 [NAL9602](INFO): No messages in MT queue
2020-08-25T16:34:21.959Z,1598373261.959 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T16:34:31.750Z,1598373271.750 [CommandLine](IMPORTANT): got command strobe off
2020-08-25T16:34:31.751Z,1598373271.751 [CommandLine](IMPORTANT): Deactivating strobe
2020-08-25T16:36:13.061Z,1598373373.061 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:36:17.926Z,1598373377.926 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:36:19.132Z,1598373379.132 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:36:19.930Z,1598373379.930 [Reporter](INFO): AMEcho.altitude 10.400000 m
2020-08-25T16:36:20.328Z,1598373380.328 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:36:20.328Z,1598373380.328 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:36:20.328Z,1598373380.328 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:36:20.328Z,1598373380.328 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:36:20.738Z,1598373380.738 [Default:CheckIn:D] Stopped
2020-08-25T16:36:20.738Z,1598373380.738 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:36:21.176Z,1598373381.176 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.146358 min 
2020-08-25T16:36:21.176Z,1598373381.176 [Default:CheckIn:E] Stopped
2020-08-25T16:36:21.176Z,1598373381.176 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:36:21.176Z,1598373381.176 [Default:CheckIn] Stopped
2020-08-25T16:36:21.176Z,1598373381.176 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:36:21.176Z,1598373381.176 [Default:CheckIn](INFO): Running loop #10
2020-08-25T16:36:21.176Z,1598373381.176 [Default:CheckIn] Running Loop=10
2020-08-25T16:36:21.176Z,1598373381.176 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:36:21.176Z,1598373381.176 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:36:23.149Z,1598373383.149 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163622.00,A,3648.16384,N,12147.28041,W,0.117,357.64,250820,,,A*78
2020-08-25T16:36:23.151Z,1598373383.151 [NAL9602](INFO): GPS fix at 20200825T163622: (36.802731, -121.788007)
2020-08-25T16:36:23.169Z,1598373383.169 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:36:23.169Z,1598373383.169 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:36:31.206Z,1598373391.206 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:36:33.870Z,1598373393.870 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0031.lzma
2020-08-25T16:36:34.872Z,1598373394.872 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0031.lzma.bak
2020-08-25T16:36:34.872Z,1598373394.872 [DataOverHttps](INFO): SBD MOMSN=12614455
2020-08-25T16:36:45.681Z,1598373405.681 [NAL9602](INFO): SBD MO Status=2, MOMSN=8112, MT Status=2, MTMSN=0
2020-08-25T16:36:45.681Z,1598373405.681 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T16:36:46.127Z,1598373406.127 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:36:50.192Z,1598373410.192 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:36:52.530Z,1598373412.530 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20200825T153601/Express0032.lzma
2020-08-25T16:36:53.532Z,1598373413.532 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0032.lzma.bak
2020-08-25T16:36:53.532Z,1598373413.532 [DataOverHttps](INFO): SBD MOMSN=12614462
2020-08-25T16:36:56.614Z,1598373416.614 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:36:56.614Z,1598373416.614 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:36:56.614Z,1598373416.614 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T16:37:28.155Z,1598373448.155 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:37:30.153Z,1598373450.153 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:37:37.031Z,1598373457.031 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:37:49.125Z,1598373469.125 [NAL9602](INFO): SBD MO Status=2, MOMSN=8112, MT Status=2, MTMSN=0
2020-08-25T16:37:49.125Z,1598373469.125 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T16:38:59.879Z,1598373539.879 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:39:11.991Z,1598373551.991 [Reporter](INFO): AMEcho.altitude 10.700000 m
2020-08-25T16:39:41.081Z,1598373581.081 [Reporter](INFO): AMEcho.altitude 10.630000 m
2020-08-25T16:39:58.090Z,1598373598.090 [CommandLine](IMPORTANT): got command failComponent
2020-08-25T16:39:58.091Z,1598373598.091 [CommandLine](IMPORTANT): Failed components:
2020-08-25T16:39:58.091Z,1598373598.091 [CommandLine](IMPORTANT): No failed Components.
2020-08-25T16:40:00.879Z,1598373600.879 [Reporter](INFO): AMEcho.altitude 10.550000 m
2020-08-25T16:40:04.929Z,1598373604.929 [Reporter](INFO): AMEcho.altitude 10.480000 m
2020-08-25T16:40:10.210Z,1598373610.210 [CommandLine](IMPORTANT): got command report
2020-08-25T16:40:10.210Z,1598373610.210 [Reporter](INFO): AMEcho.altitude reporting changes
2020-08-25T16:40:17.097Z,1598373617.097 [CommandLine](IMPORTANT): got command report clear
2020-08-25T16:40:57.833Z,1598373657.833 [NAL9602](INFO): SBD MO Status=2, MOMSN=8112, MT Status=2, MTMSN=0
2020-08-25T16:40:57.833Z,1598373657.833 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T16:41:24.903Z,1598373684.903 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T16:41:33.025Z,1598373693.025 [CommandLine](IMPORTANT): got command show variable address
2020-08-25T16:41:33.044Z,1598373693.044 [CommandLine](IMPORTANT): acoustic_contact_address (unknown)
2020-08-25T16:41:33.065Z,1598373693.065 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.localAddress (count)
2020-08-25T16:41:33.071Z,1598373693.071 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.sbdAddress (enum)
2020-08-25T16:41:33.071Z,1598373693.071 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.transponderAddress (enum)
2020-08-25T16:41:33.074Z,1598373693.074 [CommandLine](IMPORTANT): DAT.localAddress (count)
2020-08-25T16:41:33.074Z,1598373693.074 [CommandLine](IMPORTANT): DAT.sbdAddress (enum)
2020-08-25T16:41:33.075Z,1598373693.075 [CommandLine](IMPORTANT): DAT.transponderAddress (enum)
2020-08-25T16:41:33.078Z,1598373693.078 [CommandLine](IMPORTANT): Micromodem.localAddress (enum)
2020-08-25T16:41:33.079Z,1598373693.079 [CommandLine](IMPORTANT): Micromodem.destinationAddress (enum)
2020-08-25T16:41:33.293Z,1598373693.293 [CommandLine](IMPORTANT): DAT.remoteAddress (enum)
2020-08-25T16:41:33.293Z,1598373693.293 [CommandLine](IMPORTANT): DAT.localAddressReading (enum)
2020-08-25T16:41:39.770Z,1598373699.770 [CommandLine](IMPORTANT): got command get DAT.localAddress
2020-08-25T16:41:39.770Z,1598373699.770 [CommandLine](IMPORTANT): DAT.localAddress 9 count
2020-08-25T16:41:55.601Z,1598373715.601 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T16:41:57.236Z,1598373717.236 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:41:57.236Z,1598373717.236 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:41:57.236Z,1598373717.236 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:41:57.236Z,1598373717.236 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:41:57.640Z,1598373717.640 [Default:CheckIn:D] Stopped
2020-08-25T16:41:57.640Z,1598373717.640 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:41:58.082Z,1598373718.082 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 61.761393 min 
2020-08-25T16:41:58.082Z,1598373718.082 [Default:CheckIn:E] Stopped
2020-08-25T16:41:58.082Z,1598373718.082 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:41:58.082Z,1598373718.082 [Default:CheckIn] Stopped
2020-08-25T16:41:58.082Z,1598373718.082 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:41:58.083Z,1598373718.083 [Default:CheckIn](INFO): Running loop #11
2020-08-25T16:41:58.083Z,1598373718.083 [Default:CheckIn] Running Loop=11
2020-08-25T16:41:58.083Z,1598373718.083 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:41:58.083Z,1598373718.083 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:42:00.049Z,1598373720.049 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164159.00,A,3648.16407,N,12147.28243,W,0.194,0.00,250820,,,A*70
2020-08-25T16:42:00.051Z,1598373720.051 [NAL9602](INFO): GPS fix at 20200825T164159: (36.802734, -121.788040)
2020-08-25T16:42:00.062Z,1598373720.062 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:42:00.062Z,1598373720.062 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:42:08.178Z,1598373728.178 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0034.lzma
2020-08-25T16:42:09.180Z,1598373729.180 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0034.lzma.bak
2020-08-25T16:42:09.180Z,1598373729.180 [DataOverHttps](INFO): SBD MOMSN=12614471
2020-08-25T16:42:26.679Z,1598373746.679 [DataOverHttps](INFO): Sending 488 bytes from file Logs/20200825T153601/Express0035.lzma
2020-08-25T16:42:27.680Z,1598373747.680 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0035.lzma.bak
2020-08-25T16:42:27.681Z,1598373747.681 [DataOverHttps](INFO): SBD MOMSN=12614481
2020-08-25T16:42:30.767Z,1598373750.767 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-25T16:42:30.851Z,1598373750.851 [NAL9602](FAULT): received: 
+CSQ:0

OK12, 2, 0, 0, 0

OK
2020-08-25T16:42:30.851Z,1598373750.851 [NAL9602] Data Fault, FailCount= 1
2020-08-25T16:42:30.851Z,1598373750.851 [NAL9602](ERROR): Data Fault
2020-08-25T16:42:30.931Z,1598373750.931 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T16:42:31.175Z,1598373751.175 [NAL9602](INFO): Powering down
2020-08-25T16:42:31.985Z,1598373751.985 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:42:31.986Z,1598373751.986 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:42:31.986Z,1598373751.986 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T16:42:31.995Z,1598373751.995 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T16:42:31.995Z,1598373751.995 [NAL9602] No Fault, FailCount= 1
2020-08-25T16:42:37.327Z,1598373757.327 [CommandLine](IMPORTANT): got command show variable limitFwd
2020-08-25T16:42:37.478Z,1598373757.478 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter)
2020-08-25T16:42:42.704Z,1598373762.704 [CommandLine](IMPORTANT): got command get VerticalControl.massPositionLimitFwd
2020-08-25T16:42:42.705Z,1598373762.705 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd 40.000000 mm
2020-08-25T16:42:53.888Z,1598373773.888 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 3.000000 centimeter
2020-08-25T16:42:53.889Z,1598373773.889 [ComponentRegistry](DEBUG): SyncComponent "Maintain_VerticalControl.massPositionAction" handled in the control thread.
2020-08-25T16:42:54.263Z,1598373774.263 [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,Maintain_VerticalControl.massPositionAction,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-08-25T16:43:01.467Z,1598373781.467 [NAL9602](INFO): Powering up NAL9602
2020-08-25T16:43:12.375Z,1598373792.375 [NAL9602](INFO): NAL9602 initialized
2020-08-25T16:43:43.481Z,1598373823.481 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T16:46:46.440Z,1598374006.440 [CommandLine](IMPORTANT): got command get DAT.loadAtStartup
2020-08-25T16:46:46.441Z,1598374006.441 [CommandLine](IMPORTANT): DAT.loadAtStartup 1 bool
2020-08-25T16:46:50.642Z,1598374010.642 [CommandLine](IMPORTANT): got command get DAT.simulateHardware
2020-08-25T16:46:50.643Z,1598374010.643 [CommandLine](IMPORTANT): DAT.simulateHardware 0 bool
2020-08-25T16:46:56.071Z,1598374016.071 [CommandLine](IMPORTANT): got command get DAT.uart
2020-08-25T16:46:56.071Z,1598374016.071 [CommandLine](IMPORTANT): DAT.uart /dev/ttyB3
2020-08-25T16:47:32.599Z,1598374052.599 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:47:32.599Z,1598374052.599 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:47:32.599Z,1598374052.599 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:47:32.599Z,1598374052.599 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:47:33.017Z,1598374053.017 [Default:CheckIn:D] Stopped
2020-08-25T16:47:33.017Z,1598374053.017 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:47:33.426Z,1598374053.426 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.351013 min 
2020-08-25T16:47:33.426Z,1598374053.426 [Default:CheckIn:E] Stopped
2020-08-25T16:47:33.426Z,1598374053.426 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:47:33.426Z,1598374053.426 [Default:CheckIn] Stopped
2020-08-25T16:47:33.426Z,1598374053.426 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:47:33.427Z,1598374053.427 [Default:CheckIn](INFO): Running loop #12
2020-08-25T16:47:33.427Z,1598374053.427 [Default:CheckIn] Running Loop=12
2020-08-25T16:47:33.427Z,1598374053.427 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:47:33.427Z,1598374053.427 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:47:35.437Z,1598374055.437 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164735.00,A,3648.16243,N,12147.28529,W,0.330,0.00,250820,,,A*7D
2020-08-25T16:47:35.446Z,1598374055.446 [NAL9602](INFO): GPS fix at 20200825T164735: (36.802707, -121.788088)
2020-08-25T16:47:35.456Z,1598374055.456 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:47:35.456Z,1598374055.456 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:47:37.844Z,1598374057.844 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T16:47:43.862Z,1598374063.862 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0037.lzma
2020-08-25T16:47:44.864Z,1598374064.864 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0037.lzma.bak
2020-08-25T16:47:44.865Z,1598374064.865 [DataOverHttps](INFO): SBD MOMSN=12614550
2020-08-25T16:48:03.362Z,1598374083.362 [DataOverHttps](INFO): Sending 398 bytes from file Logs/20200825T153601/Express0038.lzma
2020-08-25T16:48:04.362Z,1598374084.362 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0038.lzma.bak
2020-08-25T16:48:04.362Z,1598374084.362 [DataOverHttps](INFO): SBD MOMSN=12614556
2020-08-25T16:48:07.347Z,1598374087.347 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:48:07.347Z,1598374087.347 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:48:07.347Z,1598374087.347 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T16:48:08.547Z,1598374088.547 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T16:50:34.010Z,1598374234.010 [CommandLine](IMPORTANT): got command show variable limitFwd
2020-08-25T16:50:34.152Z,1598374234.152 [CommandLine](IMPORTANT): VerticalControl.massPositionLimitFwd (millimeter)
2020-08-25T16:50:42.517Z,1598374242.517 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-25T16:50:42.519Z,1598374242.519 [BPC1](INFO): Received data from all battery sticks.
2020-08-25T16:50:48.545Z,1598374248.545 [CommandLine](IMPORTANT): got command maintain control VerticalControl.massPositionAction 3.500000 centimeter
2020-08-25T16:53:07.967Z,1598374387.967 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:53:07.967Z,1598374387.967 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:53:07.967Z,1598374387.967 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:53:07.967Z,1598374387.967 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:53:08.362Z,1598374388.362 [Default:CheckIn:D] Stopped
2020-08-25T16:53:08.362Z,1598374388.362 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:53:08.764Z,1598374388.764 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 72.940088 min 
2020-08-25T16:53:08.764Z,1598374388.764 [Default:CheckIn:E] Stopped
2020-08-25T16:53:08.764Z,1598374388.764 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:53:08.764Z,1598374388.764 [Default:CheckIn] Stopped
2020-08-25T16:53:08.764Z,1598374388.764 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:53:08.765Z,1598374388.765 [Default:CheckIn](INFO): Running loop #13
2020-08-25T16:53:08.765Z,1598374388.765 [Default:CheckIn] Running Loop=13
2020-08-25T16:53:08.765Z,1598374388.765 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:53:08.765Z,1598374388.765 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:53:10.773Z,1598374390.773 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165310.00,A,3648.16475,N,12147.28331,W,0.117,327.51,250820,,,A*76
2020-08-25T16:53:10.775Z,1598374390.775 [NAL9602](INFO): GPS fix at 20200825T165310: (36.802746, -121.788055)
2020-08-25T16:53:10.810Z,1598374390.810 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:53:10.810Z,1598374390.810 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:53:18.790Z,1598374398.790 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20200825T153601/Courier0040.lzma
2020-08-25T16:53:19.796Z,1598374399.796 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0040.lzma.bak
2020-08-25T16:53:19.796Z,1598374399.796 [DataOverHttps](INFO): SBD MOMSN=12614889
2020-08-25T16:53:28.953Z,1598374408.953 [NAL9602](INFO): SBD MO Status=0, MOMSN=8112, MT Status=0, MTMSN=0
2020-08-25T16:53:28.953Z,1598374408.953 [NAL9602](INFO): No messages in MT queue
2020-08-25T16:53:37.342Z,1598374417.342 [DataOverHttps](INFO): Sending 318 bytes from file Logs/20200825T153601/Express0041.lzma
2020-08-25T16:53:38.350Z,1598374418.350 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0041.lzma.bak
2020-08-25T16:53:38.350Z,1598374418.350 [DataOverHttps](INFO): SBD MOMSN=12614895
2020-08-25T16:53:41.101Z,1598374421.101 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:53:41.101Z,1598374421.101 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:53:41.101Z,1598374421.101 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T16:53:59.655Z,1598374439.655 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T16:58:41.721Z,1598374721.721 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T16:58:41.722Z,1598374721.722 [Default:CheckIn:C.Wait] Stopped
2020-08-25T16:58:41.722Z,1598374721.722 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T16:58:41.722Z,1598374721.722 [Default:CheckIn:D] Running Loop=1
2020-08-25T16:58:42.134Z,1598374722.134 [Default:CheckIn:D] Stopped
2020-08-25T16:58:42.134Z,1598374722.134 [Default:CheckIn:E] Running Loop=1
2020-08-25T16:58:42.528Z,1598374722.528 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.502962 min 
2020-08-25T16:58:42.528Z,1598374722.528 [Default:CheckIn:E] Stopped
2020-08-25T16:58:42.528Z,1598374722.528 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T16:58:42.528Z,1598374722.528 [Default:CheckIn] Stopped
2020-08-25T16:58:42.528Z,1598374722.528 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T16:58:42.528Z,1598374722.528 [Default:CheckIn](INFO): Running loop #14
2020-08-25T16:58:42.529Z,1598374722.529 [Default:CheckIn] Running Loop=14
2020-08-25T16:58:42.529Z,1598374722.529 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T16:58:42.529Z,1598374722.529 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T16:58:44.535Z,1598374724.535 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165844.00,A,3648.16604,N,12147.28383,W,0.039,52.29,250820,,,A*42
2020-08-25T16:58:44.537Z,1598374724.537 [NAL9602](INFO): GPS fix at 20200825T165844: (36.802767, -121.788064)
2020-08-25T16:58:44.547Z,1598374724.547 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T16:58:44.547Z,1598374724.547 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T16:58:53.074Z,1598374733.074 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T153601/Courier0043.lzma
2020-08-25T16:58:54.076Z,1598374734.076 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0043.lzma.bak
2020-08-25T16:58:54.076Z,1598374734.076 [DataOverHttps](INFO): SBD MOMSN=12614948
2020-08-25T16:59:11.322Z,1598374751.322 [DataOverHttps](INFO): Sending 128 bytes from file Logs/20200825T153601/Express0044.lzma
2020-08-25T16:59:12.324Z,1598374752.324 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0044.lzma.bak
2020-08-25T16:59:12.324Z,1598374752.324 [DataOverHttps](INFO): SBD MOMSN=12614952
2020-08-25T16:59:15.656Z,1598374755.656 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T16:59:15.657Z,1598374755.657 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T16:59:15.657Z,1598374755.657 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T17:00:17.318Z,1598374817.318 [CommandLine](IMPORTANT): got command show variable address
2020-08-25T17:00:17.319Z,1598374817.319 [CommandLine](IMPORTANT): acoustic_contact_address (unknown)
2020-08-25T17:00:17.348Z,1598374817.348 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.localAddress (count)
2020-08-25T17:00:17.349Z,1598374817.349 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.sbdAddress (enum)
2020-08-25T17:00:17.349Z,1598374817.349 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.transponderAddress (enum)
2020-08-25T17:00:17.351Z,1598374817.351 [CommandLine](IMPORTANT): DAT.localAddress (count)
2020-08-25T17:00:17.352Z,1598374817.352 [CommandLine](IMPORTANT): DAT.sbdAddress (enum)
2020-08-25T17:00:17.352Z,1598374817.352 [CommandLine](IMPORTANT): DAT.transponderAddress (enum)
2020-08-25T17:00:17.355Z,1598374817.355 [CommandLine](IMPORTANT): Micromodem.localAddress (enum)
2020-08-25T17:00:17.355Z,1598374817.355 [CommandLine](IMPORTANT): Micromodem.destinationAddress (enum)
2020-08-25T17:00:17.600Z,1598374817.600 [CommandLine](IMPORTANT): DAT.remoteAddress (enum)
2020-08-25T17:00:17.600Z,1598374817.600 [CommandLine](IMPORTANT): DAT.localAddressReading (enum)
2020-08-25T17:00:31.880Z,1598374831.880 [CommandLine](IMPORTANT): got command get DAT.remoteAddress
2020-08-25T17:00:31.880Z,1598374831.880 [CommandLine](IMPORTANT): DAT.remoteAddress 0 enum
2020-08-25T17:00:42.176Z,1598374842.176 [CommandLine](IMPORTANT): got command get DAT.sbdAddress
2020-08-25T17:00:42.176Z,1598374842.176 [CommandLine](IMPORTANT): DAT.sbdAddress -1 enum
2020-08-25T17:00:53.582Z,1598374853.582 [CommandLine](IMPORTANT): got command get DAT.transponderAddress
2020-08-25T17:00:53.583Z,1598374853.583 [CommandLine](IMPORTANT): DAT.transponderAddress 0 enum
2020-08-25T17:01:01.089Z,1598374861.089 [NAL9602](INFO): SBD MO Status=2, MOMSN=8113, MT Status=2, MTMSN=0
2020-08-25T17:01:01.089Z,1598374861.089 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T17:01:15.981Z,1598374875.981 [CommandLine](IMPORTANT): got command show variable DAT.verbosity
2020-08-25T17:01:15.995Z,1598374875.995 [CommandLine](IMPORTANT): DAT.verbosity (count)
2020-08-25T17:01:21.296Z,1598374881.296 [CommandLine](IMPORTANT): got command get DAT.verbosity
2020-08-25T17:01:21.296Z,1598374881.296 [CommandLine](IMPORTANT): DAT.verbosity 0 count
2020-08-25T17:01:27.534Z,1598374887.534 [CommandLine](IMPORTANT): got command configSet DAT.verbosity 3.000000 count persist
2020-08-25T17:01:29.539Z,1598374889.539 [CommandLine](IMPORTANT): got command failComponent hardware DAT
2020-08-25T17:01:29.539Z,1598374889.539 [DAT] Hardware Fault, FailCount= 1
2020-08-25T17:01:29.539Z,1598374889.539 [DAT](ERROR): Hardware Fault
2020-08-25T17:01:29.539Z,1598374889.539 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault
2020-08-25T17:01:29.772Z,1598374889.772 [DAT](INFO): Powering down
2020-08-25T17:01:29.930Z,1598374889.930 [CBIT](ERROR): Hardware Fault in component: DAT
2020-08-25T17:01:30.610Z,1598374890.610 [CBIT](INFO): Clearing failed state for component DAT
2020-08-25T17:01:30.610Z,1598374890.610 [DAT] No Fault, FailCount= 1
2020-08-25T17:01:33.010Z,1598374893.010 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-08-25T17:01:33.010Z,1598374893.010 [DAT](INFO): Powering up
2020-08-25T17:01:33.010Z,1598374893.010 [DAT](DEBUG): Initializing DAT.
2020-08-25T17:01:33.042Z,1598374893.042 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-08-25T17:01:43.506Z,1598374903.506 [DAT](INFO): DAT read: 

2020-08-25T17:01:43.507Z,1598374903.507 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2020-08-25T17:01:44.724Z,1598374904.724 [DAT](INFO): DAT read: MF Frequency Band

2020-08-25T17:01:44.725Z,1598374904.725 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21

2020-08-25T17:01:44.726Z,1598374904.726 [DAT](INFO): DAT read: Aug 25 2020 17:01:21 

2020-08-25T17:01:45.537Z,1598374905.537 [DAT](INFO): DAT read: Features enabled [Bearing]

2020-08-25T17:01:45.538Z,1598374905.538 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-25T17:01:45.538Z,1598374905.538 [DAT](INFO): commRate: 800
2020-08-25T17:01:45.538Z,1598374905.538 [DAT](INFO): commRate: 800
2020-08-25T17:01:45.932Z,1598374905.932 [DAT](INFO): entering command mode
2020-08-25T17:01:46.351Z,1598374906.351 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:46.755Z,1598374906.755 [DAT](INFO): DAT read: 

2020-08-25T17:01:46.755Z,1598374906.755 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:47.144Z,1598374907.144 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:47.552Z,1598374907.552 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:47.956Z,1598374907.956 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:48.356Z,1598374908.356 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:48.758Z,1598374908.758 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:49.168Z,1598374909.168 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:49.573Z,1598374909.573 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:49.976Z,1598374909.976 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:50.380Z,1598374910.380 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:50.780Z,1598374910.780 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:51.188Z,1598374911.188 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:51.588Z,1598374911.588 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:51.992Z,1598374911.992 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:52.396Z,1598374912.396 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:52.804Z,1598374912.804 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:53.204Z,1598374913.204 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:53.608Z,1598374913.608 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:54.012Z,1598374914.012 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:54.431Z,1598374914.431 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:54.843Z,1598374914.843 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:55.224Z,1598374915.224 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:55.626Z,1598374915.626 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:56.036Z,1598374916.036 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:56.436Z,1598374916.436 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:56.838Z,1598374916.838 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:57.242Z,1598374917.242 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:57.656Z,1598374917.656 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:58.050Z,1598374918.050 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:58.454Z,1598374918.454 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:58.860Z,1598374918.860 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:59.264Z,1598374919.264 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:01:59.672Z,1598374919.672 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:02:00.076Z,1598374920.076 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:02:00.474Z,1598374920.474 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:02:00.912Z,1598374920.912 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:02:01.294Z,1598374921.294 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:02:01.294Z,1598374921.294 [DAT](FAULT): failed to enter command mode
2020-08-25T17:02:01.693Z,1598374921.693 [DAT](INFO): entering command mode
2020-08-25T17:02:02.095Z,1598374922.095 [DAT](INFO): DAT read: user:1>

2020-08-25T17:02:02.096Z,1598374922.096 [DAT](INFO): DAT read: Command '+++' not found

2020-08-25T17:02:02.096Z,1598374922.096 [DAT](INFO): DAT read: Error

2020-08-25T17:02:02.096Z,1598374922.096 [DAT](INFO): setting verbose to 3
2020-08-25T17:02:02.507Z,1598374922.507 [DAT](INFO): DAT read: user:2>

2020-08-25T17:02:02.508Z,1598374922.508 [DAT](INFO): DAT read: Verbose         | 3           

2020-08-25T17:02:02.508Z,1598374922.508 [DAT](INFO): set verbose to 3
2020-08-25T17:02:02.508Z,1598374922.508 [DAT](INFO): setting DatVerbose to 27440
2020-08-25T17:02:02.900Z,1598374922.900 [DAT](INFO): DAT read: user:3>

2020-08-25T17:02:02.901Z,1598374922.901 [DAT](INFO): DAT read: DatVerbose      | 27440       

2020-08-25T17:02:02.902Z,1598374922.902 [DAT](INFO): set DatVerbose to 27440
2020-08-25T17:02:02.902Z,1598374922.902 [DAT](INFO): setting transmit power to 8
2020-08-25T17:02:03.323Z,1598374923.323 [DAT](INFO): DAT read: user:4>

2020-08-25T17:02:03.324Z,1598374923.324 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2020-08-25T17:02:03.324Z,1598374923.324 [DAT](INFO): set transmit power to 8
2020-08-25T17:02:03.325Z,1598374923.325 [DAT](INFO): setting local address to 9
2020-08-25T17:02:03.727Z,1598374923.727 [DAT](INFO): DAT read: user:5>

2020-08-25T17:02:03.728Z,1598374923.728 [DAT](INFO): DAT read: LocalAddr       | 9           

2020-08-25T17:02:03.728Z,1598374923.728 [DAT](INFO): set local address to 9
2020-08-25T17:03:47.159Z,1598375027.159 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T17:04:16.257Z,1598375056.257 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T17:04:16.257Z,1598375056.257 [Default:CheckIn:C.Wait] Stopped
2020-08-25T17:04:16.257Z,1598375056.257 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T17:04:16.257Z,1598375056.257 [Default:CheckIn:D] Running Loop=1
2020-08-25T17:04:16.672Z,1598375056.672 [Default:CheckIn:D] Stopped
2020-08-25T17:04:16.672Z,1598375056.672 [Default:CheckIn:E] Running Loop=1
2020-08-25T17:04:17.069Z,1598375057.069 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.078589 min 
2020-08-25T17:04:17.069Z,1598375057.069 [Default:CheckIn:E] Stopped
2020-08-25T17:04:17.069Z,1598375057.069 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T17:04:17.069Z,1598375057.069 [Default:CheckIn] Stopped
2020-08-25T17:04:17.069Z,1598375057.069 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T17:04:17.070Z,1598375057.070 [Default:CheckIn](INFO): Running loop #15
2020-08-25T17:04:17.070Z,1598375057.070 [Default:CheckIn] Running Loop=15
2020-08-25T17:04:17.070Z,1598375057.070 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T17:04:17.070Z,1598375057.070 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T17:04:19.087Z,1598375059.087 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170418.00,A,3648.16445,N,12147.28198,W,0.039,52.29,250820,,,A*4C
2020-08-25T17:04:19.089Z,1598375059.089 [NAL9602](INFO): GPS fix at 20200825T170418: (36.802741, -121.788033)
2020-08-25T17:04:19.100Z,1598375059.100 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T17:04:19.100Z,1598375059.100 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T17:04:32.362Z,1598375072.362 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0046.lzma
2020-08-25T17:04:33.364Z,1598375073.364 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0046.lzma.bak
2020-08-25T17:04:33.364Z,1598375073.364 [DataOverHttps](INFO): SBD MOMSN=12614992
2020-08-25T17:04:51.010Z,1598375091.010 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T17:04:51.044Z,1598375091.044 [DataOverHttps](INFO): Sending 613 bytes from file Logs/20200825T153601/Express0047.lzma
2020-08-25T17:04:52.044Z,1598375092.044 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0047.lzma.bak
2020-08-25T17:04:52.044Z,1598375092.044 [DataOverHttps](INFO): SBD MOMSN=12614995
2020-08-25T17:04:55.065Z,1598375095.065 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T17:04:55.065Z,1598375095.065 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T17:04:55.065Z,1598375095.065 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T17:09:55.644Z,1598375395.644 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T17:09:55.644Z,1598375395.644 [Default:CheckIn:C.Wait] Stopped
2020-08-25T17:09:55.644Z,1598375395.644 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T17:09:55.644Z,1598375395.644 [Default:CheckIn:D] Running Loop=1
2020-08-25T17:09:56.060Z,1598375396.060 [Default:CheckIn:D] Stopped
2020-08-25T17:09:56.060Z,1598375396.060 [Default:CheckIn:E] Running Loop=1
2020-08-25T17:09:56.456Z,1598375396.456 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.735067 min 
2020-08-25T17:09:56.456Z,1598375396.456 [Default:CheckIn:E] Stopped
2020-08-25T17:09:56.456Z,1598375396.456 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T17:09:56.456Z,1598375396.456 [Default:CheckIn] Stopped
2020-08-25T17:09:56.456Z,1598375396.456 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T17:09:56.457Z,1598375396.457 [Default:CheckIn](INFO): Running loop #16
2020-08-25T17:09:56.457Z,1598375396.457 [Default:CheckIn] Running Loop=16
2020-08-25T17:09:56.457Z,1598375396.457 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T17:09:56.457Z,1598375396.457 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T17:09:58.469Z,1598375398.469 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170958.00,A,3648.16353,N,12147.27993,W,0.078,52.29,250820,,,A*4C
2020-08-25T17:09:58.471Z,1598375398.471 [NAL9602](INFO): GPS fix at 20200825T170958: (36.802726, -121.787999)
2020-08-25T17:09:58.480Z,1598375398.480 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T17:09:58.480Z,1598375398.480 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T17:10:06.162Z,1598375406.162 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0049.lzma
2020-08-25T17:10:07.164Z,1598375407.164 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0049.lzma.bak
2020-08-25T17:10:07.164Z,1598375407.164 [DataOverHttps](INFO): SBD MOMSN=12615071
2020-08-25T17:10:26.450Z,1598375426.450 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200825T153601/Express0050.lzma
2020-08-25T17:10:27.453Z,1598375427.453 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0050.lzma.bak
2020-08-25T17:10:27.453Z,1598375427.453 [DataOverHttps](INFO): SBD MOMSN=12615074
2020-08-25T17:10:29.176Z,1598375429.176 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-08-25T17:10:29.250Z,1598375429.250 [NAL9602](FAULT): received: 
+CSQ:0

OK13, 2, 0, 0, 0

OK
2020-08-25T17:10:29.250Z,1598375429.250 [NAL9602] Data Fault, FailCount= 1
2020-08-25T17:10:29.250Z,1598375429.250 [NAL9602](ERROR): Data Fault
2020-08-25T17:10:29.280Z,1598375429.280 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T17:10:29.583Z,1598375429.583 [NAL9602](INFO): Powering down
2020-08-25T17:10:30.435Z,1598375430.435 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T17:10:30.435Z,1598375430.435 [NAL9602] No Fault, FailCount= 1
2020-08-25T17:10:31.205Z,1598375431.205 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T17:10:31.205Z,1598375431.205 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T17:10:31.205Z,1598375431.205 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T17:10:59.878Z,1598375459.878 [NAL9602](INFO): Powering up NAL9602
2020-08-25T17:11:10.791Z,1598375470.791 [NAL9602](INFO): NAL9602 initialized
2020-08-25T17:11:41.899Z,1598375501.899 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T17:15:31.802Z,1598375731.802 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T17:15:31.802Z,1598375731.802 [Default:CheckIn:C.Wait] Stopped
2020-08-25T17:15:31.802Z,1598375731.802 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T17:15:31.802Z,1598375731.802 [Default:CheckIn:D] Running Loop=1
2020-08-25T17:15:32.209Z,1598375732.209 [Default:CheckIn:D] Stopped
2020-08-25T17:15:32.209Z,1598375732.209 [Default:CheckIn:E] Running Loop=1
2020-08-25T17:15:32.612Z,1598375732.612 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.337541 min 
2020-08-25T17:15:32.612Z,1598375732.612 [Default:CheckIn:E] Stopped
2020-08-25T17:15:32.613Z,1598375732.613 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T17:15:32.613Z,1598375732.613 [Default:CheckIn] Stopped
2020-08-25T17:15:32.613Z,1598375732.613 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T17:15:32.613Z,1598375732.613 [Default:CheckIn](INFO): Running loop #17
2020-08-25T17:15:32.613Z,1598375732.613 [Default:CheckIn] Running Loop=17
2020-08-25T17:15:32.613Z,1598375732.613 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T17:15:32.613Z,1598375732.613 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T17:15:34.617Z,1598375734.617 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171533.00,A,3648.16335,N,12147.28217,W,0.058,323.52,250820,,,A*7F
2020-08-25T17:15:34.619Z,1598375734.619 [NAL9602](INFO): GPS fix at 20200825T171533: (36.802723, -121.788036)
2020-08-25T17:15:34.633Z,1598375734.633 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T17:15:34.633Z,1598375734.633 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T17:15:36.673Z,1598375736.673 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T17:15:42.734Z,1598375742.734 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0052.lzma
2020-08-25T17:15:43.736Z,1598375743.736 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0052.lzma.bak
2020-08-25T17:15:43.736Z,1598375743.736 [DataOverHttps](INFO): SBD MOMSN=12615112
2020-08-25T17:16:01.026Z,1598375761.026 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20200825T153601/Express0053.lzma
2020-08-25T17:16:02.028Z,1598375762.028 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0053.lzma.bak
2020-08-25T17:16:02.028Z,1598375762.028 [DataOverHttps](INFO): SBD MOMSN=12615115
2020-08-25T17:16:04.553Z,1598375764.553 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T17:16:04.553Z,1598375764.553 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T17:16:04.553Z,1598375764.553 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T17:16:07.371Z,1598375767.371 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T17:17:40.202Z,1598375860.202 [CommandLine](IMPORTANT): got command get DAT.verbosity
2020-08-25T17:17:40.203Z,1598375860.203 [CommandLine](IMPORTANT): DAT.verbosity 3 count
2020-08-25T17:17:43.858Z,1598375863.858 [CommandLine](IMPORTANT): got command failComponent hardware DAT
2020-08-25T17:17:43.858Z,1598375863.858 [DAT] Hardware Fault, FailCount= 2
2020-08-25T17:17:43.858Z,1598375863.858 [DAT](ERROR): Hardware Fault
2020-08-25T17:17:43.859Z,1598375863.859 [CommandLine](IMPORTANT): DAT failureMode is Hardware Fault
2020-08-25T17:17:43.936Z,1598375863.936 [DAT](INFO): Powering down
2020-08-25T17:17:44.076Z,1598375864.076 [CBIT](ERROR): Hardware Fault in component: DAT
2020-08-25T17:17:44.777Z,1598375864.777 [CBIT](INFO): Clearing failed state for component DAT
2020-08-25T17:17:44.777Z,1598375864.777 [DAT] No Fault, FailCount= 2
2020-08-25T17:17:47.165Z,1598375867.165 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-08-25T17:17:47.165Z,1598375867.165 [DAT](INFO): Powering up
2020-08-25T17:17:47.166Z,1598375867.166 [DAT](DEBUG): Initializing DAT.
2020-08-25T17:17:47.263Z,1598375867.263 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-08-25T17:17:57.672Z,1598375877.672 [DAT](INFO): DAT read: 

2020-08-25T17:17:57.673Z,1598375877.673 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2020-08-25T17:17:58.884Z,1598375878.884 [DAT](INFO): DAT read: MF Frequency Band

2020-08-25T17:17:58.885Z,1598375878.885 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21

2020-08-25T17:17:58.886Z,1598375878.886 [DAT](INFO): DAT read: Aug 25 2020 17:17:35 

2020-08-25T17:17:59.692Z,1598375879.692 [DAT](INFO): DAT read: Features enabled [Bearing]

2020-08-25T17:17:59.693Z,1598375879.693 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-25T17:17:59.694Z,1598375879.694 [DAT](INFO): commRate: 800
2020-08-25T17:17:59.694Z,1598375879.694 [DAT](INFO): commRate: 800
2020-08-25T17:18:00.105Z,1598375880.105 [DAT](INFO): entering command mode
2020-08-25T17:18:00.496Z,1598375880.496 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:00.904Z,1598375880.904 [DAT](INFO): DAT read: 

2020-08-25T17:18:00.904Z,1598375880.904 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:01.312Z,1598375881.312 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:01.721Z,1598375881.721 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:02.112Z,1598375882.112 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:02.520Z,1598375882.520 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:02.920Z,1598375882.920 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:03.324Z,1598375883.324 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:03.728Z,1598375883.728 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:04.132Z,1598375884.132 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:04.536Z,1598375884.536 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:04.947Z,1598375884.947 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:05.344Z,1598375885.344 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:05.748Z,1598375885.748 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:06.164Z,1598375886.164 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:06.566Z,1598375886.566 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:06.968Z,1598375886.968 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:07.374Z,1598375887.374 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:07.772Z,1598375887.772 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:08.176Z,1598375888.176 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:08.584Z,1598375888.584 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:08.990Z,1598375888.990 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:09.388Z,1598375889.388 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:09.788Z,1598375889.788 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:10.199Z,1598375890.199 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:10.596Z,1598375890.596 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:11.004Z,1598375891.004 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:11.402Z,1598375891.402 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:11.816Z,1598375891.816 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:12.216Z,1598375892.216 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:12.620Z,1598375892.620 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:13.020Z,1598375893.020 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:13.432Z,1598375893.432 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:13.832Z,1598375893.832 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:14.232Z,1598375894.232 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:14.640Z,1598375894.640 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:15.044Z,1598375895.044 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:15.448Z,1598375895.448 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T17:18:15.448Z,1598375895.448 [DAT](FAULT): failed to enter command mode
2020-08-25T17:18:15.847Z,1598375895.847 [DAT](INFO): entering command mode
2020-08-25T17:18:16.256Z,1598375896.256 [DAT](INFO): DAT read: user:1>

2020-08-25T17:18:16.257Z,1598375896.257 [DAT](INFO): DAT read: Command '+++' not found

2020-08-25T17:18:16.257Z,1598375896.257 [DAT](INFO): DAT read: Error

2020-08-25T17:18:16.257Z,1598375896.257 [DAT](INFO): setting verbose to 3
2020-08-25T17:18:16.661Z,1598375896.661 [DAT](INFO): DAT read: user:2>

2020-08-25T17:18:16.662Z,1598375896.662 [DAT](INFO): DAT read: Verbose         | 3           

2020-08-25T17:18:16.663Z,1598375896.663 [DAT](INFO): set verbose to 3
2020-08-25T17:18:16.663Z,1598375896.663 [DAT](INFO): setting DatVerbose to 27440
2020-08-25T17:18:17.060Z,1598375897.060 [DAT](INFO): DAT read: user:3>

2020-08-25T17:18:17.061Z,1598375897.061 [DAT](INFO): DAT read: DatVerbose      | 27440       

2020-08-25T17:18:17.061Z,1598375897.061 [DAT](INFO): set DatVerbose to 27440
2020-08-25T17:18:17.062Z,1598375897.062 [DAT](INFO): setting transmit power to 8
2020-08-25T17:18:17.462Z,1598375897.462 [DAT](INFO): DAT read: user:4>

2020-08-25T17:18:17.463Z,1598375897.463 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2020-08-25T17:18:17.463Z,1598375897.463 [DAT](INFO): set transmit power to 8
2020-08-25T17:18:17.464Z,1598375897.464 [DAT](INFO): setting local address to 9
2020-08-25T17:18:17.873Z,1598375897.873 [DAT](INFO): DAT read: user:5>

2020-08-25T17:18:17.874Z,1598375897.874 [DAT](INFO): DAT read: LocalAddr       | 9           

2020-08-25T17:18:17.875Z,1598375897.875 [DAT](INFO): set local address to 9
2020-08-25T17:21:05.153Z,1598376065.153 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T17:21:05.153Z,1598376065.153 [Default:CheckIn:C.Wait] Stopped
2020-08-25T17:21:05.153Z,1598376065.153 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T17:21:05.154Z,1598376065.154 [Default:CheckIn:D] Running Loop=1
2020-08-25T17:21:05.558Z,1598376065.558 [Default:CheckIn:D] Stopped
2020-08-25T17:21:05.558Z,1598376065.558 [Default:CheckIn:E] Running Loop=1
2020-08-25T17:21:05.966Z,1598376065.966 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.893359 min 
2020-08-25T17:21:05.966Z,1598376065.966 [Default:CheckIn:E] Stopped
2020-08-25T17:21:05.966Z,1598376065.966 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T17:21:05.967Z,1598376065.967 [Default:CheckIn] Stopped
2020-08-25T17:21:05.967Z,1598376065.967 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T17:21:05.967Z,1598376065.967 [Default:CheckIn](INFO): Running loop #18
2020-08-25T17:21:05.967Z,1598376065.967 [Default:CheckIn] Running Loop=18
2020-08-25T17:21:05.967Z,1598376065.967 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T17:21:05.967Z,1598376065.967 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T17:21:07.978Z,1598376067.978 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172107.00,A,3648.16381,N,12147.28071,W,0.117,304.99,250820,,,A*7A
2020-08-25T17:21:07.980Z,1598376067.980 [NAL9602](INFO): GPS fix at 20200825T172107: (36.802730, -121.788012)
2020-08-25T17:21:08.020Z,1598376068.020 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T17:21:08.020Z,1598376068.020 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T17:21:15.710Z,1598376075.710 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0055.lzma
2020-08-25T17:21:16.712Z,1598376076.712 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0055.lzma.bak
2020-08-25T17:21:16.712Z,1598376076.712 [DataOverHttps](INFO): SBD MOMSN=12615143
2020-08-25T17:21:34.102Z,1598376094.102 [DataOverHttps](INFO): Sending 350 bytes from file Logs/20200825T153601/Express0056.lzma
2020-08-25T17:21:35.104Z,1598376095.104 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0056.lzma.bak
2020-08-25T17:21:35.105Z,1598376095.105 [DataOverHttps](INFO): SBD MOMSN=12615146
2020-08-25T17:21:37.893Z,1598376097.893 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T17:21:37.893Z,1598376097.893 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T17:21:37.893Z,1598376097.893 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T17:21:44.343Z,1598376104.343 [NAL9602](INFO): SBD MO Status=2, MOMSN=8113, MT Status=2, MTMSN=0
2020-08-25T17:21:44.344Z,1598376104.344 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-25T17:26:10.181Z,1598376370.181 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T17:26:38.457Z,1598376398.457 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T17:26:38.457Z,1598376398.457 [Default:CheckIn:C.Wait] Stopped
2020-08-25T17:26:38.457Z,1598376398.457 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T17:26:38.457Z,1598376398.457 [Default:CheckIn:D] Running Loop=1
2020-08-25T17:26:38.861Z,1598376398.861 [Default:CheckIn:D] Stopped
2020-08-25T17:26:38.861Z,1598376398.861 [Default:CheckIn:E] Running Loop=1
2020-08-25T17:26:39.277Z,1598376399.277 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.448413 min 
2020-08-25T17:26:39.277Z,1598376399.277 [Default:CheckIn:E] Stopped
2020-08-25T17:26:39.277Z,1598376399.277 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T17:26:39.277Z,1598376399.277 [Default:CheckIn] Stopped
2020-08-25T17:26:39.277Z,1598376399.277 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T17:26:39.278Z,1598376399.278 [Default:CheckIn](INFO): Running loop #19
2020-08-25T17:26:39.278Z,1598376399.278 [Default:CheckIn] Running Loop=19
2020-08-25T17:26:39.278Z,1598376399.278 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T17:26:39.278Z,1598376399.278 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T17:26:41.281Z,1598376401.281 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172640.00,A,3648.16586,N,12147.27845,W,0.292,304.99,250820,,,D*74
2020-08-25T17:26:41.283Z,1598376401.283 [NAL9602](INFO): GPS fix at 20200825T172640: (36.802764, -121.787974)
2020-08-25T17:26:41.293Z,1598376401.293 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T17:26:41.294Z,1598376401.294 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T17:26:49.920Z,1598376409.920 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200825T153601/Courier0058.lzma
2020-08-25T17:26:50.841Z,1598376410.841 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0058.lzma.bak
2020-08-25T17:26:50.841Z,1598376410.841 [DataOverHttps](INFO): SBD MOMSN=12615184
2020-08-25T17:27:12.102Z,1598376432.102 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20200825T153601/Express0059.lzma
2020-08-25T17:27:13.104Z,1598376433.104 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0059.lzma.bak
2020-08-25T17:27:13.104Z,1598376433.104 [DataOverHttps](INFO): SBD MOMSN=12615187
2020-08-25T17:27:13.191Z,1598376433.191 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-25T17:27:16.041Z,1598376436.041 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T17:27:16.041Z,1598376436.041 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T17:27:16.041Z,1598376436.041 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T17:32:16.669Z,1598376736.669 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T17:32:16.669Z,1598376736.669 [Default:CheckIn:C.Wait] Stopped
2020-08-25T17:32:16.669Z,1598376736.669 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T17:32:16.669Z,1598376736.669 [Default:CheckIn:D] Running Loop=1
2020-08-25T17:32:17.061Z,1598376737.061 [Default:CheckIn:D] Stopped
2020-08-25T17:32:17.061Z,1598376737.061 [Default:CheckIn:E] Running Loop=1
2020-08-25T17:32:17.461Z,1598376737.461 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 112.085083 min 
2020-08-25T17:32:17.461Z,1598376737.461 [Default:CheckIn:E] Stopped
2020-08-25T17:32:17.461Z,1598376737.461 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T17:32:17.461Z,1598376737.461 [Default:CheckIn] Stopped
2020-08-25T17:32:17.462Z,1598376737.462 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T17:32:17.462Z,1598376737.462 [Default:CheckIn](INFO): Running loop #20
2020-08-25T17:32:17.462Z,1598376737.462 [Default:CheckIn] Running Loop=20
2020-08-25T17:32:17.462Z,1598376737.462 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T17:32:17.462Z,1598376737.462 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T17:32:19.481Z,1598376739.481 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173219.00,A,3648.16078,N,12147.27651,W,0.058,170.95,250820,,,D*7B
2020-08-25T17:32:19.483Z,1598376739.483 [NAL9602](INFO): GPS fix at 20200825T173219: (36.802680, -121.787942)
2020-08-25T17:32:19.493Z,1598376739.493 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T17:32:19.493Z,1598376739.493 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T17:32:21.205Z,1598376741.205 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200825T153601/Courier0061.lzma
2020-08-25T17:32:22.212Z,1598376742.212 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Courier0061.lzma.bak
2020-08-25T17:32:22.212Z,1598376742.212 [DataOverHttps](INFO): SBD MOMSN=12615201
2020-08-25T17:32:42.878Z,1598376762.878 [DataOverHttps](INFO): Sending 130 bytes from file Logs/20200825T153601/Express0062.lzma
2020-08-25T17:32:44.884Z,1598376764.884 [DataOverHttps](INFO): Moved sent file to Logs/20200825T153601/Express0062.lzma.bak
2020-08-25T17:32:44.884Z,1598376764.884 [DataOverHttps](INFO): SBD MOMSN=12615204
2020-08-25T17:32:47.793Z,1598376767.793 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T17:32:47.793Z,1598376767.793 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T17:32:47.793Z,1598376767.793 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T17:35:29.704Z,1598376929.704 [DataOverHttps](IMPORTANT): SBD MTMSN=20200825T173529
2020-08-25T17:35:37.019Z,1598376937.019 [DataOverHttps](INFO): Received command:restart app
2020-08-25T17:35:37.059Z,1598376937.059 [CommandLine](IMPORTANT): got command restart application
2020-08-25T17:35:38.063Z,1598376938.063 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T17:35:38.063Z,1598376938.063 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:38.255Z,1598376938.255 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-08-25T17:35:38.256Z,1598376938.256 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:38.258Z,1598376938.258 [CommandLine](INFO): Join timeout helper Thread ID is 2193
2020-08-25T17:35:38.279Z,1598376938.279 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-08-25T17:35:38.279Z,1598376938.279 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:38.279Z,1598376938.279 [NavChartDb](INFO): Join timeout helper Thread ID is 2194
2020-08-25T17:35:38.395Z,1598376938.395 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T17:35:38.395Z,1598376938.395 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:38.406Z,1598376938.406 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-08-25T17:35:38.406Z,1598376938.406 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:38.407Z,1598376938.407 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2195
2020-08-25T17:35:38.479Z,1598376938.479 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T17:35:38.479Z,1598376938.479 [WetLabsBB2FL](INFO): Powering down
2020-08-25T17:35:38.480Z,1598376938.480 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:38.489Z,1598376938.489 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-08-25T17:35:38.489Z,1598376938.489 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:38.489Z,1598376938.489 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2196
2020-08-25T17:35:39.371Z,1598376939.371 [CTD_Seabird](INFO): Powering down
2020-08-25T17:35:39.382Z,1598376939.382 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T17:35:39.383Z,1598376939.383 [CTD_Seabird](INFO): Powering down
2020-08-25T17:35:39.394Z,1598376939.394 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:39.402Z,1598376939.402 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2020-08-25T17:35:39.402Z,1598376939.402 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:39.403Z,1598376939.403 [BackSeatDriver](INFO): Join timeout helper Thread ID is 2197
2020-08-25T17:35:39.766Z,1598376939.766 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T17:35:39.767Z,1598376939.767 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:39.783Z,1598376939.783 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-08-25T17:35:39.783Z,1598376939.783 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:39.784Z,1598376939.784 [Radio_Surface](INFO): Join timeout helper Thread ID is 2198
2020-08-25T17:35:40.110Z,1598376940.110 [Radio_Surface](INFO): Powering down
2020-08-25T17:35:40.111Z,1598376940.111 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T17:35:40.112Z,1598376940.112 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:40.127Z,1598376940.127 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-08-25T17:35:40.127Z,1598376940.127 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:40.128Z,1598376940.128 [Onboard](INFO): Join timeout helper Thread ID is 2199
2020-08-25T17:35:41.031Z,1598376941.031 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-08-25T17:35:42.566Z,1598376942.566 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T17:35:42.567Z,1598376942.567 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:42.587Z,1598376942.587 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-08-25T17:35:42.587Z,1598376942.587 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:42.588Z,1598376942.588 [DataOverHttps](INFO): Join timeout helper Thread ID is 2200
2020-08-25T17:35:42.791Z,1598376942.791 [CBIT](FAULT): Humidity exceeds 50% of running average: Humidity:2285304 %. Average:303220.093750
2020-08-25T17:35:43.038Z,1598376943.038 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T17:35:43.039Z,1598376943.039 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.055Z,1598376943.055 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-08-25T17:35:43.055Z,1598376943.055 [logger ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.056Z,1598376943.056 [logger](INFO): Join timeout helper Thread ID is 2201
2020-08-25T17:35:43.070Z,1598376943.070 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T17:35:43.071Z,1598376943.071 [logger ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.075Z,1598376943.075 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-08-25T17:35:43.075Z,1598376943.075 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.075Z,1598376943.075 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-08-25T17:35:43.075Z,1598376943.075 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.076Z,1598376943.076 [controlThread](INFO): Join timeout helper Thread ID is 2202
2020-08-25T17:35:43.138Z,1598376943.138 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T17:35:43.139Z,1598376943.139 [controlThread](DEBUG): Uninitializing ControlThread
2020-08-25T17:35:43.139Z,1598376943.139 [AHRS_M2](INFO): Powering down
2020-08-25T17:35:43.211Z,1598376943.211 [NAL9602](INFO): Powering down
2020-08-25T17:35:43.212Z,1598376943.212 [DAT](INFO): Powering down
2020-08-25T17:35:43.498Z,1598376943.498 [AMEcho](INFO): Powering down
2020-08-25T17:35:43.500Z,1598376943.500 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-08-25T17:35:43.500Z,1598376943.500 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-08-25T17:35:43.501Z,1598376943.501 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-08-25T17:35:43.501Z,1598376943.501 [MissionManager](INFO): Uninitializing Mission Default
2020-08-25T17:35:43.501Z,1598376943.501 [Default] Stopped
2020-08-25T17:35:43.502Z,1598376943.502 [Default](DEBUG): Aggregate::uninitialize Default
2020-08-25T17:35:43.502Z,1598376943.502 [Default:B.GoToSurface] Stopped
2020-08-25T17:35:43.502Z,1598376943.502 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-25T17:35:43.502Z,1598376943.502 [Default:CheckIn] Stopped
2020-08-25T17:35:43.502Z,1598376943.502 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T17:35:43.502Z,1598376943.502 [Default:CheckIn:C.Wait] Stopped
2020-08-25T17:35:43.502Z,1598376943.502 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T17:35:43.505Z,1598376943.505 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-08-25T17:35:43.505Z,1598376943.505 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-08-25T17:35:43.505Z,1598376943.505 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-08-25T17:35:43.505Z,1598376943.505 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-08-25T17:35:43.506Z,1598376943.506 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-08-25T17:35:43.506Z,1598376943.506 [BuoyancyServo](INFO): Powering down
2020-08-25T17:35:43.518Z,1598376943.518 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-08-25T17:35:43.519Z,1598376943.519 [ElevatorServo](INFO): Powering down
2020-08-25T17:35:43.519Z,1598376943.519 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-08-25T17:35:43.519Z,1598376943.519 [MassServo](INFO): Powering down
2020-08-25T17:35:43.520Z,1598376943.520 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-08-25T17:35:43.520Z,1598376943.520 [RudderServo](INFO): Powering down
2020-08-25T17:35:43.521Z,1598376943.521 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-08-25T17:35:43.521Z,1598376943.521 [ThrusterServo](INFO): Powering down
2020-08-25T17:35:43.522Z,1598376943.522 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-08-25T17:35:43.522Z,1598376943.522 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-08-25T17:35:43.523Z,1598376943.523 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-08-25T17:35:43.523Z,1598376943.523 [CBIT](DEBUG): Powering off loads.
2020-08-25T17:35:43.534Z,1598376943.534 [CBIT](DEBUG): Disabling WDT.
2020-08-25T17:35:43.546Z,1598376943.546 [CBIT](DEBUG): Opening all GF detection circuits.
2020-08-25T17:35:43.547Z,1598376943.547 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.651Z,1598376943.651 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.653Z,1598376943.653 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.658Z,1598376943.658 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.727Z,1598376943.727 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.730Z,1598376943.730 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.733Z,1598376943.733 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.749Z,1598376943.749 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T17:35:43.823Z,1598376943.823 [logger ThreadHandler](INFO): Thread cancelled.