2020-08-26T20:14:46.885Z,1598472886.885 [Supervisor](DEBUG): Initializing supervisor.
2020-08-26T20:14:46.888Z,1598472886.888 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-08-26T20:14:46.888Z,1598472886.888 [SyncHandler](INFO): Protected caller Thread ID is 1054
2020-08-26T20:14:46.889Z,1598472886.889 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-08-26T20:14:46.890Z,1598472886.890 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-08-26T20:14:46.890Z,1598472886.890 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1055
2020-08-26T20:14:46.893Z,1598472886.893 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-08-26T20:14:46.907Z,1598472886.907 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-08-26T20:14:46.908Z,1598472886.908 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-08-26T20:14:46.908Z,1598472886.908 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1056
2020-08-26T20:14:46.909Z,1598472886.909 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-08-26T20:14:46.910Z,1598472886.910 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-08-26T20:14:46.910Z,1598472886.910 [logger ThreadHandler](INFO): Protected caller Thread ID is 1057
2020-08-26T20:14:46.912Z,1598472886.912 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-08-26T20:14:46.912Z,1598472886.912 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-08-26T20:14:46.914Z,1598472886.914 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-08-26T20:14:47.009Z,1598472887.009 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-08-26T20:14:47.009Z,1598472887.009 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-08-26T20:14:47.613Z,1598472887.613 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-08-26T20:14:47.613Z,1598472887.613 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-08-26T20:14:47.809Z,1598472887.809 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-08-26T20:14:47.809Z,1598472887.809 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-08-26T20:14:47.909Z,1598472887.909 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-08-26T20:14:47.909Z,1598472887.909 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-08-26T20:14:48.013Z,1598472888.013 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-08-26T20:14:48.013Z,1598472888.013 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-08-26T20:14:48.097Z,1598472888.097 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-08-26T20:14:48.237Z,1598472888.237 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-08-26T20:14:48.238Z,1598472888.238 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-08-26T20:14:48.526Z,1598472888.526 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-08-26T20:14:48.527Z,1598472888.527 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-08-26T20:14:48.972Z,1598472888.972 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-08-26T20:14:48.973Z,1598472888.973 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-08-26T20:14:49.118Z,1598472889.118 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-08-26T20:14:49.118Z,1598472889.118 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-08-26T20:14:49.310Z,1598472889.310 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-08-26T20:14:49.311Z,1598472889.311 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-08-26T20:14:49.775Z,1598472889.775 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-08-26T20:14:49.775Z,1598472889.775 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-08-26T20:14:49.993Z,1598472889.993 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-08-26T20:14:49.993Z,1598472889.993 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-08-26T20:14:50.193Z,1598472890.193 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-08-26T20:14:50.193Z,1598472890.193 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-08-26T20:14:50.599Z,1598472890.599 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-08-26T20:14:50.599Z,1598472890.599 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-08-26T20:14:50.926Z,1598472890.926 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-08-26T20:14:50.928Z,1598472890.928 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-08-26T20:14:50.929Z,1598472890.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-08-26T20:14:51.016Z,1598472891.016 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-08-26T20:14:51.172Z,1598472891.172 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-08-26T20:14:51.278Z,1598472891.278 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-08-26T20:14:51.369Z,1598472891.369 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-08-26T20:14:51.465Z,1598472891.465 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-08-26T20:14:51.668Z,1598472891.668 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-08-26T20:14:51.986Z,1598472891.986 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-08-26T20:14:51.986Z,1598472891.986 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-08-26T20:14:52.191Z,1598472892.191 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-08-26T20:14:52.392Z,1598472892.392 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-08-26T20:14:52.700Z,1598472892.700 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-08-26T20:14:52.915Z,1598472892.915 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-08-26T20:14:52.928Z,1598472892.928 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-08-26T20:14:53.001Z,1598472893.001 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-08-26T20:14:53.002Z,1598472893.002 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-08-26T20:14:53.046Z,1598472893.046 [VerticalControl](DEBUG): Construct VerticalControl.
2020-08-26T20:14:53.157Z,1598472893.157 [VerticalControl] Loaded
2020-08-26T20:14:53.158Z,1598472893.158 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-08-26T20:14:53.158Z,1598472893.158 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-08-26T20:14:53.233Z,1598472893.233 [HorizontalControl] Loaded
2020-08-26T20:14:53.233Z,1598472893.233 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-08-26T20:14:53.234Z,1598472893.234 [SpeedControl](DEBUG): Construct SpeedControl.
2020-08-26T20:14:53.239Z,1598472893.239 [SpeedControl] Loaded
2020-08-26T20:14:53.239Z,1598472893.239 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-08-26T20:14:53.240Z,1598472893.240 [LoopControl](DEBUG): Construct LoopControl.
2020-08-26T20:14:53.241Z,1598472893.241 [LoopControl] Loaded
2020-08-26T20:14:53.241Z,1598472893.241 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-08-26T20:14:53.241Z,1598472893.241 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-08-26T20:14:53.242Z,1598472893.242 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-08-26T20:14:53.284Z,1598472893.284 [DepthRateCalculator] Loaded
2020-08-26T20:14:53.285Z,1598472893.285 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-08-26T20:14:53.290Z,1598472893.290 [PitchRateCalculator] Loaded
2020-08-26T20:14:53.290Z,1598472893.290 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-08-26T20:14:53.304Z,1598472893.304 [SpeedCalculator] Loaded
2020-08-26T20:14:53.305Z,1598472893.305 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-08-26T20:14:53.324Z,1598472893.324 [TempGradientCalculator] Loaded
2020-08-26T20:14:53.325Z,1598472893.325 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-08-26T20:14:53.329Z,1598472893.329 [YawRateCalculator] Loaded
2020-08-26T20:14:53.330Z,1598472893.330 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-08-26T20:14:53.362Z,1598472893.362 [ElevatorOffsetCalculator] Loaded
2020-08-26T20:14:53.362Z,1598472893.362 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-08-26T20:14:53.362Z,1598472893.362 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-08-26T20:14:53.363Z,1598472893.363 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-08-26T20:14:53.389Z,1598472893.389 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-08-26T20:14:53.389Z,1598472893.389 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-08-26T20:14:53.473Z,1598472893.473 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-08-26T20:14:53.473Z,1598472893.473 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-08-26T20:14:53.745Z,1598472893.745 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-08-26T20:14:53.746Z,1598472893.746 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-08-26T20:14:53.840Z,1598472893.840 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-08-26T20:14:53.841Z,1598472893.841 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-08-26T20:14:54.180Z,1598472894.180 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-08-26T20:14:54.184Z,1598472894.184 [AHRS_M2](INFO): created writer for : platform_orientation
2020-08-26T20:14:54.186Z,1598472894.186 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-08-26T20:14:54.192Z,1598472894.192 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-08-26T20:14:54.192Z,1598472894.192 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-08-26T20:14:54.197Z,1598472894.197 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-08-26T20:14:54.198Z,1598472894.198 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-08-26T20:14:54.203Z,1598472894.203 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-08-26T20:14:54.270Z,1598472894.270 [AHRS_M2] Loaded
2020-08-26T20:14:54.270Z,1598472894.270 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-08-26T20:14:54.344Z,1598472894.344 [DataOverHttps] Loaded
2020-08-26T20:14:54.344Z,1598472894.344 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-08-26T20:14:54.345Z,1598472894.345 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4090D4E0
2020-08-26T20:14:54.346Z,1598472894.346 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1141
2020-08-26T20:14:54.374Z,1598472894.374 [Depth_Keller] Loaded
2020-08-26T20:14:54.375Z,1598472894.375 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-08-26T20:14:54.481Z,1598472894.481 [NAL9602] Loaded
2020-08-26T20:14:54.481Z,1598472894.481 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-08-26T20:14:54.528Z,1598472894.528 [Onboard] Loaded
2020-08-26T20:14:54.528Z,1598472894.528 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-08-26T20:14:54.529Z,1598472894.529 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4093D4E0
2020-08-26T20:14:54.529Z,1598472894.529 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1142
2020-08-26T20:14:54.547Z,1598472894.547 [Radio_Surface] Loaded
2020-08-26T20:14:54.548Z,1598472894.548 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-08-26T20:14:54.549Z,1598472894.549 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4096D4E0
2020-08-26T20:14:54.549Z,1598472894.549 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1143
2020-08-26T20:14:54.692Z,1598472894.692 [DAT] Loaded
2020-08-26T20:14:54.692Z,1598472894.692 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-08-26T20:14:56.116Z,1598472896.116 [BPC1] Loaded
2020-08-26T20:14:56.117Z,1598472896.117 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-08-26T20:14:56.148Z,1598472896.148 [AMEcho] Loaded
2020-08-26T20:14:56.148Z,1598472896.148 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread.
2020-08-26T20:14:56.149Z,1598472896.149 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-08-26T20:14:56.149Z,1598472896.149 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-08-26T20:14:56.261Z,1598472896.261 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-08-26T20:14:56.262Z,1598472896.262 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-08-26T20:14:56.281Z,1598472896.281 [NavChart] Loaded
2020-08-26T20:14:56.281Z,1598472896.281 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-08-26T20:14:56.285Z,1598472896.285 [UniversalFixResidualReporter] Loaded
2020-08-26T20:14:56.285Z,1598472896.285 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-08-26T20:14:56.286Z,1598472896.286 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-08-26T20:14:56.286Z,1598472896.286 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-08-26T20:14:56.413Z,1598472896.413 [SBIT](DEBUG): Construct Startup Built In Test.
2020-08-26T20:14:56.423Z,1598472896.423 [SBIT] Loaded
2020-08-26T20:14:56.424Z,1598472896.424 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-08-26T20:14:56.424Z,1598472896.424 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-08-26T20:14:56.436Z,1598472896.436 [IBIT] Loaded
2020-08-26T20:14:56.437Z,1598472896.437 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-08-26T20:14:56.440Z,1598472896.440 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-08-26T20:14:56.572Z,1598472896.572 [CBIT] Loaded
2020-08-26T20:14:56.572Z,1598472896.572 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-08-26T20:14:56.572Z,1598472896.572 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-08-26T20:14:56.573Z,1598472896.573 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-08-26T20:14:56.688Z,1598472896.688 [BuoyancyServo] Loaded
2020-08-26T20:14:56.688Z,1598472896.688 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-08-26T20:14:56.715Z,1598472896.715 [ElevatorServo] Loaded
2020-08-26T20:14:56.716Z,1598472896.716 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-08-26T20:14:56.742Z,1598472896.742 [MassServo] Loaded
2020-08-26T20:14:56.743Z,1598472896.743 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-08-26T20:14:56.769Z,1598472896.769 [RudderServo] Loaded
2020-08-26T20:14:56.769Z,1598472896.769 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-08-26T20:14:56.794Z,1598472896.794 [ThrusterServo] Loaded
2020-08-26T20:14:56.795Z,1598472896.795 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-08-26T20:14:56.795Z,1598472896.795 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-08-26T20:14:56.795Z,1598472896.795 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-08-26T20:14:56.814Z,1598472896.814 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-08-26T20:14:56.814Z,1598472896.814 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-08-26T20:14:57.047Z,1598472897.047 [BackSeatDriver] Loaded
2020-08-26T20:14:57.047Z,1598472897.047 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2020-08-26T20:14:57.048Z,1598472897.048 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40B034E0
2020-08-26T20:14:57.049Z,1598472897.049 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 1144
2020-08-26T20:14:57.076Z,1598472897.076 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-08-26T20:14:57.081Z,1598472897.081 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-08-26T20:14:57.081Z,1598472897.081 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-08-26T20:14:57.086Z,1598472897.086 [CTD_Seabird](INFO): created writer for : depth
2020-08-26T20:14:57.086Z,1598472897.086 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-08-26T20:14:57.092Z,1598472897.092 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-08-26T20:14:57.093Z,1598472897.093 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-08-26T20:14:57.098Z,1598472897.098 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-08-26T20:14:57.098Z,1598472897.098 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-08-26T20:14:57.103Z,1598472897.103 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-08-26T20:14:57.104Z,1598472897.104 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-08-26T20:14:57.109Z,1598472897.109 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-08-26T20:14:57.109Z,1598472897.109 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-08-26T20:14:57.114Z,1598472897.114 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-08-26T20:14:57.194Z,1598472897.194 [CTD_Seabird] Loaded
2020-08-26T20:14:57.194Z,1598472897.194 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-08-26T20:14:57.196Z,1598472897.196 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40B334E0
2020-08-26T20:14:57.196Z,1598472897.196 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1145
2020-08-26T20:14:57.256Z,1598472897.256 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-08-26T20:14:57.257Z,1598472897.257 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-08-26T20:14:57.261Z,1598472897.261 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-08-26T20:14:57.261Z,1598472897.261 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-08-26T20:14:57.265Z,1598472897.265 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-08-26T20:14:57.265Z,1598472897.265 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-08-26T20:14:57.269Z,1598472897.269 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-08-26T20:14:57.269Z,1598472897.269 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-08-26T20:14:57.273Z,1598472897.273 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-08-26T20:14:57.273Z,1598472897.273 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-08-26T20:14:57.277Z,1598472897.277 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-08-26T20:14:57.277Z,1598472897.277 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-08-26T20:14:57.281Z,1598472897.281 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-08-26T20:14:57.282Z,1598472897.282 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-08-26T20:14:57.286Z,1598472897.286 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-08-26T20:14:57.290Z,1598472897.290 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-08-26T20:14:57.290Z,1598472897.290 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-26T20:14:57.291Z,1598472897.291 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-26T20:14:57.294Z,1598472897.294 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-26T20:14:57.294Z,1598472897.294 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-26T20:14:57.298Z,1598472897.298 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-26T20:14:57.299Z,1598472897.299 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-26T20:14:57.303Z,1598472897.303 [WetLabsBB2FL] Loaded
2020-08-26T20:14:57.303Z,1598472897.303 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-08-26T20:14:57.304Z,1598472897.304 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B634E0
2020-08-26T20:14:57.304Z,1598472897.304 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1146
2020-08-26T20:14:57.305Z,1598472897.305 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-08-26T20:14:57.309Z,1598472897.309 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-08-26T20:14:57.310Z,1598472897.310 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-08-26T20:14:57.316Z,1598472897.316 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-08-26T20:14:57.317Z,1598472897.317 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B934E0
2020-08-26T20:14:57.318Z,1598472897.318 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1147
2020-08-26T20:14:57.322Z,1598472897.322 [Supervisor](INFO): Main Thread ID is 1053
2020-08-26T20:14:57.322Z,1598472897.322 [Supervisor](DEBUG): Running supervisor.
2020-08-26T20:14:57.323Z,1598472897.323 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1148
2020-08-26T20:14:57.325Z,1598472897.325 [controlThread ThreadHandler](INFO): Handler Thread ID is 1149
2020-08-26T20:14:57.326Z,1598472897.326 [controlThread](DEBUG): Initializing ControlThread
2020-08-26T20:14:57.327Z,1598472897.327 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-08-26T20:14:57.328Z,1598472897.328 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-08-26T20:14:57.329Z,1598472897.329 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-08-26T20:14:57.330Z,1598472897.330 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-08-26T20:14:57.330Z,1598472897.330 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-08-26T20:14:57.330Z,1598472897.330 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-08-26T20:14:57.331Z,1598472897.331 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-08-26T20:14:57.331Z,1598472897.331 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-08-26T20:14:57.331Z,1598472897.331 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-08-26T20:14:57.332Z,1598472897.332 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-08-26T20:14:57.337Z,1598472897.337 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-08-26T20:14:57.338Z,1598472897.338 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-08-26T20:14:57.338Z,1598472897.338 [SBIT](INFO): Initialize SBIT Component.
2020-08-26T20:14:57.338Z,1598472897.338 [SBIT](IMPORTANT): git: 2020-08-18a-28-g0d8891e
2020-08-26T20:14:57.339Z,1598472897.339 [SBIT](INFO): git hash: 0d8891e4c136abd7dd8b76b3c91e52f720a234d8
2020-08-26T20:14:57.339Z,1598472897.339 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-08-26T20:14:57.340Z,1598472897.340 [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-26T20:14:57.341Z,1598472897.341 [SBIT](INFO): Beginning SBIT in 65.000000 seconds.
2020-08-26T20:14:57.342Z,1598472897.342 [IBIT](INFO): Initialize IBIT Component.
2020-08-26T20:14:57.342Z,1598472897.342 [CBIT](DEBUG): Initialize CBIT Component.
2020-08-26T20:14:57.343Z,1598472897.343 [logger ThreadHandler](INFO): Handler Thread ID is 1150
2020-08-26T20:14:57.356Z,1598472897.356 [CBIT](DEBUG): Initialized mux pins.
2020-08-26T20:14:57.356Z,1598472897.356 [CBIT](DEBUG): Initializing the watchdog timer.
2020-08-26T20:14:57.360Z,1598472897.360 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1151
2020-08-26T20:14:57.361Z,1598472897.361 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-08-26T20:14:57.368Z,1598472897.368 [Onboard ThreadHandler](INFO): Handler Thread ID is 1152
2020-08-26T20:14:57.381Z,1598472897.381 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2020-08-26T20:14:57.381Z,1598472897.381 [CBIT](DEBUG): Initializing heartbeat.
2020-08-26T20:14:57.391Z,1598472897.391 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1153
2020-08-26T20:14:57.412Z,1598472897.412 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 1154
2020-08-26T20:14:57.424Z,1598472897.424 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1155
2020-08-26T20:14:57.425Z,1598472897.425 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-08-26T20:14:57.429Z,1598472897.429 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1157
2020-08-26T20:14:57.430Z,1598472897.430 [WetLabsBB2FL](INFO): Powering down
2020-08-26T20:14:57.452Z,1598472897.452 [CBIT](DEBUG): Deactivating GF circuits.
2020-08-26T20:14:57.452Z,1598472897.452 [CBIT](DEBUG): Deactivating emergency mode.
2020-08-26T20:14:57.464Z,1598472897.464 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1158
2020-08-26T20:14:57.467Z,1598472897.467 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-08-26T20:14:57.468Z,1598472897.468 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-08-26T20:14:57.468Z,1598472897.468 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-08-26T20:14:57.468Z,1598472897.468 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-08-26T20:14:57.468Z,1598472897.468 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-08-26T20:14:57.468Z,1598472897.468 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-08-26T20:14:57.468Z,1598472897.468 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-08-26T20:14:57.469Z,1598472897.469 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-08-26T20:14:57.469Z,1598472897.469 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-08-26T20:14:57.469Z,1598472897.469 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-08-26T20:14:57.469Z,1598472897.469 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-08-26T20:14:57.469Z,1598472897.469 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-08-26T20:14:57.469Z,1598472897.469 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-08-26T20:14:57.470Z,1598472897.470 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-08-26T20:14:57.470Z,1598472897.470 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-08-26T20:14:57.470Z,1598472897.470 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-08-26T20:14:57.488Z,1598472897.488 [CBIT](DEBUG): Backplane powered.
2020-08-26T20:14:57.489Z,1598472897.489 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-08-26T20:14:57.500Z,1598472897.500 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-26T20:14:57.511Z,1598472897.511 [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-26T20:14:57.512Z,1598472897.511 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-08-26T20:14:57.589Z,1598472897.589 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-08-26T20:14:57.590Z,1598472897.590 [Default:A.Wait](DEBUG): Construct Wait.
2020-08-26T20:14:57.592Z,1598472897.592 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-26T20:14:57.630Z,1598472897.630 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-08-26T20:14:57.644Z,1598472897.644 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-08-26T20:14:57.678Z,1598472897.678 [Default:E.Execute](DEBUG): Construct Execute.
2020-08-26T20:14:57.681Z,1598472897.681 [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-26T20:14:57.699Z,1598472897.699 [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-26T20:14:57.720Z,1598472897.720 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-08-26T20:14:57.772Z,1598472897.772 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar
2020-08-26T20:14:57.775Z,1598472897.775 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-08-26T20:14:57.776Z,1598472897.776 [DAT](INFO): Powering up
2020-08-26T20:14:57.776Z,1598472897.776 [DAT](DEBUG): Initializing DAT.
2020-08-26T20:14:57.796Z,1598472897.796 [Radio_Surface](INFO): Powering up
2020-08-26T20:14:57.824Z,1598472897.824 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-08-26T20:14:57.840Z,1598472897.840 [AMEcho](INFO): Powering up
2020-08-26T20:14:57.868Z,1598472897.868 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-08-26T20:14:57.881Z,1598472897.881 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-08-26T20:14:57.892Z,1598472897.892 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-08-26T20:14:57.893Z,1598472897.893 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-08-26T20:14:57.904Z,1598472897.904 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-08-26T20:14:57.905Z,1598472897.905 [MassServo](DEBUG): Initializing EZServoServo.
2020-08-26T20:14:57.916Z,1598472897.916 [MassServo](DEBUG): Initializing MassServo.
2020-08-26T20:14:57.917Z,1598472897.917 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-26T20:14:57.928Z,1598472897.928 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-26T20:14:57.929Z,1598472897.929 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-08-26T20:14:57.940Z,1598472897.940 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-08-26T20:14:57.943Z,1598472897.943 [CommandLine](FAULT): Scheduling is paused
2020-08-26T20:14:57.943Z,1598472897.943 [CBIT](INFO): Critical error at 20200826T201457
2020-08-26T20:14:57.943Z,1598472897.943 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-08-26T20:14:58.396Z,1598472898.396 [AMEcho](INFO): Powering down
2020-08-26T20:14:58.824Z,1598472898.824 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-08-26T20:14:58.824Z,1598472898.824 [RudderServo](FAULT): Rudder failed to initialize
2020-08-26T20:14:58.824Z,1598472898.824 [RudderServo] Communications Fault, FailCount= 1
2020-08-26T20:14:58.824Z,1598472898.824 [RudderServo](ERROR): Communications Fault
2020-08-26T20:14:58.935Z,1598472898.935 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-08-26T20:14:59.097Z,1598472899.097 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-08-26T20:14:59.097Z,1598472899.097 [RudderServo](INFO): Powering down
2020-08-26T20:14:59.790Z,1598472899.790 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-26T20:14:59.909Z,1598472899.909 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-26T20:14:59.913Z,1598472899.913 [CBIT](INFO): Clearing failed state for component RudderServo
2020-08-26T20:14:59.913Z,1598472899.913 [RudderServo] No Fault, FailCount= 1
2020-08-26T20:15:08.241Z,1598472908.241 [DAT](INFO): DAT read: 

2020-08-26T20:15:08.243Z,1598472908.243 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2020-08-26T20:15:09.454Z,1598472909.454 [DAT](INFO): DAT read: MF Frequency Band

2020-08-26T20:15:09.455Z,1598472909.455 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.12.21

2020-08-26T20:15:09.455Z,1598472909.455 [DAT](INFO): DAT read: Aug 26 2020 20:14:38 

2020-08-26T20:15:10.262Z,1598472910.262 [DAT](INFO): DAT read: Features enabled [Bearing]

2020-08-26T20:15:10.263Z,1598472910.263 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-26T20:15:10.263Z,1598472910.263 [DAT](INFO): commRate: 800
2020-08-26T20:15:10.263Z,1598472910.263 [DAT](INFO): commRate: 800
2020-08-26T20:15:10.334Z,1598472910.334 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004825
2020-08-26T20:15:10.666Z,1598472910.666 [DAT](INFO): entering command mode
2020-08-26T20:15:11.069Z,1598472911.069 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:11.473Z,1598472911.473 [DAT](INFO): DAT read: 

2020-08-26T20:15:11.474Z,1598472911.474 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:11.877Z,1598472911.877 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:12.281Z,1598472912.281 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:12.685Z,1598472912.685 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:13.089Z,1598472913.089 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:13.493Z,1598472913.493 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:13.897Z,1598472913.897 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:14.301Z,1598472914.301 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:14.705Z,1598472914.705 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:15.109Z,1598472915.109 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:15.513Z,1598472915.513 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:15.917Z,1598472915.917 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:16.321Z,1598472916.321 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:16.725Z,1598472916.725 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:17.129Z,1598472917.129 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:17.339Z,1598472917.339 [CommandLine](IMPORTANT): got command strobe off
2020-08-26T20:15:17.339Z,1598472917.339 [CommandLine](IMPORTANT): Deactivating strobe
2020-08-26T20:15:17.533Z,1598472917.533 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:17.937Z,1598472917.937 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:18.341Z,1598472918.341 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:18.745Z,1598472918.745 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:19.149Z,1598472919.149 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:19.553Z,1598472919.553 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:19.957Z,1598472919.957 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:20.361Z,1598472920.361 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:20.765Z,1598472920.765 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:21.170Z,1598472921.170 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:21.573Z,1598472921.573 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:21.977Z,1598472921.977 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:22.381Z,1598472922.381 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:22.797Z,1598472922.797 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:23.189Z,1598472923.189 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:23.593Z,1598472923.593 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:24.005Z,1598472924.005 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:24.401Z,1598472924.401 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:24.801Z,1598472924.801 [NAL9602](INFO): Powering up NAL9602
2020-08-26T20:15:24.803Z,1598472924.803 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:25.209Z,1598472925.209 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:25.617Z,1598472925.617 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:26.017Z,1598472926.017 [DAT](DEBUG): checking for command mode acknowledgment
2020-08-26T20:15:26.017Z,1598472926.017 [DAT](FAULT): failed to enter command mode
2020-08-26T20:15:26.421Z,1598472926.421 [DAT](INFO): entering command mode
2020-08-26T20:15:26.826Z,1598472926.826 [DAT](INFO): DAT read: user:1>

2020-08-26T20:15:26.826Z,1598472926.826 [DAT](INFO): DAT read: Command '+++' not found

2020-08-26T20:15:26.827Z,1598472926.827 [DAT](INFO): DAT read: Error

2020-08-26T20:15:26.827Z,1598472926.827 [DAT](INFO): setting verbose to 3
2020-08-26T20:15:27.231Z,1598472927.231 [DAT](INFO): DAT read: user:2>

2020-08-26T20:15:27.232Z,1598472927.232 [DAT](INFO): DAT read: Verbose         | 3           

2020-08-26T20:15:27.232Z,1598472927.232 [DAT](INFO): set verbose to 3
2020-08-26T20:15:27.232Z,1598472927.232 [DAT](INFO): setting DatVerbose to 27440
2020-08-26T20:15:27.633Z,1598472927.633 [DAT](INFO): DAT read: user:3>

2020-08-26T20:15:27.634Z,1598472927.634 [DAT](INFO): DAT read: DatVerbose      | 27440       

2020-08-26T20:15:27.635Z,1598472927.635 [DAT](INFO): set DatVerbose to 27440
2020-08-26T20:15:27.635Z,1598472927.635 [DAT](INFO): setting transmit power to 8
2020-08-26T20:15:28.038Z,1598472928.038 [DAT](INFO): DAT read: user:4>

2020-08-26T20:15:28.038Z,1598472928.038 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2020-08-26T20:15:28.039Z,1598472928.039 [DAT](INFO): set transmit power to 8
2020-08-26T20:15:28.039Z,1598472928.039 [DAT](INFO): setting local address to 9
2020-08-26T20:15:28.443Z,1598472928.443 [DAT](INFO): DAT read: user:5>

2020-08-26T20:15:28.443Z,1598472928.443 [DAT](INFO): DAT read: LocalAddr       | 9           

2020-08-26T20:15:28.444Z,1598472928.444 [DAT](INFO): set local address to 9
2020-08-26T20:15:35.713Z,1598472935.713 [NAL9602](INFO): NAL9602 initialized
2020-08-26T20:15:47.402Z,1598472947.402 [CommandLine](IMPORTANT): got command strobe off
2020-08-26T20:15:47.402Z,1598472947.402 [CommandLine](IMPORTANT): Deactivating strobe
2020-08-26T20:16:02.834Z,1598472962.834 [SBIT](IMPORTANT): Beginning Startup BIT
2020-08-26T20:16:02.863Z,1598472962.863 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-26T20:16:13.853Z,1598472973.853 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.010267
CHAN A1 (24V): -0.000702
CHAN A2 (12V): -0.007282
CHAN A3 (5V): -0.002543
CHAN B0 (3.3V): 0.000151
CHAN B1 (3.15aV): 0.000146
CHAN B2 (3.15bV): -0.000067
CHAN B3 (GND): 0.002257
OPEN: 0.005297
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-26T20:16:56.534Z,1598473016.534 [SBIT](IMPORTANT): SBIT PASSED
2020-08-26T20:16:56.535Z,1598473016.535 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-08-26T20:16:56.535Z,1598473016.535 [SBIT](IMPORTANT): BackSeatDriver.loadAtStartup=1 bool;

2020-08-26T20:16:56.536Z,1598473016.536 [SBIT](IMPORTANT): CBIT.gf24Offset=145 microampere;

2020-08-26T20:16:56.536Z,1598473016.536 [SBIT](IMPORTANT): DAT.sbdAddress=6 enum;

2020-08-26T20:16:56.536Z,1598473016.536 [SBIT](IMPORTANT): DAT.surfaceThreshold=-1 meter;

2020-08-26T20:16:56.536Z,1598473016.536 [SBIT](IMPORTANT): DAT.verbosity=3 count;

2020-08-26T20:16:56.536Z,1598473016.536 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2020-08-26T20:16:56.536Z,1598473016.536 [SBIT](IMPORTANT): Express none ThrusterServo.component_avgCurrent;

2020-08-26T20:16:56.537Z,1598473016.537 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 1.000000 liter_per_second;

2020-08-26T20:16:56.537Z,1598473016.537 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2020-08-26T20:16:56.537Z,1598473016.537 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool;

2020-08-26T20:16:56.537Z,1598473016.537 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=344.685708 cubic_centimeter;

2020-08-26T20:16:56.537Z,1598473016.537 [SBIT](IMPORTANT): VerticalControl.massDefault=11.293600 millimeter;

2020-08-26T20:16:56.537Z,1598473016.537 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=0 bool;

2020-08-26T20:16:56.945Z,1598473016.945 [MissionManager](IMPORTANT): Started mission Startup
2020-08-26T20:16:56.945Z,1598473016.945 [Startup] Running Loop=1
2020-08-26T20:16:56.946Z,1598473016.946 [Startup](DEBUG): Aggregate::initialize Startup
2020-08-26T20:16:56.946Z,1598473016.946 [Startup:A.GoToSurface] Running Loop=1
2020-08-26T20:16:56.946Z,1598473016.946 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-26T20:16:56.946Z,1598473016.946 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-26T20:16:56.947Z,1598473016.947 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-26T20:16:56.947Z,1598473016.947 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-26T20:16:56.947Z,1598473016.947 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-26T20:16:56.948Z,1598473016.948 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-26T20:16:56.949Z,1598473016.949 [Startup:StartupSatComms] Running Loop=1
2020-08-26T20:16:56.949Z,1598473016.949 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-08-26T20:16:56.949Z,1598473016.949 [Startup:StartupSatComms:A] Running Loop=1
2020-08-26T20:16:57.357Z,1598473017.357 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-08-26T20:16:57.746Z,1598473017.746 [AMEcho](INFO): Powering up
2020-08-26T20:16:58.149Z,1598473018.149 [DAT](INFO): DAT read: user:6>Rx Time:20:16:30.0500

2020-08-26T20:16:58.538Z,1598473018.538 [DAT](INFO): DAT read: 

2020-08-26T20:16:58.946Z,1598473018.946 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:16:58.947Z,1598473018.947 [DAT](INFO): received a packet notification
2020-08-26T20:17:19.550Z,1598473039.550 [DAT](INFO): DAT read: Rx Time:20:16:51.5505

2020-08-26T20:17:19.550Z,1598473039.550 [DAT](INFO): received an acoustic signal
2020-08-26T20:17:20.354Z,1598473040.354 [DAT](INFO): DAT read: 

2020-08-26T20:17:20.355Z,1598473040.355 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:17:20.355Z,1598473040.355 [DAT](INFO): received a packet notification
2020-08-26T20:17:57.138Z,1598473077.138 [Startup:StartupSatComms:A](INFO): Timed out from 2020-08-26T20:16:56.9Z
2020-08-26T20:17:57.139Z,1598473077.139 [Startup:StartupSatComms:A] Stopped
2020-08-26T20:17:57.139Z,1598473077.139 [Startup:StartupSatComms:B] Running Loop=1
2020-08-26T20:17:57.544Z,1598473077.544 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-08-26T20:17:57.544Z,1598473077.544 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:17:57.546Z,1598473077.546 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-26T20:17:57.621Z,1598473077.621 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:17:59.504Z,1598473079.504 [DAT](INFO): #Outgoing data=1
2020-08-26T20:17:59.504Z,1598473079.504 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:17:59.577Z,1598473079.577 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:17:59.577Z,1598473079.577 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-08-26T20:17:59.607Z,1598473079.607 [DAT](INFO): setting remote address to 6
2020-08-26T20:18:00.005Z,1598473080.005 [DAT](INFO): DAT read: 

2020-08-26T20:18:00.005Z,1598473080.005 [DAT](INFO): DAT read: RemoteAddr      | 6           

2020-08-26T20:18:00.006Z,1598473080.006 [DAT](INFO): set remote address to 6
2020-08-26T20:18:00.006Z,1598473080.006 [DAT](INFO): entering online mode
2020-08-26T20:18:00.417Z,1598473080.417 [DAT](INFO): DAT read: user:7>

2020-08-26T20:18:00.417Z,1598473080.417 [DAT](INFO): DAT read: 

2020-08-26T20:18:00.418Z,1598473080.418 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2020-08-26T20:18:00.419Z,1598473080.419 [DAT](INFO): commRate: 800
2020-08-26T20:18:00.419Z,1598473080.419 [DAT](INFO): online mode acknowledged
2020-08-26T20:18:00.419Z,1598473080.419 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:18:01.088Z,1598473081.088 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200826T193220/Courier0004.lzma
2020-08-26T20:18:01.189Z,1598473081.189 [DataOverHttps](INFO): Moved sent file to Logs/20200826T193220/Courier0004.lzma.bak
2020-08-26T20:18:01.190Z,1598473081.190 [DataOverHttps](INFO): SBD MOMSN=12622393
2020-08-26T20:18:01.614Z,1598473081.614 [DAT](INFO): DAT read: Rx Time:20:17:33.6513

2020-08-26T20:18:01.615Z,1598473081.615 [DAT](INFO): received an acoustic signal
2020-08-26T20:18:02.418Z,1598473082.418 [DAT](INFO): DAT read: 

2020-08-26T20:18:02.418Z,1598473082.418 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:18:02.419Z,1598473082.419 [DAT](INFO): received a packet notification
2020-08-26T20:18:04.035Z,1598473084.035 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:17:36.2370

2020-08-26T20:18:04.035Z,1598473084.035 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:18:10.517Z,1598473090.517 [DAT](INFO): DAT read: Rx Time:20:17:42.4513

2020-08-26T20:18:10.517Z,1598473090.517 [DAT](INFO): received an acoustic signal
2020-08-26T20:18:11.328Z,1598473091.328 [DAT](INFO): DAT read: 

2020-08-26T20:18:11.329Z,1598473091.329 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:18:11.329Z,1598473091.329 [DAT](INFO): received a packet notification
2020-08-26T20:18:16.704Z,1598473096.704 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20200826T194527/Courier0000.lzma
2020-08-26T20:18:17.708Z,1598473097.708 [DataOverHttps](INFO): Moved sent file to Logs/20200826T194527/Courier0000.lzma.bak
2020-08-26T20:18:17.709Z,1598473097.709 [DataOverHttps](INFO): SBD MOMSN=12622395
2020-08-26T20:18:20.602Z,1598473100.602 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T20:18:20.602Z,1598473100.602 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:18:22.459Z,1598473102.459 [DAT](INFO): #Outgoing data=1
2020-08-26T20:18:22.459Z,1598473102.459 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:18:22.569Z,1598473102.569 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:18:23.349Z,1598473103.349 [DAT](INFO): DAT read: Rx Time:20:17:55.1016

2020-08-26T20:18:23.349Z,1598473103.349 [DAT](INFO): received an acoustic signal
2020-08-26T20:18:23.743Z,1598473103.743 [DAT](INFO): DAT read: 

2020-08-26T20:18:23.744Z,1598473103.744 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:18:23.744Z,1598473103.744 [DAT](INFO): received a packet notification
2020-08-26T20:18:26.162Z,1598473106.162 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:17:58.3869

2020-08-26T20:18:26.163Z,1598473106.163 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:18:33.041Z,1598473113.041 [DAT](INFO): DAT read: Rx Time:20:18:04.7517

2020-08-26T20:18:33.041Z,1598473113.041 [DAT](INFO): received an acoustic signal
2020-08-26T20:18:33.448Z,1598473113.448 [DAT](INFO): DAT read: 

2020-08-26T20:18:33.449Z,1598473113.449 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:18:33.450Z,1598473113.450 [DAT](INFO): received a packet notification
2020-08-26T20:18:35.388Z,1598473115.388 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20200826T201446/Courier0000.lzma
2020-08-26T20:18:36.390Z,1598473116.390 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Courier0000.lzma.bak
2020-08-26T20:18:36.390Z,1598473116.390 [DataOverHttps](INFO): SBD MOMSN=12622399
2020-08-26T20:18:42.726Z,1598473122.726 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T20:18:42.726Z,1598473122.726 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:18:44.577Z,1598473124.577 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:18:44.601Z,1598473124.601 [Startup:StartupSatComms:B] Stopped
2020-08-26T20:18:44.601Z,1598473124.601 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-08-26T20:18:44.601Z,1598473124.601 [Startup:StartupSatComms] Stopped
2020-08-26T20:18:44.601Z,1598473124.601 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-08-26T20:18:44.602Z,1598473124.602 [Startup](INFO): Completed Startup
2020-08-26T20:18:44.602Z,1598473124.602 [MissionManager](INFO): Startup is completed.
2020-08-26T20:18:44.602Z,1598473124.602 [MissionManager](INFO): Uninitializing Mission Startup
2020-08-26T20:18:44.603Z,1598473124.603 [Startup] Stopped
2020-08-26T20:18:44.603Z,1598473124.603 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-08-26T20:18:44.603Z,1598473124.603 [Startup:A.GoToSurface] Stopped
2020-08-26T20:18:44.603Z,1598473124.603 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-26T20:18:44.713Z,1598473124.713 [DAT](INFO): DAT read: Rx Time:20:18:16.5520

2020-08-26T20:18:44.714Z,1598473124.714 [DAT](INFO): received an acoustic signal
2020-08-26T20:18:44.714Z,1598473124.714 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:18:44.775Z,1598473124.775 [MissionManager](IMPORTANT): Started mission Default
2020-08-26T20:18:44.776Z,1598473124.776 [Default] Running Loop=1
2020-08-26T20:18:44.784Z,1598473124.784 [Default](DEBUG): Aggregate::initialize Default
2020-08-26T20:18:44.784Z,1598473124.784 [Default:B.GoToSurface] Running Loop=1
2020-08-26T20:18:44.784Z,1598473124.784 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-26T20:18:44.784Z,1598473124.784 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-26T20:18:44.785Z,1598473124.785 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-26T20:18:44.785Z,1598473124.785 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-26T20:18:44.785Z,1598473124.785 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-26T20:18:44.785Z,1598473124.785 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-26T20:18:44.786Z,1598473124.786 [Default:A.Wait] Running Loop=1
2020-08-26T20:18:44.786Z,1598473124.786 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-08-26T20:18:45.053Z,1598473125.053 [DAT](INFO): DAT read: 

2020-08-26T20:18:45.054Z,1598473125.054 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:18:45.054Z,1598473125.054 [DAT](INFO): received a packet notification
2020-08-26T20:18:45.236Z,1598473125.236 [AMEcho](INFO): Powering down
2020-08-26T20:18:45.461Z,1598473125.461 [DAT](INFO): DAT read: 06] DATA PACKET

2020-08-26T20:18:45.461Z,1598473125.461 [DAT](INFO): unknown deviceResponse_: 06] DATA PACKET

2020-08-26T20:18:46.321Z,1598473126.321 [AMEcho](INFO): Powering up
2020-08-26T20:18:48.275Z,1598473128.275 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:18:20.5371

2020-08-26T20:18:48.275Z,1598473128.275 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:18:54.380Z,1598473134.380 [DataOverHttps](INFO): Sending 263 bytes from file Logs/20200826T185927/Express0011.lzma
2020-08-26T20:18:54.749Z,1598473134.749 [DAT](INFO): DAT read: Rx Time:20:18:26.5021

2020-08-26T20:18:54.749Z,1598473134.749 [DAT](INFO): received an acoustic signal
2020-08-26T20:18:55.153Z,1598473135.153 [DAT](INFO): DAT read: 

2020-08-26T20:18:55.153Z,1598473135.153 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:18:55.154Z,1598473135.154 [DAT](INFO): received a packet notification
2020-08-26T20:18:55.382Z,1598473135.382 [DataOverHttps](INFO): Moved sent file to Logs/20200826T185927/Express0011.lzma.bak
2020-08-26T20:18:55.382Z,1598473135.382 [DataOverHttps](INFO): SBD MOMSN=12622403
2020-08-26T20:18:57.983Z,1598473137.983 [Default:A.Wait](INFO): Done Waiting.
2020-08-26T20:18:57.983Z,1598473137.983 [Default:A.Wait] Stopped
2020-08-26T20:18:57.983Z,1598473137.983 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-08-26T20:18:58.385Z,1598473138.385 [Default:CheckIn] Running Loop=1
2020-08-26T20:18:58.385Z,1598473138.385 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-26T20:18:58.385Z,1598473138.385 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-26T20:18:58.795Z,1598473138.795 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-08-26T20:19:04.846Z,1598473144.846 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T20:19:04.846Z,1598473144.846 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:19:05.260Z,1598473145.260 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:19:05.653Z,1598473145.653 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:19:09.279Z,1598473149.279 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:18:41.4870

2020-08-26T20:19:09.279Z,1598473149.279 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:19:15.761Z,1598473155.761 [DAT](INFO): DAT read: Rx Time:20:18:47.5025

2020-08-26T20:19:15.761Z,1598473155.761 [DAT](INFO): received an acoustic signal
2020-08-26T20:19:16.164Z,1598473156.164 [DAT](INFO): DAT read: 

2020-08-26T20:19:16.165Z,1598473156.165 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:19:16.165Z,1598473156.165 [DAT](INFO): received a packet notification
2020-08-26T20:19:25.842Z,1598473165.842 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T20:19:25.842Z,1598473165.842 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-26T20:19:26.275Z,1598473166.275 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:19:26.661Z,1598473166.661 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:19:27.072Z,1598473167.072 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:19:30.695Z,1598473170.695 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:19:03.0367

2020-08-26T20:19:30.695Z,1598473170.695 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:19:38.774Z,1598473178.774 [DAT](INFO): DAT read: Rx Time:20:19:10.5528

2020-08-26T20:19:38.774Z,1598473178.774 [DAT](INFO): received an acoustic signal
2020-08-26T20:19:39.584Z,1598473179.584 [DAT](INFO): DAT read: 

2020-08-26T20:19:39.987Z,1598473179.987 [DAT](INFO): DAT read: DATA(0036):set _.pressure 0.539886 atmosphere~~

2020-08-26T20:19:39.987Z,1598473179.987 [DAT](INFO): Got DATA 36
2020-08-26T20:19:39.988Z,1598473179.988 [DAT](INFO): DAT read: Source:006  Destination:009

2020-08-26T20:19:39.988Z,1598473179.988 [DAT](INFO): Got Src/Dest after DATA 
2020-08-26T20:19:39.989Z,1598473179.989 [DAT](INFO): DATA Src=6, Dst=9
2020-08-26T20:19:39.990Z,1598473179.990 [DAT](INFO): DAT read: CRC:Pass MPD:14.7 PSNR:13.9 AGC:77 SPD:+00.0 CCERR:010

2020-08-26T20:19:39.990Z,1598473179.990 [DAT](INFO): Got CRC:Pass
2020-08-26T20:19:39.990Z,1598473179.990 [DAT](INFO): Got CRC:Pass
2020-08-26T20:19:39.990Z,1598473179.990 [DAT](INFO): Incoming data is intended for us
2020-08-26T20:19:39.990Z,1598473179.990 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2020-08-26T20:19:39.990Z,1598473179.990 [DAT](INFO): Got ack
2020-08-26T20:19:39.991Z,1598473179.991 [DAT](INFO): Received command:set _.pressure 0.539886 atmosphere
2020-08-26T20:19:40.692Z,1598473180.692 [CommandLine](IMPORTANT): got command set _.pressure 0.539886 atmosphere
2020-08-26T20:19:40.699Z,1598473180.699 [DAT](INFO): Sending ack
2020-08-26T20:19:40.699Z,1598473180.699 [DAT](INFO): DAT read: 

2020-08-26T20:19:40.700Z,1598473180.700 [DAT](INFO): DAT read: <EOP>

2020-08-26T20:19:40.700Z,1598473180.700 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:19:43.999Z,1598473183.999 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:19:16.4867

2020-08-26T20:19:51.278Z,1598473191.278 [DAT](INFO): DAT read: Rx Time:20:19:23.1031

2020-08-26T20:19:51.279Z,1598473191.279 [DAT](INFO): received an acoustic signal
2020-08-26T20:19:52.503Z,1598473192.503 [DAT](INFO): DAT read: 20:19:23.1031 LVL= 17808, 18993, 25714, 32755, AGC= 70, IDX= 475,-0.08, 2.378,-2.931, 1.690, 2.978, PHS=-0.566, 0.403,-1.216, RAW= 353.5,  19.1, CAL= 354.8,  22.3, ROT= 140.2, -22.3

2020-08-26T20:19:52.504Z,1598473192.504 [DAT](INFO): got valid direction response:
 20:19:23.1031 LVL= 17808, 18993, 25714, 32755, AGC= 70, IDX= 475,-0.08, 2.378,-2.931, 1.690, 2.978, PHS=-0.566, 0.403,-1.216, RAW= 353.5,  19.1, CAL= 354.8,  22.3, ROT= 140.2, -22.3

2020-08-26T20:19:52.504Z,1598473192.504 [DAT](INFO): DAT read: 

2020-08-26T20:19:52.506Z,1598473192.506 [DAT](INFO): DAT read: DATA(0035):set _.temperature 26.636560 celsius

2020-08-26T20:19:52.506Z,1598473192.506 [DAT](INFO): Got DATA 35
2020-08-26T20:19:52.507Z,1598473192.507 [DAT](INFO): DAT read: Source:006  Destination:009

2020-08-26T20:19:52.507Z,1598473192.507 [DAT](INFO): Got Src/Dest after DATA 
2020-08-26T20:19:52.507Z,1598473192.507 [DAT](INFO): DATA Src=6, Dst=9
2020-08-26T20:19:52.509Z,1598473192.509 [DAT](INFO): DAT read: CRC:Pass MPD:11.7 PSNR:14.1 AGC:77 SPD:+00.0 CCERR:010

2020-08-26T20:19:52.509Z,1598473192.509 [DAT](INFO): Got CRC:Pass
2020-08-26T20:19:52.509Z,1598473192.509 [DAT](INFO): Got CRC:Pass
2020-08-26T20:19:52.509Z,1598473192.509 [DAT](INFO): Incoming data is intended for us
2020-08-26T20:19:52.509Z,1598473192.509 [DAT](INFO): Received command:set _.temperature 26.636560 celsius
2020-08-26T20:19:53.426Z,1598473193.426 [CommandLine](IMPORTANT): got command set _.temperature 26.636560 celsius
2020-08-26T20:19:53.433Z,1598473193.433 [DAT](INFO): Sending ack
2020-08-26T20:19:53.434Z,1598473193.434 [DAT](INFO): DAT read: 

2020-08-26T20:19:53.434Z,1598473193.434 [DAT](INFO): DAT read: <EOP>

2020-08-26T20:19:53.435Z,1598473193.435 [DAT](INFO): Read direction message, but no range.
2020-08-26T20:19:56.704Z,1598473196.704 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:19:29.1867

2020-08-26T20:20:03.588Z,1598473203.588 [DAT](INFO): DAT read: Rx Time:20:19:35.6032

2020-08-26T20:20:03.589Z,1598473203.589 [DAT](INFO): received an acoustic signal
2020-08-26T20:20:04.803Z,1598473204.803 [DAT](INFO): DAT read: 20:19:35.6032 LVL= 17136, 20177, 21618, 32755, AGC= 71, IDX= 255, 0.24,-2.685,-0.786,-0.560,-1.320, PHS=-1.331, 0.563, 0.831, RAW= 263.5,  -0.6, CAL= 261.6,  -4.8, ROT= 233.4,   4.8

2020-08-26T20:20:04.805Z,1598473204.805 [DAT](INFO): got valid direction response:
 20:19:35.6032 LVL= 17136, 20177, 21618, 32755, AGC= 71, IDX= 255, 0.24,-2.685,-0.786,-0.560,-1.320, PHS=-1.331, 0.563, 0.831, RAW= 263.5,  -0.6, CAL= 261.6,  -4.8, ROT= 233.4,   4.8

2020-08-26T20:20:04.805Z,1598473204.805 [DAT](INFO): DAT read: 

2020-08-26T20:20:04.807Z,1598473204.807 [DAT](INFO): DAT read: DATA(0031):set _.humidity 7.679160 percent

2020-08-26T20:20:04.807Z,1598473204.807 [DAT](INFO): Got DATA 31
2020-08-26T20:20:04.808Z,1598473204.808 [DAT](INFO): DAT read: Source:006  Destination:009

2020-08-26T20:20:04.808Z,1598473204.808 [DAT](INFO): Got Src/Dest after DATA 
2020-08-26T20:20:04.809Z,1598473204.809 [DAT](INFO): DATA Src=6, Dst=9
2020-08-26T20:20:04.809Z,1598473204.809 [DAT](INFO): Read direction message, but no range.
2020-08-26T20:20:05.183Z,1598473205.183 [DAT](INFO): DAT read: CRC:Pass MPD:11.5 PSNR:14.3 AGC:75 SPD:+00.0 CCERR:010

2020-08-26T20:20:05.183Z,1598473205.183 [DAT](INFO): Got CRC:Pass
2020-08-26T20:20:05.183Z,1598473205.183 [DAT](INFO): Got CRC:Pass
2020-08-26T20:20:05.183Z,1598473205.183 [DAT](INFO): Incoming data is intended for us
2020-08-26T20:20:05.183Z,1598473205.183 [DAT](INFO): Received command:set _.humidity 7.679160 percent
2020-08-26T20:20:05.822Z,1598473205.822 [CommandLine](IMPORTANT): got command set _.humidity 7.679160 percent
2020-08-26T20:20:05.829Z,1598473205.829 [DAT](INFO): Sending ack
2020-08-26T20:20:05.830Z,1598473205.830 [DAT](INFO): DAT read: 

2020-08-26T20:20:05.830Z,1598473205.830 [DAT](INFO): DAT read: <EOP>

2020-08-26T20:20:09.105Z,1598473209.105 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:19:41.5866

2020-08-26T20:20:38.581Z,1598473238.581 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-26T20:21:00.032Z,1598473260.032 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-08-26T20:21:00.032Z,1598473260.032 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:21:00.044Z,1598473260.044 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:21:00.437Z,1598473260.437 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:21:00.437Z,1598473260.437 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-08-26T20:22:10.317Z,1598473330.317 [DAT](INFO): DAT read: Rx Time:20:21:42.1566

2020-08-26T20:22:10.317Z,1598473330.317 [DAT](INFO): received an acoustic signal
2020-08-26T20:22:10.721Z,1598473330.721 [DAT](INFO): DAT read: range request

2020-08-26T20:22:10.721Z,1598473330.721 [DAT](INFO): received a range request message
2020-08-26T20:22:10.722Z,1598473330.722 [DAT](INFO): DAT read: Tx time:20:21:43.7594

2020-08-26T20:22:10.722Z,1598473330.722 [DAT](INFO): Ping request sent.
2020-08-26T20:22:10.722Z,1598473330.722 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:22:10.722Z,1598473330.722 [DAT](INFO): publishing transmit ping time
2020-08-26T20:22:10.723Z,1598473330.723 [DAT](INFO): publishing range request flag
2020-08-26T20:22:23.655Z,1598473343.655 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-26T20:22:23.658Z,1598473343.658 [BPC1](INFO): Received data from all battery sticks.
2020-08-26T20:22:53.938Z,1598473373.938 [DAT](INFO): DAT read: Rx Time:20:22:25.8074

2020-08-26T20:22:53.939Z,1598473373.939 [DAT](INFO): received an acoustic signal
2020-08-26T20:22:54.338Z,1598473374.338 [DAT](INFO): DAT read: range request

2020-08-26T20:22:54.338Z,1598473374.338 [DAT](INFO): received a range request message
2020-08-26T20:22:54.339Z,1598473374.339 [DAT](INFO): DAT read: Tx time:20:22:27.4102

2020-08-26T20:22:54.339Z,1598473374.339 [DAT](INFO): Ping request sent.
2020-08-26T20:22:54.339Z,1598473374.339 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:22:54.340Z,1598473374.340 [DAT](INFO): publishing transmit ping time
2020-08-26T20:22:54.340Z,1598473374.340 [DAT](INFO): publishing range request flag
2020-08-26T20:23:58.589Z,1598473438.589 [DAT](INFO): DAT read: Rx Time:20:23:30.4584

2020-08-26T20:23:58.589Z,1598473438.589 [DAT](INFO): received an acoustic signal
2020-08-26T20:23:58.596Z,1598473438.596 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T20:18:58.4Z
2020-08-26T20:23:58.596Z,1598473438.596 [Default:CheckIn:Read_GPS] Stopped
2020-08-26T20:23:58.597Z,1598473438.597 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-26T20:23:59.011Z,1598473439.011 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-26T20:23:59.409Z,1598473439.409 [DAT](INFO): DAT read: 20:23:30.4584 LVL= 15152, 19089, 22242, 32755, AGC= 72, IDX= 506,-0.04, 1.814,-2.765, 2.791, 2.197, PHS=-0.349, 1.351, 0.666, RAW= 293.6, -21.7, CAL= 293.8, -26.0, ROT= 201.2,  26.0

2020-08-26T20:23:59.410Z,1598473439.410 [DAT](INFO): got valid direction response:
 20:23:30.4584 LVL= 15152, 19089, 22242, 32755, AGC= 72, IDX= 506,-0.04, 1.814,-2.765, 2.791, 2.197, PHS=-0.349, 1.351, 0.666, RAW= 293.6, -21.7, CAL= 293.8, -26.0, ROT= 201.2,  26.0

2020-08-26T20:23:59.411Z,1598473439.411 [DAT](INFO): DAT read: bearing request

2020-08-26T20:23:59.411Z,1598473439.411 [DAT](INFO): received a bearing request message
2020-08-26T20:23:59.412Z,1598473439.412 [DAT](INFO): DAT read: Tx time:20:23:32.0613

2020-08-26T20:23:59.412Z,1598473439.412 [DAT](INFO): Ping request sent.
2020-08-26T20:23:59.412Z,1598473439.412 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:24:00.900Z,1598473440.900 [DAT](INFO): #Outgoing data=1
2020-08-26T20:24:00.900Z,1598473440.900 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:24:00.901Z,1598473440.901 [DAT](INFO): Read direction message, but no range.
2020-08-26T20:24:00.901Z,1598473440.901 [DAT](INFO): publishing transmit ping time
2020-08-26T20:24:00.901Z,1598473440.901 [DAT](INFO): publishing range request flag
2020-08-26T20:24:00.907Z,1598473440.907 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-08-26T20:24:00.907Z,1598473440.907 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:24:00.917Z,1598473440.917 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:24:01.016Z,1598473441.016 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:24:01.133Z,1598473441.133 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:24:01.134Z,1598473441.134 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-08-26T20:24:04.577Z,1598473444.577 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:23:36.9359

2020-08-26T20:24:04.577Z,1598473444.577 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:24:06.107Z,1598473446.107 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20200826T201446/Courier0004.lzma
2020-08-26T20:24:07.114Z,1598473447.114 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Courier0004.lzma.bak
2020-08-26T20:24:07.114Z,1598473447.114 [DataOverHttps](INFO): SBD MOMSN=12622424
2020-08-26T20:24:13.859Z,1598473453.859 [DAT](INFO): DAT read: Rx Time:20:23:45.6575

2020-08-26T20:24:13.859Z,1598473453.859 [DAT](INFO): received an acoustic signal
2020-08-26T20:24:14.693Z,1598473454.693 [DAT](INFO): DAT read: 

2020-08-26T20:24:14.694Z,1598473454.694 [DAT](INFO): DAT read: DATA(0002):~~

2020-08-26T20:24:14.694Z,1598473454.694 [DAT](INFO): Got DATA 2
2020-08-26T20:24:14.695Z,1598473454.695 [DAT](INFO): DAT read: Source:006  Destination:009

2020-08-26T20:24:14.695Z,1598473454.695 [DAT](INFO): Got Src/Dest after DATA 
2020-08-26T20:24:14.695Z,1598473454.695 [DAT](INFO): DATA Src=6, Dst=9
2020-08-26T20:24:14.697Z,1598473454.697 [DAT](INFO): DAT read: CRC:Pass MPD:14.4 PSNR:15.4 AGC:75 SPD:+00.0 CCERR:011

2020-08-26T20:24:14.697Z,1598473454.697 [DAT](INFO): Got CRC:Pass
2020-08-26T20:24:14.697Z,1598473454.697 [DAT](INFO): Got CRC:Pass
2020-08-26T20:24:14.697Z,1598473454.697 [DAT](INFO): Incoming data is intended for us
2020-08-26T20:24:14.697Z,1598473454.697 [DAT](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2020-08-26T20:24:14.697Z,1598473454.697 [DAT](INFO): Got ack
2020-08-26T20:24:14.697Z,1598473454.697 [DAT](INFO): DAT read: 

2020-08-26T20:24:14.698Z,1598473454.698 [DAT](INFO): DAT read: <EOP>

2020-08-26T20:24:14.698Z,1598473454.698 [DAT](INFO): Sent 168 bytes from file Logs/20200826T201446/Courier0004.lzma.parts
2020-08-26T20:24:14.699Z,1598473454.699 [DAT](INFO): Packets left to send: 0
2020-08-26T20:24:14.703Z,1598473454.703 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:24:15.859Z,1598473455.859 [Default:CheckIn:Read_Iridium] Stopped
2020-08-26T20:24:15.859Z,1598473455.859 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-26T20:24:15.859Z,1598473455.859 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-26T20:24:24.414Z,1598473464.414 [DataOverHttps](INFO): Sending 1053 bytes from file Logs/20200826T193220/Express0001.lzma
2020-08-26T20:24:25.413Z,1598473465.413 [DataOverHttps](INFO): Moved sent file to Logs/20200826T193220/Express0001.lzma.bak
2020-08-26T20:24:25.414Z,1598473465.414 [DataOverHttps](INFO): SBD MOMSN=12622426
2020-08-26T20:25:37.897Z,1598473537.897 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-26T20:25:37.897Z,1598473537.897 [NAL9602] Data Fault, FailCount= 1
2020-08-26T20:25:37.897Z,1598473537.897 [NAL9602](ERROR): Data Fault
2020-08-26T20:25:37.974Z,1598473537.974 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-26T20:25:38.297Z,1598473538.297 [NAL9602](INFO): Powering down
2020-08-26T20:25:39.136Z,1598473539.136 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-26T20:25:39.136Z,1598473539.136 [NAL9602] No Fault, FailCount= 1
2020-08-26T20:26:08.603Z,1598473568.603 [NAL9602](INFO): Powering up NAL9602
2020-08-26T20:26:19.509Z,1598473579.509 [NAL9602](INFO): NAL9602 initialized
2020-08-26T20:26:26.389Z,1598473586.389 [DAT](INFO): DAT read: Rx Time:20:25:58.3107

2020-08-26T20:26:26.389Z,1598473586.389 [DAT](INFO): received an acoustic signal
2020-08-26T20:26:27.186Z,1598473587.186 [DAT](INFO): DAT read: range request

2020-08-26T20:26:27.186Z,1598473587.186 [DAT](INFO): received a range request message
2020-08-26T20:26:27.187Z,1598473587.187 [DAT](INFO): DAT read: Tx time:20:25:59.9135

2020-08-26T20:26:27.187Z,1598473587.187 [DAT](INFO): Ping request sent.
2020-08-26T20:26:27.187Z,1598473587.187 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:26:27.188Z,1598473587.188 [DAT](INFO): publishing transmit ping time
2020-08-26T20:26:27.188Z,1598473587.188 [DAT](INFO): publishing range request flag
2020-08-26T20:26:56.289Z,1598473616.289 [DAT](INFO): DAT read: Rx Time:20:26:28.2612

2020-08-26T20:26:56.289Z,1598473616.289 [DAT](INFO): received an acoustic signal
2020-08-26T20:26:57.082Z,1598473617.082 [DAT](INFO): DAT read: range request

2020-08-26T20:26:57.082Z,1598473617.082 [DAT](INFO): received a range request message
2020-08-26T20:26:57.083Z,1598473617.083 [DAT](INFO): DAT read: Tx time:20:26:29.8640

2020-08-26T20:26:57.083Z,1598473617.083 [DAT](INFO): Ping request sent.
2020-08-26T20:26:57.083Z,1598473617.083 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:26:57.116Z,1598473617.116 [DAT](INFO): publishing transmit ping time
2020-08-26T20:26:57.116Z,1598473617.116 [DAT](INFO): publishing range request flag
2020-08-26T20:27:01.553Z,1598473621.553 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-08-26T20:27:01.553Z,1598473621.553 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:27:01.563Z,1598473621.563 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:27:01.964Z,1598473621.964 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:27:01.964Z,1598473621.964 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-08-26T20:27:18.094Z,1598473638.094 [DAT](INFO): DAT read: Rx Time:20:26:49.7604

2020-08-26T20:27:18.094Z,1598473638.094 [DAT](INFO): received an acoustic signal
2020-08-26T20:27:18.494Z,1598473638.494 [DAT](INFO): DAT read: 

2020-08-26T20:27:18.495Z,1598473638.495 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:27:18.495Z,1598473638.495 [DAT](INFO): received a packet notification
2020-08-26T20:29:16.085Z,1598473756.085 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-26T20:29:16.085Z,1598473756.085 [Default:CheckIn:C.Wait] Stopped
2020-08-26T20:29:16.085Z,1598473756.085 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-26T20:29:16.085Z,1598473756.085 [Default:CheckIn:D] Running Loop=1
2020-08-26T20:29:16.493Z,1598473756.493 [Default:CheckIn:D] Stopped
2020-08-26T20:29:16.493Z,1598473756.493 [Default:CheckIn:E] Running Loop=1
2020-08-26T20:29:16.873Z,1598473756.873 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.528629 min 
2020-08-26T20:29:16.873Z,1598473756.873 [Default:CheckIn:E] Stopped
2020-08-26T20:29:16.873Z,1598473756.873 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-26T20:29:16.873Z,1598473756.873 [Default:CheckIn] Stopped
2020-08-26T20:29:16.873Z,1598473756.873 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-26T20:29:16.874Z,1598473756.874 [Default:CheckIn](INFO): Running loop #2
2020-08-26T20:29:16.874Z,1598473756.874 [Default:CheckIn] Running Loop=2
2020-08-26T20:29:16.874Z,1598473756.874 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-26T20:29:16.874Z,1598473756.874 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-26T20:30:02.538Z,1598473802.538 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-08-26T20:30:02.538Z,1598473802.538 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:30:02.548Z,1598473802.548 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:30:02.943Z,1598473802.943 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:30:02.943Z,1598473802.943 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-08-26T20:30:24.357Z,1598473824.357 [DAT](INFO): DAT read: Rx Time:20:29:56.2631

2020-08-26T20:30:24.357Z,1598473824.357 [DAT](INFO): received an acoustic signal
2020-08-26T20:30:25.150Z,1598473825.150 [DAT](INFO): DAT read: 

2020-08-26T20:30:25.151Z,1598473825.151 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:30:25.151Z,1598473825.151 [DAT](INFO): received a packet notification
2020-08-26T20:31:16.877Z,1598473876.877 [DAT](INFO): DAT read: Rx Time:20:30:48.5967

2020-08-26T20:31:16.877Z,1598473876.877 [DAT](INFO): received an acoustic signal
2020-08-26T20:31:17.281Z,1598473877.281 [DAT](INFO): DAT read: 

2020-08-26T20:31:17.281Z,1598473877.281 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:31:17.282Z,1598473877.282 [DAT](INFO): received a packet notification
2020-08-26T20:31:37.887Z,1598473897.887 [DAT](INFO): DAT read: Rx Time:20:31:09.5471

2020-08-26T20:31:37.887Z,1598473897.887 [DAT](INFO): received an acoustic signal
2020-08-26T20:31:38.284Z,1598473898.284 [DAT](INFO): DAT read: 

2020-08-26T20:31:38.285Z,1598473898.285 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:31:38.285Z,1598473898.285 [DAT](INFO): received a packet notification
2020-08-26T20:31:58.897Z,1598473918.897 [DAT](INFO): DAT read: Rx Time:20:31:30.5973

2020-08-26T20:31:58.897Z,1598473918.897 [DAT](INFO): received an acoustic signal
2020-08-26T20:31:59.293Z,1598473919.293 [DAT](INFO): DAT read: 

2020-08-26T20:31:59.293Z,1598473919.293 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:31:59.294Z,1598473919.294 [DAT](INFO): received a packet notification
2020-08-26T20:32:19.891Z,1598473939.891 [DAT](INFO): DAT read: Rx Time:20:31:51.6476

2020-08-26T20:32:19.891Z,1598473939.891 [DAT](INFO): received an acoustic signal
2020-08-26T20:32:20.290Z,1598473940.290 [DAT](INFO): DAT read: 

2020-08-26T20:32:20.291Z,1598473940.291 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:32:20.291Z,1598473940.291 [DAT](INFO): received a packet notification
2020-08-26T20:32:41.302Z,1598473961.302 [DAT](INFO): DAT read: Rx Time:20:32:12.9979

2020-08-26T20:32:41.302Z,1598473961.302 [DAT](INFO): received an acoustic signal
2020-08-26T20:32:41.713Z,1598473961.713 [DAT](INFO): DAT read: 

2020-08-26T20:32:41.714Z,1598473961.714 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:32:41.714Z,1598473961.714 [DAT](INFO): received a packet notification
2020-08-26T20:33:03.540Z,1598473983.540 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-08-26T20:33:03.540Z,1598473983.540 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:33:03.550Z,1598473983.550 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:33:03.953Z,1598473983.953 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:33:03.953Z,1598473983.953 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-08-26T20:34:17.085Z,1598474057.085 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T20:29:16.9Z
2020-08-26T20:34:17.085Z,1598474057.085 [Default:CheckIn:Read_GPS] Stopped
2020-08-26T20:34:17.085Z,1598474057.085 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-26T20:34:18.902Z,1598474058.902 [DAT](INFO): #Outgoing data=1
2020-08-26T20:34:18.902Z,1598474058.902 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:34:19.019Z,1598474059.019 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:34:22.609Z,1598474062.609 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:33:54.8331

2020-08-26T20:34:22.609Z,1598474062.609 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:34:24.771Z,1598474064.771 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200826T201446/Courier0007.lzma
2020-08-26T20:34:25.773Z,1598474065.773 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Courier0007.lzma.bak
2020-08-26T20:34:25.774Z,1598474065.774 [DataOverHttps](INFO): SBD MOMSN=12622807
2020-08-26T20:34:39.154Z,1598474079.154 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T20:34:39.154Z,1598474079.154 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:34:40.960Z,1598474080.960 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:34:40.984Z,1598474080.984 [Default:CheckIn:Read_Iridium] Stopped
2020-08-26T20:34:40.985Z,1598474080.985 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-26T20:34:40.985Z,1598474080.985 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-26T20:34:41.058Z,1598474081.058 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:34:43.347Z,1598474083.347 [DataOverHttps](INFO): Sending 208 bytes from file Logs/20200826T193220/Express0005.lzma
2020-08-26T20:34:44.341Z,1598474084.341 [DataOverHttps](INFO): Moved sent file to Logs/20200826T193220/Express0005.lzma.bak
2020-08-26T20:34:44.342Z,1598474084.342 [DataOverHttps](INFO): SBD MOMSN=12622809
2020-08-26T20:34:44.661Z,1598474084.661 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:34:16.8831

2020-08-26T20:34:44.661Z,1598474084.661 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:34:51.135Z,1598474091.135 [DAT](INFO): DAT read: Rx Time:20:34:22.9498

2020-08-26T20:34:51.135Z,1598474091.135 [DAT](INFO): received an acoustic signal
2020-08-26T20:34:51.529Z,1598474091.529 [DAT](INFO): DAT read: 

2020-08-26T20:34:51.529Z,1598474091.529 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:34:51.530Z,1598474091.530 [DAT](INFO): received a packet notification
2020-08-26T20:35:01.228Z,1598474101.228 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T20:35:01.229Z,1598474101.229 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:35:01.619Z,1598474101.619 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:35:02.023Z,1598474102.023 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:35:05.265Z,1598474105.265 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:34:37.8328

2020-08-26T20:35:05.265Z,1598474105.265 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:35:12.133Z,1598474112.133 [DAT](INFO): DAT read: Rx Time:20:34:43.9500

2020-08-26T20:35:12.133Z,1598474112.133 [DAT](INFO): received an acoustic signal
2020-08-26T20:35:12.537Z,1598474112.537 [DAT](INFO): DAT read: 

2020-08-26T20:35:12.537Z,1598474112.537 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:35:12.538Z,1598474112.538 [DAT](INFO): received a packet notification
2020-08-26T20:35:22.239Z,1598474122.239 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T20:35:22.239Z,1598474122.239 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:35:22.626Z,1598474122.626 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:35:23.033Z,1598474123.033 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:35:26.266Z,1598474126.266 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:34:58.8327

2020-08-26T20:35:26.267Z,1598474126.267 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:35:33.137Z,1598474133.137 [DAT](INFO): DAT read: Rx Time:20:35:04.9503

2020-08-26T20:35:33.137Z,1598474133.137 [DAT](INFO): received an acoustic signal
2020-08-26T20:35:33.551Z,1598474133.551 [DAT](INFO): DAT read: 

2020-08-26T20:35:33.552Z,1598474133.552 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:35:33.552Z,1598474133.552 [DAT](INFO): received a packet notification
2020-08-26T20:35:40.002Z,1598474140.002 [DAT](INFO): DAT read: Rx Time:20:35:11.9005

2020-08-26T20:35:40.003Z,1598474140.003 [DAT](INFO): received an acoustic signal
2020-08-26T20:35:40.429Z,1598474140.429 [DAT](INFO): DAT read: 

2020-08-26T20:35:40.429Z,1598474140.429 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:35:40.430Z,1598474140.430 [DAT](INFO): received a packet notification
2020-08-26T20:35:43.241Z,1598474143.241 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T20:35:43.241Z,1598474143.241 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-26T20:35:43.634Z,1598474143.634 [DAT](DEBUG): In sendingVerified, sbd done so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:36:04.668Z,1598474164.668 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2020-08-26T20:36:04.668Z,1598474164.668 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:36:04.678Z,1598474164.678 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:36:05.085Z,1598474165.085 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:36:05.085Z,1598474165.085 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2020-08-26T20:36:20.401Z,1598474180.401 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-26T20:36:20.401Z,1598474180.401 [NAL9602] Data Fault, FailCount= 2
2020-08-26T20:36:20.401Z,1598474180.401 [NAL9602](ERROR): Data Fault
2020-08-26T20:36:20.417Z,1598474180.417 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-26T20:36:20.801Z,1598474180.801 [NAL9602](INFO): Powering down
2020-08-26T20:36:21.629Z,1598474181.629 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-26T20:36:21.629Z,1598474181.629 [NAL9602] No Fault, FailCount= 2
2020-08-26T20:36:51.105Z,1598474211.105 [NAL9602](INFO): Powering up NAL9602
2020-08-26T20:37:02.009Z,1598474222.009 [NAL9602](INFO): NAL9602 initialized
2020-08-26T20:38:51.915Z,1598474331.915 [DAT](INFO): DAT read: Rx Time:20:38:23.9041

2020-08-26T20:38:51.916Z,1598474331.916 [DAT](INFO): received an acoustic signal
2020-08-26T20:38:52.710Z,1598474332.710 [DAT](INFO): DAT read: range request

2020-08-26T20:38:52.710Z,1598474332.710 [DAT](INFO): received a range request message
2020-08-26T20:38:52.711Z,1598474332.711 [DAT](INFO): DAT read: Tx time:20:38:25.5069

2020-08-26T20:38:52.711Z,1598474332.711 [DAT](INFO): Ping request sent.
2020-08-26T20:38:52.711Z,1598474332.711 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:38:52.712Z,1598474332.712 [DAT](INFO): publishing transmit ping time
2020-08-26T20:38:52.712Z,1598474332.712 [DAT](INFO): publishing range request flag
2020-08-26T20:39:05.644Z,1598474345.644 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2020-08-26T20:39:05.644Z,1598474345.644 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:39:05.654Z,1598474345.654 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:39:06.073Z,1598474346.073 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:39:06.073Z,1598474346.073 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2020-08-26T20:39:23.822Z,1598474363.822 [DAT](INFO): DAT read: Rx Time:20:38:55.7044

2020-08-26T20:39:23.822Z,1598474363.822 [DAT](INFO): received an acoustic signal
2020-08-26T20:39:24.223Z,1598474364.223 [DAT](INFO): DAT read: range request

2020-08-26T20:39:24.223Z,1598474364.223 [DAT](INFO): received a range request message
2020-08-26T20:39:24.224Z,1598474364.224 [DAT](INFO): DAT read: Tx time:20:38:57.3073

2020-08-26T20:39:24.224Z,1598474364.224 [DAT](INFO): Ping request sent.
2020-08-26T20:39:24.224Z,1598474364.224 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:39:24.225Z,1598474364.225 [DAT](INFO): publishing transmit ping time
2020-08-26T20:39:24.225Z,1598474364.225 [DAT](INFO): publishing range request flag
2020-08-26T20:39:41.201Z,1598474381.201 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-26T20:39:41.201Z,1598474381.201 [Default:CheckIn:C.Wait] Stopped
2020-08-26T20:39:41.201Z,1598474381.201 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-26T20:39:41.201Z,1598474381.201 [Default:CheckIn:D] Running Loop=1
2020-08-26T20:39:41.617Z,1598474381.617 [Default:CheckIn:D] Stopped
2020-08-26T20:39:41.617Z,1598474381.617 [Default:CheckIn:E] Running Loop=1
2020-08-26T20:39:42.021Z,1598474382.021 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.947355 min 
2020-08-26T20:39:42.021Z,1598474382.021 [Default:CheckIn:E] Stopped
2020-08-26T20:39:42.021Z,1598474382.021 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-26T20:39:42.021Z,1598474382.021 [Default:CheckIn] Stopped
2020-08-26T20:39:42.021Z,1598474382.021 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-26T20:39:42.021Z,1598474382.021 [Default:CheckIn](INFO): Running loop #3
2020-08-26T20:39:42.021Z,1598474382.021 [Default:CheckIn] Running Loop=3
2020-08-26T20:39:42.021Z,1598474382.021 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-26T20:39:42.022Z,1598474382.022 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-26T20:39:48.881Z,1598474388.881 [DAT](INFO): DAT read: Rx Time:20:39:20.7548

2020-08-26T20:39:48.881Z,1598474388.881 [DAT](INFO): received an acoustic signal
2020-08-26T20:39:49.289Z,1598474389.289 [DAT](INFO): DAT read: range request

2020-08-26T20:39:49.289Z,1598474389.289 [DAT](INFO): received a range request message
2020-08-26T20:39:49.289Z,1598474389.289 [DAT](INFO): DAT read: Tx time:20:39:22.3577

2020-08-26T20:39:49.290Z,1598474389.290 [DAT](INFO): Ping request sent.
2020-08-26T20:39:49.290Z,1598474389.290 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:39:49.290Z,1598474389.290 [DAT](INFO): publishing transmit ping time
2020-08-26T20:39:49.290Z,1598474389.290 [DAT](INFO): publishing range request flag
2020-08-26T20:40:13.933Z,1598474413.933 [DAT](INFO): DAT read: Rx Time:20:39:45.8552

2020-08-26T20:40:13.933Z,1598474413.933 [DAT](INFO): received an acoustic signal
2020-08-26T20:40:14.733Z,1598474414.733 [DAT](INFO): DAT read: range request

2020-08-26T20:40:14.733Z,1598474414.733 [DAT](INFO): received a range request message
2020-08-26T20:40:14.734Z,1598474414.734 [DAT](INFO): DAT read: Tx time:20:39:47.4581

2020-08-26T20:40:14.734Z,1598474414.734 [DAT](INFO): Ping request sent.
2020-08-26T20:40:14.734Z,1598474414.734 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:40:14.734Z,1598474414.734 [DAT](INFO): publishing transmit ping time
2020-08-26T20:40:14.735Z,1598474414.735 [DAT](INFO): publishing range request flag
2020-08-26T20:40:39.385Z,1598474439.385 [DAT](INFO): DAT read: Rx Time:20:40:11.3054

2020-08-26T20:40:39.385Z,1598474439.385 [DAT](INFO): received an acoustic signal
2020-08-26T20:40:40.178Z,1598474440.178 [DAT](INFO): DAT read: range request

2020-08-26T20:40:40.178Z,1598474440.178 [DAT](INFO): received a range request message
2020-08-26T20:40:40.179Z,1598474440.179 [DAT](INFO): DAT read: Tx time:20:40:12.9083

2020-08-26T20:40:40.179Z,1598474440.179 [DAT](INFO): Ping request sent.
2020-08-26T20:40:40.179Z,1598474440.179 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:40:40.179Z,1598474440.179 [DAT](INFO): publishing transmit ping time
2020-08-26T20:40:40.232Z,1598474440.232 [DAT](INFO): publishing range request flag
2020-08-26T20:41:04.422Z,1598474464.422 [DAT](INFO): DAT read: Rx Time:20:40:36.3559

2020-08-26T20:41:04.423Z,1598474464.423 [DAT](INFO): received an acoustic signal
2020-08-26T20:41:05.227Z,1598474465.227 [DAT](INFO): DAT read: range request

2020-08-26T20:41:05.227Z,1598474465.227 [DAT](INFO): received a range request message
2020-08-26T20:41:05.227Z,1598474465.227 [DAT](INFO): DAT read: Tx time:20:40:37.9587

2020-08-26T20:41:05.228Z,1598474465.228 [DAT](INFO): Ping request sent.
2020-08-26T20:41:05.228Z,1598474465.228 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:41:05.228Z,1598474465.228 [DAT](INFO): publishing transmit ping time
2020-08-26T20:41:05.229Z,1598474465.229 [DAT](INFO): publishing range request flag
2020-08-26T20:41:34.333Z,1598474494.333 [DAT](INFO): DAT read: Rx Time:20:41:06.2562

2020-08-26T20:41:34.333Z,1598474494.333 [DAT](INFO): received an acoustic signal
2020-08-26T20:41:35.122Z,1598474495.122 [DAT](INFO): DAT read: range request

2020-08-26T20:41:35.122Z,1598474495.122 [DAT](INFO): received a range request message
2020-08-26T20:41:35.123Z,1598474495.123 [DAT](INFO): DAT read: Tx time:20:41:07.8590

2020-08-26T20:41:35.123Z,1598474495.123 [DAT](INFO): Ping request sent.
2020-08-26T20:41:35.123Z,1598474495.123 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:41:35.124Z,1598474495.124 [DAT](INFO): publishing transmit ping time
2020-08-26T20:41:35.124Z,1598474495.124 [DAT](INFO): publishing range request flag
2020-08-26T20:41:59.365Z,1598474519.365 [DAT](INFO): DAT read: Rx Time:20:41:31.3065

2020-08-26T20:41:59.365Z,1598474519.365 [DAT](INFO): received an acoustic signal
2020-08-26T20:42:00.171Z,1598474520.171 [DAT](INFO): DAT read: range request

2020-08-26T20:42:00.171Z,1598474520.171 [DAT](INFO): received a range request message
2020-08-26T20:42:00.171Z,1598474520.171 [DAT](INFO): DAT read: Tx time:20:41:32.9093

2020-08-26T20:42:00.172Z,1598474520.172 [DAT](INFO): Ping request sent.
2020-08-26T20:42:00.172Z,1598474520.172 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:42:00.172Z,1598474520.172 [DAT](INFO): publishing transmit ping time
2020-08-26T20:42:00.172Z,1598474520.172 [DAT](INFO): publishing range request flag
2020-08-26T20:42:06.640Z,1598474526.640 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2020-08-26T20:42:06.640Z,1598474526.640 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:42:06.651Z,1598474526.651 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:42:07.069Z,1598474527.069 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:42:07.069Z,1598474527.069 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2020-08-26T20:42:28.850Z,1598474548.850 [DAT](INFO): DAT read: Rx Time:20:42:00.8070

2020-08-26T20:42:28.851Z,1598474548.851 [DAT](INFO): received an acoustic signal
2020-08-26T20:42:29.677Z,1598474549.677 [DAT](INFO): DAT read: range request

2020-08-26T20:42:29.677Z,1598474549.677 [DAT](INFO): received a range request message
2020-08-26T20:42:29.677Z,1598474549.677 [DAT](INFO): DAT read: Tx time:20:42:02.4098

2020-08-26T20:42:29.678Z,1598474549.678 [DAT](INFO): Ping request sent.
2020-08-26T20:42:29.678Z,1598474549.678 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:42:29.678Z,1598474549.678 [DAT](INFO): publishing transmit ping time
2020-08-26T20:42:29.679Z,1598474549.679 [DAT](INFO): publishing range request flag
2020-08-26T20:43:54.502Z,1598474634.502 [DAT](INFO): DAT read: Rx Time:20:43:26.5570

2020-08-26T20:43:54.503Z,1598474634.503 [DAT](INFO): received an acoustic signal
2020-08-26T20:43:55.320Z,1598474635.320 [DAT](INFO): DAT read: 

2020-08-26T20:43:55.321Z,1598474635.321 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:43:55.321Z,1598474635.321 [DAT](INFO): received a packet notification
2020-08-26T20:44:16.337Z,1598474656.337 [DAT](INFO): DAT read: Rx Time:20:43:48.4073

2020-08-26T20:44:16.337Z,1598474656.337 [DAT](INFO): received an acoustic signal
2020-08-26T20:44:17.126Z,1598474657.126 [DAT](INFO): DAT read: 

2020-08-26T20:44:17.127Z,1598474657.127 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:44:17.127Z,1598474657.127 [DAT](INFO): received a packet notification
2020-08-26T20:44:37.749Z,1598474677.749 [DAT](INFO): DAT read: Rx Time:20:44:09.4576

2020-08-26T20:44:37.749Z,1598474677.749 [DAT](INFO): received an acoustic signal
2020-08-26T20:44:38.130Z,1598474678.130 [DAT](INFO): DAT read: 

2020-08-26T20:44:38.131Z,1598474678.131 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:44:38.131Z,1598474678.131 [DAT](INFO): received a packet notification
2020-08-26T20:44:42.187Z,1598474682.187 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T20:39:42.0Z
2020-08-26T20:44:42.188Z,1598474682.188 [Default:CheckIn:Read_GPS] Stopped
2020-08-26T20:44:42.188Z,1598474682.188 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-26T20:44:43.970Z,1598474683.970 [DAT](INFO): #Outgoing data=1
2020-08-26T20:44:43.970Z,1598474683.970 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:44:44.081Z,1598474684.081 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:44:47.671Z,1598474687.671 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:44:19.8797

2020-08-26T20:44:47.671Z,1598474687.671 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:44:50.875Z,1598474690.875 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200826T201446/Courier0010.lzma
2020-08-26T20:44:51.877Z,1598474691.877 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Courier0010.lzma.bak
2020-08-26T20:44:51.878Z,1598474691.878 [DataOverHttps](INFO): SBD MOMSN=12622868
2020-08-26T20:44:58.582Z,1598474698.582 [DAT](INFO): DAT read: Rx Time:20:44:30.4079

2020-08-26T20:44:58.583Z,1598474698.583 [DAT](INFO): received an acoustic signal
2020-08-26T20:44:58.982Z,1598474698.982 [DAT](INFO): DAT read: 

2020-08-26T20:44:58.983Z,1598474698.983 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:44:58.983Z,1598474698.983 [DAT](INFO): received a packet notification
2020-08-26T20:45:04.234Z,1598474704.234 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T20:45:04.234Z,1598474704.234 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-26T20:45:04.638Z,1598474704.638 [DAT](INFO): Sent 39 bytes from file Logs/20200826T201446/Courier0010.lzma.parts
2020-08-26T20:45:04.638Z,1598474704.638 [DAT](INFO): Packets left to send: 0
2020-08-26T20:45:05.493Z,1598474705.493 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:45:07.067Z,1598474707.067 [Default:CheckIn:Read_Iridium] Stopped
2020-08-26T20:45:07.067Z,1598474707.067 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-26T20:45:07.067Z,1598474707.067 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-26T20:45:07.532Z,1598474707.532 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2020-08-26T20:45:07.532Z,1598474707.532 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:45:07.573Z,1598474707.573 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:45:07.949Z,1598474707.949 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:45:07.949Z,1598474707.949 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2020-08-26T20:45:10.463Z,1598474710.463 [DataOverHttps](INFO): Sending 709 bytes from file Logs/20200826T194527/Express0001.lzma
2020-08-26T20:45:11.345Z,1598474711.345 [DataOverHttps](INFO): Moved sent file to Logs/20200826T194527/Express0001.lzma.bak
2020-08-26T20:45:11.346Z,1598474711.346 [DataOverHttps](INFO): SBD MOMSN=12622870
2020-08-26T20:45:20.053Z,1598474720.053 [DAT](INFO): DAT read: Rx Time:20:44:51.8082

2020-08-26T20:45:20.053Z,1598474720.053 [DAT](INFO): received an acoustic signal
2020-08-26T20:45:20.447Z,1598474720.447 [DAT](INFO): DAT read: 

2020-08-26T20:45:20.448Z,1598474720.448 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:45:20.449Z,1598474720.449 [DAT](INFO): received a packet notification
2020-08-26T20:46:18.796Z,1598474778.796 [CommandLine](IMPORTANT): got command failComponent
2020-08-26T20:46:18.796Z,1598474778.796 [CommandLine](IMPORTANT): Failed components:
2020-08-26T20:46:18.797Z,1598474778.797 [CommandLine](IMPORTANT): No failed Components.
2020-08-26T20:46:35.227Z,1598474795.227 [CommandLine](IMPORTANT): got command show variable SBDAddress
2020-08-26T20:46:35.257Z,1598474795.257 [CommandLine](IMPORTANT): AcousticModem_Benthos_ATM900.sbdAddress (enum)
2020-08-26T20:46:35.259Z,1598474795.259 [CommandLine](IMPORTANT): DAT.sbdAddress (enum)
2020-08-26T20:46:39.981Z,1598474799.981 [CommandLine](IMPORTANT): got command get DAT.sbdAddress
2020-08-26T20:46:39.982Z,1598474799.982 [CommandLine](IMPORTANT): DAT.sbdAddress 6 enum
2020-08-26T20:47:04.280Z,1598474824.280 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-26T20:47:04.280Z,1598474824.280 [NAL9602] Data Fault, FailCount= 3
2020-08-26T20:47:04.280Z,1598474824.280 [NAL9602](ERROR): Data Fault
2020-08-26T20:47:04.301Z,1598474824.301 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-26T20:47:04.677Z,1598474824.677 [NAL9602](INFO): Powering down
2020-08-26T20:47:05.501Z,1598474825.501 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-26T20:47:05.501Z,1598474825.501 [NAL9602] No Fault, FailCount= 3
2020-08-26T20:47:21.242Z,1598474841.242 [DAT](INFO): DAT read: Rx Time:20:46:53.3097

2020-08-26T20:47:21.242Z,1598474841.242 [DAT](INFO): received an acoustic signal
2020-08-26T20:47:22.456Z,1598474842.456 [DAT](INFO): DAT read: 

2020-08-26T20:47:22.457Z,1598474842.457 [DAT](INFO): DAT read: DATA(0020):�I�hY���׆k�=��	���

2020-08-26T20:47:22.458Z,1598474842.458 [DAT](INFO): Got DATA 20
2020-08-26T20:47:22.458Z,1598474842.458 [DAT](INFO): DAT read: Source:006  Destination:009

2020-08-26T20:47:22.459Z,1598474842.459 [DAT](INFO): Got Src/Dest after DATA 
2020-08-26T20:47:22.459Z,1598474842.459 [DAT](INFO): DATA Src=6, Dst=9
2020-08-26T20:47:22.460Z,1598474842.460 [DAT](INFO): DAT read: CRC:Pass MPD:11.4 PSNR:14.4 AGC:76 SPD:+00.0 CCERR:010

2020-08-26T20:47:22.460Z,1598474842.460 [DAT](INFO): Got CRC:Pass
2020-08-26T20:47:22.460Z,1598474842.460 [DAT](INFO): Got CRC:Pass
2020-08-26T20:47:22.461Z,1598474842.461 [DAT](INFO): Incoming data is intended for us
2020-08-26T20:47:22.462Z,1598474842.462 [DAT](INFO): Received command:failc
2020-08-26T20:47:22.463Z,1598474842.463 [DAT](INFO): Sending ack
2020-08-26T20:47:22.463Z,1598474842.463 [DAT](INFO): DAT read: 

2020-08-26T20:47:22.463Z,1598474842.463 [DAT](INFO): DAT read: <EOP>

2020-08-26T20:47:22.487Z,1598474842.487 [CommandLine](IMPORTANT): got command failComponent
2020-08-26T20:47:22.487Z,1598474842.487 [CommandLine](IMPORTANT): Failed components:
2020-08-26T20:47:22.488Z,1598474842.488 [CommandLine](IMPORTANT): No failed Components.
2020-08-26T20:47:25.686Z,1598474845.686 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:46:58.2284

2020-08-26T20:47:34.981Z,1598474854.981 [NAL9602](INFO): Powering up NAL9602
2020-08-26T20:47:45.881Z,1598474865.881 [NAL9602](INFO): NAL9602 initialized
2020-08-26T20:48:08.516Z,1598474888.516 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2020-08-26T20:48:08.516Z,1598474888.516 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:48:08.526Z,1598474888.526 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:48:08.949Z,1598474888.949 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:48:08.949Z,1598474888.949 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2020-08-26T20:49:30.118Z,1598474970.118 [DAT](INFO): DAT read: Rx Time:20:49:01.9138

2020-08-26T20:49:30.118Z,1598474970.118 [DAT](INFO): received an acoustic signal
2020-08-26T20:49:30.522Z,1598474970.522 [DAT](INFO): DAT read: range request

2020-08-26T20:49:30.522Z,1598474970.522 [DAT](INFO): received a range request message
2020-08-26T20:49:30.523Z,1598474970.523 [DAT](INFO): DAT read: Tx time:20:49:03.5166

2020-08-26T20:49:30.523Z,1598474970.523 [DAT](INFO): Ping request sent.
2020-08-26T20:49:30.523Z,1598474970.523 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:49:30.523Z,1598474970.523 [DAT](INFO): publishing transmit ping time
2020-08-26T20:49:30.524Z,1598474970.524 [DAT](INFO): publishing range request flag
2020-08-26T20:49:59.633Z,1598474999.633 [DAT](INFO): DAT read: Rx Time:20:49:31.4141

2020-08-26T20:49:59.633Z,1598474999.633 [DAT](INFO): received an acoustic signal
2020-08-26T20:50:00.010Z,1598475000.010 [DAT](INFO): DAT read: range request

2020-08-26T20:50:00.010Z,1598475000.010 [DAT](INFO): received a range request message
2020-08-26T20:50:00.011Z,1598475000.011 [DAT](INFO): DAT read: Tx time:20:49:33.0169

2020-08-26T20:50:00.011Z,1598475000.011 [DAT](INFO): Ping request sent.
2020-08-26T20:50:00.011Z,1598475000.011 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:50:00.012Z,1598475000.012 [DAT](INFO): publishing transmit ping time
2020-08-26T20:50:00.012Z,1598475000.012 [DAT](INFO): publishing range request flag
2020-08-26T20:50:07.289Z,1598475007.289 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-26T20:50:07.290Z,1598475007.290 [Default:CheckIn:C.Wait] Stopped
2020-08-26T20:50:07.290Z,1598475007.290 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-26T20:50:07.290Z,1598475007.290 [Default:CheckIn:D] Running Loop=1
2020-08-26T20:50:07.702Z,1598475007.702 [Default:CheckIn:D] Stopped
2020-08-26T20:50:07.702Z,1598475007.702 [Default:CheckIn:E] Running Loop=1
2020-08-26T20:50:08.120Z,1598475008.120 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.382111 min 
2020-08-26T20:50:08.120Z,1598475008.120 [Default:CheckIn:E] Stopped
2020-08-26T20:50:08.120Z,1598475008.120 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-26T20:50:08.120Z,1598475008.120 [Default:CheckIn] Stopped
2020-08-26T20:50:08.120Z,1598475008.120 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-26T20:50:08.120Z,1598475008.120 [Default:CheckIn](INFO): Running loop #4
2020-08-26T20:50:08.120Z,1598475008.120 [Default:CheckIn] Running Loop=4
2020-08-26T20:50:08.120Z,1598475008.120 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-26T20:50:08.121Z,1598475008.121 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-26T20:50:29.502Z,1598475029.502 [DAT](INFO): DAT read: Rx Time:20:50:01.3146

2020-08-26T20:50:29.503Z,1598475029.503 [DAT](INFO): received an acoustic signal
2020-08-26T20:50:30.333Z,1598475030.333 [DAT](INFO): DAT read: 20:50:01.3146 LVL= 15664, 18033, 22162, 32755, AGC= 71, IDX=  41,-0.28,-0.149, 0.266,-0.504,-1.619, PHS= 1.504, 1.914, 1.186, RAW= 355.8, -68.8, CAL= 357.8, -68.7, ROT= 137.2,  68.7

2020-08-26T20:50:30.334Z,1598475030.334 [DAT](INFO): got valid direction response:
 20:50:01.3146 LVL= 15664, 18033, 22162, 32755, AGC= 71, IDX=  41,-0.28,-0.149, 0.266,-0.504,-1.619, PHS= 1.504, 1.914, 1.186, RAW= 355.8, -68.8, CAL= 357.8, -68.7, ROT= 137.2,  68.7

2020-08-26T20:50:30.335Z,1598475030.335 [DAT](INFO): DAT read: bearing request

2020-08-26T20:50:30.335Z,1598475030.335 [DAT](INFO): received a bearing request message
2020-08-26T20:50:30.336Z,1598475030.336 [DAT](INFO): DAT read: Tx time:20:50:02.9174

2020-08-26T20:50:30.336Z,1598475030.336 [DAT](INFO): Ping request sent.
2020-08-26T20:50:30.336Z,1598475030.336 [DAT](INFO): transmitted an acoustic signal
2020-08-26T20:50:30.337Z,1598475030.337 [DAT](INFO): Read direction message, but no range.
2020-08-26T20:50:30.337Z,1598475030.337 [DAT](INFO): publishing transmit ping time
2020-08-26T20:50:30.337Z,1598475030.337 [DAT](INFO): publishing range request flag
2020-08-26T20:51:09.512Z,1598475069.512 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2020-08-26T20:51:09.512Z,1598475069.512 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:51:09.568Z,1598475069.568 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:51:09.929Z,1598475069.929 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:51:09.929Z,1598475069.929 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2020-08-26T20:52:17.374Z,1598475137.374 [DAT](INFO): DAT read: Rx Time:20:51:49.1650

2020-08-26T20:52:17.374Z,1598475137.374 [DAT](INFO): received an acoustic signal
2020-08-26T20:52:17.785Z,1598475137.785 [DAT](INFO): DAT read: 

2020-08-26T20:52:17.786Z,1598475137.786 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:52:17.786Z,1598475137.786 [DAT](INFO): received a packet notification
2020-08-26T20:52:38.801Z,1598475158.801 [DAT](INFO): DAT read: Rx Time:20:52:10.5652

2020-08-26T20:52:38.801Z,1598475158.801 [DAT](INFO): received an acoustic signal
2020-08-26T20:52:39.200Z,1598475159.200 [DAT](INFO): DAT read: 

2020-08-26T20:52:39.201Z,1598475159.201 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:52:39.201Z,1598475159.201 [DAT](INFO): received a packet notification
2020-08-26T20:52:59.805Z,1598475179.805 [DAT](INFO): DAT read: Rx Time:20:52:31.5655

2020-08-26T20:52:59.805Z,1598475179.805 [DAT](INFO): received an acoustic signal
2020-08-26T20:53:00.217Z,1598475180.217 [DAT](INFO): DAT read: 

2020-08-26T20:53:00.217Z,1598475180.217 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:53:00.218Z,1598475180.218 [DAT](INFO): received a packet notification
2020-08-26T20:53:20.813Z,1598475200.813 [DAT](INFO): DAT read: Rx Time:20:52:52.5658

2020-08-26T20:53:20.813Z,1598475200.813 [DAT](INFO): received an acoustic signal
2020-08-26T20:53:21.233Z,1598475201.233 [DAT](INFO): DAT read: 20:52:52.5658 LVL= 14720, 17905, 21602, 32755, AGC= 71, IDX= 245,-0.24,-1.664, 0.601,-0.943,-1.266, PHS=-0.365, 1.896, 0.395, RAW= 310.7, -18.9, CAL= 311.7, -23.3, ROT= 183.3,  23.3

2020-08-26T20:53:21.235Z,1598475201.235 [DAT](INFO): got valid direction response:
 20:52:52.5658 LVL= 14720, 17905, 21602, 32755, AGC= 71, IDX= 245,-0.24,-1.664, 0.601,-0.943,-1.266, PHS=-0.365, 1.896, 0.395, RAW= 310.7, -18.9, CAL= 311.7, -23.3, ROT= 183.3,  23.3

2020-08-26T20:53:21.235Z,1598475201.235 [DAT](INFO): DAT read: 

2020-08-26T20:53:21.236Z,1598475201.236 [DAT](INFO): Read direction message, but no range.
2020-08-26T20:53:21.621Z,1598475201.621 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:53:21.621Z,1598475201.621 [DAT](INFO): received a packet notification
2020-08-26T20:54:10.524Z,1598475250.524 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2020-08-26T20:54:10.524Z,1598475250.524 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:54:10.558Z,1598475250.558 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:54:10.925Z,1598475250.925 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:54:10.925Z,1598475250.925 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2020-08-26T20:55:08.275Z,1598475308.275 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T20:50:08.1Z
2020-08-26T20:55:08.275Z,1598475308.275 [Default:CheckIn:Read_GPS] Stopped
2020-08-26T20:55:08.275Z,1598475308.275 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-26T20:55:10.432Z,1598475310.432 [DAT](INFO): #Outgoing data=1
2020-08-26T20:55:10.433Z,1598475310.433 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T20:55:10.533Z,1598475310.533 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T20:55:14.099Z,1598475314.099 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:54:46.3268

2020-08-26T20:55:14.099Z,1598475314.099 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T20:55:16.603Z,1598475316.603 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200826T201446/Courier0013.lzma
2020-08-26T20:55:17.605Z,1598475317.605 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Courier0013.lzma.bak
2020-08-26T20:55:17.606Z,1598475317.606 [DataOverHttps](INFO): SBD MOMSN=12622956
2020-08-26T20:55:20.566Z,1598475320.566 [DAT](INFO): DAT read: Rx Time:20:54:52.3673

2020-08-26T20:55:20.566Z,1598475320.566 [DAT](INFO): received an acoustic signal
2020-08-26T20:55:20.971Z,1598475320.971 [DAT](INFO): DAT read: 

2020-08-26T20:55:20.971Z,1598475320.971 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T20:55:20.972Z,1598475320.972 [DAT](INFO): received a packet notification
2020-08-26T20:55:30.681Z,1598475330.681 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T20:55:30.681Z,1598475330.681 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-26T20:55:31.066Z,1598475331.066 [DAT](INFO): Sent 39 bytes from file Logs/20200826T201446/Courier0013.lzma.parts
2020-08-26T20:55:31.066Z,1598475331.066 [DAT](INFO): Packets left to send: 0
2020-08-26T20:55:31.070Z,1598475331.070 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T20:55:32.960Z,1598475332.960 [Default:CheckIn:Read_Iridium] Stopped
2020-08-26T20:55:32.960Z,1598475332.960 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-26T20:55:32.960Z,1598475332.960 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-26T20:55:35.353Z,1598475335.353 [DataOverHttps](INFO): Sending 1103 bytes from file Logs/20200826T201446/Express0001.lzma
2020-08-26T20:55:36.354Z,1598475336.354 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Express0001.lzma.bak
2020-08-26T20:55:36.354Z,1598475336.354 [DataOverHttps](INFO): SBD MOMSN=12622958
2020-08-26T20:57:11.567Z,1598475431.567 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2020-08-26T20:57:11.567Z,1598475431.567 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T20:57:11.577Z,1598475431.577 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T20:57:11.994Z,1598475431.994 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T20:57:11.994Z,1598475431.994 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2020-08-26T20:57:49.133Z,1598475469.133 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-26T20:57:49.133Z,1598475469.133 [NAL9602] Data Fault, FailCount= 4
2020-08-26T20:57:49.133Z,1598475469.133 [NAL9602](ERROR): Data Fault
2020-08-26T20:57:49.178Z,1598475469.178 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-26T20:57:49.538Z,1598475469.538 [NAL9602](INFO): Powering down
2020-08-26T20:57:50.377Z,1598475470.377 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-26T20:57:50.377Z,1598475470.377 [NAL9602] No Fault, FailCount= 4
2020-08-26T20:58:19.842Z,1598475499.842 [NAL9602](INFO): Powering up NAL9602
2020-08-26T20:58:30.745Z,1598475510.745 [NAL9602](INFO): NAL9602 initialized
2020-08-26T21:00:12.574Z,1598475612.574 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2020-08-26T21:00:12.574Z,1598475612.574 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:00:12.584Z,1598475612.584 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:00:12.993Z,1598475612.993 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:00:12.993Z,1598475612.993 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2020-08-26T21:00:33.165Z,1598475633.165 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-26T21:00:33.165Z,1598475633.165 [Default:CheckIn:C.Wait] Stopped
2020-08-26T21:00:33.165Z,1598475633.165 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-26T21:00:33.166Z,1598475633.166 [Default:CheckIn:D] Running Loop=1
2020-08-26T21:00:33.577Z,1598475633.577 [Default:CheckIn:D] Stopped
2020-08-26T21:00:33.577Z,1598475633.577 [Default:CheckIn:E] Running Loop=1
2020-08-26T21:00:33.970Z,1598475633.970 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 41.813354 min 
2020-08-26T21:00:33.970Z,1598475633.970 [Default:CheckIn:E] Stopped
2020-08-26T21:00:33.970Z,1598475633.970 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-26T21:00:33.970Z,1598475633.970 [Default:CheckIn] Stopped
2020-08-26T21:00:33.970Z,1598475633.970 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-26T21:00:33.970Z,1598475633.970 [Default:CheckIn](INFO): Running loop #5
2020-08-26T21:00:33.970Z,1598475633.970 [Default:CheckIn] Running Loop=5
2020-08-26T21:00:33.970Z,1598475633.970 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-26T21:00:33.970Z,1598475633.970 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-26T21:02:40.829Z,1598475760.829 [DAT](INFO): DAT read: Rx Time:21:02:12.8232

2020-08-26T21:02:40.830Z,1598475760.830 [DAT](INFO): received an acoustic signal
2020-08-26T21:02:41.637Z,1598475761.637 [DAT](INFO): DAT read: 

2020-08-26T21:02:41.638Z,1598475761.638 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T21:02:41.638Z,1598475761.638 [DAT](INFO): received a packet notification
2020-08-26T21:03:13.555Z,1598475793.555 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2020-08-26T21:03:13.555Z,1598475793.555 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:03:13.565Z,1598475793.565 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:03:13.981Z,1598475793.981 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:03:13.981Z,1598475793.981 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2020-08-26T21:05:34.154Z,1598475934.154 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T21:00:33.0Z
2020-08-26T21:05:34.154Z,1598475934.154 [Default:CheckIn:Read_GPS] Stopped
2020-08-26T21:05:34.154Z,1598475934.154 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-26T21:05:37.141Z,1598475937.141 [DAT](INFO): #Outgoing data=1
2020-08-26T21:05:37.141Z,1598475937.141 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T21:05:37.265Z,1598475937.265 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T21:05:40.819Z,1598475940.819 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:05:13.0724

2020-08-26T21:05:40.819Z,1598475940.819 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T21:05:46.783Z,1598475946.783 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200826T201446/Courier0016.lzma
2020-08-26T21:05:46.889Z,1598475946.889 [DAT](INFO): DAT read: Rx Time:21:05:18.9257

2020-08-26T21:05:46.889Z,1598475946.889 [DAT](INFO): received an acoustic signal
2020-08-26T21:05:47.696Z,1598475947.696 [DAT](INFO): DAT read: 

2020-08-26T21:05:47.697Z,1598475947.697 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T21:05:47.697Z,1598475947.697 [DAT](INFO): received a packet notification
2020-08-26T21:05:47.786Z,1598475947.786 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Courier0016.lzma.bak
2020-08-26T21:05:47.786Z,1598475947.786 [DataOverHttps](INFO): SBD MOMSN=12623092
2020-08-26T21:05:57.386Z,1598475957.386 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T21:05:57.386Z,1598475957.386 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-26T21:05:57.791Z,1598475957.791 [DAT](INFO): Sent 39 bytes from file Logs/20200826T201446/Courier0016.lzma.parts
2020-08-26T21:05:57.791Z,1598475957.791 [DAT](INFO): Packets left to send: 0
2020-08-26T21:05:57.801Z,1598475957.801 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T21:05:58.930Z,1598475958.930 [Default:CheckIn:Read_Iridium] Stopped
2020-08-26T21:05:58.930Z,1598475958.930 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-26T21:05:58.931Z,1598475958.931 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-26T21:06:05.136Z,1598475965.136 [DataOverHttps](INFO): Sending 330 bytes from file Logs/20200826T201446/Express0005.lzma
2020-08-26T21:06:06.137Z,1598475966.137 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Express0005.lzma.bak
2020-08-26T21:06:06.138Z,1598475966.138 [DataOverHttps](INFO): SBD MOMSN=12623094
2020-08-26T21:06:14.736Z,1598475974.736 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17
2020-08-26T21:06:14.736Z,1598475974.736 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:06:14.746Z,1598475974.746 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:06:15.157Z,1598475975.157 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:06:15.157Z,1598475975.157 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17
2020-08-26T21:08:32.877Z,1598476112.877 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-26T21:08:32.877Z,1598476112.877 [NAL9602] Data Fault, FailCount= 5
2020-08-26T21:08:32.877Z,1598476112.877 [NAL9602](ERROR): Data Fault
2020-08-26T21:08:32.906Z,1598476112.906 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-26T21:08:32.906Z,1598476112.906 [CBIT](CRITICAL): Data Fault in component: NAL9602
2020-08-26T21:08:33.285Z,1598476113.285 [NAL9602](INFO): Powering down
2020-08-26T21:08:33.323Z,1598476113.323 [CBIT](INFO): Critical error at 20200826T210832
2020-08-26T21:09:15.714Z,1598476155.714 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18
2020-08-26T21:09:15.714Z,1598476155.714 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:09:15.725Z,1598476155.725 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:09:16.138Z,1598476156.138 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:09:16.138Z,1598476156.138 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18
2020-08-26T21:10:32.888Z,1598476232.888 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-26T21:10:32.888Z,1598476232.888 [NAL9602] No Fault, FailCount= 5
2020-08-26T21:10:33.273Z,1598476233.273 [NAL9602](INFO): Powering up NAL9602
2020-08-26T21:10:44.177Z,1598476244.177 [NAL9602](INFO): NAL9602 initialized
2020-08-26T21:10:59.161Z,1598476259.161 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-26T21:10:59.161Z,1598476259.161 [Default:CheckIn:C.Wait] Stopped
2020-08-26T21:10:59.161Z,1598476259.161 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-26T21:10:59.161Z,1598476259.161 [Default:CheckIn:D] Running Loop=1
2020-08-26T21:10:59.573Z,1598476259.573 [Default:CheckIn:D] Stopped
2020-08-26T21:10:59.573Z,1598476259.573 [Default:CheckIn:E] Running Loop=1
2020-08-26T21:10:59.973Z,1598476259.973 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.246619 min 
2020-08-26T21:10:59.973Z,1598476259.973 [Default:CheckIn:E] Stopped
2020-08-26T21:10:59.974Z,1598476259.974 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-26T21:10:59.974Z,1598476259.974 [Default:CheckIn] Stopped
2020-08-26T21:10:59.974Z,1598476259.974 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-26T21:10:59.974Z,1598476259.974 [Default:CheckIn](INFO): Running loop #6
2020-08-26T21:10:59.974Z,1598476259.974 [Default:CheckIn] Running Loop=6
2020-08-26T21:10:59.974Z,1598476259.974 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-26T21:10:59.974Z,1598476259.974 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-26T21:12:16.744Z,1598476336.744 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19
2020-08-26T21:12:16.744Z,1598476336.744 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:12:16.775Z,1598476336.775 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:12:17.161Z,1598476337.161 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:12:17.161Z,1598476337.161 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19
2020-08-26T21:13:05.213Z,1598476385.213 [DAT](INFO): DAT read: Rx Time:21:12:37.2318

2020-08-26T21:13:05.213Z,1598476385.213 [DAT](INFO): received an acoustic signal
2020-08-26T21:13:06.017Z,1598476386.017 [DAT](INFO): DAT read: 

2020-08-26T21:13:06.017Z,1598476386.017 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T21:13:06.018Z,1598476386.018 [DAT](INFO): received a packet notification
2020-08-26T21:15:17.752Z,1598476517.752 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20
2020-08-26T21:15:17.752Z,1598476517.752 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:15:17.762Z,1598476517.762 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:15:18.153Z,1598476518.153 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:15:18.153Z,1598476518.153 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20
2020-08-26T21:16:00.157Z,1598476560.157 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T21:10:59.0Z
2020-08-26T21:16:00.157Z,1598476560.157 [Default:CheckIn:Read_GPS] Stopped
2020-08-26T21:16:00.157Z,1598476560.157 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-26T21:16:01.849Z,1598476561.849 [DAT](INFO): #Outgoing data=1
2020-08-26T21:16:01.850Z,1598476561.850 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T21:16:01.946Z,1598476561.946 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T21:16:05.547Z,1598476565.547 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:15:37.8194

2020-08-26T21:16:05.549Z,1598476565.549 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T21:16:06.872Z,1598476566.872 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20200826T201446/Courier0019.lzma
2020-08-26T21:16:07.874Z,1598476567.874 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Courier0019.lzma.bak
2020-08-26T21:16:07.874Z,1598476567.874 [DataOverHttps](INFO): SBD MOMSN=12623129
2020-08-26T21:16:12.833Z,1598476572.833 [DAT](INFO): DAT read: Rx Time:21:15:44.5344

2020-08-26T21:16:12.833Z,1598476572.833 [DAT](INFO): received an acoustic signal
2020-08-26T21:16:13.233Z,1598476573.233 [DAT](INFO): DAT read: 

2020-08-26T21:16:13.233Z,1598476573.233 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T21:16:13.234Z,1598476573.234 [DAT](INFO): received a packet notification
2020-08-26T21:16:22.123Z,1598476582.123 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T21:16:22.123Z,1598476582.123 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-26T21:16:22.514Z,1598476582.514 [DAT](INFO): Sent 81 bytes from file Logs/20200826T201446/Courier0019.lzma.parts
2020-08-26T21:16:22.514Z,1598476582.514 [DAT](INFO): Packets left to send: 0
2020-08-26T21:16:22.518Z,1598476582.518 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T21:16:24.371Z,1598476584.371 [Default:CheckIn:Read_Iridium] Stopped
2020-08-26T21:16:24.371Z,1598476584.371 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-26T21:16:24.371Z,1598476584.371 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-26T21:16:25.732Z,1598476585.732 [DataOverHttps](INFO): Sending 181 bytes from file Logs/20200826T201446/Express0008.lzma
2020-08-26T21:16:26.733Z,1598476586.733 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Express0008.lzma.bak
2020-08-26T21:16:26.734Z,1598476586.734 [DataOverHttps](INFO): SBD MOMSN=12623132
2020-08-26T21:18:18.748Z,1598476698.748 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21
2020-08-26T21:18:18.748Z,1598476698.748 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:18:18.794Z,1598476698.794 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:18:19.197Z,1598476699.197 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:18:19.198Z,1598476699.198 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21
2020-08-26T21:20:46.189Z,1598476846.189 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-26T21:20:46.189Z,1598476846.189 [NAL9602] Data Fault, FailCount= 1
2020-08-26T21:20:46.189Z,1598476846.189 [NAL9602](ERROR): Data Fault
2020-08-26T21:20:46.213Z,1598476846.213 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-26T21:20:46.598Z,1598476846.598 [NAL9602](INFO): Powering down
2020-08-26T21:20:47.417Z,1598476847.417 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-26T21:20:47.417Z,1598476847.417 [NAL9602] No Fault, FailCount= 1
2020-08-26T21:21:16.889Z,1598476876.889 [NAL9602](INFO): Powering up NAL9602
2020-08-26T21:21:19.728Z,1598476879.728 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22
2020-08-26T21:21:19.728Z,1598476879.728 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:21:19.738Z,1598476879.738 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:21:20.153Z,1598476880.153 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:21:20.153Z,1598476880.153 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22
2020-08-26T21:21:24.577Z,1598476884.577 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-26T21:21:24.577Z,1598476884.577 [Default:CheckIn:C.Wait] Stopped
2020-08-26T21:21:24.577Z,1598476884.577 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-26T21:21:24.577Z,1598476884.577 [Default:CheckIn:D] Running Loop=1
2020-08-26T21:21:24.973Z,1598476884.973 [Default:CheckIn:D] Stopped
2020-08-26T21:21:24.973Z,1598476884.973 [Default:CheckIn:E] Running Loop=1
2020-08-26T21:21:25.384Z,1598476885.384 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.669963 min 
2020-08-26T21:21:25.384Z,1598476885.384 [Default:CheckIn:E] Stopped
2020-08-26T21:21:25.385Z,1598476885.385 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-26T21:21:25.385Z,1598476885.385 [Default:CheckIn] Stopped
2020-08-26T21:21:25.385Z,1598476885.385 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-26T21:21:25.385Z,1598476885.385 [Default:CheckIn](INFO): Running loop #7
2020-08-26T21:21:25.385Z,1598476885.385 [Default:CheckIn] Running Loop=7
2020-08-26T21:21:25.385Z,1598476885.385 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-26T21:21:25.385Z,1598476885.385 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-26T21:21:27.801Z,1598476887.801 [NAL9602](INFO): NAL9602 initialized
2020-08-26T21:23:29.821Z,1598477009.821 [DAT](INFO): DAT read: Rx Time:21:23:01.5408

2020-08-26T21:23:29.821Z,1598477009.821 [DAT](INFO): received an acoustic signal
2020-08-26T21:23:30.214Z,1598477010.214 [DAT](INFO): DAT read: 

2020-08-26T21:23:30.215Z,1598477010.215 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T21:23:30.215Z,1598477010.215 [DAT](INFO): received a packet notification
2020-08-26T21:24:20.716Z,1598477060.716 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23
2020-08-26T21:24:20.717Z,1598477060.717 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:24:20.727Z,1598477060.727 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:24:21.142Z,1598477061.142 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:24:21.142Z,1598477061.142 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23
2020-08-26T21:26:25.561Z,1598477185.561 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T21:21:25.4Z
2020-08-26T21:26:25.561Z,1598477185.561 [Default:CheckIn:Read_GPS] Stopped
2020-08-26T21:26:25.561Z,1598477185.561 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-26T21:26:27.670Z,1598477187.670 [DAT](INFO): #Outgoing data=1
2020-08-26T21:26:27.670Z,1598477187.670 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T21:26:27.901Z,1598477187.901 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T21:26:31.477Z,1598477191.477 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:26:03.7160

2020-08-26T21:26:31.477Z,1598477191.477 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T21:26:32.779Z,1598477192.779 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20200826T201446/Courier0022.lzma
2020-08-26T21:26:33.781Z,1598477193.781 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Courier0022.lzma.bak
2020-08-26T21:26:33.782Z,1598477193.782 [DataOverHttps](INFO): SBD MOMSN=12623154
2020-08-26T21:26:37.945Z,1598477197.945 [DAT](INFO): DAT read: Rx Time:21:26:09.6435

2020-08-26T21:26:37.945Z,1598477197.945 [DAT](INFO): received an acoustic signal
2020-08-26T21:26:38.344Z,1598477198.344 [DAT](INFO): DAT read: 

2020-08-26T21:26:38.345Z,1598477198.345 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T21:26:38.346Z,1598477198.346 [DAT](INFO): received a packet notification
2020-08-26T21:26:48.030Z,1598477208.030 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T21:26:48.030Z,1598477208.030 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-26T21:26:48.434Z,1598477208.434 [DAT](INFO): Sent 38 bytes from file Logs/20200826T201446/Courier0022.lzma.parts
2020-08-26T21:26:48.434Z,1598477208.434 [DAT](INFO): Packets left to send: 0
2020-08-26T21:26:48.437Z,1598477208.437 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T21:26:50.328Z,1598477210.328 [Default:CheckIn:Read_Iridium] Stopped
2020-08-26T21:26:50.328Z,1598477210.328 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-26T21:26:50.329Z,1598477210.329 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-26T21:26:51.684Z,1598477211.684 [DataOverHttps](INFO): Sending 190 bytes from file Logs/20200826T201446/Express0011.lzma
2020-08-26T21:26:52.685Z,1598477212.685 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Express0011.lzma.bak
2020-08-26T21:26:52.686Z,1598477212.686 [DataOverHttps](INFO): SBD MOMSN=12623156
2020-08-26T21:27:21.921Z,1598477241.921 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24
2020-08-26T21:27:21.921Z,1598477241.921 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:27:21.933Z,1598477241.933 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:27:22.336Z,1598477242.336 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:27:22.336Z,1598477242.336 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24
2020-08-26T21:29:50.570Z,1598477390.570 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-26T21:29:50.573Z,1598477390.573 [BPC1](INFO): Received data from all battery sticks.
2020-08-26T21:30:22.890Z,1598477422.890 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 25
2020-08-26T21:30:22.890Z,1598477422.890 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:30:22.904Z,1598477422.904 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:30:23.320Z,1598477423.320 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:30:23.320Z,1598477423.320 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 25
2020-08-26T21:31:30.751Z,1598477490.751 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-26T21:31:30.751Z,1598477490.751 [NAL9602] Data Fault, FailCount= 2
2020-08-26T21:31:30.751Z,1598477490.751 [NAL9602](ERROR): Data Fault
2020-08-26T21:31:30.773Z,1598477490.773 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-26T21:31:31.149Z,1598477491.149 [NAL9602](INFO): Powering down
2020-08-26T21:31:31.977Z,1598477491.977 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-26T21:31:31.977Z,1598477491.977 [NAL9602] No Fault, FailCount= 2
2020-08-26T21:31:50.557Z,1598477510.557 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-26T21:31:50.557Z,1598477510.557 [Default:CheckIn:C.Wait] Stopped
2020-08-26T21:31:50.557Z,1598477510.557 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-26T21:31:50.557Z,1598477510.557 [Default:CheckIn:D] Running Loop=1
2020-08-26T21:31:50.963Z,1598477510.963 [Default:CheckIn:D] Stopped
2020-08-26T21:31:50.963Z,1598477510.963 [Default:CheckIn:E] Running Loop=1
2020-08-26T21:31:51.375Z,1598477511.375 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.103125 min 
2020-08-26T21:31:51.375Z,1598477511.375 [Default:CheckIn:E] Stopped
2020-08-26T21:31:51.376Z,1598477511.376 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-26T21:31:51.376Z,1598477511.376 [Default:CheckIn] Stopped
2020-08-26T21:31:51.376Z,1598477511.376 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-26T21:31:51.376Z,1598477511.376 [Default:CheckIn](INFO): Running loop #8
2020-08-26T21:31:51.376Z,1598477511.376 [Default:CheckIn] Running Loop=8
2020-08-26T21:31:51.376Z,1598477511.376 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-26T21:31:51.376Z,1598477511.376 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-26T21:32:01.453Z,1598477521.453 [NAL9602](INFO): Powering up NAL9602
2020-08-26T21:32:12.365Z,1598477532.365 [NAL9602](INFO): NAL9602 initialized
2020-08-26T21:33:23.871Z,1598477603.871 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 26
2020-08-26T21:33:23.871Z,1598477603.871 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:33:23.881Z,1598477603.881 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:33:24.317Z,1598477604.317 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:33:24.317Z,1598477604.317 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 26
2020-08-26T21:33:54.166Z,1598477634.166 [DAT](INFO): DAT read: Rx Time:21:33:26.1998

2020-08-26T21:33:54.166Z,1598477634.166 [DAT](INFO): received an acoustic signal
2020-08-26T21:33:54.978Z,1598477634.978 [DAT](INFO): DAT read: 

2020-08-26T21:33:54.979Z,1598477634.979 [DAT](INFO): DAT read: $Packet for address 1

2020-08-26T21:33:54.979Z,1598477634.979 [DAT](INFO): received a packet notification
2020-08-26T21:36:24.867Z,1598477784.867 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 27
2020-08-26T21:36:24.867Z,1598477784.867 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-26T21:36:24.877Z,1598477784.877 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-26T21:36:25.313Z,1598477785.313 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-26T21:36:25.313Z,1598477785.313 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 27
2020-08-26T21:36:51.533Z,1598477811.533 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-26T21:31:51.4Z
2020-08-26T21:36:51.533Z,1598477811.533 [Default:CheckIn:Read_GPS] Stopped
2020-08-26T21:36:51.534Z,1598477811.534 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-26T21:36:53.475Z,1598477813.475 [DAT](INFO): #Outgoing data=1
2020-08-26T21:36:53.476Z,1598477813.476 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2020-08-26T21:36:53.605Z,1598477813.605 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2020-08-26T21:36:57.171Z,1598477817.171 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:36:29.4129

2020-08-26T21:36:57.171Z,1598477817.171 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2020-08-26T21:37:00.163Z,1598477820.163 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20200826T201446/Courier0025.lzma
2020-08-26T21:37:01.166Z,1598477821.166 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Courier0025.lzma.bak
2020-08-26T21:37:01.166Z,1598477821.166 [DataOverHttps](INFO): SBD MOMSN=12623180
2020-08-26T21:37:13.748Z,1598477833.748 [DAT](FAULT): Ack receipt timeout failure.
2020-08-26T21:37:13.749Z,1598477833.749 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2020-08-26T21:37:14.173Z,1598477834.173 [DAT](INFO): Sent 50 bytes from file Logs/20200826T201446/Courier0025.lzma.parts
2020-08-26T21:37:14.173Z,1598477834.173 [DAT](INFO): Packets left to send: 0
2020-08-26T21:37:14.175Z,1598477834.175 [DAT](DEBUG): In sendingVerified, sbd waiting so set commsState_ = SENDING_FILL_BUFFER
2020-08-26T21:37:16.024Z,1598477836.024 [Default:CheckIn:Read_Iridium] Stopped
2020-08-26T21:37:16.024Z,1598477836.024 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-26T21:37:16.024Z,1598477836.024 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-26T21:37:19.044Z,1598477839.044 [DataOverHttps](INFO): Sending 343 bytes from file Logs/20200826T201446/Express0014.lzma
2020-08-26T21:37:20.041Z,1598477840.042 [DataOverHttps](INFO): Moved sent file to Logs/20200826T201446/Express0014.lzma.bak
2020-08-26T21:37:20.042Z,1598477840.042 [DataOverHttps](INFO): SBD MOMSN=12623182
2020-08-26T21:37:39.370Z,1598477859.370 [CommandLine](IMPORTANT): got command quit
2020-08-26T21:37:40.376Z,1598477860.376 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-26T21:37:40.377Z,1598477860.377 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:40.496Z,1598477860.496 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-08-26T21:37:40.496Z,1598477860.496 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:40.497Z,1598477860.497 [CommandLine](INFO): Join timeout helper Thread ID is 1274
2020-08-26T21:37:40.497Z,1598477860.497 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-08-26T21:37:40.497Z,1598477860.497 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:40.498Z,1598477860.498 [NavChartDb](INFO): Join timeout helper Thread ID is 1275
2020-08-26T21:37:40.744Z,1598477860.744 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-26T21:37:40.744Z,1598477860.744 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:40.760Z,1598477860.760 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-08-26T21:37:40.760Z,1598477860.760 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:40.760Z,1598477860.760 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1276
2020-08-26T21:37:41.204Z,1598477861.204 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-26T21:37:41.205Z,1598477861.205 [WetLabsBB2FL](INFO): Powering down
2020-08-26T21:37:41.205Z,1598477861.205 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:41.212Z,1598477861.212 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-08-26T21:37:41.212Z,1598477861.212 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:41.212Z,1598477861.212 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1277
2020-08-26T21:37:42.084Z,1598477862.084 [CTD_Seabird](INFO): Powering down
2020-08-26T21:37:42.096Z,1598477862.096 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-26T21:37:42.096Z,1598477862.096 [CTD_Seabird](INFO): Powering down
2020-08-26T21:37:42.108Z,1598477862.108 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:42.116Z,1598477862.116 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2020-08-26T21:37:42.116Z,1598477862.116 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:42.116Z,1598477862.116 [BackSeatDriver](INFO): Join timeout helper Thread ID is 1278
2020-08-26T21:37:42.136Z,1598477862.136 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-26T21:37:42.136Z,1598477862.136 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:42.138Z,1598477862.138 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-08-26T21:37:42.138Z,1598477862.138 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:42.138Z,1598477862.138 [Radio_Surface](INFO): Join timeout helper Thread ID is 1279
2020-08-26T21:37:42.139Z,1598477862.139 [Radio_Surface](INFO): Powering down
2020-08-26T21:37:42.140Z,1598477862.140 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-26T21:37:42.140Z,1598477862.140 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:42.141Z,1598477862.141 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-08-26T21:37:42.141Z,1598477862.141 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:42.142Z,1598477862.142 [Onboard](INFO): Join timeout helper Thread ID is 1280
2020-08-26T21:37:42.280Z,1598477862.280 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2020-08-26T21:37:46.524Z,1598477866.524 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-26T21:37:46.524Z,1598477866.524 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:46.529Z,1598477866.529 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-08-26T21:37:46.529Z,1598477866.529 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:46.529Z,1598477866.529 [DataOverHttps](INFO): Join timeout helper Thread ID is 1281
2020-08-26T21:37:47.300Z,1598477867.300 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-26T21:37:47.300Z,1598477867.300 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:47.313Z,1598477867.313 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-08-26T21:37:47.313Z,1598477867.313 [logger ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:47.313Z,1598477867.313 [logger](INFO): Join timeout helper Thread ID is 1282
2020-08-26T21:37:47.340Z,1598477867.340 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-26T21:37:47.340Z,1598477867.340 [logger ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:47.352Z,1598477867.352 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-08-26T21:37:47.353Z,1598477867.353 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:47.353Z,1598477867.353 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-08-26T21:37:47.353Z,1598477867.353 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:47.353Z,1598477867.353 [controlThread](INFO): Join timeout helper Thread ID is 1283
2020-08-26T21:37:47.556Z,1598477867.556 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-08-26T21:37:47.556Z,1598477867.556 [controlThread](DEBUG): Uninitializing ControlThread
2020-08-26T21:37:47.557Z,1598477867.557 [AHRS_M2](INFO): Powering down
2020-08-26T21:37:47.628Z,1598477867.628 [NAL9602](INFO): Powering down
2020-08-26T21:37:47.629Z,1598477867.629 [DAT](INFO): Powering down
2020-08-26T21:37:47.916Z,1598477867.916 [AMEcho](INFO): Powering down
2020-08-26T21:37:47.917Z,1598477867.917 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-08-26T21:37:47.918Z,1598477867.918 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-08-26T21:37:47.918Z,1598477867.918 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-08-26T21:37:47.919Z,1598477867.919 [MissionManager](INFO): Uninitializing Mission Default
2020-08-26T21:37:47.919Z,1598477867.919 [Default] Stopped
2020-08-26T21:37:47.919Z,1598477867.919 [Default](DEBUG): Aggregate::uninitialize Default
2020-08-26T21:37:47.919Z,1598477867.919 [Default:B.GoToSurface] Stopped
2020-08-26T21:37:47.919Z,1598477867.919 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-26T21:37:47.919Z,1598477867.919 [Default:CheckIn] Stopped
2020-08-26T21:37:47.919Z,1598477867.919 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-26T21:37:47.919Z,1598477867.919 [Default:CheckIn:C.Wait] Stopped
2020-08-26T21:37:47.920Z,1598477867.920 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-26T21:37:47.922Z,1598477867.922 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-08-26T21:37:47.922Z,1598477867.922 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-08-26T21:37:47.923Z,1598477867.923 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-08-26T21:37:47.923Z,1598477867.923 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-08-26T21:37:47.923Z,1598477867.923 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-08-26T21:37:47.923Z,1598477867.923 [BuoyancyServo](INFO): Powering down
2020-08-26T21:37:47.936Z,1598477867.936 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-08-26T21:37:47.936Z,1598477867.936 [ElevatorServo](INFO): Powering down
2020-08-26T21:37:47.937Z,1598477867.937 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-08-26T21:37:47.937Z,1598477867.937 [MassServo](INFO): Powering down
2020-08-26T21:37:47.938Z,1598477867.938 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-08-26T21:37:47.938Z,1598477867.938 [RudderServo](INFO): Powering down
2020-08-26T21:37:47.939Z,1598477867.939 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-08-26T21:37:47.939Z,1598477867.939 [ThrusterServo](INFO): Powering down
2020-08-26T21:37:47.939Z,1598477867.939 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-08-26T21:37:47.940Z,1598477867.940 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-08-26T21:37:47.940Z,1598477867.940 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-08-26T21:37:47.940Z,1598477867.940 [CBIT](DEBUG): Powering off loads.
2020-08-26T21:37:47.952Z,1598477867.952 [CBIT](DEBUG): Disabling WDT.
2020-08-26T21:37:47.964Z,1598477867.964 [CBIT](DEBUG): Opening all GF detection circuits.
2020-08-26T21:37:47.965Z,1598477867.965 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:48.058Z,1598477868.058 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:48.060Z,1598477868.060 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:48.065Z,1598477868.065 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:48.124Z,1598477868.124 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:48.127Z,1598477868.127 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:48.131Z,1598477868.131 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:48.140Z,1598477868.140 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-08-26T21:37:48.202Z,1598477868.202 [logger ThreadHandler](INFO): Thread cancelled.