2020-08-25T20:52:05.535Z,1598388725.535 [Supervisor](DEBUG): Initializing supervisor.
2020-08-25T20:52:05.538Z,1598388725.538 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-08-25T20:52:05.539Z,1598388725.539 [SyncHandler](INFO): Protected caller Thread ID is 3261
2020-08-25T20:52:05.540Z,1598388725.540 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-08-25T20:52:05.540Z,1598388725.540 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-08-25T20:52:05.541Z,1598388725.541 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 3262
2020-08-25T20:52:05.545Z,1598388725.545 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-08-25T20:52:05.559Z,1598388725.559 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-08-25T20:52:05.559Z,1598388725.559 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-08-25T20:52:05.560Z,1598388725.560 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 3263
2020-08-25T20:52:05.560Z,1598388725.560 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-08-25T20:52:05.561Z,1598388725.561 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-08-25T20:52:05.562Z,1598388725.562 [logger ThreadHandler](INFO): Protected caller Thread ID is 3264
2020-08-25T20:52:05.564Z,1598388725.564 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-08-25T20:52:05.564Z,1598388725.564 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-08-25T20:52:05.566Z,1598388725.566 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-08-25T20:52:05.734Z,1598388725.734 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-08-25T20:52:05.735Z,1598388725.735 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-08-25T20:52:06.392Z,1598388726.392 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-08-25T20:52:06.393Z,1598388726.393 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-08-25T20:52:06.603Z,1598388726.603 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-08-25T20:52:06.604Z,1598388726.604 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-08-25T20:52:06.708Z,1598388726.708 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-08-25T20:52:06.709Z,1598388726.709 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-08-25T20:52:06.817Z,1598388726.817 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-08-25T20:52:06.818Z,1598388726.818 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-08-25T20:52:06.904Z,1598388726.904 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-08-25T20:52:07.051Z,1598388727.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-08-25T20:52:07.052Z,1598388727.052 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-08-25T20:52:07.368Z,1598388727.368 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-08-25T20:52:07.369Z,1598388727.369 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-08-25T20:52:07.860Z,1598388727.860 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-08-25T20:52:07.861Z,1598388727.861 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-08-25T20:52:08.015Z,1598388728.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-08-25T20:52:08.016Z,1598388728.016 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-08-25T20:52:08.232Z,1598388728.232 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-08-25T20:52:08.232Z,1598388728.232 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-08-25T20:52:08.739Z,1598388728.739 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-08-25T20:52:08.740Z,1598388728.740 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-08-25T20:52:08.973Z,1598388728.973 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-08-25T20:52:08.974Z,1598388728.974 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-08-25T20:52:09.192Z,1598388729.192 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-08-25T20:52:09.193Z,1598388729.193 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-08-25T20:52:09.668Z,1598388729.668 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-08-25T20:52:09.669Z,1598388729.669 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-08-25T20:52:10.294Z,1598388730.294 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-08-25T20:52:10.296Z,1598388730.296 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-08-25T20:52:10.297Z,1598388730.297 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-08-25T20:52:10.385Z,1598388730.385 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-08-25T20:52:10.557Z,1598388730.557 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-08-25T20:52:10.673Z,1598388730.673 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-08-25T20:52:10.763Z,1598388730.763 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-08-25T20:52:10.863Z,1598388730.863 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-08-25T20:52:11.085Z,1598388731.085 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-08-25T20:52:11.328Z,1598388731.328 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-08-25T20:52:11.329Z,1598388731.329 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-08-25T20:52:11.428Z,1598388731.428 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-08-25T20:52:11.534Z,1598388731.534 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-08-25T20:52:11.676Z,1598388731.676 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-08-25T20:52:11.782Z,1598388731.782 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-08-25T20:52:11.796Z,1598388731.796 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-08-25T20:52:11.895Z,1598388731.895 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-08-25T20:52:11.895Z,1598388731.895 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-08-25T20:52:11.959Z,1598388731.959 [VerticalControl](DEBUG): Construct VerticalControl.
2020-08-25T20:52:12.071Z,1598388732.071 [VerticalControl] Loaded
2020-08-25T20:52:12.071Z,1598388732.071 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-08-25T20:52:12.072Z,1598388732.072 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-08-25T20:52:12.152Z,1598388732.152 [HorizontalControl] Loaded
2020-08-25T20:52:12.152Z,1598388732.152 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-08-25T20:52:12.153Z,1598388732.153 [SpeedControl](DEBUG): Construct SpeedControl.
2020-08-25T20:52:12.158Z,1598388732.158 [SpeedControl] Loaded
2020-08-25T20:52:12.159Z,1598388732.159 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-08-25T20:52:12.159Z,1598388732.159 [LoopControl](DEBUG): Construct LoopControl.
2020-08-25T20:52:12.160Z,1598388732.160 [LoopControl] Loaded
2020-08-25T20:52:12.160Z,1598388732.160 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-08-25T20:52:12.160Z,1598388732.160 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-08-25T20:52:12.161Z,1598388732.161 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-08-25T20:52:12.217Z,1598388732.217 [DepthRateCalculator] Loaded
2020-08-25T20:52:12.217Z,1598388732.217 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-08-25T20:52:12.222Z,1598388732.222 [PitchRateCalculator] Loaded
2020-08-25T20:52:12.222Z,1598388732.222 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-08-25T20:52:12.238Z,1598388732.238 [SpeedCalculator] Loaded
2020-08-25T20:52:12.238Z,1598388732.238 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-08-25T20:52:12.259Z,1598388732.259 [TempGradientCalculator] Loaded
2020-08-25T20:52:12.259Z,1598388732.259 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-08-25T20:52:12.264Z,1598388732.264 [YawRateCalculator] Loaded
2020-08-25T20:52:12.264Z,1598388732.264 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-08-25T20:52:12.293Z,1598388732.293 [ElevatorOffsetCalculator] Loaded
2020-08-25T20:52:12.294Z,1598388732.294 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-08-25T20:52:12.294Z,1598388732.294 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-08-25T20:52:12.295Z,1598388732.295 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-08-25T20:52:12.335Z,1598388732.335 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-08-25T20:52:12.336Z,1598388732.336 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-08-25T20:52:12.467Z,1598388732.467 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-08-25T20:52:12.467Z,1598388732.467 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-08-25T20:52:12.810Z,1598388732.810 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-08-25T20:52:12.811Z,1598388732.811 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-08-25T20:52:12.939Z,1598388732.939 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-08-25T20:52:12.940Z,1598388732.940 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-08-25T20:52:13.381Z,1598388733.381 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-08-25T20:52:13.386Z,1598388733.386 [AHRS_M2](INFO): created writer for : platform_orientation
2020-08-25T20:52:13.388Z,1598388733.388 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-08-25T20:52:13.394Z,1598388733.394 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-08-25T20:52:13.394Z,1598388733.394 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-08-25T20:52:13.399Z,1598388733.399 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-08-25T20:52:13.400Z,1598388733.400 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-08-25T20:52:13.405Z,1598388733.405 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-08-25T20:52:13.477Z,1598388733.477 [AHRS_M2] Loaded
2020-08-25T20:52:13.477Z,1598388733.477 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-08-25T20:52:13.552Z,1598388733.552 [DataOverHttps] Loaded
2020-08-25T20:52:13.553Z,1598388733.553 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-08-25T20:52:13.554Z,1598388733.554 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0
2020-08-25T20:52:13.554Z,1598388733.554 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 3346
2020-08-25T20:52:13.585Z,1598388733.585 [Depth_Keller] Loaded
2020-08-25T20:52:13.585Z,1598388733.585 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-08-25T20:52:13.700Z,1598388733.700 [NAL9602] Loaded
2020-08-25T20:52:13.701Z,1598388733.701 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-08-25T20:52:13.750Z,1598388733.750 [Onboard] Loaded
2020-08-25T20:52:13.751Z,1598388733.751 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-08-25T20:52:13.752Z,1598388733.752 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0
2020-08-25T20:52:13.752Z,1598388733.752 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 3347
2020-08-25T20:52:13.771Z,1598388733.771 [Radio_Surface] Loaded
2020-08-25T20:52:13.772Z,1598388733.772 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-08-25T20:52:13.773Z,1598388733.773 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2020-08-25T20:52:13.773Z,1598388733.773 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 3348
2020-08-25T20:52:13.926Z,1598388733.926 [DAT] Loaded
2020-08-25T20:52:13.927Z,1598388733.927 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-08-25T20:52:15.778Z,1598388735.778 [BPC1] Loaded
2020-08-25T20:52:15.778Z,1598388735.778 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-08-25T20:52:15.811Z,1598388735.811 [AMEcho] Loaded
2020-08-25T20:52:15.811Z,1598388735.811 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread.
2020-08-25T20:52:15.811Z,1598388735.811 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-08-25T20:52:15.812Z,1598388735.812 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-08-25T20:52:15.949Z,1598388735.949 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-08-25T20:52:15.949Z,1598388735.949 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-08-25T20:52:15.970Z,1598388735.970 [NavChart] Loaded
2020-08-25T20:52:15.970Z,1598388735.970 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-08-25T20:52:15.974Z,1598388735.974 [UniversalFixResidualReporter] Loaded
2020-08-25T20:52:15.974Z,1598388735.974 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-08-25T20:52:15.975Z,1598388735.975 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-08-25T20:52:15.975Z,1598388735.975 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-08-25T20:52:16.140Z,1598388736.140 [SBIT](DEBUG): Construct Startup Built In Test.
2020-08-25T20:52:16.151Z,1598388736.151 [SBIT] Loaded
2020-08-25T20:52:16.151Z,1598388736.151 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-08-25T20:52:16.152Z,1598388736.152 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-08-25T20:52:16.164Z,1598388736.164 [IBIT] Loaded
2020-08-25T20:52:16.164Z,1598388736.164 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-08-25T20:52:16.168Z,1598388736.168 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-08-25T20:52:16.306Z,1598388736.306 [CBIT] Loaded
2020-08-25T20:52:16.306Z,1598388736.306 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-08-25T20:52:16.307Z,1598388736.307 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-08-25T20:52:16.307Z,1598388736.307 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-08-25T20:52:16.454Z,1598388736.454 [BuoyancyServo] Loaded
2020-08-25T20:52:16.454Z,1598388736.454 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-08-25T20:52:16.483Z,1598388736.483 [ElevatorServo] Loaded
2020-08-25T20:52:16.483Z,1598388736.483 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-08-25T20:52:16.511Z,1598388736.511 [MassServo] Loaded
2020-08-25T20:52:16.511Z,1598388736.511 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-08-25T20:52:16.539Z,1598388736.539 [RudderServo] Loaded
2020-08-25T20:52:16.539Z,1598388736.539 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-08-25T20:52:16.567Z,1598388736.567 [ThrusterServo] Loaded
2020-08-25T20:52:16.567Z,1598388736.567 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-08-25T20:52:16.567Z,1598388736.567 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-08-25T20:52:16.568Z,1598388736.568 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-08-25T20:52:16.597Z,1598388736.597 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-08-25T20:52:16.597Z,1598388736.597 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-08-25T20:52:16.923Z,1598388736.923 [BackSeatDriver] Loaded
2020-08-25T20:52:16.923Z,1598388736.923 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2020-08-25T20:52:16.925Z,1598388736.925 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2020-08-25T20:52:16.925Z,1598388736.925 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 3349
2020-08-25T20:52:16.954Z,1598388736.954 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-08-25T20:52:16.959Z,1598388736.959 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-08-25T20:52:16.960Z,1598388736.960 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-08-25T20:52:16.965Z,1598388736.965 [CTD_Seabird](INFO): created writer for : depth
2020-08-25T20:52:16.965Z,1598388736.965 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-08-25T20:52:16.971Z,1598388736.971 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-08-25T20:52:16.972Z,1598388736.972 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-08-25T20:52:16.977Z,1598388736.977 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-08-25T20:52:16.978Z,1598388736.978 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-08-25T20:52:16.983Z,1598388736.983 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-08-25T20:52:16.984Z,1598388736.984 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-08-25T20:52:16.989Z,1598388736.989 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-08-25T20:52:16.990Z,1598388736.990 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-08-25T20:52:16.995Z,1598388736.995 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-08-25T20:52:17.023Z,1598388737.023 [CTD_Seabird] Loaded
2020-08-25T20:52:17.024Z,1598388737.024 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-08-25T20:52:17.025Z,1598388737.025 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B334E0
2020-08-25T20:52:17.025Z,1598388737.025 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 3350
2020-08-25T20:52:17.048Z,1598388737.048 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-08-25T20:52:17.048Z,1598388737.048 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-08-25T20:52:17.052Z,1598388737.052 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-08-25T20:52:17.052Z,1598388737.052 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-08-25T20:52:17.057Z,1598388737.057 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-08-25T20:52:17.057Z,1598388737.057 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-08-25T20:52:17.061Z,1598388737.061 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-08-25T20:52:17.061Z,1598388737.061 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-08-25T20:52:17.066Z,1598388737.066 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-08-25T20:52:17.066Z,1598388737.066 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-08-25T20:52:17.070Z,1598388737.070 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-08-25T20:52:17.071Z,1598388737.071 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-08-25T20:52:17.075Z,1598388737.075 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-08-25T20:52:17.075Z,1598388737.075 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-08-25T20:52:17.080Z,1598388737.080 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T20:52:17.084Z,1598388737.084 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T20:52:17.085Z,1598388737.085 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T20:52:17.085Z,1598388737.085 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T20:52:17.089Z,1598388737.089 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T20:52:17.089Z,1598388737.089 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T20:52:17.093Z,1598388737.093 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T20:52:17.094Z,1598388737.094 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-25T20:52:17.098Z,1598388737.098 [WetLabsBB2FL] Loaded
2020-08-25T20:52:17.098Z,1598388737.098 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-08-25T20:52:17.099Z,1598388737.099 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B634E0
2020-08-25T20:52:17.100Z,1598388737.100 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 3351
2020-08-25T20:52:17.100Z,1598388737.100 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-08-25T20:52:17.104Z,1598388737.104 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-08-25T20:52:17.105Z,1598388737.105 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-08-25T20:52:17.113Z,1598388737.113 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-08-25T20:52:17.114Z,1598388737.114 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B934E0
2020-08-25T20:52:17.114Z,1598388737.114 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 3352
2020-08-25T20:52:17.119Z,1598388737.119 [Supervisor](INFO): Main Thread ID is 715
2020-08-25T20:52:17.119Z,1598388737.119 [Supervisor](DEBUG): Running supervisor.
2020-08-25T20:52:17.120Z,1598388737.120 [CommandLine ThreadHandler](INFO): Handler Thread ID is 3353
2020-08-25T20:52:17.122Z,1598388737.122 [controlThread ThreadHandler](INFO): Handler Thread ID is 3354
2020-08-25T20:52:17.123Z,1598388737.123 [controlThread](DEBUG): Initializing ControlThread
2020-08-25T20:52:17.124Z,1598388737.124 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-08-25T20:52:17.125Z,1598388737.125 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-08-25T20:52:17.126Z,1598388737.126 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-08-25T20:52:17.127Z,1598388737.127 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-08-25T20:52:17.127Z,1598388737.127 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-08-25T20:52:17.127Z,1598388737.127 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-08-25T20:52:17.128Z,1598388737.128 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-08-25T20:52:17.128Z,1598388737.128 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-08-25T20:52:17.128Z,1598388737.128 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-08-25T20:52:17.129Z,1598388737.129 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-08-25T20:52:17.132Z,1598388737.132 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-08-25T20:52:17.132Z,1598388737.132 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-08-25T20:52:17.133Z,1598388737.133 [SBIT](INFO): Initialize SBIT Component.
2020-08-25T20:52:17.133Z,1598388737.133 [SBIT](IMPORTANT): git: 2020-08-18a-30-g8cc0a1c87
2020-08-25T20:52:17.133Z,1598388737.133 [SBIT](INFO): git hash: 8cc0a1c87b994ada9a621eded1d43a5b5e56617e
2020-08-25T20:52:17.133Z,1598388737.133 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-08-25T20:52:17.135Z,1598388737.135 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
Kernel Reported: #1 PREEMPT Thu Aug 6 12:04:53 PDT 2020
2020-08-25T20:52:17.136Z,1598388737.136 [SBIT](INFO): Beginning SBIT in 65.000000 seconds.
2020-08-25T20:52:17.136Z,1598388737.136 [IBIT](INFO): Initialize IBIT Component.
2020-08-25T20:52:17.137Z,1598388737.137 [CBIT](DEBUG): Initialize CBIT Component.
2020-08-25T20:52:17.138Z,1598388737.138 [logger ThreadHandler](INFO): Handler Thread ID is 3355
2020-08-25T20:52:17.150Z,1598388737.150 [CBIT](DEBUG): Initialized mux pins.
2020-08-25T20:52:17.151Z,1598388737.151 [CBIT](DEBUG): Initializing the watchdog timer.
2020-08-25T20:52:17.155Z,1598388737.155 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 3356
2020-08-25T20:52:17.156Z,1598388737.156 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-08-25T20:52:17.163Z,1598388737.163 [Onboard ThreadHandler](INFO): Handler Thread ID is 3357
2020-08-25T20:52:17.174Z,1598388737.174 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-08-25T20:52:17.174Z,1598388737.174 [CBIT](DEBUG): Initializing heartbeat.
2020-08-25T20:52:17.180Z,1598388737.180 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 3358
2020-08-25T20:52:17.203Z,1598388737.203 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 3359
2020-08-25T20:52:17.219Z,1598388737.219 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 3360
2020-08-25T20:52:17.219Z,1598388737.219 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-08-25T20:52:17.224Z,1598388737.224 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 3362
2020-08-25T20:52:17.225Z,1598388737.225 [WetLabsBB2FL](INFO): Powering down
2020-08-25T20:52:17.246Z,1598388737.246 [CBIT](DEBUG): Deactivating GF circuits.
2020-08-25T20:52:17.246Z,1598388737.246 [CBIT](DEBUG): Deactivating emergency mode.
2020-08-25T20:52:17.259Z,1598388737.259 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 3363
2020-08-25T20:52:17.266Z,1598388737.266 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-08-25T20:52:17.266Z,1598388737.266 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-08-25T20:52:17.267Z,1598388737.267 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-08-25T20:52:17.267Z,1598388737.267 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-08-25T20:52:17.267Z,1598388737.267 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-08-25T20:52:17.267Z,1598388737.267 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-08-25T20:52:17.267Z,1598388737.267 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-08-25T20:52:17.267Z,1598388737.267 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-08-25T20:52:17.267Z,1598388737.267 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-08-25T20:52:17.268Z,1598388737.268 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-08-25T20:52:17.268Z,1598388737.268 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-08-25T20:52:17.268Z,1598388737.268 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-08-25T20:52:17.268Z,1598388737.268 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-08-25T20:52:17.268Z,1598388737.268 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-08-25T20:52:17.268Z,1598388737.268 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-08-25T20:52:17.269Z,1598388737.269 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-08-25T20:52:17.282Z,1598388737.282 [CBIT](DEBUG): Backplane powered.
2020-08-25T20:52:17.284Z,1598388737.284 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-08-25T20:52:17.308Z,1598388737.308 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-25T20:52:17.319Z,1598388737.319 [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-25T20:52:17.320Z,1598388737.320 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-08-25T20:52:17.396Z,1598388737.396 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-08-25T20:52:17.397Z,1598388737.397 [Default:A.Wait](DEBUG): Construct Wait.
2020-08-25T20:52:17.399Z,1598388737.399 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-25T20:52:17.418Z,1598388737.418 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-08-25T20:52:17.445Z,1598388737.445 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-08-25T20:52:17.466Z,1598388737.466 [Default:E.Execute](DEBUG): Construct Execute.
2020-08-25T20:52:17.471Z,1598388737.471 [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-25T20:52:17.490Z,1598388737.490 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,DAT,BPC1,AMEcho,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-08-25T20:52:17.511Z,1598388737.511 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-08-25T20:52:17.586Z,1598388737.586 [Radio_Surface](INFO): Powering up
2020-08-25T20:52:17.659Z,1598388737.659 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-08-25T20:52:17.659Z,1598388737.659 [DAT](INFO): Powering up
2020-08-25T20:52:17.659Z,1598388737.659 [DAT](DEBUG): Initializing DAT.
2020-08-25T20:52:17.707Z,1598388737.707 [AMEcho](INFO): Powering up
2020-08-25T20:52:17.723Z,1598388737.723 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-08-25T20:52:17.790Z,1598388737.790 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-08-25T20:52:17.807Z,1598388737.807 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-08-25T20:52:17.808Z,1598388737.808 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-08-25T20:52:17.819Z,1598388737.819 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-08-25T20:52:17.820Z,1598388737.820 [MassServo](DEBUG): Initializing EZServoServo.
2020-08-25T20:52:17.831Z,1598388737.831 [MassServo](DEBUG): Initializing MassServo.
2020-08-25T20:52:17.832Z,1598388737.832 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-25T20:52:17.843Z,1598388737.843 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-25T20:52:17.844Z,1598388737.844 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-08-25T20:52:17.855Z,1598388737.855 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-08-25T20:52:18.111Z,1598388738.111 [AMEcho](INFO): Powering down
2020-08-25T20:52:28.020Z,1598388748.020 [DAT](INFO): DAT read: 

2020-08-25T20:52:28.021Z,1598388748.021 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2020-08-25T20:52:29.232Z,1598388749.232 [DAT](INFO): DAT read: MF Frequency Band

2020-08-25T20:52:29.233Z,1598388749.233 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21

2020-08-25T20:52:29.234Z,1598388749.234 [DAT](INFO): DAT read: Aug 25 2020 20:52:05 

2020-08-25T20:52:30.040Z,1598388750.040 [DAT](INFO): DAT read: Features enabled [Bearing]

2020-08-25T20:52:30.041Z,1598388750.041 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-25T20:52:30.042Z,1598388750.042 [DAT](INFO): commRate: 800
2020-08-25T20:52:30.042Z,1598388750.042 [DAT](INFO): commRate: 800
2020-08-25T20:52:30.444Z,1598388750.444 [DAT](INFO): entering command mode
2020-08-25T20:52:30.848Z,1598388750.848 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:31.252Z,1598388751.252 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:31.656Z,1598388751.656 [DAT](INFO): DAT read: 

2020-08-25T20:52:31.656Z,1598388751.656 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:32.060Z,1598388752.060 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:32.464Z,1598388752.464 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:32.868Z,1598388752.868 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:33.272Z,1598388753.272 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:33.676Z,1598388753.676 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:34.080Z,1598388754.080 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:34.484Z,1598388754.484 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:34.888Z,1598388754.888 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:35.292Z,1598388755.292 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:35.704Z,1598388755.704 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:36.100Z,1598388756.100 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:36.504Z,1598388756.504 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:36.908Z,1598388756.908 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:37.312Z,1598388757.312 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:37.716Z,1598388757.716 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:38.128Z,1598388758.128 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:38.524Z,1598388758.524 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:38.928Z,1598388758.928 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:39.332Z,1598388759.332 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:39.732Z,1598388759.732 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:40.140Z,1598388760.140 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:40.556Z,1598388760.556 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:40.948Z,1598388760.948 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:41.352Z,1598388761.352 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:41.756Z,1598388761.756 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:42.161Z,1598388762.161 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:42.574Z,1598388762.574 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:42.968Z,1598388762.968 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:43.376Z,1598388763.376 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:43.780Z,1598388763.780 [NAL9602](INFO): Powering up NAL9602
2020-08-25T20:52:43.781Z,1598388763.781 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:44.180Z,1598388764.180 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:44.584Z,1598388764.584 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:44.984Z,1598388764.984 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:45.388Z,1598388765.388 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:45.792Z,1598388765.792 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-25T20:52:45.792Z,1598388765.792 [DAT](FAULT): failed to enter command mode
2020-08-25T20:52:46.200Z,1598388766.200 [DAT](INFO): entering command mode
2020-08-25T20:52:46.604Z,1598388766.604 [DAT](INFO): DAT read: user:1>

2020-08-25T20:52:46.605Z,1598388766.605 [DAT](INFO): DAT read: Command '+++' not found

2020-08-25T20:52:46.605Z,1598388766.605 [DAT](INFO): DAT read: Error

2020-08-25T20:52:46.606Z,1598388766.606 [DAT](INFO): setting verbose to 3
2020-08-25T20:52:47.008Z,1598388767.008 [DAT](INFO): DAT read: user:2>

2020-08-25T20:52:47.009Z,1598388767.009 [DAT](INFO): DAT read: Verbose         | 3           

2020-08-25T20:52:47.009Z,1598388767.009 [DAT](INFO): set verbose to 3
2020-08-25T20:52:47.010Z,1598388767.010 [DAT](INFO): setting DatVerbose to 27440
2020-08-25T20:52:47.412Z,1598388767.412 [DAT](INFO): DAT read: user:3>

2020-08-25T20:52:47.413Z,1598388767.413 [DAT](INFO): DAT read: DatVerbose      | 27440       

2020-08-25T20:52:47.413Z,1598388767.413 [DAT](INFO): set DatVerbose to 27440
2020-08-25T20:52:47.414Z,1598388767.414 [DAT](INFO): setting transmit power to 8
2020-08-25T20:52:47.828Z,1598388767.828 [DAT](INFO): DAT read: user:4>

2020-08-25T20:52:47.829Z,1598388767.829 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2020-08-25T20:52:47.829Z,1598388767.829 [DAT](INFO): set transmit power to 8
2020-08-25T20:52:47.830Z,1598388767.830 [DAT](INFO): setting local address to 9
2020-08-25T20:52:48.216Z,1598388768.216 [DAT](INFO): DAT read: user:5>

2020-08-25T20:52:48.217Z,1598388768.217 [DAT](INFO): DAT read: LocalAddr       | 9           

2020-08-25T20:52:48.217Z,1598388768.217 [DAT](INFO): set local address to 9
2020-08-25T20:52:54.684Z,1598388774.684 [NAL9602](INFO): NAL9602 initialized
2020-08-25T20:53:02.763Z,1598388782.763 [CommandLine](IMPORTANT): got command report mod AMEcho.altitude
2020-08-25T20:53:02.816Z,1598388782.816 [Reporter](INFO): AMEcho.altitude no_value
2020-08-25T20:53:22.580Z,1598388802.580 [SBIT](IMPORTANT): Beginning Startup BIT
2020-08-25T20:53:22.585Z,1598388802.585 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-25T20:53:33.583Z,1598388813.583 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.010146
CHAN A1 (24V): -0.001563
CHAN A2 (12V): -0.007976
CHAN A3 (5V): -0.001984
CHAN B0 (3.3V): 0.000134
CHAN B1 (3.15aV): -0.000314
CHAN B2 (3.15bV): -0.000334
CHAN B3 (GND): 0.002378
OPEN: 0.005730
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-25T20:53:57.366Z,1598388837.366 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-08-25T20:54:16.324Z,1598388856.324 [SBIT](IMPORTANT): SBIT PASSED
2020-08-25T20:54:16.324Z,1598388856.324 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-08-25T20:54:16.325Z,1598388856.325 [SBIT](IMPORTANT): BackSeatDriver.loadAtStartup=1 bool;

2020-08-25T20:54:16.325Z,1598388856.325 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere;

2020-08-25T20:54:16.326Z,1598388856.326 [SBIT](IMPORTANT): DAT.sbdAddress=6 enum;

2020-08-25T20:54:16.326Z,1598388856.326 [SBIT](IMPORTANT): DAT.surfaceThreshold=-1 meter;

2020-08-25T20:54:16.326Z,1598388856.326 [SBIT](IMPORTANT): DAT.verbosity=3 count;

2020-08-25T20:54:16.326Z,1598388856.326 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2020-08-25T20:54:16.326Z,1598388856.326 [SBIT](IMPORTANT): Express none ThrusterServo.component_avgCurrent;

2020-08-25T20:54:16.326Z,1598388856.326 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second;

2020-08-25T20:54:16.326Z,1598388856.326 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2020-08-25T20:54:16.327Z,1598388856.327 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool;

2020-08-25T20:54:16.327Z,1598388856.327 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=344.685708 cubic_centimeter;

2020-08-25T20:54:16.327Z,1598388856.327 [SBIT](IMPORTANT): VerticalControl.massDefault=11.293600 millimeter;

2020-08-25T20:54:16.327Z,1598388856.327 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=0 bool;

2020-08-25T20:54:16.720Z,1598388856.720 [MissionManager](IMPORTANT): Started mission Startup
2020-08-25T20:54:16.720Z,1598388856.720 [Startup] Running Loop=1
2020-08-25T20:54:16.720Z,1598388856.720 [Startup](DEBUG): Aggregate::initialize Startup
2020-08-25T20:54:16.720Z,1598388856.720 [Startup:A.GoToSurface] Running Loop=1
2020-08-25T20:54:16.720Z,1598388856.720 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-25T20:54:16.721Z,1598388856.721 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-25T20:54:16.721Z,1598388856.721 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-25T20:54:16.721Z,1598388856.721 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-25T20:54:16.722Z,1598388856.722 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-25T20:54:16.722Z,1598388856.722 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-25T20:54:16.724Z,1598388856.724 [Startup:StartupSatComms] Running Loop=1
2020-08-25T20:54:16.724Z,1598388856.724 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-08-25T20:54:16.724Z,1598388856.724 [Startup:StartupSatComms:A] Running Loop=1
2020-08-25T20:54:17.128Z,1598388857.128 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-08-25T20:54:17.505Z,1598388857.505 [AMEcho](INFO): Powering up
2020-08-25T20:54:39.424Z,1598388879.424 [Reporter](INFO): AMEcho.altitude 132.880005 m
2020-08-25T20:54:40.191Z,1598388880.191 [Reporter](INFO): AMEcho.altitude 132.279999 m
2020-08-25T20:54:41.395Z,1598388881.395 [Reporter](INFO): AMEcho.altitude 132.949997 m
2020-08-25T20:54:42.181Z,1598388882.181 [Reporter](INFO): AMEcho.altitude 130.479996 m
2020-08-25T20:54:43.411Z,1598388883.411 [Reporter](INFO): AMEcho.altitude 127.550003 m
2020-08-25T20:54:44.200Z,1598388884.200 [Reporter](INFO): AMEcho.altitude 125.980003 m
2020-08-25T20:54:45.075Z,1598388885.075 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005808
2020-08-25T20:54:47.441Z,1598388887.441 [Reporter](INFO): AMEcho.altitude 121.480003 m
2020-08-25T20:54:49.042Z,1598388889.042 [Reporter](INFO): AMEcho.altitude 116.980003 m
2020-08-25T20:54:50.250Z,1598388890.250 [Reporter](INFO): AMEcho.altitude 115.400002 m
2020-08-25T20:54:51.075Z,1598388891.075 [Reporter](INFO): AMEcho.altitude 112.480003 m
2020-08-25T20:54:53.120Z,1598388893.120 [Reporter](INFO): AMEcho.altitude 115.400002 m
2020-08-25T20:54:59.548Z,1598388899.548 [CommandLine](IMPORTANT): got command configSet AMEcho.enabled 0.000000 bool
2020-08-25T20:54:59.929Z,1598388899.929 [AMEcho](ERROR): Setting 'enabled' to 0
2020-08-25T20:54:59.944Z,1598388899.944 [Reporter](INFO): AMEcho.altitude no_value
2020-08-25T20:55:00.499Z,1598388900.499 [AMEcho](INFO): Powering down
2020-08-25T20:55:11.580Z,1598388911.580 [CommandLine](IMPORTANT): got command configSet AMEcho.enabled 1.000000 bool
2020-08-25T20:55:11.655Z,1598388911.655 [AMEcho](ERROR): Setting 'enabled' to 1
2020-08-25T20:55:12.051Z,1598388912.051 [AMEcho](INFO): Powering up
2020-08-25T20:55:15.313Z,1598388915.313 [Reporter](INFO): AMEcho.altitude 115.400002 m
2020-08-25T20:55:16.912Z,1598388916.912 [Startup:StartupSatComms:A](INFO): Timed out from 2020-08-25T20:54:16.7Z
2020-08-25T20:55:16.912Z,1598388916.912 [Startup:StartupSatComms:A] Stopped
2020-08-25T20:55:16.912Z,1598388916.912 [Startup:StartupSatComms:B] Running Loop=1
2020-08-25T20:55:17.333Z,1598388917.333 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-08-25T20:55:17.333Z,1598388917.333 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-25T20:55:17.335Z,1598388917.335 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-25T20:55:17.385Z,1598388917.385 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-25T20:55:17.863Z,1598388917.863 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-25T20:55:17.863Z,1598388917.863 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-08-25T20:55:19.844Z,1598388919.844 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200825T202551/Courier0010.lzma
2020-08-25T20:55:20.159Z,1598388920.159 [DAT](INFO): #Outgoing data=1
2020-08-25T20:55:20.159Z,1598388920.159 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T20:55:20.387Z,1598388920.387 [DAT](INFO): setting remote address to 6
2020-08-25T20:55:20.737Z,1598388920.737 [DAT](INFO): DAT read: user:6>

2020-08-25T20:55:20.738Z,1598388920.738 [DAT](INFO): DAT read: RemoteAddr      | 6           

2020-08-25T20:55:20.739Z,1598388920.739 [DAT](INFO): set remote address to 6
2020-08-25T20:55:20.740Z,1598388920.740 [DAT](INFO): entering online mode
2020-08-25T20:55:20.860Z,1598388920.860 [DataOverHttps](INFO): Moved sent file to Logs/20200825T202551/Courier0010.lzma.bak
2020-08-25T20:55:20.860Z,1598388920.860 [DataOverHttps](INFO): SBD MOMSN=12616388
2020-08-25T20:55:21.133Z,1598388921.133 [DAT](INFO): DAT read: user:7>

2020-08-25T20:55:21.133Z,1598388921.133 [DAT](INFO): DAT read: 

2020-08-25T20:55:21.135Z,1598388921.135 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-25T20:55:21.135Z,1598388921.135 [DAT](INFO): commRate: 800
2020-08-25T20:55:21.135Z,1598388921.135 [DAT](INFO): online mode acknowledged
2020-08-25T20:55:21.136Z,1598388921.136 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T20:55:24.376Z,1598388924.376 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:55:04.6707

2020-08-25T20:55:24.376Z,1598388924.376 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T20:55:33.975Z,1598388933.975 [Reporter](INFO): AMEcho.altitude 131.679993 m
2020-08-25T20:55:34.941Z,1598388934.941 [Reporter](INFO): AMEcho.altitude 133.399994 m
2020-08-25T20:55:35.711Z,1598388935.711 [Reporter](INFO): AMEcho.altitude 140.149994 m
2020-08-25T20:55:37.713Z,1598388937.713 [Reporter](INFO): AMEcho.altitude 133.399994 m
2020-08-25T20:55:39.452Z,1598388939.452 [CommandLine](IMPORTANT): got command report touch AMEcho.altitude
2020-08-25T20:55:39.749Z,1598388939.749 [Reporter](INFO): AMEcho.altitude 133.399994 m
2020-08-25T20:55:41.328Z,1598388941.328 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T20:55:41.328Z,1598388941.328 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T20:55:43.970Z,1598388943.970 [DAT](INFO): #Outgoing data=1
2020-08-25T20:55:43.970Z,1598388943.970 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T20:55:44.073Z,1598388944.073 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T20:55:46.046Z,1598388946.046 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200825T205205/Courier0000.lzma
2020-08-25T20:55:47.048Z,1598388947.048 [DataOverHttps](INFO): Moved sent file to Logs/20200825T205205/Courier0000.lzma.bak
2020-08-25T20:55:47.048Z,1598388947.048 [DataOverHttps](INFO): SBD MOMSN=12616407
2020-08-25T20:55:47.286Z,1598388947.286 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:55:27.5706

2020-08-25T20:55:47.286Z,1598388947.286 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T20:56:04.260Z,1598388964.260 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T20:56:04.261Z,1598388964.261 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T20:56:05.144Z,1598388965.144 [DataOverHttps](INFO): Sending 364 bytes from file Logs/20200825T202551/Express0008.lzma
2020-08-25T20:56:05.400Z,1598388965.400 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T20:56:05.416Z,1598388965.416 [Startup:StartupSatComms:B] Stopped
2020-08-25T20:56:05.417Z,1598388965.417 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-08-25T20:56:05.417Z,1598388965.417 [Startup:StartupSatComms] Stopped
2020-08-25T20:56:05.417Z,1598388965.417 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-08-25T20:56:05.417Z,1598388965.417 [Startup](INFO): Completed Startup
2020-08-25T20:56:05.418Z,1598388965.418 [MissionManager](INFO): Startup is completed.
2020-08-25T20:56:05.418Z,1598388965.418 [MissionManager](INFO): Uninitializing Mission Startup
2020-08-25T20:56:05.418Z,1598388965.418 [Startup] Stopped
2020-08-25T20:56:05.418Z,1598388965.418 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-08-25T20:56:05.418Z,1598388965.418 [Startup:A.GoToSurface] Stopped
2020-08-25T20:56:05.418Z,1598388965.418 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-25T20:56:05.535Z,1598388965.535 [MissionManager](IMPORTANT): Started mission Default
2020-08-25T20:56:05.536Z,1598388965.536 [Default] Running Loop=1
2020-08-25T20:56:05.536Z,1598388965.536 [Default](DEBUG): Aggregate::initialize Default
2020-08-25T20:56:05.536Z,1598388965.536 [Default:B.GoToSurface] Running Loop=1
2020-08-25T20:56:05.536Z,1598388965.536 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-25T20:56:05.536Z,1598388965.536 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-25T20:56:05.536Z,1598388965.536 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-25T20:56:05.537Z,1598388965.537 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-25T20:56:05.537Z,1598388965.537 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-25T20:56:05.537Z,1598388965.537 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-25T20:56:05.538Z,1598388965.538 [Default:A.Wait] Running Loop=1
2020-08-25T20:56:05.538Z,1598388965.538 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-08-25T20:56:06.015Z,1598388966.015 [AMEcho](INFO): Powering down
2020-08-25T20:56:06.144Z,1598388966.144 [DataOverHttps](INFO): Moved sent file to Logs/20200825T202551/Express0008.lzma.bak
2020-08-25T20:56:06.144Z,1598388966.144 [DataOverHttps](INFO): SBD MOMSN=12616410
2020-08-25T20:56:07.053Z,1598388967.053 [AMEcho](INFO): Powering up
2020-08-25T20:56:13.991Z,1598388973.991 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-08-25T20:56:14.055Z,1598388974.055 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-08-25T20:56:18.784Z,1598388978.784 [Default:A.Wait](INFO): Done Waiting.
2020-08-25T20:56:18.784Z,1598388978.784 [Default:A.Wait] Stopped
2020-08-25T20:56:18.784Z,1598388978.784 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T20:56:19.191Z,1598388979.191 [Default:CheckIn] Running Loop=1
2020-08-25T20:56:19.191Z,1598388979.191 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T20:56:19.191Z,1598388979.191 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T20:56:19.602Z,1598388979.602 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-08-25T20:56:29.719Z,1598388989.719 [Reporter](INFO): AMEcho.altitude 132.729996 m
2020-08-25T20:56:30.509Z,1598388990.509 [Reporter](INFO): AMEcho.altitude 132.050003 m
2020-08-25T20:56:31.749Z,1598388991.749 [Reporter](INFO): AMEcho.altitude 132.050003 m
2020-08-25T20:56:32.541Z,1598388992.541 [Reporter](INFO): AMEcho.altitude 132.050003 m
2020-08-25T20:56:33.741Z,1598388993.741 [Reporter](INFO): AMEcho.altitude 132.050003 m
2020-08-25T20:56:34.568Z,1598388994.568 [Reporter](INFO): AMEcho.altitude 125.980003 m
2020-08-25T20:56:35.770Z,1598388995.770 [Reporter](INFO): AMEcho.altitude 125.980003 m
2020-08-25T20:56:36.570Z,1598388996.570 [Reporter](INFO): AMEcho.altitude 121.480003 m
2020-08-25T20:56:55.596Z,1598389015.596 [Reporter](INFO): AMEcho.altitude 7.930000 m
2020-08-25T20:56:56.769Z,1598389016.769 [Reporter](INFO): AMEcho.altitude 7.930000 m
2020-08-25T20:57:30.750Z,1598389050.750 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-08-25T20:57:30.767Z,1598389050.767 [Reporter](INFO): AMEcho.altitude 8.080000 m
2020-08-25T20:57:31.528Z,1598389051.528 [Reporter](INFO): AMEcho.altitude 7.630000 m
2020-08-25T20:57:32.726Z,1598389052.726 [Reporter](INFO): AMEcho.altitude 7.780000 m
2020-08-25T20:57:54.980Z,1598389074.980 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-08-25T20:57:57.748Z,1598389077.748 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-25T20:58:18.366Z,1598389098.366 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-08-25T20:58:18.366Z,1598389098.366 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-25T20:58:18.376Z,1598389098.376 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-25T20:58:18.800Z,1598389098.800 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-25T20:58:18.800Z,1598389098.800 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-08-25T20:58:25.674Z,1598389105.674 [Reporter](INFO): AMEcho.altitude 9.730000 m
2020-08-25T20:58:26.480Z,1598389106.480 [Reporter](INFO): AMEcho.altitude 9.730000 m
2020-08-25T20:58:44.684Z,1598389124.684 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-08-25T20:58:57.584Z,1598389137.584 [Reporter](INFO): AMEcho.altitude 7.330000 m
2020-08-25T20:58:58.793Z,1598389138.793 [Reporter](INFO): AMEcho.altitude 5.830000 m
2020-08-25T20:58:59.605Z,1598389139.605 [Reporter](INFO): AMEcho.altitude 6.280000 m
2020-08-25T20:59:00.814Z,1598389140.814 [Reporter](INFO): AMEcho.altitude 7.200000 m
2020-08-25T20:59:52.969Z,1598389192.969 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-08-25T20:59:58.604Z,1598389198.604 [Reporter](INFO): AMEcho.altitude 129.580002 m
2020-08-25T20:59:59.782Z,1598389199.782 [Reporter](INFO): AMEcho.altitude 129.580002 m
2020-08-25T21:00:00.596Z,1598389200.596 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-25T21:00:00.598Z,1598389200.598 [BPC1](INFO): Received data from all battery sticks.
2020-08-25T21:00:00.648Z,1598389200.648 [Reporter](INFO): AMEcho.altitude 129.580002 m
2020-08-25T21:00:24.427Z,1598389224.427 [Reporter](INFO): AMEcho.altitude 8.380000 m
2020-08-25T21:00:25.661Z,1598389225.661 [Reporter](INFO): AMEcho.altitude 6.580000 m
2020-08-25T21:00:26.459Z,1598389226.459 [Reporter](INFO): AMEcho.altitude 3.130000 m
2020-08-25T21:00:27.693Z,1598389227.693 [Reporter](INFO): AMEcho.altitude 2.850000 m
2020-08-25T21:01:16.549Z,1598389276.549 [Reporter](INFO): AMEcho.altitude 134.229996 m
2020-08-25T21:01:17.760Z,1598389277.760 [Reporter](INFO): AMEcho.altitude 134.229996 m
2020-08-25T21:01:19.358Z,1598389279.358 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-08-25T21:01:19.358Z,1598389279.358 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-25T21:01:19.360Z,1598389279.360 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-25T20:56:19.2Z
2020-08-25T21:01:19.360Z,1598389279.360 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T21:01:19.360Z,1598389279.360 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-25T21:01:19.373Z,1598389279.373 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-25T21:01:19.787Z,1598389279.787 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-25T21:01:19.797Z,1598389279.797 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-25T21:01:19.797Z,1598389279.797 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-08-25T21:01:20.659Z,1598389280.659 [Reporter](INFO): AMEcho.altitude 3.880000 m
2020-08-25T21:01:21.401Z,1598389281.401 [DAT](INFO): DAT read: Rx Time:20:56:29.3511

2020-08-25T21:01:21.402Z,1598389281.402 [DAT](INFO): received an acoustic signal
2020-08-25T21:01:21.402Z,1598389281.402 [DAT](INFO): DAT read: 

2020-08-25T21:01:21.404Z,1598389281.404 [DAT](INFO): DAT read: DATA(0035):set _.temperature 24.420710 celsius

2020-08-25T21:01:21.404Z,1598389281.404 [DAT](INFO): Got DATA 35
2020-08-25T21:01:21.405Z,1598389281.405 [DAT](INFO): DAT read: Source:006  Destination:009

2020-08-25T21:01:21.405Z,1598389281.405 [DAT](INFO): Got Src/Dest after DATA 
2020-08-25T21:01:21.405Z,1598389281.405 [DAT](INFO): DATA Src=6, Dst=9
2020-08-25T21:01:21.407Z,1598389281.407 [DAT](INFO): DAT read: CRC:Pass MPD:12.4 PSNR:13.8 AGC:77 SPD:+00.0 CCERR:010

2020-08-25T21:01:21.407Z,1598389281.407 [DAT](INFO): Got CRC:Pass
2020-08-25T21:01:21.407Z,1598389281.407 [DAT](INFO): Got CRC:Pass
2020-08-25T21:01:21.407Z,1598389281.407 [DAT](INFO): Incoming data is intended for us
2020-08-25T21:01:21.408Z,1598389281.408 [DAT](INFO): Received command:set _.temperature 24.420710 celsius
2020-08-25T21:01:22.808Z,1598389282.808 [CommandLine](IMPORTANT): got command set _.temperature 24.420710 celsius
2020-08-25T21:01:22.815Z,1598389282.815 [DAT](INFO): Sending ack
2020-08-25T21:01:22.815Z,1598389282.815 [DAT](INFO): DAT read: 

2020-08-25T21:01:22.816Z,1598389282.816 [DAT](INFO): DAT read: <EOP>

2020-08-25T21:01:22.893Z,1598389282.893 [Reporter](INFO): AMEcho.altitude 2.230000 m
2020-08-25T21:01:22.982Z,1598389282.982 [Reporter](INFO): AMEcho.altitude 3.000000 m
2020-08-25T21:01:23.753Z,1598389283.753 [Reporter](INFO): AMEcho.altitude 3.000000 m
2020-08-25T21:01:24.569Z,1598389284.569 [Reporter](INFO): AMEcho.altitude 3.000000 m
2020-08-25T21:01:26.137Z,1598389286.137 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:01:06.2694

2020-08-25T21:01:26.138Z,1598389286.138 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-25T21:01:26.594Z,1598389286.594 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20200825T205205/Courier0004.lzma
2020-08-25T21:01:27.596Z,1598389287.596 [DataOverHttps](INFO): Moved sent file to Logs/20200825T205205/Courier0004.lzma.bak
2020-08-25T21:01:27.596Z,1598389287.596 [DataOverHttps](INFO): SBD MOMSN=12616434
2020-08-25T21:01:29.380Z,1598389289.380 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:01:09.6693

2020-08-25T21:01:29.380Z,1598389289.380 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-25T21:01:44.663Z,1598389304.663 [DataOverHttps](INFO): Sending 269 bytes from file Logs/20200825T202551/Express0011.lzma
2020-08-25T21:01:45.664Z,1598389305.664 [DataOverHttps](INFO): Moved sent file to Logs/20200825T202551/Express0011.lzma.bak
2020-08-25T21:01:45.664Z,1598389305.664 [DataOverHttps](INFO): SBD MOMSN=12616436
2020-08-25T21:01:46.355Z,1598389306.355 [DAT](FAULT): Ack receipt timeout failure.
2020-08-25T21:01:46.355Z,1598389306.355 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-25T21:01:48.149Z,1598389308.149 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-25T21:01:48.167Z,1598389308.167 [Default:CheckIn:Read_Iridium] Stopped
2020-08-25T21:01:48.167Z,1598389308.167 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-25T21:01:48.167Z,1598389308.167 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-25T21:02:11.669Z,1598389331.669 [Reporter](INFO): AMEcho.altitude 7.180000 m
2020-08-25T21:02:12.453Z,1598389332.453 [Reporter](INFO): AMEcho.altitude 6.430000 m
2020-08-25T21:02:13.676Z,1598389333.676 [Reporter](INFO): AMEcho.altitude 6.430000 m
2020-08-25T21:02:30.296Z,1598389350.296 [DataOverHttps](INFO): Sending 1069 bytes from file Logs/20200825T205205/Express0001.lzma
2020-08-25T21:02:31.296Z,1598389351.296 [DataOverHttps](INFO): Moved sent file to Logs/20200825T205205/Express0001.lzma.bak
2020-08-25T21:02:31.296Z,1598389351.296 [DataOverHttps](INFO): SBD MOMSN=12616443
2020-08-25T21:02:56.872Z,1598389376.872 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-25T21:02:56.872Z,1598389376.872 [NAL9602] Data Fault, FailCount= 1
2020-08-25T21:02:56.872Z,1598389376.872 [NAL9602](ERROR): Data Fault
2020-08-25T21:02:56.924Z,1598389376.924 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-25T21:02:57.272Z,1598389377.272 [NAL9602](INFO): Powering down
2020-08-25T21:02:58.102Z,1598389378.102 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-25T21:02:58.102Z,1598389378.102 [NAL9602] No Fault, FailCount= 1
2020-08-25T21:03:16.703Z,1598389396.703 [Reporter](INFO): AMEcho.altitude 134.080002 m
2020-08-25T21:03:17.496Z,1598389397.496 [Reporter](INFO): AMEcho.altitude 125.980003 m
2020-08-25T21:03:18.704Z,1598389398.704 [Reporter](INFO): AMEcho.altitude 125.980003 m
2020-08-25T21:03:19.520Z,1598389399.520 [Reporter](INFO): AMEcho.altitude 128.229996 m
2020-08-25T21:03:20.729Z,1598389400.729 [Reporter](INFO): AMEcho.altitude 131.149994 m
2020-08-25T21:03:21.546Z,1598389401.546 [Reporter](INFO): AMEcho.altitude 128.229996 m
2020-08-25T21:03:22.763Z,1598389402.763 [Reporter](INFO): AMEcho.altitude 128.229996 m
2020-08-25T21:03:23.570Z,1598389403.570 [Reporter](INFO): AMEcho.altitude 128.679993 m
2020-08-25T21:03:24.770Z,1598389404.770 [Reporter](INFO): AMEcho.altitude 125.300003 m
2020-08-25T21:03:25.573Z,1598389405.573 [Reporter](INFO): AMEcho.altitude 125.300003 m
2020-08-25T21:03:26.801Z,1598389406.801 [Reporter](INFO): AMEcho.altitude 126.650002 m
2020-08-25T21:03:27.572Z,1598389407.572 [NAL9602](INFO): Powering up NAL9602
2020-08-25T21:03:27.591Z,1598389407.591 [Reporter](INFO): AMEcho.altitude 121.250000 m
2020-08-25T21:03:28.809Z,1598389408.809 [Reporter](INFO): AMEcho.altitude 123.050003 m
2020-08-25T21:03:29.617Z,1598389409.617 [Reporter](INFO): AMEcho.altitude 110.900002 m
2020-08-25T21:03:30.443Z,1598389410.443 [Reporter](INFO): AMEcho.altitude 113.150002 m
2020-08-25T21:03:31.648Z,1598389411.648 [Reporter](INFO): AMEcho.altitude 113.150002 m
2020-08-25T21:03:32.446Z,1598389412.446 [Reporter](INFO): AMEcho.altitude 113.150002 m
2020-08-25T21:03:33.649Z,1598389413.649 [Reporter](INFO): AMEcho.altitude 113.150002 m
2020-08-25T21:03:34.469Z,1598389414.469 [Reporter](INFO): AMEcho.altitude 107.300003 m
2020-08-25T21:03:35.676Z,1598389415.676 [Reporter](INFO): AMEcho.altitude 111.580002 m
2020-08-25T21:03:36.498Z,1598389416.498 [Reporter](INFO): AMEcho.altitude 112.250000 m
2020-08-25T21:03:37.718Z,1598389417.718 [Reporter](INFO): AMEcho.altitude 112.250000 m
2020-08-25T21:03:38.484Z,1598389418.484 [NAL9602](INFO): NAL9602 initialized
2020-08-25T21:03:38.538Z,1598389418.538 [Reporter](INFO): AMEcho.altitude 116.980003 m
2020-08-25T21:03:39.733Z,1598389419.733 [Reporter](INFO): AMEcho.altitude 123.500000 m
2020-08-25T21:03:40.521Z,1598389420.521 [Reporter](INFO): AMEcho.altitude 115.180000 m
2020-08-25T21:03:41.753Z,1598389421.753 [Reporter](INFO): AMEcho.altitude 120.349998 m
2020-08-25T21:03:42.561Z,1598389422.561 [Reporter](INFO): AMEcho.altitude 125.080002 m
2020-08-25T21:03:43.777Z,1598389423.777 [Reporter](INFO): AMEcho.altitude 129.130005 m
2020-08-25T21:03:44.585Z,1598389424.585 [Reporter](INFO): AMEcho.altitude 141.279999 m
2020-08-25T21:03:45.770Z,1598389425.770 [Reporter](INFO): AMEcho.altitude 137.449997 m
2020-08-25T21:03:46.596Z,1598389426.596 [Reporter](INFO): AMEcho.altitude 132.050003 m
2020-08-25T21:03:47.836Z,1598389427.836 [Reporter](INFO): AMEcho.altitude 136.330002 m
2020-08-25T21:03:48.625Z,1598389428.625 [Reporter](INFO): AMEcho.altitude 129.350006 m
2020-08-25T21:03:49.418Z,1598389429.418 [Reporter](INFO): AMEcho.altitude 123.730003 m
2020-08-25T21:03:50.633Z,1598389430.633 [Reporter](INFO): AMEcho.altitude 119.449997 m
2020-08-25T21:03:51.454Z,1598389431.454 [Reporter](INFO): AMEcho.altitude 115.180000 m
2020-08-25T21:03:52.646Z,1598389432.646 [Reporter](INFO): AMEcho.altitude 111.800003 m
2020-08-25T21:03:53.478Z,1598389433.478 [Reporter](INFO): AMEcho.altitude 114.949997 m
2020-08-25T21:03:54.672Z,1598389434.672 [Reporter](INFO): AMEcho.altitude 114.949997 m
2020-08-25T21:03:55.469Z,1598389435.469 [Reporter](INFO): AMEcho.altitude 113.379997 m
2020-08-25T21:03:56.711Z,1598389436.711 [Reporter](INFO): AMEcho.altitude 106.180000 m
2020-08-25T21:03:57.507Z,1598389437.507 [Reporter](INFO): AMEcho.altitude 102.129997 m
2020-08-25T21:03:58.705Z,1598389438.705 [Reporter](INFO): AMEcho.altitude 102.129997 m
2020-08-25T21:03:59.524Z,1598389439.524 [Reporter](INFO): AMEcho.altitude 102.129997 m
2020-08-25T21:04:00.727Z,1598389440.727 [Reporter](INFO): AMEcho.altitude 102.580002 m
2020-08-25T21:04:01.526Z,1598389441.526 [Reporter](INFO): AMEcho.altitude 95.150002 m
2020-08-25T21:04:02.760Z,1598389442.760 [Reporter](INFO): AMEcho.altitude 97.629997 m
2020-08-25T21:04:03.563Z,1598389443.563 [Reporter](INFO): AMEcho.altitude 97.629997 m
2020-08-25T21:04:04.761Z,1598389444.761 [Reporter](INFO): AMEcho.altitude 102.800003 m
2020-08-25T21:04:05.594Z,1598389445.594 [Reporter](INFO): AMEcho.altitude 107.529999 m
2020-08-25T21:04:06.785Z,1598389446.785 [Reporter](INFO): AMEcho.altitude 102.800003 m
2020-08-25T21:04:07.607Z,1598389447.607 [Reporter](INFO): AMEcho.altitude 98.300003 m
2020-08-25T21:04:08.824Z,1598389448.824 [Reporter](INFO): AMEcho.altitude 94.930000 m
2020-08-25T21:04:09.629Z,1598389449.629 [Reporter](INFO): AMEcho.altitude 93.580002 m
2020-08-25T21:04:10.431Z,1598389450.431 [Reporter](INFO): AMEcho.altitude 93.879997 m
2020-08-25T21:04:11.645Z,1598389451.645 [Reporter](INFO): AMEcho.altitude 93.879997 m
2020-08-25T21:04:12.467Z,1598389452.467 [Reporter](INFO): AMEcho.altitude 94.930000 m
2020-08-25T21:04:13.661Z,1598389453.661 [Reporter](INFO): AMEcho.altitude 94.930000 m
2020-08-25T21:04:14.498Z,1598389454.498 [Reporter](INFO): AMEcho.altitude 94.930000 m
2020-08-25T21:04:15.688Z,1598389455.688 [Reporter](INFO): AMEcho.altitude 94.930000 m
2020-08-25T21:04:16.479Z,1598389456.479 [Reporter](INFO): AMEcho.altitude 94.930000 m
2020-08-25T21:04:17.723Z,1598389457.723 [Reporter](INFO): AMEcho.altitude 94.930000 m
2020-08-25T21:04:20.520Z,1598389460.520 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-08-25T21:04:20.520Z,1598389460.520 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-25T21:04:20.530Z,1598389460.530 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-25T21:04:20.951Z,1598389460.951 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-25T21:04:20.951Z,1598389460.951 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-08-25T21:04:24.566Z,1598389464.566 [Reporter](INFO): AMEcho.altitude 7.930000 m
2020-08-25T21:04:25.793Z,1598389465.793 [Reporter](INFO): AMEcho.altitude 7.930000 m
2020-08-25T21:04:28.603Z,1598389468.603 [Reporter](INFO): AMEcho.altitude 4.330000 m
2020-08-25T21:04:29.845Z,1598389469.845 [Reporter](INFO): AMEcho.altitude 2.410000 m
2020-08-25T21:04:30.622Z,1598389470.622 [Reporter](INFO): AMEcho.altitude 2.410000 m
2020-08-25T21:04:31.430Z,1598389471.430 [Reporter](INFO): AMEcho.altitude 2.410000 m
2020-08-25T21:04:32.661Z,1598389472.661 [Reporter](INFO): AMEcho.altitude 2.400000 m
2020-08-25T21:04:33.471Z,1598389473.471 [Reporter](INFO): AMEcho.altitude 2.080000 m
2020-08-25T21:04:34.658Z,1598389474.658 [Reporter](INFO): AMEcho.altitude 2.400000 m
2020-08-25T21:05:15.478Z,1598389515.478 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T21:05:16.697Z,1598389516.697 [Reporter](INFO): AMEcho.altitude 10.180000 m
2020-08-25T21:05:19.529Z,1598389519.529 [Reporter](INFO): AMEcho.altitude 3.130000 m
2020-08-25T21:05:20.722Z,1598389520.722 [Reporter](INFO): AMEcho.altitude 3.780000 m
2020-08-25T21:05:21.549Z,1598389521.549 [Reporter](INFO): AMEcho.altitude 2.360000 m
2020-08-25T21:05:22.761Z,1598389522.761 [Reporter](INFO): AMEcho.altitude 5.320000 m
2020-08-25T21:05:23.545Z,1598389523.545 [Reporter](INFO): AMEcho.altitude 4.830000 m
2020-08-25T21:05:24.784Z,1598389524.784 [Reporter](INFO): AMEcho.altitude 8.560000 m
2020-08-25T21:06:18.501Z,1598389578.501 [Reporter](INFO): AMEcho.altitude 7.030000 m
2020-08-25T21:06:19.702Z,1598389579.702 [Reporter](INFO): AMEcho.altitude 3.220000 m
2020-08-25T21:06:20.523Z,1598389580.523 [Reporter](INFO): AMEcho.altitude 4.480000 m
2020-08-25T21:06:21.717Z,1598389581.717 [Reporter](INFO): AMEcho.altitude 2.750000 m
2020-08-25T21:06:22.541Z,1598389582.541 [Reporter](INFO): AMEcho.altitude 4.910000 m
2020-08-25T21:06:48.381Z,1598389608.381 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-25T21:06:48.381Z,1598389608.381 [Default:CheckIn:C.Wait] Stopped
2020-08-25T21:06:48.381Z,1598389608.381 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-25T21:06:48.381Z,1598389608.381 [Default:CheckIn:D] Running Loop=1
2020-08-25T21:06:48.796Z,1598389608.796 [Default:CheckIn:D] Stopped
2020-08-25T21:06:48.796Z,1598389608.796 [Default:CheckIn:E] Running Loop=1
2020-08-25T21:06:49.204Z,1598389609.204 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.720997 min 
2020-08-25T21:06:49.204Z,1598389609.204 [Default:CheckIn:E] Stopped
2020-08-25T21:06:49.204Z,1598389609.204 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-25T21:06:49.204Z,1598389609.204 [Default:CheckIn] Stopped
2020-08-25T21:06:49.204Z,1598389609.204 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T21:06:49.204Z,1598389609.204 [Default:CheckIn](INFO): Running loop #2
2020-08-25T21:06:49.204Z,1598389609.204 [Default:CheckIn] Running Loop=2
2020-08-25T21:06:49.204Z,1598389609.204 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-25T21:06:49.204Z,1598389609.204 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-25T21:07:08.584Z,1598389628.584 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T21:07:09.827Z,1598389629.827 [Reporter](INFO): AMEcho.altitude 9.880000 m
2020-08-25T21:07:17.260Z,1598389637.260 [CommandLine](IMPORTANT): got command configSet AMEcho.enabled 0.000000 bool
2020-08-25T21:07:17.458Z,1598389637.458 [AMEcho](ERROR): Setting 'enabled' to 0
2020-08-25T21:07:18.031Z,1598389638.031 [AMEcho](INFO): Powering down
2020-08-25T21:07:21.507Z,1598389641.507 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-08-25T21:07:21.507Z,1598389641.507 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-25T21:07:21.539Z,1598389641.539 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-25T21:07:21.947Z,1598389641.947 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-25T21:07:21.947Z,1598389641.947 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-08-25T21:10:05.247Z,1598389805.247 [CommandLine](IMPORTANT): got command restart application
2020-08-25T21:10:06.254Z,1598389806.254 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2020-08-25T21:10:06.255Z,1598389806.255 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T21:10:06.255Z,1598389806.255 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:06.414Z,1598389806.414 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-08-25T21:10:06.414Z,1598389806.414 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:06.415Z,1598389806.415 [CommandLine](INFO): Join timeout helper Thread ID is 3404
2020-08-25T21:10:06.427Z,1598389806.427 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-08-25T21:10:06.428Z,1598389806.428 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:06.429Z,1598389806.429 [NavChartDb](INFO): Join timeout helper Thread ID is 3405
2020-08-25T21:10:06.690Z,1598389806.690 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T21:10:06.691Z,1598389806.691 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:06.698Z,1598389806.698 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-08-25T21:10:06.698Z,1598389806.698 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:06.699Z,1598389806.699 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 3406
2020-08-25T21:10:07.139Z,1598389807.139 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T21:10:07.139Z,1598389807.139 [WetLabsBB2FL](INFO): Powering down
2020-08-25T21:10:07.140Z,1598389807.140 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:07.158Z,1598389807.158 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-08-25T21:10:07.158Z,1598389807.158 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:07.159Z,1598389807.159 [CTD_Seabird](INFO): Join timeout helper Thread ID is 3407
2020-08-25T21:10:07.651Z,1598389807.651 [CTD_Seabird](INFO): Powering down
2020-08-25T21:10:07.662Z,1598389807.662 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T21:10:07.663Z,1598389807.663 [CTD_Seabird](INFO): Powering down
2020-08-25T21:10:07.674Z,1598389807.674 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:07.678Z,1598389807.678 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2020-08-25T21:10:07.678Z,1598389807.678 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:07.679Z,1598389807.679 [BackSeatDriver](INFO): Join timeout helper Thread ID is 3408
2020-08-25T21:10:07.918Z,1598389807.918 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T21:10:07.919Z,1598389807.919 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:07.939Z,1598389807.939 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-08-25T21:10:07.939Z,1598389807.939 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:07.940Z,1598389807.940 [Radio_Surface](INFO): Join timeout helper Thread ID is 3409
2020-08-25T21:10:08.034Z,1598389808.034 [Radio_Surface](INFO): Powering down
2020-08-25T21:10:08.035Z,1598389808.035 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T21:10:08.036Z,1598389808.036 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:08.047Z,1598389808.047 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-08-25T21:10:08.047Z,1598389808.047 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:08.048Z,1598389808.048 [Onboard](INFO): Join timeout helper Thread ID is 3410
2020-08-25T21:10:08.070Z,1598389808.070 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T21:10:08.071Z,1598389808.071 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:08.072Z,1598389808.072 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-08-25T21:10:08.072Z,1598389808.072 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:08.073Z,1598389808.073 [DataOverHttps](INFO): Join timeout helper Thread ID is 3411
2020-08-25T21:10:08.393Z,1598389808.393 [CBIT](FAULT): Humidity exceeds 50% of running average: Humidity:2285304 %. Average:280387.375000
2020-08-25T21:10:08.522Z,1598389808.522 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T21:10:08.526Z,1598389808.526 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:08.543Z,1598389808.543 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-08-25T21:10:08.543Z,1598389808.543 [logger ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:08.544Z,1598389808.544 [logger](INFO): Join timeout helper Thread ID is 3412
2020-08-25T21:10:08.583Z,1598389808.583 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T21:10:08.583Z,1598389808.583 [logger ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:08.603Z,1598389808.603 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-08-25T21:10:08.603Z,1598389808.603 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:08.603Z,1598389808.603 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-08-25T21:10:08.603Z,1598389808.603 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:08.604Z,1598389808.604 [controlThread](INFO): Join timeout helper Thread ID is 3413
2020-08-25T21:10:08.734Z,1598389808.734 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-25T21:10:08.735Z,1598389808.735 [controlThread](DEBUG): Uninitializing ControlThread
2020-08-25T21:10:08.735Z,1598389808.735 [AHRS_M2](INFO): Powering down
2020-08-25T21:10:08.807Z,1598389808.807 [NAL9602](INFO): Powering down
2020-08-25T21:10:08.808Z,1598389808.808 [DAT](INFO): Powering down
2020-08-25T21:10:08.927Z,1598389808.927 [AMEcho](INFO): Powering down
2020-08-25T21:10:08.928Z,1598389808.928 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-08-25T21:10:08.929Z,1598389808.929 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-08-25T21:10:08.929Z,1598389808.929 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-08-25T21:10:08.930Z,1598389808.930 [MissionManager](INFO): Uninitializing Mission Default
2020-08-25T21:10:08.930Z,1598389808.930 [Default] Stopped
2020-08-25T21:10:08.930Z,1598389808.930 [Default](DEBUG): Aggregate::uninitialize Default
2020-08-25T21:10:08.930Z,1598389808.930 [Default:B.GoToSurface] Stopped
2020-08-25T21:10:08.930Z,1598389808.930 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-25T21:10:08.930Z,1598389808.930 [Default:CheckIn] Stopped
2020-08-25T21:10:08.930Z,1598389808.930 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-25T21:10:08.930Z,1598389808.930 [Default:CheckIn:Read_GPS] Stopped
2020-08-25T21:10:08.933Z,1598389808.933 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-08-25T21:10:08.933Z,1598389808.933 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-08-25T21:10:08.934Z,1598389808.934 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-08-25T21:10:08.934Z,1598389808.934 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-08-25T21:10:08.934Z,1598389808.934 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-08-25T21:10:08.934Z,1598389808.934 [BuoyancyServo](INFO): Powering down
2020-08-25T21:10:08.947Z,1598389808.947 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-08-25T21:10:08.947Z,1598389808.947 [ElevatorServo](INFO): Powering down
2020-08-25T21:10:08.947Z,1598389808.947 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-08-25T21:10:08.948Z,1598389808.948 [MassServo](INFO): Powering down
2020-08-25T21:10:08.948Z,1598389808.948 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-08-25T21:10:08.948Z,1598389808.948 [RudderServo](INFO): Powering down
2020-08-25T21:10:08.949Z,1598389808.949 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-08-25T21:10:08.949Z,1598389808.949 [ThrusterServo](INFO): Powering down
2020-08-25T21:10:08.950Z,1598389808.950 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-08-25T21:10:08.951Z,1598389808.951 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-08-25T21:10:08.951Z,1598389808.951 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-08-25T21:10:08.951Z,1598389808.951 [CBIT](DEBUG): Powering off loads.
2020-08-25T21:10:08.962Z,1598389808.962 [CBIT](DEBUG): Disabling WDT.
2020-08-25T21:10:08.974Z,1598389808.974 [CBIT](DEBUG): Opening all GF detection circuits.
2020-08-25T21:10:08.975Z,1598389808.975 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:09.069Z,1598389809.069 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:09.071Z,1598389809.071 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:09.077Z,1598389809.077 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:09.139Z,1598389809.139 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:09.143Z,1598389809.143 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:09.146Z,1598389809.146 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:09.155Z,1598389809.155 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-25T21:10:09.220Z,1598389809.220 [logger ThreadHandler](INFO): Thread cancelled.