2023-05-09T16:32:30.699Z,1683649950.699 [Supervisor](DEBUG): Initializing supervisor.
2023-05-09T16:32:30.703Z,1683649950.703 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-05-09T16:32:30.704Z,1683649950.704 [SyncHandler](INFO): Protected caller Thread ID is 5095
2023-05-09T16:32:30.704Z,1683649950.704 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-05-09T16:32:30.705Z,1683649950.705 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-05-09T16:32:30.705Z,1683649950.705 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 5096
2023-05-09T16:32:30.709Z,1683649950.709 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-05-09T16:32:30.727Z,1683649950.727 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-05-09T16:32:30.727Z,1683649950.727 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-05-09T16:32:30.728Z,1683649950.728 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 5097
2023-05-09T16:32:30.732Z,1683649950.732 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-05-09T16:32:30.733Z,1683649950.733 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-05-09T16:32:30.733Z,1683649950.733 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 5098
2023-05-09T16:32:30.735Z,1683649950.735 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-05-09T16:32:30.740Z,1683649950.740 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-05-09T16:32:30.740Z,1683649950.740 [logger ThreadHandler](INFO): Protected caller Thread ID is 5099
2023-05-09T16:32:30.744Z,1683649950.744 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-05-09T16:32:30.744Z,1683649950.744 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-05-09T16:32:30.746Z,1683649950.746 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-05-09T16:32:31.343Z,1683649951.343 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-05-09T16:32:31.344Z,1683649951.344 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-05-09T16:32:31.548Z,1683649951.548 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-05-09T16:32:31.549Z,1683649951.549 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-05-09T16:32:31.626Z,1683649951.626 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-05-09T16:32:31.836Z,1683649951.836 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-05-09T16:32:31.836Z,1683649951.836 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-05-09T16:32:31.915Z,1683649951.915 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-05-09T16:32:32.008Z,1683649952.008 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-05-09T16:32:32.009Z,1683649952.009 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-05-09T16:32:32.329Z,1683649952.329 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-05-09T16:32:32.330Z,1683649952.330 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-05-09T16:32:32.457Z,1683649952.457 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-05-09T16:32:32.458Z,1683649952.458 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-05-09T16:32:32.937Z,1683649952.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-05-09T16:32:32.937Z,1683649952.937 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-05-09T16:32:33.112Z,1683649953.112 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-05-09T16:32:33.113Z,1683649953.113 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-05-09T16:32:33.491Z,1683649953.491 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-05-09T16:32:33.492Z,1683649953.492 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-05-09T16:32:33.760Z,1683649953.760 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-05-09T16:32:33.761Z,1683649953.761 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-05-09T16:32:33.867Z,1683649953.867 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-05-09T16:32:33.867Z,1683649953.867 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-05-09T16:32:34.730Z,1683649954.730 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-05-09T16:32:34.730Z,1683649954.730 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-05-09T16:32:35.244Z,1683649955.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-05-09T16:32:35.244Z,1683649955.244 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-05-09T16:32:35.455Z,1683649955.455 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-05-09T16:32:35.457Z,1683649955.457 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-05-09T16:32:35.458Z,1683649955.458 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-05-09T16:32:35.636Z,1683649955.636 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-05-09T16:32:35.718Z,1683649955.718 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-05-09T16:32:35.846Z,1683649955.846 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-05-09T16:32:35.929Z,1683649955.929 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-05-09T16:32:36.185Z,1683649956.185 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-05-09T16:32:36.186Z,1683649956.186 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-05-09T16:32:36.286Z,1683649956.286 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-05-09T16:32:36.395Z,1683649956.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-05-09T16:32:36.504Z,1683649956.504 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-05-09T16:32:36.647Z,1683649956.647 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-05-09T16:32:36.743Z,1683649956.743 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-05-09T16:32:36.834Z,1683649956.834 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2023-05-09T16:32:36.835Z,1683649956.835 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-05-09T16:32:36.848Z,1683649956.848 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-05-09T16:32:36.862Z,1683649956.862 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-05-09T16:32:36.862Z,1683649956.862 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-05-09T16:32:37.020Z,1683649957.020 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-05-09T16:32:37.021Z,1683649957.021 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-05-09T16:32:37.097Z,1683649957.097 [VerticalControl](DEBUG): Construct VerticalControl.
2023-05-09T16:32:37.156Z,1683649957.156 [VerticalControl] Loaded
2023-05-09T16:32:37.156Z,1683649957.156 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-05-09T16:32:37.159Z,1683649957.159 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-05-09T16:32:37.199Z,1683649957.199 [HorizontalControl] Loaded
2023-05-09T16:32:37.199Z,1683649957.199 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-05-09T16:32:37.201Z,1683649957.201 [SpeedControl](DEBUG): Construct SpeedControl.
2023-05-09T16:32:37.204Z,1683649957.204 [SpeedControl] Loaded
2023-05-09T16:32:37.205Z,1683649957.205 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-05-09T16:32:37.207Z,1683649957.207 [LoopControl](DEBUG): Construct LoopControl.
2023-05-09T16:32:37.208Z,1683649957.208 [LoopControl] Loaded
2023-05-09T16:32:37.208Z,1683649957.208 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-05-09T16:32:37.208Z,1683649957.208 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-05-09T16:32:37.209Z,1683649957.209 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-05-09T16:32:37.368Z,1683649957.368 [BuoyancyServo] Loaded
2023-05-09T16:32:37.368Z,1683649957.368 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-05-09T16:32:37.388Z,1683649957.388 [ElevatorServo] Loaded
2023-05-09T16:32:37.388Z,1683649957.388 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-05-09T16:32:37.407Z,1683649957.407 [MassServo] Loaded
2023-05-09T16:32:37.407Z,1683649957.407 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-05-09T16:32:37.425Z,1683649957.425 [RudderServo] Loaded
2023-05-09T16:32:37.425Z,1683649957.425 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-05-09T16:32:37.439Z,1683649957.439 [ThrusterHE] Loaded
2023-05-09T16:32:37.440Z,1683649957.440 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-05-09T16:32:37.440Z,1683649957.440 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-05-09T16:32:37.441Z,1683649957.441 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-05-09T16:32:37.502Z,1683649957.502 [DepthRateCalculator] Loaded
2023-05-09T16:32:37.502Z,1683649957.502 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-05-09T16:32:37.507Z,1683649957.507 [PitchRateCalculator] Loaded
2023-05-09T16:32:37.507Z,1683649957.507 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-05-09T16:32:37.517Z,1683649957.517 [SpeedCalculator] Loaded
2023-05-09T16:32:37.517Z,1683649957.517 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-05-09T16:32:37.521Z,1683649957.521 [YawRateCalculator] Loaded
2023-05-09T16:32:37.521Z,1683649957.521 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-05-09T16:32:37.539Z,1683649957.539 [ElevatorOffsetCalculator] Loaded
2023-05-09T16:32:37.540Z,1683649957.540 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-05-09T16:32:37.540Z,1683649957.540 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-05-09T16:32:37.541Z,1683649957.541 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-05-09T16:32:37.655Z,1683649957.655 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-05-09T16:32:37.655Z,1683649957.655 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-05-09T16:32:37.669Z,1683649957.669 [NavChart] Loaded
2023-05-09T16:32:37.669Z,1683649957.669 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-05-09T16:32:37.675Z,1683649957.675 [UniversalFixResidualReporter] Loaded
2023-05-09T16:32:37.675Z,1683649957.675 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-05-09T16:32:37.676Z,1683649957.676 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-05-09T16:32:37.676Z,1683649957.676 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-05-09T16:32:38.371Z,1683649958.371 [AHRS_M2] Loaded
2023-05-09T16:32:38.371Z,1683649958.371 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-05-09T16:32:38.626Z,1683649958.626 [BackseatComponent] Loaded
2023-05-09T16:32:38.626Z,1683649958.626 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-05-09T16:32:38.628Z,1683649958.628 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408E74E0
2023-05-09T16:32:38.628Z,1683649958.628 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 5182
2023-05-09T16:32:38.631Z,1683649958.631 [LcmUniversalReporter] Loaded
2023-05-09T16:32:38.631Z,1683649958.631 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-05-09T16:32:39.451Z,1683649959.451 [BPC1] Loaded
2023-05-09T16:32:39.452Z,1683649959.452 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-05-09T16:32:39.545Z,1683649959.545 [DataOverHttps] Loaded
2023-05-09T16:32:39.545Z,1683649959.545 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-05-09T16:32:39.546Z,1683649959.546 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409174E0
2023-05-09T16:32:39.547Z,1683649959.547 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 5183
2023-05-09T16:32:39.567Z,1683649959.567 [Depth_Keller] Loaded
2023-05-09T16:32:39.567Z,1683649959.567 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-05-09T16:32:39.629Z,1683649959.629 [NAL9602] Loaded
2023-05-09T16:32:39.629Z,1683649959.629 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-05-09T16:32:39.659Z,1683649959.659 [Onboard] Loaded
2023-05-09T16:32:39.659Z,1683649959.659 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-05-09T16:32:39.660Z,1683649959.660 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409474E0
2023-05-09T16:32:39.660Z,1683649959.660 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 5184
2023-05-09T16:32:39.674Z,1683649959.674 [Power24vConverter] Loaded
2023-05-09T16:32:39.674Z,1683649959.674 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-05-09T16:32:39.731Z,1683649959.731 [Radio_Surface] Loaded
2023-05-09T16:32:39.731Z,1683649959.731 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-05-09T16:32:39.752Z,1683649959.752 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409774E0
2023-05-09T16:32:39.752Z,1683649959.752 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 5185
2023-05-09T16:32:40.087Z,1683649960.087 [DATMMP] Loaded
2023-05-09T16:32:40.087Z,1683649960.087 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2023-05-09T16:32:40.089Z,1683649960.089 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 409A84E0
2023-05-09T16:32:40.089Z,1683649960.089 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 5186
2023-05-09T16:32:40.089Z,1683649960.089 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-05-09T16:32:40.090Z,1683649960.090 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-05-09T16:32:40.345Z,1683649960.345 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-05-09T16:32:40.345Z,1683649960.345 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-05-09T16:32:40.534Z,1683649960.534 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-05-09T16:32:40.534Z,1683649960.534 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-05-09T16:32:40.577Z,1683649960.577 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-05-09T16:32:40.578Z,1683649960.578 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-05-09T16:32:40.793Z,1683649960.793 [CTD_Seabird] Loaded
2023-05-09T16:32:40.793Z,1683649960.793 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-05-09T16:32:40.798Z,1683649960.798 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40ADE4E0
2023-05-09T16:32:40.798Z,1683649960.798 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 5187
2023-05-09T16:32:40.831Z,1683649960.831 [ESPComponent] Loaded
2023-05-09T16:32:40.832Z,1683649960.832 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-05-09T16:32:40.851Z,1683649960.851 [PAR_Licor] Loaded
2023-05-09T16:32:40.852Z,1683649960.852 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-05-09T16:32:40.882Z,1683649960.882 [WetLabsBB2FL] Loaded
2023-05-09T16:32:40.882Z,1683649960.882 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-05-09T16:32:40.883Z,1683649960.883 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B0E4E0
2023-05-09T16:32:40.884Z,1683649960.884 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 5188
2023-05-09T16:32:40.885Z,1683649960.885 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-05-09T16:32:40.885Z,1683649960.885 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-05-09T16:32:41.242Z,1683649961.242 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-05-09T16:32:41.242Z,1683649961.242 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-05-09T16:32:41.408Z,1683649961.408 [SBIT](DEBUG): Construct Startup Built In Test.
2023-05-09T16:32:41.418Z,1683649961.418 [SBIT] Loaded
2023-05-09T16:32:41.419Z,1683649961.419 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-05-09T16:32:41.421Z,1683649961.421 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-05-09T16:32:41.434Z,1683649961.434 [IBIT] Loaded
2023-05-09T16:32:41.434Z,1683649961.434 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-05-09T16:32:41.440Z,1683649961.440 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-05-09T16:32:41.543Z,1683649961.543 [CBIT] Loaded
2023-05-09T16:32:41.544Z,1683649961.544 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-05-09T16:32:41.544Z,1683649961.544 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-05-09T16:32:41.550Z,1683649961.550 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-05-09T16:32:41.553Z,1683649961.553 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-05-09T16:32:41.564Z,1683649961.564 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-05-09T16:32:41.571Z,1683649961.571 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40BF14E0
2023-05-09T16:32:41.571Z,1683649961.571 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 5189
2023-05-09T16:32:41.576Z,1683649961.576 [Supervisor](INFO): Main Thread ID is 5094
2023-05-09T16:32:41.576Z,1683649961.576 [Supervisor](DEBUG): Running supervisor.
2023-05-09T16:32:41.577Z,1683649961.577 [CommandExec ThreadHandler](INFO): Handler Thread ID is 5190
2023-05-09T16:32:41.577Z,1683649961.577 [CommandExec](INFO): Initializing the command executive.
2023-05-09T16:32:41.579Z,1683649961.579 [CommandLine ThreadHandler](INFO): Handler Thread ID is 5191
2023-05-09T16:32:41.581Z,1683649961.581 [controlThread ThreadHandler](INFO): Handler Thread ID is 5192
2023-05-09T16:32:41.582Z,1683649961.582 [controlThread](DEBUG): Initializing ControlThread
2023-05-09T16:32:41.582Z,1683649961.582 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-05-09T16:32:41.584Z,1683649961.584 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-05-09T16:32:41.585Z,1683649961.585 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-05-09T16:32:41.585Z,1683649961.585 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-05-09T16:32:41.587Z,1683649961.587 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-05-09T16:32:41.587Z,1683649961.587 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-05-09T16:32:41.587Z,1683649961.587 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-05-09T16:32:41.588Z,1683649961.588 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-05-09T16:32:41.588Z,1683649961.588 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-05-09T16:32:41.589Z,1683649961.589 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-05-09T16:32:41.590Z,1683649961.590 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-05-09T16:32:41.596Z,1683649961.596 [SBIT](INFO): Initialize SBIT Component.
2023-05-09T16:32:41.597Z,1683649961.597 [SBIT](IMPORTANT): git: 2023-01-24-38-g3a865bb8c
2023-05-09T16:32:41.597Z,1683649961.597 [SBIT](INFO): git hash: 3a865bb8cac9b788bcd3aa40e502ce5ce0bbf34f
2023-05-09T16:32:41.597Z,1683649961.597 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-05-09T16:32:41.598Z,1683649961.598 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Wed Mar 17 08:23:48 PDT 2021
2023-05-09T16:32:41.599Z,1683649961.599 [SBIT](INFO): Beginning SBIT in 81.000000 seconds.
2023-05-09T16:32:41.600Z,1683649961.600 [IBIT](INFO): Initialize IBIT Component.
2023-05-09T16:32:41.601Z,1683649961.601 [CBIT](DEBUG): Initialize CBIT Component.
2023-05-09T16:32:41.602Z,1683649961.602 [logger ThreadHandler](INFO): Handler Thread ID is 5193
2023-05-09T16:32:41.612Z,1683649961.612 [CBIT](DEBUG): Initialized mux pins.
2023-05-09T16:32:41.612Z,1683649961.612 [CBIT](DEBUG): Initializing the watchdog timer.
2023-05-09T16:32:41.620Z,1683649961.620 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 5194
2023-05-09T16:32:41.632Z,1683649961.632 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 5195
2023-05-09T16:32:41.633Z,1683649961.633 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-05-09T16:32:41.636Z,1683649961.636 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-05-09T16:32:41.637Z,1683649961.637 [CBIT](DEBUG): Initializing heartbeat.
2023-05-09T16:32:41.644Z,1683649961.644 [Onboard ThreadHandler](INFO): Handler Thread ID is 5196
2023-05-09T16:32:41.662Z,1683649961.662 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 5197
2023-05-09T16:32:41.684Z,1683649961.684 [DATMMP ThreadHandler](INFO): Handler Thread ID is 5198
2023-05-09T16:32:41.685Z,1683649961.685 [DATMMP](INFO): Start
2023-05-09T16:32:41.685Z,1683649961.685 [DATMMP](INFO): Powering up
2023-05-09T16:32:41.685Z,1683649961.685 [DATMMP](DEBUG): Initializing DATMMP.
2023-05-09T16:32:41.689Z,1683649961.689 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 5200
2023-05-09T16:32:41.690Z,1683649961.690 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-05-09T16:32:41.694Z,1683649961.694 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 5202
2023-05-09T16:32:41.696Z,1683649961.696 [WetLabsBB2FL](INFO): Powering up
2023-05-09T16:32:41.698Z,1683649961.698 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 5204
2023-05-09T16:32:41.703Z,1683649961.703 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-05-09T16:32:41.704Z,1683649961.704 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-05-09T16:32:41.704Z,1683649961.704 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-05-09T16:32:41.704Z,1683649961.704 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-05-09T16:32:41.705Z,1683649961.705 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-05-09T16:32:41.705Z,1683649961.705 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-05-09T16:32:41.705Z,1683649961.705 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-05-09T16:32:41.705Z,1683649961.705 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-05-09T16:32:41.708Z,1683649961.708 [CBIT](DEBUG): Deactivating GF circuits.
2023-05-09T16:32:41.708Z,1683649961.708 [CBIT](DEBUG): Deactivating emergency mode.
2023-05-09T16:32:41.744Z,1683649961.744 [CBIT](DEBUG): Backplane powered.
2023-05-09T16:32:41.745Z,1683649961.745 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-05-09T16:32:41.771Z,1683649961.771 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-09T16:32:41.806Z,1683649961.806 [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>


2023-05-09T16:32:41.807Z,1683649961.807 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-05-09T16:32:41.883Z,1683649961.883 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-05-09T16:32:41.896Z,1683649961.896 [Default:A.Wait](DEBUG): Construct Wait.
2023-05-09T16:32:41.898Z,1683649961.898 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-09T16:32:41.997Z,1683649961.997 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-05-09T16:32:41.000Z,1683649962.000 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-05-09T16:32:42.022Z,1683649962.022 [Default:E.Execute](DEBUG): Construct Execute.
2023-05-09T16:32:42.025Z,1683649962.025 [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="P4H">
                <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>


2023-05-09T16:32:42.030Z,1683649962.030 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-05-09T16:32:42.048Z,1683649962.048 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-05-09T16:32:42.068Z,1683649962.068 [Radio_Surface](INFO): Powering up
2023-05-09T16:32:42.130Z,1683649962.130 [Power24vConverter](INFO): Powering up.
2023-05-09T16:32:42.158Z,1683649962.158 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-05-09T16:32:42.164Z,1683649962.164 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-05-09T16:32:42.165Z,1683649962.165 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-05-09T16:32:42.172Z,1683649962.172 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-05-09T16:32:42.173Z,1683649962.173 [MassServo](DEBUG): Initializing EZServoServo.
2023-05-09T16:32:42.180Z,1683649962.180 [MassServo](DEBUG): Initializing MassServo.
2023-05-09T16:32:42.181Z,1683649962.181 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-09T16:32:42.228Z,1683649962.228 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-09T16:32:42.229Z,1683649962.229 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-05-09T16:32:42.292Z,1683649962.292 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-05-09T16:32:43.192Z,1683649963.192 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2023-05-09T16:32:43.192Z,1683649963.192 [RudderServo](FAULT): Rudder failed to initialize
2023-05-09T16:32:43.192Z,1683649963.192 [RudderServo] Communications Fault, FailCount= 1
2023-05-09T16:32:43.192Z,1683649963.192 [RudderServo](ERROR): Communications Fault
2023-05-09T16:32:43.197Z,1683649963.197 [CBIT](ERROR): Communications Fault in component: RudderServo
2023-05-09T16:32:43.393Z,1683649963.393 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-09T16:32:43.393Z,1683649963.393 [RudderServo](INFO): Powering down
2023-05-09T16:32:43.804Z,1683649963.804 [WetLabsBB2FL](INFO): Powering down
2023-05-09T16:32:44.117Z,1683649964.117 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-09T16:32:44.237Z,1683649964.237 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-09T16:32:44.241Z,1683649964.241 [CBIT](INFO): Clearing failed state for component RudderServo
2023-05-09T16:32:44.241Z,1683649964.241 [RudderServo] No Fault, FailCount= 1
2023-05-09T16:32:48.073Z,1683649968.073 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-05-09T16:32:53.781Z,1683649973.781 [DATMMP](INFO): DAT read: 

2023-05-09T16:32:53.781Z,1683649973.781 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-05-09T16:32:54.358Z,1683649974.358 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004622
2023-05-09T16:32:55.545Z,1683649975.545 [DATMMP](INFO): DAT read: MF Frequency Band

2023-05-09T16:32:55.546Z,1683649975.546 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-05-09T16:32:55.546Z,1683649975.546 [DATMMP](INFO): DAT read: Apr  5 2000 20:58:26 

2023-05-09T16:32:56.805Z,1683649976.805 [DATMMP](INFO): DAT read: Features enabled [Bearing]

2023-05-09T16:32:56.806Z,1683649976.806 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-09T16:32:56.806Z,1683649976.806 [DATMMP](INFO): commRate: 800
2023-05-09T16:32:58.872Z,1683649978.872 [DATMMP](INFO): entering command mode
2023-05-09T16:32:59.072Z,1683649979.072 [DATMMP](INFO): DAT read: 

2023-05-09T16:32:59.073Z,1683649979.073 [DATMMP](INFO): DAT read: user:1>

2023-05-09T16:32:59.073Z,1683649979.073 [DATMMP](DEBUG): read user prompt 1: user:1>

2023-05-09T16:32:59.073Z,1683649979.073 [DATMMP](INFO): entering MMP mode
2023-05-09T16:32:59.325Z,1683649979.325 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:32:59.326Z,1683649979.326 [DATMMP](INFO): status rx: 	 x1
2023-05-09T16:32:59.327Z,1683649979.327 [DATMMP](INFO): MMP status: 1: started
2023-05-09T16:32:59.327Z,1683649979.327 [DATMMP](INFO): Received message type: status
2023-05-09T16:32:59.327Z,1683649979.327 [DATMMP](INFO): Handled
2023-05-09T16:32:59.577Z,1683649979.577 [DATMMP](INFO): Sent Tx Power Config 8
2023-05-09T16:32:59.578Z,1683649979.578 [DATMMP](INFO): Setting local address: 5
2023-05-09T16:32:59.585Z,1683649979.585 [DATMMP](INFO): Setting time to: 16:32:59 And date to:5/9/2023
2023-05-09T16:32:59.828Z,1683649979.828 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:32:59.829Z,1683649979.829 [DATMMP](INFO): mdmpower rx: 	 x8	 x0	 x5	 x0
2023-05-09T16:32:59.829Z,1683649979.829 [DATMMP](INFO): Received message type: mdmpower
2023-05-09T16:32:59.830Z,1683649979.830 [DATMMP](INFO): Handled
2023-05-09T16:33:00.080Z,1683649980.080 [DATMMP](INFO): GSXN notify for xid: 10
2023-05-09T16:33:00.081Z,1683649980.081 [DATMMP](INFO): sreg_txpower rx: 	 x8
2023-05-09T16:33:00.081Z,1683649980.081 [DATMMP](INFO): Received message type: sreg_txpower
2023-05-09T16:33:00.082Z,1683649980.082 [DATMMP](INFO): Match for : sreg_txpower
2023-05-09T16:33:00.082Z,1683649980.082 [DATMMP](INFO): ACK
2023-05-09T16:33:00.332Z,1683649980.332 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:33:00.333Z,1683649980.333 [DATMMP](INFO): mdmlocal rx: 	 x5	 x0	 x0	 x0
2023-05-09T16:33:00.334Z,1683649980.334 [DATMMP](INFO): Received message type: mdmlocal
2023-05-09T16:33:00.334Z,1683649980.334 [DATMMP](INFO): Handled
2023-05-09T16:33:00.585Z,1683649980.585 [DATMMP](INFO): GSXN notify for xid: 11
2023-05-09T16:33:00.585Z,1683649980.585 [DATMMP](INFO): sreg_locaddr rx: 	 x5
2023-05-09T16:33:00.585Z,1683649980.585 [DATMMP](INFO): Received message type: sreg_locaddr
2023-05-09T16:33:00.586Z,1683649980.586 [DATMMP](INFO): Match for : sreg_locaddr
2023-05-09T16:33:00.586Z,1683649980.586 [DATMMP](INFO): ACK
2023-05-09T16:33:00.836Z,1683649980.836 [DATMMP](INFO): GSXN notify for xid: 12
2023-05-09T16:33:00.838Z,1683649980.838 [DATMMP](INFO): timedate rx: 	 x0	 x10	 x20	 x3B	 x4	 x9	 x7B	 x0
2023-05-09T16:33:00.838Z,1683649980.838 [DATMMP](INFO): Received message type: timedate
2023-05-09T16:33:00.838Z,1683649980.838 [DATMMP](INFO): Match for : timedate
2023-05-09T16:33:00.838Z,1683649980.838 [DATMMP](INFO): ACK
2023-05-09T16:33:01.088Z,1683649981.088 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:33:01.089Z,1683649981.089 [DATMMP](INFO): sys_verb rx: 	 x0	 x0	 x0	 x0
2023-05-09T16:33:01.089Z,1683649981.089 [DATMMP](INFO): Received message type: sys_verb
2023-05-09T16:33:01.089Z,1683649981.089 [DATMMP](INFO): Handled
2023-05-09T16:33:01.340Z,1683649981.340 [DATMMP](INFO): GSXN notify for xid: 13
2023-05-09T16:33:01.341Z,1683649981.341 [DATMMP](INFO): sreg_verbosity rx: 	 x0
2023-05-09T16:33:01.341Z,1683649981.341 [DATMMP](INFO): Received message type: sreg_verbosity
2023-05-09T16:33:01.341Z,1683649981.341 [DATMMP](INFO): Match for : sreg_verbosity
2023-05-09T16:33:01.341Z,1683649981.341 [DATMMP](INFO): ACK
2023-05-09T16:33:01.592Z,1683649981.592 [DATMMP](INFO): GSXN notify for xid: 14
2023-05-09T16:33:01.593Z,1683649981.593 [DATMMP](INFO): version rx: 	 x2	 x5
2023-05-09T16:33:01.593Z,1683649981.593 [DATMMP](INFO): DatMMPVersion: 2.5
2023-05-09T16:33:01.594Z,1683649981.594 [DATMMP](INFO): Received message type: version
2023-05-09T16:33:01.594Z,1683649981.594 [DATMMP](INFO): Match for : version
2023-05-09T16:33:01.594Z,1683649981.594 [DATMMP](INFO): ACK
2023-05-09T16:33:01.594Z,1683649981.594 [DATMMP](INFO): in MMP mode: config complete going to runnable
2023-05-09T16:33:09.965Z,1683649989.965 [NAL9602](INFO): Powering up NAL9602
2023-05-09T16:33:16.221Z,1683649996.221 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:33:16.222Z,1683649996.222 [DATMMP](INFO): timesync rx: 	 x0	 x1	 x1	 x0
2023-05-09T16:33:16.222Z,1683649996.222 [DATMMP](INFO): Received message type: timesync
2023-05-09T16:33:16.222Z,1683649996.222 [DATMMP](INFO): Handled
2023-05-09T16:33:20.874Z,1683650000.874 [NAL9602](INFO): NAL9602 initialized
2023-05-09T16:33:26.065Z,1683650006.065 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:33:26.066Z,1683650006.066 [DATMMP](INFO): timesync rx: 	 x1	 x0	 x1	 x0
2023-05-09T16:33:26.066Z,1683650006.066 [DATMMP](INFO): Received message type: timesync
2023-05-09T16:33:26.066Z,1683650006.066 [DATMMP](INFO): Handled
2023-05-09T16:34:03.323Z,1683650043.323 [SBIT](IMPORTANT): Beginning Startup BIT
2023-05-09T16:34:03.328Z,1683650043.328 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-09T16:34:14.244Z,1683650054.244 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.010327
CHAN A1 (24V): -0.007754
CHAN A2 (12V): -0.004681
CHAN A3 (5V): -0.002767
CHAN B0 (3.3V): -0.000505
CHAN B1 (3.15aV): -0.001184
CHAN B2 (3.15bV): -0.001390
CHAN B3 (GND): 0.000199
OPEN: 0.004567
Full Scale: +/- 1 mA
2023-05-09T16:34:57.078Z,1683650097.078 [SBIT](IMPORTANT): SBIT PASSED
2023-05-09T16:34:57.078Z,1683650097.078 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-05-09T16:34:57.079Z,1683650097.079 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2023-05-09T16:34:57.079Z,1683650097.079 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;

2023-05-09T16:34:57.079Z,1683650097.079 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2023-05-09T16:34:57.079Z,1683650097.079 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2023-05-09T16:34:57.079Z,1683650097.079 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2023-05-09T16:34:57.080Z,1683650097.080 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2023-05-09T16:34:57.080Z,1683650097.080 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-09T16:34:57.080Z,1683650097.080 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-09T16:34:57.080Z,1683650097.080 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;

2023-05-09T16:34:57.080Z,1683650097.080 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=184.896478 cubic_centimeter;

2023-05-09T16:34:57.080Z,1683650097.080 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;

2023-05-09T16:34:57.081Z,1683650097.081 [SBIT](IMPORTANT): VerticalControl.massDefault=15.484465 millimeter;

2023-05-09T16:34:57.473Z,1683650097.473 [MissionManager](IMPORTANT): Started mission Startup
2023-05-09T16:34:57.473Z,1683650097.473 [Startup] Running Loop=1
2023-05-09T16:34:57.473Z,1683650097.473 [Startup](DEBUG): Aggregate::initialize Startup
2023-05-09T16:34:57.473Z,1683650097.473 [Startup:A.GoToSurface] Running Loop=1
2023-05-09T16:34:57.474Z,1683650097.474 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-09T16:34:57.474Z,1683650097.474 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-09T16:34:57.474Z,1683650097.474 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-09T16:34:57.475Z,1683650097.475 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-09T16:34:57.475Z,1683650097.475 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-09T16:34:57.475Z,1683650097.475 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-09T16:34:57.477Z,1683650097.477 [Startup:StartupSatComms] Running Loop=1
2023-05-09T16:34:57.477Z,1683650097.477 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-05-09T16:34:57.477Z,1683650097.477 [Startup:StartupSatComms:A] Running Loop=1
2023-05-09T16:34:57.863Z,1683650097.863 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-05-09T16:35:10.764Z,1683650110.764 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:35:24.495Z,1683650124.495 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:35:38.230Z,1683650138.230 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:35:41.893Z,1683650141.893 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-05-09T16:35:41.893Z,1683650141.893 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-05-09T16:35:41.942Z,1683650141.942 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-05-09T16:35:42.302Z,1683650142.302 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-05-09T16:35:42.302Z,1683650142.302 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-05-09T16:35:51.562Z,1683650151.562 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:35:57.637Z,1683650157.637 [Startup:StartupSatComms:A](INFO): Timed out from 2023-05-09T16:34:57.5Z
2023-05-09T16:35:57.637Z,1683650157.637 [Startup:StartupSatComms:A] Stopped
2023-05-09T16:35:57.637Z,1683650157.637 [Startup:StartupSatComms:B] Running Loop=1
2023-05-09T16:35:58.047Z,1683650158.047 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-09T16:36:04.491Z,1683650164.491 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:36:04.885Z,1683650164.885 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230505T202828/Courier0004.lzma
2023-05-09T16:36:05.886Z,1683650165.886 [DataOverHttps](INFO): Moved sent file to Logs/20230505T202828/Courier0004.lzma.bak
2023-05-09T16:36:05.886Z,1683650165.886 [DataOverHttps](INFO): SBD MOMSN=18283268
2023-05-09T16:36:18.226Z,1683650178.226 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:36:21.356Z,1683650181.356 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20230509T163230/Courier0000.lzma
2023-05-09T16:36:22.358Z,1683650182.358 [DataOverHttps](INFO): Moved sent file to Logs/20230509T163230/Courier0000.lzma.bak
2023-05-09T16:36:22.358Z,1683650182.358 [DataOverHttps](INFO): SBD MOMSN=18283275
2023-05-09T16:36:31.559Z,1683650191.559 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:36:39.347Z,1683650199.347 [DataOverHttps](INFO): Sending 1253 bytes from file Logs/20230505T202828/Express0001.lzma
2023-05-09T16:36:40.346Z,1683650200.346 [DataOverHttps](INFO): Moved sent file to Logs/20230505T202828/Express0001.lzma.bak
2023-05-09T16:36:40.346Z,1683650200.346 [DataOverHttps](INFO): SBD MOMSN=18283283
2023-05-09T16:36:45.295Z,1683650205.295 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:36:57.174Z,1683650217.174 [DataOverHttps](INFO): Sending 435 bytes from file Logs/20230505T202828/Express0005.lzma
2023-05-09T16:36:57.851Z,1683650217.851 [Startup:StartupSatComms:B](INFO): Timed out from 2023-05-09T16:35:57.6Z
2023-05-09T16:36:57.851Z,1683650217.851 [Startup:StartupSatComms:B] Stopped
2023-05-09T16:36:57.851Z,1683650217.851 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-05-09T16:36:57.851Z,1683650217.851 [Startup:StartupSatComms] Stopped
2023-05-09T16:36:57.851Z,1683650217.851 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-05-09T16:36:57.852Z,1683650217.852 [Startup](INFO): Completed Startup
2023-05-09T16:36:57.853Z,1683650217.853 [MissionManager](INFO): Startup is completed.
2023-05-09T16:36:57.853Z,1683650217.853 [MissionManager](INFO): Uninitializing Mission Startup
2023-05-09T16:36:57.853Z,1683650217.853 [Startup] Stopped
2023-05-09T16:36:57.853Z,1683650217.853 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-05-09T16:36:57.853Z,1683650217.853 [Startup:A.GoToSurface] Stopped
2023-05-09T16:36:57.853Z,1683650217.853 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-09T16:36:58.170Z,1683650218.170 [DataOverHttps](INFO): Moved sent file to Logs/20230505T202828/Express0005.lzma.bak
2023-05-09T16:36:58.170Z,1683650218.170 [DataOverHttps](INFO): SBD MOMSN=18283318
2023-05-09T16:36:58.307Z,1683650218.307 [MissionManager](IMPORTANT): Started mission Default
2023-05-09T16:36:58.307Z,1683650218.307 [Default] Running Loop=1
2023-05-09T16:36:58.308Z,1683650218.308 [Default](DEBUG): Aggregate::initialize Default
2023-05-09T16:36:58.308Z,1683650218.308 [Default:B.GoToSurface] Running Loop=1
2023-05-09T16:36:58.308Z,1683650218.308 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-09T16:36:58.308Z,1683650218.308 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-09T16:36:58.308Z,1683650218.308 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-09T16:36:58.309Z,1683650218.309 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-09T16:36:58.309Z,1683650218.309 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-09T16:36:58.309Z,1683650218.309 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-09T16:36:58.310Z,1683650218.310 [Default:A.Wait] Running Loop=1
2023-05-09T16:36:58.310Z,1683650218.310 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-09T16:36:58.626Z,1683650218.626 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:37:11.625Z,1683650231.625 [Default:A.Wait](INFO): Done Waiting.
2023-05-09T16:37:11.625Z,1683650231.625 [Default:A.Wait] Stopped
2023-05-09T16:37:11.625Z,1683650231.625 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-09T16:37:11.959Z,1683650231.959 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:37:11.995Z,1683650231.995 [Default:CheckIn] Running Loop=1
2023-05-09T16:37:11.995Z,1683650231.995 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-09T16:37:11.995Z,1683650231.995 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-09T16:37:12.400Z,1683650232.400 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-05-09T16:37:25.290Z,1683650245.290 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2023-05-09T16:38:24.686Z,1683650304.686 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-09T16:38:31.246Z,1683650311.246 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.8 degree
2023-05-09T16:38:31.262Z,1683650311.262 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2023-05-09T16:38:31.263Z,1683650311.263 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.9 degree
2023-05-09T16:38:31.266Z,1683650311.266 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2023-05-09T16:38:31.267Z,1683650311.267 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.8 meter
2023-05-09T16:38:31.270Z,1683650311.270 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2023-05-09T16:38:31.638Z,1683650311.638 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BPC1,Depth_Keller,NAL9602,Power24vConverter,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,Maintain_NAL9602.latitude_fix,Maintain_NAL9602.longitude_fix,Maintain_Depth_Keller.depth,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterHE,SBIT,IBIT,CBIT,LcmUniversalReporter,Reporter,LogSplitter,
2023-05-09T16:38:44.162Z,1683650324.162 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1683650311 second
2023-05-09T16:38:44.546Z,1683650324.546 [Default:CheckIn:Read_GPS] Stopped
2023-05-09T16:38:44.547Z,1683650324.547 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-09T16:38:44.909Z,1683650324.909 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-09T16:38:51.519Z,1683650331.519 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20230509T163230/Courier0004.lzma
2023-05-09T16:38:53.024Z,1683650333.024 [DataOverHttps](INFO): Moved sent file to Logs/20230509T163230/Courier0004.lzma.bak
2023-05-09T16:38:53.025Z,1683650333.025 [DataOverHttps](INFO): SBD MOMSN=18283335
2023-05-09T16:39:09.982Z,1683650349.982 [CommandExec](IMPORTANT): got command report touch DATMMP.acoustic_contact_range
2023-05-09T16:39:11.494Z,1683650351.494 [DataOverHttps](INFO): Sending 1019 bytes from file Logs/20230509T163230/Express0001.lzma
2023-05-09T16:39:12.494Z,1683650352.494 [DataOverHttps](INFO): Moved sent file to Logs/20230509T163230/Express0001.lzma.bak
2023-05-09T16:39:12.494Z,1683650352.494 [DataOverHttps](INFO): SBD MOMSN=18283339
2023-05-09T16:39:15.998Z,1683650355.998 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-09T16:39:20.806Z,1683650360.806 [CommandExec](IMPORTANT): got command get 
2023-05-09T16:39:20.806Z,1683650360.806 [CommandExec](FAULT): Incomplete syntax. Try: help get
2023-05-09T16:39:25.631Z,1683650365.631 [CommandExec](IMPORTANT): got command get DATMMP.loadAtStartup
2023-05-09T16:39:25.632Z,1683650365.632 [CommandExec](IMPORTANT): DATMMP.loadAtStartup 1 bool
2023-05-09T16:39:30.976Z,1683650370.976 [DataOverHttps](INFO): Sending 465 bytes from file Logs/20230509T163230/Express0005.lzma
2023-05-09T16:39:32.847Z,1683650372.847 [DataOverHttps](INFO): Moved sent file to Logs/20230509T163230/Express0005.lzma.bak
2023-05-09T16:39:32.848Z,1683650372.848 [DataOverHttps](INFO): SBD MOMSN=18283371
2023-05-09T16:39:34.641Z,1683650374.641 [Default:CheckIn:Read_Iridium] Stopped
2023-05-09T16:39:34.641Z,1683650374.641 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-09T16:39:34.641Z,1683650374.641 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-09T16:40:08.929Z,1683650408.929 [BPC1](INFO): Calculating totals. Valid battery stick count: 53. Valid reserve battery stick count: 5.
2023-05-09T16:40:08.952Z,1683650408.952 [BPC1](INFO): Received data from all battery sticks.
2023-05-09T16:40:19.929Z,1683650419.929 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-09T16:40:19.929Z,1683650419.929 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-09T16:40:20.004Z,1683650420.004 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 9.000000 count
2023-05-09T16:40:20.007Z,1683650420.007 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m
2023-05-09T16:40:20.009Z,1683650420.009 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s
2023-05-09T16:40:20.012Z,1683650420.012 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count
2023-05-09T16:40:20.015Z,1683650420.015 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count
2023-05-09T16:40:20.018Z,1683650420.018 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count
2023-05-09T16:40:20.021Z,1683650420.021 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min
2023-05-09T16:40:20.024Z,1683650420.024 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum
2023-05-09T16:40:20.027Z,1683650420.027 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum
2023-05-09T16:40:20.030Z,1683650420.030 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum
2023-05-09T16:40:20.163Z,1683650420.163 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait.
2023-05-09T16:40:20.205Z,1683650420.205 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Units="Tethys/Units"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                        Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                        Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd"
    Id="senddata_direct_and_track_test">


    <DefineArg Name="AcousticTargetContactLabel"><Description>
        The acoustic address of the asset to be tracked. 21 is waveglider Tiny
    </Description><Units:count/><Value>9</Value></DefineArg>

    <DefineArg Name="AcousticTargetDepth"><Description>
        Depth of acoustic target if known and fixed (or nearly fixed). For
        example, if the acoustic target is a Wave Glider, set it to zero. This
        will improve 2D projected position estimates in the Earth reference
        frame. Defaults to NaN.
    </Description><Units:meter/><Value>0</Value></DefineArg>

    <DefineArg Name="TrackingUpdatePeriod"><Description>
        How long to wait between acoustic queries
    </Description><Units:second/><Value>15</Value></DefineArg>

    <DefineArg Name="NumberOfPings"><Description>
        Number of return pings to request with each acoustic query (more than 1
        will activate oneway mode)
    </Description><Units:count/><Value>1</Value></DefineArg>    

    <DefineArg Name="NumberOfFixesLowPass"><Description>
        Number of fixes to average to produce smoothed lat/lon/dep output
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="NumberOfStartingFixesToIgnore"><Description>
        Number of fixes to ignore at the start of mission (as the vehicle just
        leaves surface, contact's location estimate especailly bearing can be
        erroneous. Initialized to 8, corresponding to 2 minutes if query
        interval TrackingUpdatePeriod = 15 s.
    </Description><Units:count/><Value>2</Value></DefineArg>
    
    <DefineArg Name="AcommsInterval"><Description></Description><Units:minute/><Value>1</Value></DefineArg>    
    
    <DefineArg Name="modemId1"><Description>
        Modem ID1.
    </Description><Units:enum/><Value>9</Value></DefineArg>

    <DefineArg Name="modemId2"><Description>
        Modem ID2.
    </Description><Units:enum/><Value>5</Value></DefineArg>

    <DefineOutput Name="ModemID"><Description>
        Modem ID. Set to modemId1 or modemId2. Initialized to 1.
    </Description><Units:enum/><Value>1</Value></DefineOutput>            


    <Estimation:TrackAcousticContact Id="TrackAC">
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="AcousticTargetContactLabel"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>



    <Aggregate Id="DirectData">
    <Sequence Repeat="4"/>
    
      <Guidance:Wait>
          <Sequence/>
          <Setting><Guidance:Wait.duration/><Arg Name="AcommsInterval"/></Setting>
      </Guidance:Wait>
                  
      <SendData Service="Direct" Destination="modem:9:_.pressure">
          <Sensor:Onboard.Pressure/><Units:atmosphere/>
      </SendData>
    
      <SendData Service="Direct" Destination="modem:9:_.temperature">
          <Sensor:Onboard.Temperature/><Units:celsius/>
      </SendData>
    
      <SendData Service="Direct" Destination="modem:9:_.humidity">
          <Sensor:Onboard.Humidity/><Units:percent/>
      </SendData>
    
    </Aggregate>

</Mission>


2023-05-09T16:40:20.207Z,1683650420.207 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-09T16:40:20.280Z,1683650420.280 [Default] Stopped
2023-05-09T16:40:20.292Z,1683650420.292 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-09T16:40:20.292Z,1683650420.292 [Default:B.GoToSurface] Stopped
2023-05-09T16:40:20.292Z,1683650420.292 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-09T16:40:20.292Z,1683650420.292 [Default:CheckIn] Stopped
2023-05-09T16:40:20.292Z,1683650420.292 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-09T16:40:20.292Z,1683650420.292 [Default:CheckIn:C.Wait] Stopped
2023-05-09T16:40:20.292Z,1683650420.292 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-09T16:40:20.293Z,1683650420.293 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test
2023-05-09T16:40:20.293Z,1683650420.293 [senddata_direct_and_track_test] Running Loop=1
2023-05-09T16:40:20.293Z,1683650420.293 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test
2023-05-09T16:40:20.293Z,1683650420.293 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-09T16:40:20.293Z,1683650420.293 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact.
2023-05-09T16:40:20.294Z,1683650420.294 [senddata_direct_and_track_test:DirectData] Running Loop=1
2023-05-09T16:40:20.294Z,1683650420.294 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-09T16:40:20.294Z,1683650420.294 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-09T16:40:20.294Z,1683650420.294 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-09T16:40:20.294Z,1683650420.294 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-09T16:40:32.917Z,1683650432.917 [CommandExec](IMPORTANT): got command report
2023-05-09T16:40:32.917Z,1683650432.917 [Reporter](INFO): DATMMP.acoustic_contact_range reporting when touched
2023-05-09T16:40:35.603Z,1683650435.603 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-09T16:40:35.772Z,1683650435.772 [DATMMP](INFO): ****** received valid address query ******
2023-05-09T16:40:35.773Z,1683650435.773 [DATMMP](INFO): ****** received valid ping request ******
2023-05-09T16:40:35.773Z,1683650435.773 [DATMMP](INFO): Querying Benthos address 9
2023-05-09T16:40:36.025Z,1683650436.025 [DATMMP](INFO): GSXN notify for xid: 15
2023-05-09T16:40:36.026Z,1683650436.026 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x0	 x2
2023-05-09T16:40:36.026Z,1683650436.026 [DATMMP](INFO): Progress on cmd
2023-05-09T16:40:36.026Z,1683650436.026 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:40:36.026Z,1683650436.026 [DATMMP](INFO): Handled
2023-05-09T16:40:36.026Z,1683650436.026 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:36.277Z,1683650436.277 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:36.278Z,1683650436.278 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x28	 x22	 xD58
2023-05-09T16:40:36.278Z,1683650436.278 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:40:36.278Z,1683650436.278 [DATMMP](INFO): Handled
2023-05-09T16:40:36.278Z,1683650436.278 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:36.529Z,1683650436.529 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:36.529Z,1683650436.529 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:40:36.529Z,1683650436.529 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:40:36.530Z,1683650436.530 [DATMMP](INFO): Handled
2023-05-09T16:40:36.530Z,1683650436.530 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:36.784Z,1683650436.784 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:37.036Z,1683650437.036 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:37.288Z,1683650437.288 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:37.540Z,1683650437.540 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:37.792Z,1683650437.792 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:38.044Z,1683650438.044 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:38.296Z,1683650438.296 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:38.548Z,1683650438.548 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:38.803Z,1683650438.803 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:38.809Z,1683650438.809 [DATMMP](INFO): doppler rx: 	 x0
2023-05-09T16:40:38.809Z,1683650438.809 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:40:38.809Z,1683650438.809 [DATMMP](INFO): Handled
2023-05-09T16:40:38.809Z,1683650438.809 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:39.057Z,1683650439.057 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:39.058Z,1683650439.058 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:40:39.058Z,1683650439.058 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:40:39.058Z,1683650439.058 [DATMMP](INFO): Handled
2023-05-09T16:40:39.058Z,1683650439.058 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:39.309Z,1683650439.309 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:39.310Z,1683650439.310 [DATMMP](INFO): directional_debug rx: 	 x9	 x1B9	 x22	 x12C	 xF50	 x1161	 x10E2	 x14C3
2023-05-09T16:40:39.311Z,1683650439.311 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:40:39.311Z,1683650439.311 [DATMMP](INFO): Handled
2023-05-09T16:40:39.311Z,1683650439.311 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:39.561Z,1683650439.561 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:39.562Z,1683650439.562 [DATMMP](INFO): directional rx: 	 x1	 x16C	 x5D3	 xFE47	 xC0B	 xFE4B	 x6E28	 x649	 x7	 xFFEF	 x27B5966	 x-43569E0
2023-05-09T16:40:39.564Z,1683650439.564 [DATMMP](INFO): Received message type: directional
2023-05-09T16:40:39.564Z,1683650439.564 [DATMMP](INFO): Handled
2023-05-09T16:40:39.565Z,1683650439.565 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:39.675Z,1683650439.675 [Reporter](INFO): DATMMP.acoustic_contact_range 2.820000 m
2023-05-09T16:40:39.813Z,1683650439.813 [DATMMP](INFO): GSXN notify for xid: 15
2023-05-09T16:40:39.814Z,1683650439.814 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x1	 x6
2023-05-09T16:40:39.814Z,1683650439.814 [DATMMP](INFO): Progress on cmd
2023-05-09T16:40:39.814Z,1683650439.814 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:40:39.814Z,1683650439.814 [DATMMP](INFO): Handled
2023-05-09T16:40:39.814Z,1683650439.814 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:40.065Z,1683650440.065 [DATMMP](INFO): GSXN notify for xid: 15
2023-05-09T16:40:40.065Z,1683650440.065 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x2	 x3
2023-05-09T16:40:40.066Z,1683650440.066 [DATMMP](ERROR): 3:COMPLETE
2023-05-09T16:40:40.066Z,1683650440.066 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:40:40.066Z,1683650440.066 [DATMMP](INFO): Handled
2023-05-09T16:40:40.066Z,1683650440.066 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:40.317Z,1683650440.317 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:40.317Z,1683650440.317 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:40:40.317Z,1683650440.317 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:40:40.318Z,1683650440.318 [DATMMP](INFO): Handled
2023-05-09T16:40:40.318Z,1683650440.318 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:40.568Z,1683650440.568 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:40.820Z,1683650440.820 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:41.072Z,1683650441.072 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:41.324Z,1683650441.324 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:41.576Z,1683650441.576 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:41.828Z,1683650441.828 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:42.081Z,1683650442.081 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:42.332Z,1683650442.332 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:42.584Z,1683650442.584 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:42.836Z,1683650442.836 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:43.088Z,1683650443.088 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:43.340Z,1683650443.340 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:43.592Z,1683650443.592 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:43.844Z,1683650443.844 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:44.101Z,1683650444.101 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:44.352Z,1683650444.352 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:44.604Z,1683650444.604 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:44.856Z,1683650444.856 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:45.108Z,1683650445.108 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:45.360Z,1683650445.360 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:45.612Z,1683650445.612 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:45.864Z,1683650445.864 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:46.116Z,1683650446.116 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:50.950Z,1683650450.950 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-09T16:40:51.164Z,1683650451.164 [DATMMP](INFO): ****** received valid address query ******
2023-05-09T16:40:51.164Z,1683650451.164 [DATMMP](INFO): ****** received valid ping request ******
2023-05-09T16:40:51.165Z,1683650451.165 [DATMMP](INFO): Querying Benthos address 9
2023-05-09T16:40:51.417Z,1683650451.417 [DATMMP](INFO): GSXN notify for xid: 16
2023-05-09T16:40:51.417Z,1683650451.417 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x0	 x2
2023-05-09T16:40:51.418Z,1683650451.418 [DATMMP](INFO): Progress on cmd
2023-05-09T16:40:51.418Z,1683650451.418 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:40:51.418Z,1683650451.418 [DATMMP](INFO): Handled
2023-05-09T16:40:51.418Z,1683650451.418 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:51.669Z,1683650451.669 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:51.669Z,1683650451.669 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:40:51.670Z,1683650451.670 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:40:51.670Z,1683650451.670 [DATMMP](INFO): Handled
2023-05-09T16:40:51.670Z,1683650451.670 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:51.921Z,1683650451.921 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:51.922Z,1683650451.922 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x28	 x31	 x1CF8
2023-05-09T16:40:51.922Z,1683650451.922 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:40:51.922Z,1683650451.922 [DATMMP](INFO): Handled
2023-05-09T16:40:51.922Z,1683650451.922 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:52.172Z,1683650452.172 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:52.424Z,1683650452.424 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:52.676Z,1683650452.676 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:52.928Z,1683650452.928 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:53.181Z,1683650453.181 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:53.432Z,1683650453.432 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:53.684Z,1683650453.684 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:53.936Z,1683650453.936 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:54.189Z,1683650454.189 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:54.189Z,1683650454.189 [DATMMP](INFO): doppler rx: 	 x0
2023-05-09T16:40:54.189Z,1683650454.189 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:40:54.190Z,1683650454.190 [DATMMP](INFO): Handled
2023-05-09T16:40:54.190Z,1683650454.190 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:54.441Z,1683650454.441 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:54.441Z,1683650454.441 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:40:54.441Z,1683650454.441 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:40:54.442Z,1683650454.442 [DATMMP](INFO): Handled
2023-05-09T16:40:54.442Z,1683650454.442 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:54.693Z,1683650454.693 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:54.694Z,1683650454.694 [DATMMP](INFO): directional_debug rx: 	 x7	 x19E	 x21	 x12D	 xF80	 x1161	 x1142	 x14B3
2023-05-09T16:40:54.695Z,1683650454.695 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:40:54.695Z,1683650454.695 [DATMMP](INFO): Handled
2023-05-09T16:40:54.695Z,1683650454.695 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:54.945Z,1683650454.945 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:54.946Z,1683650454.946 [DATMMP](INFO): directional rx: 	 xE0E	 x14E	 x5D5	 xFE62	 xC01	 xFE66	 x6E32	 x63B	 x5	 xFFEE	 x27B5966	 x-43569E0
2023-05-09T16:40:54.948Z,1683650454.948 [DATMMP](INFO): Received message type: directional
2023-05-09T16:40:54.948Z,1683650454.948 [DATMMP](INFO): Handled
2023-05-09T16:40:54.948Z,1683650454.948 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:55.045Z,1683650455.045 [Reporter](INFO): DATMMP.acoustic_contact_range 2.821000 m
2023-05-09T16:40:55.197Z,1683650455.197 [DATMMP](INFO): GSXN notify for xid: 16
2023-05-09T16:40:55.198Z,1683650455.198 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x1	 x6
2023-05-09T16:40:55.198Z,1683650455.198 [DATMMP](INFO): Progress on cmd
2023-05-09T16:40:55.198Z,1683650455.198 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:40:55.198Z,1683650455.198 [DATMMP](INFO): Handled
2023-05-09T16:40:55.198Z,1683650455.198 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:55.449Z,1683650455.449 [DATMMP](INFO): GSXN notify for xid: 16
2023-05-09T16:40:55.449Z,1683650455.449 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x2	 x3
2023-05-09T16:40:55.450Z,1683650455.450 [DATMMP](ERROR): 3:COMPLETE
2023-05-09T16:40:55.450Z,1683650455.450 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:40:55.450Z,1683650455.450 [DATMMP](INFO): Handled
2023-05-09T16:40:55.450Z,1683650455.450 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:55.701Z,1683650455.701 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:40:55.701Z,1683650455.701 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:40:55.701Z,1683650455.701 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:40:55.702Z,1683650455.702 [DATMMP](INFO): Handled
2023-05-09T16:40:55.702Z,1683650455.702 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:55.953Z,1683650455.953 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:56.205Z,1683650456.205 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:56.456Z,1683650456.456 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:56.708Z,1683650456.708 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:56.960Z,1683650456.960 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:57.212Z,1683650457.212 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:57.464Z,1683650457.464 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:57.716Z,1683650457.716 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:57.968Z,1683650457.968 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:58.220Z,1683650458.220 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:58.472Z,1683650458.472 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:58.724Z,1683650458.724 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:58.976Z,1683650458.976 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:59.228Z,1683650459.228 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:59.480Z,1683650459.480 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:59.732Z,1683650459.732 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:40:59.984Z,1683650459.984 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:00.237Z,1683650460.237 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:00.488Z,1683650460.488 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:00.740Z,1683650460.740 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:00.992Z,1683650460.992 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:01.244Z,1683650461.244 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:01.496Z,1683650461.496 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:01.748Z,1683650461.748 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:06.306Z,1683650466.306 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-09T16:41:06.544Z,1683650466.544 [DATMMP](INFO): ****** received valid address query ******
2023-05-09T16:41:06.545Z,1683650466.545 [DATMMP](INFO): ****** received valid ping request ******
2023-05-09T16:41:06.545Z,1683650466.545 [DATMMP](INFO): Querying Benthos address 9
2023-05-09T16:41:06.797Z,1683650466.797 [DATMMP](INFO): GSXN notify for xid: 17
2023-05-09T16:41:06.797Z,1683650466.797 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x0	 x2
2023-05-09T16:41:06.797Z,1683650466.797 [DATMMP](INFO): Progress on cmd
2023-05-09T16:41:06.798Z,1683650466.798 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:41:06.798Z,1683650466.798 [DATMMP](INFO): Handled
2023-05-09T16:41:06.798Z,1683650466.798 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:07.049Z,1683650467.049 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:07.049Z,1683650467.049 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:41:07.049Z,1683650467.049 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:41:07.050Z,1683650467.050 [DATMMP](INFO): Handled
2023-05-09T16:41:07.050Z,1683650467.050 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:07.301Z,1683650467.301 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:07.301Z,1683650467.301 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x29	 x5	 x587
2023-05-09T16:41:07.302Z,1683650467.302 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:41:07.302Z,1683650467.302 [DATMMP](INFO): Handled
2023-05-09T16:41:07.302Z,1683650467.302 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:07.552Z,1683650467.552 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:07.804Z,1683650467.804 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:08.056Z,1683650468.056 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:08.308Z,1683650468.308 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:08.560Z,1683650468.560 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:08.812Z,1683650468.812 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:09.064Z,1683650469.064 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:09.316Z,1683650469.316 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:09.569Z,1683650469.569 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:09.569Z,1683650469.569 [DATMMP](INFO): doppler rx: 	 x0
2023-05-09T16:41:09.569Z,1683650469.569 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:41:09.569Z,1683650469.569 [DATMMP](INFO): Handled
2023-05-09T16:41:09.570Z,1683650469.570 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:09.821Z,1683650469.821 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:09.821Z,1683650469.821 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:41:09.822Z,1683650469.822 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:41:09.822Z,1683650469.822 [DATMMP](INFO): Handled
2023-05-09T16:41:09.822Z,1683650469.822 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:10.073Z,1683650470.073 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:10.074Z,1683650470.074 [DATMMP](INFO): directional_debug rx: 	 xDDE	 x1C8	 x22	 x114	 xF70	 x1171	 x1112	 x14D3
2023-05-09T16:41:10.075Z,1683650470.075 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:41:10.075Z,1683650470.075 [DATMMP](INFO): Handled
2023-05-09T16:41:10.075Z,1683650470.075 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:10.325Z,1683650470.325 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:10.326Z,1683650470.326 [DATMMP](INFO): directional rx: 	 xDD6	 x180	 x60E	 xFE38	 xC26	 xFE3C	 x6E32	 x62A	 x4	 xFFEF	 x27B5966	 x-43569E0
2023-05-09T16:41:10.328Z,1683650470.328 [DATMMP](INFO): Received message type: directional
2023-05-09T16:41:10.329Z,1683650470.329 [DATMMP](INFO): Handled
2023-05-09T16:41:10.329Z,1683650470.329 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:10.404Z,1683650470.404 [Reporter](INFO): DATMMP.acoustic_contact_range 2.821000 m
2023-05-09T16:41:10.577Z,1683650470.577 [DATMMP](INFO): GSXN notify for xid: 17
2023-05-09T16:41:10.578Z,1683650470.578 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x1	 x6
2023-05-09T16:41:10.578Z,1683650470.578 [DATMMP](INFO): Progress on cmd
2023-05-09T16:41:10.578Z,1683650470.578 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:41:10.578Z,1683650470.578 [DATMMP](INFO): Handled
2023-05-09T16:41:10.578Z,1683650470.578 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:10.829Z,1683650470.829 [DATMMP](INFO): GSXN notify for xid: 17
2023-05-09T16:41:10.829Z,1683650470.829 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x2	 x3
2023-05-09T16:41:10.830Z,1683650470.830 [DATMMP](ERROR): 3:COMPLETE
2023-05-09T16:41:10.830Z,1683650470.830 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:41:10.830Z,1683650470.830 [DATMMP](INFO): Handled
2023-05-09T16:41:10.830Z,1683650470.830 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:11.081Z,1683650471.081 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:11.081Z,1683650471.081 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:41:11.082Z,1683650471.082 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:41:11.082Z,1683650471.082 [DATMMP](INFO): Handled
2023-05-09T16:41:11.082Z,1683650471.082 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:11.332Z,1683650471.332 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:11.584Z,1683650471.584 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:11.836Z,1683650471.836 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:12.088Z,1683650472.088 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:12.340Z,1683650472.340 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:12.592Z,1683650472.592 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:12.844Z,1683650472.844 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:13.096Z,1683650473.096 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:13.348Z,1683650473.348 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:13.600Z,1683650473.600 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:13.853Z,1683650473.853 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:14.105Z,1683650474.105 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:14.357Z,1683650474.357 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:14.609Z,1683650474.609 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:14.861Z,1683650474.861 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:15.113Z,1683650475.113 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:15.365Z,1683650475.365 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:15.616Z,1683650475.616 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:15.869Z,1683650475.869 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:16.123Z,1683650476.123 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:16.375Z,1683650476.375 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:16.628Z,1683650476.628 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:16.881Z,1683650476.881 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:17.134Z,1683650477.134 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:20.456Z,1683650480.456 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting.
2023-05-09T16:41:20.456Z,1683650480.456 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-09T16:41:20.456Z,1683650480.456 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-09T16:41:20.457Z,1683650480.457 [senddata_direct_and_track_test:DirectData:B] Running Loop=1
2023-05-09T16:41:20.869Z,1683650480.869 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:9:_.pressure
2023-05-09T16:41:20.869Z,1683650480.869 [senddata_direct_and_track_test:DirectData:B] Stopped
2023-05-09T16:41:20.869Z,1683650480.869 [senddata_direct_and_track_test:DirectData:C] Running Loop=1
2023-05-09T16:41:20.913Z,1683650480.913 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-09T16:41:20.914Z,1683650480.914 [DATMMP](INFO): modem://9: set _.pressure 0.742939 atmosphere
2023-05-09T16:41:20.914Z,1683650480.914 [DATMMP](INFO): #Outgoing data=1
2023-05-09T16:41:20.916Z,1683650480.916 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-09T16:41:21.165Z,1683650481.165 [DATMMP](INFO): GSXN notify for xid: 18
2023-05-09T16:41:21.166Z,1683650481.166 [DATMMP](INFO): depth rx: 	 x1	 x1	 x4	 x0
2023-05-09T16:41:21.166Z,1683650481.166 [DATMMP](INFO): Received message type: depth
2023-05-09T16:41:21.166Z,1683650481.166 [DATMMP](INFO): Match for : depth
2023-05-09T16:41:21.166Z,1683650481.166 [DATMMP](INFO): ACK
2023-05-09T16:41:21.166Z,1683650481.166 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-09T16:41:21.286Z,1683650481.286 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:9:_.temperature
2023-05-09T16:41:21.286Z,1683650481.286 [senddata_direct_and_track_test:DirectData:C] Stopped
2023-05-09T16:41:21.286Z,1683650481.286 [senddata_direct_and_track_test:DirectData:D] Running Loop=1
2023-05-09T16:41:21.418Z,1683650481.418 [DATMMP](INFO): GSXN notify for xid: 19
2023-05-09T16:41:21.419Z,1683650481.419 [DATMMP](INFO): lat rx: 	 x2318600	 x6	 x1	 x0
2023-05-09T16:41:21.419Z,1683650481.419 [DATMMP](INFO): Received message type: lat
2023-05-09T16:41:21.419Z,1683650481.419 [DATMMP](INFO): Match for : lat
2023-05-09T16:41:21.419Z,1683650481.419 [DATMMP](INFO): ACK
2023-05-09T16:41:21.419Z,1683650481.419 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-09T16:41:21.669Z,1683650481.669 [DATMMP](INFO): GSXN notify for xid: 20
2023-05-09T16:41:21.671Z,1683650481.671 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:9:_.humidity
2023-05-09T16:41:21.671Z,1683650481.671 [senddata_direct_and_track_test:DirectData:D] Stopped
2023-05-09T16:41:21.671Z,1683650481.671 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData
2023-05-09T16:41:21.671Z,1683650481.671 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-09T16:41:21.671Z,1683650481.671 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-09T16:41:21.672Z,1683650481.672 [senddata_direct_and_track_test:DirectData](INFO): Running loop #2
2023-05-09T16:41:21.672Z,1683650481.672 [senddata_direct_and_track_test:DirectData] Running Loop=2
2023-05-09T16:41:21.674Z,1683650481.674 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-09T16:41:21.674Z,1683650481.674 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-09T16:41:21.674Z,1683650481.674 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-09T16:41:21.675Z,1683650481.675 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-09T16:41:21.753Z,1683650481.753 [DATMMP](INFO): lon rx: 	 x0	 x6	 x1	 x0
2023-05-09T16:41:21.753Z,1683650481.753 [DATMMP](INFO): Received message type: lon
2023-05-09T16:41:21.753Z,1683650481.753 [DATMMP](INFO): Match for : lon
2023-05-09T16:41:21.753Z,1683650481.753 [DATMMP](INFO): ACK
2023-05-09T16:41:21.753Z,1683650481.753 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-09T16:41:21.753Z,1683650481.753 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-09T16:41:21.754Z,1683650481.754 [DATMMP](INFO): ****** received valid address query ******
2023-05-09T16:41:21.754Z,1683650481.754 [DATMMP](INFO): ****** received valid ping request ******
2023-05-09T16:41:21.754Z,1683650481.754 [DATMMP](INFO): Querying Benthos address 9
2023-05-09T16:41:21.921Z,1683650481.921 [DATMMP](INFO): GSXN notify for xid: 21
2023-05-09T16:41:21.922Z,1683650481.922 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x0	 x2
2023-05-09T16:41:21.922Z,1683650481.922 [DATMMP](INFO): Progress on cmd
2023-05-09T16:41:21.922Z,1683650481.922 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:41:21.922Z,1683650481.922 [DATMMP](INFO): Handled
2023-05-09T16:41:21.922Z,1683650481.922 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-09T16:41:21.923Z,1683650481.923 [DATMMP](INFO): Tx to 9 len 34 xid 22
2023-05-09T16:41:21.924Z,1683650481.924 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-09T16:41:21.924Z,1683650481.924 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-09T16:41:21.924Z,1683650481.924 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:22.173Z,1683650482.173 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:22.174Z,1683650482.174 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:41:22.174Z,1683650482.174 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:41:22.174Z,1683650482.174 [DATMMP](INFO): Handled
2023-05-09T16:41:22.174Z,1683650482.174 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-09T16:41:22.174Z,1683650482.174 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:22.425Z,1683650482.425 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:22.426Z,1683650482.426 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x29	 x14	 xD57
2023-05-09T16:41:22.426Z,1683650482.426 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:41:22.426Z,1683650482.426 [DATMMP](INFO): Handled
2023-05-09T16:41:22.426Z,1683650482.426 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-09T16:41:22.426Z,1683650482.426 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:22.681Z,1683650482.681 [DATMMP](INFO): GSXN notify for xid: 22
2023-05-09T16:41:22.682Z,1683650482.682 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-09T16:41:22.682Z,1683650482.682 [DATMMP](DEBUG): Command complete send
2023-05-09T16:41:22.682Z,1683650482.682 [DATMMP](ERROR): 1:COMPLETE
2023-05-09T16:41:22.682Z,1683650482.682 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:41:22.682Z,1683650482.682 [DATMMP](INFO): Handled
2023-05-09T16:41:22.683Z,1683650482.683 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:22.683Z,1683650482.683 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:22.933Z,1683650482.933 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:22.934Z,1683650482.934 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x29	 x14	 x1519
2023-05-09T16:41:22.934Z,1683650482.934 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:41:22.934Z,1683650482.934 [DATMMP](INFO): Handled
2023-05-09T16:41:22.934Z,1683650482.934 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:22.934Z,1683650482.934 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:23.185Z,1683650483.185 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:23.185Z,1683650483.185 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:23.437Z,1683650483.437 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:23.437Z,1683650483.437 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:23.695Z,1683650483.695 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:23.948Z,1683650483.948 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:23.949Z,1683650483.949 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:24.201Z,1683650484.201 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:24.201Z,1683650484.201 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:24.452Z,1683650484.452 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:24.453Z,1683650484.453 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:24.704Z,1683650484.704 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:24.705Z,1683650484.705 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:24.956Z,1683650484.956 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:24.957Z,1683650484.957 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:25.208Z,1683650485.208 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:25.209Z,1683650485.209 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:25.461Z,1683650485.461 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:25.461Z,1683650485.461 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:25.712Z,1683650485.712 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:25.713Z,1683650485.713 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:25.964Z,1683650485.964 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:25.965Z,1683650485.965 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:26.216Z,1683650486.216 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:26.217Z,1683650486.217 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:26.468Z,1683650486.468 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:26.469Z,1683650486.469 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:26.721Z,1683650486.721 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:26.721Z,1683650486.721 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:26.973Z,1683650486.973 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:26.973Z,1683650486.973 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:27.224Z,1683650487.224 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:27.225Z,1683650487.225 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:27.476Z,1683650487.476 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:27.476Z,1683650487.476 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:27.729Z,1683650487.729 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:27.729Z,1683650487.729 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:27.980Z,1683650487.980 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:27.981Z,1683650487.981 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:28.232Z,1683650488.232 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:28.233Z,1683650488.233 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:28.484Z,1683650488.484 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:28.484Z,1683650488.484 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:28.736Z,1683650488.736 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:28.737Z,1683650488.737 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:28.989Z,1683650488.989 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:28.989Z,1683650488.989 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:29.240Z,1683650489.240 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:29.241Z,1683650489.241 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:29.492Z,1683650489.492 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:29.493Z,1683650489.493 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:29.744Z,1683650489.744 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:29.745Z,1683650489.745 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:29.996Z,1683650489.996 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:29.996Z,1683650489.996 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:30.248Z,1683650490.248 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:30.249Z,1683650490.249 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:30.501Z,1683650490.501 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:30.501Z,1683650490.501 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:30.753Z,1683650490.753 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:30.753Z,1683650490.753 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:31.004Z,1683650491.004 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:31.004Z,1683650491.004 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:31.256Z,1683650491.256 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:31.257Z,1683650491.257 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:31.508Z,1683650491.508 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:31.509Z,1683650491.509 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:31.760Z,1683650491.760 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:32.012Z,1683650492.012 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:32.013Z,1683650492.013 [DATMMP](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2023-05-09T16:41:32.013Z,1683650492.013 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:32.264Z,1683650492.264 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-09T16:41:32.265Z,1683650492.265 [DATMMP](INFO): modem://9: set _.temperature 23.937250 celsius
2023-05-09T16:41:32.266Z,1683650492.266 [DATMMP](INFO): #Outgoing data=1
2023-05-09T16:41:32.266Z,1683650492.266 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-09T16:41:32.266Z,1683650492.266 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-09T16:41:32.266Z,1683650492.266 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:32.516Z,1683650492.516 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-09T16:41:32.517Z,1683650492.517 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-09T16:41:32.517Z,1683650492.517 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:32.769Z,1683650492.769 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-09T16:41:32.769Z,1683650492.769 [DATMMP](INFO): Tx to 9 len 34 xid 23
2023-05-09T16:41:32.770Z,1683650492.770 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-09T16:41:32.770Z,1683650492.770 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-09T16:41:32.770Z,1683650492.770 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:33.021Z,1683650493.021 [DATMMP](INFO): GSXN notify for xid: 23
2023-05-09T16:41:33.021Z,1683650493.021 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-09T16:41:33.022Z,1683650493.022 [DATMMP](DEBUG): Command complete send
2023-05-09T16:41:33.022Z,1683650493.022 [DATMMP](ERROR): 1:COMPLETE
2023-05-09T16:41:33.022Z,1683650493.022 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:41:33.022Z,1683650493.022 [DATMMP](INFO): Handled
2023-05-09T16:41:33.022Z,1683650493.022 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:33.273Z,1683650493.273 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:33.274Z,1683650493.274 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x29	 x1F	 xF3C
2023-05-09T16:41:33.274Z,1683650493.274 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:41:33.274Z,1683650493.274 [DATMMP](INFO): Handled
2023-05-09T16:41:33.274Z,1683650493.274 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:33.274Z,1683650493.274 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:33.525Z,1683650493.525 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:33.525Z,1683650493.525 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:33.779Z,1683650493.779 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:34.033Z,1683650494.033 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:34.033Z,1683650494.033 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:34.285Z,1683650494.285 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:34.285Z,1683650494.285 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:34.536Z,1683650494.536 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:34.537Z,1683650494.537 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:34.788Z,1683650494.788 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:34.789Z,1683650494.789 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:35.040Z,1683650495.040 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:35.041Z,1683650495.041 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:35.293Z,1683650495.293 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:35.293Z,1683650495.293 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:35.545Z,1683650495.545 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:35.545Z,1683650495.545 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:35.796Z,1683650495.796 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:35.796Z,1683650495.796 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:36.049Z,1683650496.049 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:36.049Z,1683650496.049 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:36.301Z,1683650496.301 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:36.301Z,1683650496.301 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:36.553Z,1683650496.553 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:36.553Z,1683650496.553 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:36.805Z,1683650496.805 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:36.806Z,1683650496.806 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:41:36.806Z,1683650496.806 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:41:36.806Z,1683650496.806 [DATMMP](INFO): Handled
2023-05-09T16:41:36.806Z,1683650496.806 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:36.806Z,1683650496.806 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:37.057Z,1683650497.057 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:37.141Z,1683650497.141 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-09T16:41:37.308Z,1683650497.308 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:37.309Z,1683650497.309 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:37.560Z,1683650497.560 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:37.561Z,1683650497.561 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:37.813Z,1683650497.813 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:37.813Z,1683650497.813 [DATMMP](INFO): doppler rx: 	 x0
2023-05-09T16:41:37.813Z,1683650497.813 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:41:37.814Z,1683650497.814 [DATMMP](INFO): Handled
2023-05-09T16:41:37.814Z,1683650497.814 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:37.814Z,1683650497.814 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:38.064Z,1683650498.064 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:38.065Z,1683650498.065 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x29	 x23	 x2177
2023-05-09T16:41:38.066Z,1683650498.066 [DATMMP](INFO): Rx dataTimestamp_ set to:1683650514.694272
2023-05-09T16:41:38.066Z,1683650498.066 [DATMMP](INFO): Rx ping set to:1683650498.065482
2023-05-09T16:41:38.067Z,1683650498.067 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:41:38.067Z,1683650498.067 [DATMMP](INFO): Handled
2023-05-09T16:41:38.067Z,1683650498.067 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:38.067Z,1683650498.067 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:38.316Z,1683650498.316 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:38.317Z,1683650498.317 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:38.569Z,1683650498.569 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:38.570Z,1683650498.570 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 x5	 x9	 x0
2023-05-09T16:41:38.570Z,1683650498.570 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-09T16:41:38.570Z,1683650498.570 [DATMMP](INFO): Received message type: remote_header
2023-05-09T16:41:38.570Z,1683650498.570 [DATMMP](INFO): Handled
2023-05-09T16:41:38.571Z,1683650498.571 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:38.571Z,1683650498.571 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:38.821Z,1683650498.821 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:38.821Z,1683650498.821 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:41:38.822Z,1683650498.822 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:41:38.822Z,1683650498.822 [DATMMP](INFO): Handled
2023-05-09T16:41:38.822Z,1683650498.822 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:38.822Z,1683650498.822 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:39.073Z,1683650499.073 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:39.074Z,1683650499.074 [DATMMP](INFO): directional_debug rx: 	 xDFE	 x1A6	 x21	 x125	 xF80	 x11A1	 x1122	 x14E3
2023-05-09T16:41:39.075Z,1683650499.075 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:41:39.075Z,1683650499.075 [DATMMP](INFO): Handled
2023-05-09T16:41:39.075Z,1683650499.075 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:39.075Z,1683650499.075 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:39.324Z,1683650499.324 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:39.326Z,1683650499.326 [DATMMP](INFO): directional rx: 	 xDF5	 x158	 x5EE	 xFE5A	 xBF4	 xFE62	 x0	 x616	 x1	 xFFEC	 x2318600	 x0
2023-05-09T16:41:39.328Z,1683650499.328 [DATMMP](INFO): Received message type: directional
2023-05-09T16:41:39.328Z,1683650499.328 [DATMMP](INFO): Handled
2023-05-09T16:41:39.328Z,1683650499.328 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:39.328Z,1683650499.328 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:39.468Z,1683650499.468 [Reporter](INFO): DATMMP.acoustic_contact_range 0.000000 m
2023-05-09T16:41:39.576Z,1683650499.576 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:39.578Z,1683650499.578 [DATMMP](INFO): acstats rx: 	 x9	 x5	 x0	 x29F	 x22	 x8B	 xBC	 xAF	 xD	 xFFFF	 xA9	 x20	 xD	 x0
2023-05-09T16:41:39.578Z,1683650499.578 [DATMMP](INFO): Received message type: acstats
2023-05-09T16:41:39.579Z,1683650499.579 [DATMMP](INFO): Handled
2023-05-09T16:41:39.579Z,1683650499.579 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:39.579Z,1683650499.579 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:39.829Z,1683650499.829 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:39.830Z,1683650499.830 [DATMMP](INFO): data_rx rx: 	 x9	 x0	 x0	 x4
2023-05-09T16:41:39.830Z,1683650499.830 [DATMMP](INFO): Check CRC
2023-05-09T16:41:39.831Z,1683650499.831 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-09T16:41:39.831Z,1683650499.831 [DATMMP](INFO): Got DATA: len 4
2023-05-09T16:41:39.831Z,1683650499.831 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-09T16:41:39.831Z,1683650499.831 [DATMMP](INFO): Got ~~ ack, bytes left 0
2023-05-09T16:41:39.831Z,1683650499.831 [DATMMP](INFO): Received command: 

2023-05-09T16:41:39.832Z,1683650499.832 [DATMMP](INFO): Received message type: data_rx
2023-05-09T16:41:39.832Z,1683650499.832 [DATMMP](INFO): Handled
2023-05-09T16:41:39.839Z,1683650499.839 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-09T16:41:39.839Z,1683650499.839 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-09T16:41:39.839Z,1683650499.839 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:40.080Z,1683650500.080 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-09T16:41:40.081Z,1683650500.081 [DATMMP](INFO): modem://9: set _.humidity 12.947136 percent
2023-05-09T16:41:40.082Z,1683650500.082 [DATMMP](INFO): #Outgoing data=2
2023-05-09T16:41:40.082Z,1683650500.082 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-09T16:41:40.082Z,1683650500.082 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-09T16:41:40.082Z,1683650500.082 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:40.332Z,1683650500.332 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-09T16:41:40.332Z,1683650500.332 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-09T16:41:40.333Z,1683650500.333 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:40.584Z,1683650500.584 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-09T16:41:40.585Z,1683650500.585 [DATMMP](INFO): Tx to 9 len 35 xid 24
2023-05-09T16:41:40.585Z,1683650500.585 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-09T16:41:40.585Z,1683650500.585 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-09T16:41:40.586Z,1683650500.586 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:40.837Z,1683650500.837 [DATMMP](INFO): GSXN notify for xid: 24
2023-05-09T16:41:40.837Z,1683650500.837 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-09T16:41:40.838Z,1683650500.838 [DATMMP](DEBUG): Command complete send
2023-05-09T16:41:40.838Z,1683650500.838 [DATMMP](ERROR): 1:COMPLETE
2023-05-09T16:41:40.838Z,1683650500.838 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:41:40.838Z,1683650500.838 [DATMMP](INFO): Handled
2023-05-09T16:41:40.838Z,1683650500.838 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:40.838Z,1683650500.838 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:41.089Z,1683650501.089 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:41.090Z,1683650501.090 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x29	 x27	 x962
2023-05-09T16:41:41.090Z,1683650501.090 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:41:41.090Z,1683650501.090 [DATMMP](INFO): Handled
2023-05-09T16:41:41.090Z,1683650501.090 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:41.090Z,1683650501.090 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:41.340Z,1683650501.340 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:41.341Z,1683650501.341 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:41.592Z,1683650501.592 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:41.593Z,1683650501.593 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:41.849Z,1683650501.849 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:41.849Z,1683650501.849 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:42.097Z,1683650502.097 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:42.097Z,1683650502.097 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:42.348Z,1683650502.348 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:42.349Z,1683650502.349 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:42.600Z,1683650502.600 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:42.601Z,1683650502.601 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:42.852Z,1683650502.852 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:42.853Z,1683650502.853 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:43.104Z,1683650503.104 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:43.105Z,1683650503.105 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:43.356Z,1683650503.356 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:43.356Z,1683650503.356 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:43.610Z,1683650503.610 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:43.611Z,1683650503.611 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:43.861Z,1683650503.861 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:43.861Z,1683650503.861 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:44.112Z,1683650504.112 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:44.112Z,1683650504.112 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:44.364Z,1683650504.364 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:44.364Z,1683650504.364 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:44.616Z,1683650504.616 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:44.616Z,1683650504.616 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:44.868Z,1683650504.868 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:44.869Z,1683650504.869 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:45.121Z,1683650505.121 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:45.121Z,1683650505.121 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:45.372Z,1683650505.372 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:45.373Z,1683650505.373 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:45.625Z,1683650505.625 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:45.625Z,1683650505.625 [DATMMP](INFO): doppler rx: 	 x0
2023-05-09T16:41:45.625Z,1683650505.625 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:41:45.626Z,1683650505.626 [DATMMP](INFO): Handled
2023-05-09T16:41:45.626Z,1683650505.626 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:45.626Z,1683650505.626 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:45.877Z,1683650505.877 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:45.878Z,1683650505.878 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x29	 x2B	 x19A7
2023-05-09T16:41:45.878Z,1683650505.878 [DATMMP](INFO): Rx dataTimestamp_ set to:1683650503.137216
2023-05-09T16:41:45.878Z,1683650505.878 [DATMMP](INFO): Rx ping set to:1683650505.877683
2023-05-09T16:41:45.879Z,1683650505.879 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:41:45.879Z,1683650505.879 [DATMMP](INFO): Handled
2023-05-09T16:41:45.879Z,1683650505.879 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:45.879Z,1683650505.879 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:46.129Z,1683650506.129 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:46.129Z,1683650506.129 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:46.381Z,1683650506.381 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:46.383Z,1683650506.383 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 x5	 x9	 x0
2023-05-09T16:41:46.383Z,1683650506.383 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-09T16:41:46.383Z,1683650506.383 [DATMMP](INFO): Received message type: remote_header
2023-05-09T16:41:46.383Z,1683650506.383 [DATMMP](INFO): Handled
2023-05-09T16:41:46.383Z,1683650506.383 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:46.383Z,1683650506.383 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:46.633Z,1683650506.633 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:46.633Z,1683650506.633 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:41:46.634Z,1683650506.634 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:41:46.634Z,1683650506.634 [DATMMP](INFO): Handled
2023-05-09T16:41:46.634Z,1683650506.634 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:46.634Z,1683650506.634 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:46.885Z,1683650506.885 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:46.886Z,1683650506.886 [DATMMP](INFO): directional_debug rx: 	 xDFE	 x1B3	 x21	 x125	 xFA0	 x1191	 x1122	 x14D3
2023-05-09T16:41:46.887Z,1683650506.887 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:41:46.887Z,1683650506.887 [DATMMP](INFO): Handled
2023-05-09T16:41:46.887Z,1683650506.887 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:46.887Z,1683650506.887 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:47.137Z,1683650507.137 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:47.138Z,1683650507.138 [DATMMP](INFO): directional rx: 	 xDF5	 x167	 x5EE	 xFE4D	 xBED	 xFE54	 x0	 x610	 x3	 xFFEC	 x2318600	 x0
2023-05-09T16:41:47.141Z,1683650507.141 [DATMMP](INFO): Received message type: directional
2023-05-09T16:41:47.141Z,1683650507.141 [DATMMP](INFO): Handled
2023-05-09T16:41:47.141Z,1683650507.141 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:47.164Z,1683650507.164 [Reporter](INFO): DATMMP.acoustic_contact_range 0.000000 m
2023-05-09T16:41:47.389Z,1683650507.389 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:47.390Z,1683650507.390 [DATMMP](INFO): acstats rx: 	 x9	 x5	 x0	 x2D0	 x22	 x8D	 xBA	 xB8	 xD	 xFFFF	 xB1	 x24	 xD	 x0
2023-05-09T16:41:47.391Z,1683650507.391 [DATMMP](INFO): Received message type: acstats
2023-05-09T16:41:47.391Z,1683650507.391 [DATMMP](INFO): Handled
2023-05-09T16:41:47.391Z,1683650507.391 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:47.391Z,1683650507.391 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:47.641Z,1683650507.641 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:47.642Z,1683650507.642 [DATMMP](INFO): data_rx rx: 	 x9	 x0	 x0	 x4
2023-05-09T16:41:47.642Z,1683650507.642 [DATMMP](INFO): Check CRC
2023-05-09T16:41:47.642Z,1683650507.642 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-09T16:41:47.642Z,1683650507.642 [DATMMP](INFO): Got DATA: len 4
2023-05-09T16:41:47.642Z,1683650507.642 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-09T16:41:47.642Z,1683650507.642 [DATMMP](INFO): Got ~~ ack, bytes left 2
2023-05-09T16:41:47.642Z,1683650507.642 [DATMMP](INFO): Received command: 

2023-05-09T16:41:47.643Z,1683650507.643 [DATMMP](INFO): Received message type: data_rx
2023-05-09T16:41:47.643Z,1683650507.643 [DATMMP](INFO): Handled
2023-05-09T16:41:47.643Z,1683650507.643 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-09T16:41:47.643Z,1683650507.643 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-09T16:41:47.643Z,1683650507.643 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:47.897Z,1683650507.897 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-09T16:41:47.897Z,1683650507.897 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-09T16:41:47.897Z,1683650507.897 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-09T16:41:47.897Z,1683650507.897 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:48.148Z,1683650508.148 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-09T16:41:48.148Z,1683650508.148 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-09T16:41:48.149Z,1683650508.149 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:48.400Z,1683650508.400 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-09T16:41:48.401Z,1683650508.401 [DATMMP](INFO): Tx to 9 len 32 xid 25
2023-05-09T16:41:48.401Z,1683650508.401 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-09T16:41:48.402Z,1683650508.402 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-09T16:41:48.402Z,1683650508.402 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:48.653Z,1683650508.653 [DATMMP](INFO): GSXN notify for xid: 25
2023-05-09T16:41:48.654Z,1683650508.654 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-09T16:41:48.654Z,1683650508.654 [DATMMP](DEBUG): Command complete send
2023-05-09T16:41:48.654Z,1683650508.654 [DATMMP](ERROR): 1:COMPLETE
2023-05-09T16:41:48.654Z,1683650508.654 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:41:48.654Z,1683650508.654 [DATMMP](INFO): Handled
2023-05-09T16:41:48.654Z,1683650508.654 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:48.655Z,1683650508.655 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:48.905Z,1683650508.905 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:48.906Z,1683650508.906 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x29	 x2F	 x191
2023-05-09T16:41:48.906Z,1683650508.906 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:41:48.906Z,1683650508.906 [DATMMP](INFO): Handled
2023-05-09T16:41:48.906Z,1683650508.906 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:48.906Z,1683650508.906 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:49.156Z,1683650509.156 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:49.157Z,1683650509.157 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:49.408Z,1683650509.408 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:49.409Z,1683650509.409 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:49.660Z,1683650509.660 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:49.661Z,1683650509.661 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:49.912Z,1683650509.912 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:49.913Z,1683650509.913 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:50.164Z,1683650510.164 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:50.165Z,1683650510.165 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:50.416Z,1683650510.416 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:50.417Z,1683650510.417 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:50.668Z,1683650510.668 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:50.668Z,1683650510.668 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:50.920Z,1683650510.920 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:50.921Z,1683650510.921 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:51.173Z,1683650511.173 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:51.173Z,1683650511.173 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:51.424Z,1683650511.424 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:51.424Z,1683650511.424 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:51.676Z,1683650511.676 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:51.677Z,1683650511.677 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:51.928Z,1683650511.928 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:51.928Z,1683650511.928 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:52.180Z,1683650512.180 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:52.181Z,1683650512.181 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:52.394Z,1683650512.394 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-09T16:41:52.436Z,1683650512.436 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:52.437Z,1683650512.437 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:52.688Z,1683650512.688 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:52.689Z,1683650512.689 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:52.941Z,1683650512.941 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:52.941Z,1683650512.941 [DATMMP](INFO): doppler rx: 	 x0
2023-05-09T16:41:52.941Z,1683650512.941 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:41:52.941Z,1683650512.941 [DATMMP](INFO): Handled
2023-05-09T16:41:52.942Z,1683650512.942 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:52.942Z,1683650512.942 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:53.193Z,1683650513.193 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:53.194Z,1683650513.194 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x29	 x32	 x255E
2023-05-09T16:41:53.194Z,1683650513.194 [DATMMP](INFO): Rx dataTimestamp_ set to:1683650539.438272
2023-05-09T16:41:53.195Z,1683650513.195 [DATMMP](INFO): Rx ping set to:1683650513.193742
2023-05-09T16:41:53.195Z,1683650513.195 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:41:53.195Z,1683650513.195 [DATMMP](INFO): Handled
2023-05-09T16:41:53.195Z,1683650513.195 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:53.195Z,1683650513.195 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:53.444Z,1683650513.444 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:53.445Z,1683650513.445 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:53.697Z,1683650513.697 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:53.698Z,1683650513.698 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 x5	 x9	 x0
2023-05-09T16:41:53.698Z,1683650513.698 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-09T16:41:53.698Z,1683650513.698 [DATMMP](INFO): Received message type: remote_header
2023-05-09T16:41:53.698Z,1683650513.698 [DATMMP](INFO): Handled
2023-05-09T16:41:53.699Z,1683650513.699 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:53.699Z,1683650513.699 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:53.949Z,1683650513.949 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:53.949Z,1683650513.949 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:41:53.950Z,1683650513.950 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:41:53.950Z,1683650513.950 [DATMMP](INFO): Handled
2023-05-09T16:41:53.950Z,1683650513.950 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:53.950Z,1683650513.950 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:54.200Z,1683650514.200 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:54.202Z,1683650514.202 [DATMMP](INFO): directional_debug rx: 	 xE09	 x1AC	 x23	 x125	 xF30	 x11C1	 x1122	 x1493
2023-05-09T16:41:54.203Z,1683650514.203 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:41:54.203Z,1683650514.203 [DATMMP](INFO): Handled
2023-05-09T16:41:54.203Z,1683650514.203 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:54.203Z,1683650514.203 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:54.453Z,1683650514.453 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:54.454Z,1683650514.454 [DATMMP](INFO): directional rx: 	 xE00	 x15E	 x5E3	 xFE54	 xBDC	 xFE5A	 x0	 x60B	 x5	 xFFED	 x2318600	 x0
2023-05-09T16:41:54.456Z,1683650514.456 [DATMMP](INFO): Received message type: directional
2023-05-09T16:41:54.457Z,1683650514.457 [DATMMP](INFO): Handled
2023-05-09T16:41:54.457Z,1683650514.457 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:54.457Z,1683650514.457 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:54.705Z,1683650514.705 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:54.706Z,1683650514.706 [DATMMP](INFO): acstats rx: 	 x9	 x5	 x0	 x2A6	 x22	 x97	 xBD	 xBD	 xD	 xFFFF	 xAA	 x25	 xD	 x0
2023-05-09T16:41:54.707Z,1683650514.707 [DATMMP](INFO): Received message type: acstats
2023-05-09T16:41:54.707Z,1683650514.707 [DATMMP](INFO): Handled
2023-05-09T16:41:54.707Z,1683650514.707 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:41:54.707Z,1683650514.707 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:54.836Z,1683650514.836 [Reporter](INFO): DATMMP.acoustic_contact_range 0.000000 m
2023-05-09T16:41:54.957Z,1683650514.957 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:54.957Z,1683650514.957 [DATMMP](INFO): data_rx rx: 	 x9	 x0	 x0	 x4
2023-05-09T16:41:54.958Z,1683650514.958 [DATMMP](INFO): Check CRC
2023-05-09T16:41:54.958Z,1683650514.958 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-09T16:41:54.958Z,1683650514.958 [DATMMP](INFO): Got DATA: len 4
2023-05-09T16:41:54.958Z,1683650514.958 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-09T16:41:54.958Z,1683650514.958 [DATMMP](INFO): Got ~~ ack, bytes left 2
2023-05-09T16:41:54.958Z,1683650514.958 [DATMMP](INFO): Received command: 

2023-05-09T16:41:54.959Z,1683650514.959 [DATMMP](INFO): Received message type: data_rx
2023-05-09T16:41:54.959Z,1683650514.959 [DATMMP](INFO): Handled
2023-05-09T16:41:54.959Z,1683650514.959 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-09T16:41:54.959Z,1683650514.959 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-09T16:41:54.959Z,1683650514.959 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:55.208Z,1683650515.208 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:55.460Z,1683650515.460 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:55.713Z,1683650515.713 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:55.964Z,1683650515.964 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:56.216Z,1683650516.216 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:56.468Z,1683650516.468 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:56.720Z,1683650516.720 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:56.972Z,1683650516.972 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:57.224Z,1683650517.224 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:57.476Z,1683650517.476 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:57.728Z,1683650517.728 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:57.980Z,1683650517.980 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:58.232Z,1683650518.232 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:58.484Z,1683650518.484 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:58.736Z,1683650518.736 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:58.988Z,1683650518.988 [DATMMP](INFO): ****** received valid address query ******
2023-05-09T16:41:58.989Z,1683650518.989 [DATMMP](INFO): ****** received valid ping request ******
2023-05-09T16:41:58.990Z,1683650518.990 [DATMMP](INFO): Querying Benthos address 9
2023-05-09T16:41:59.241Z,1683650519.241 [DATMMP](INFO): GSXN notify for xid: 26
2023-05-09T16:41:59.242Z,1683650519.242 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x0	 x2
2023-05-09T16:41:59.242Z,1683650519.242 [DATMMP](INFO): Progress on cmd
2023-05-09T16:41:59.242Z,1683650519.242 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:41:59.242Z,1683650519.242 [DATMMP](INFO): Handled
2023-05-09T16:41:59.242Z,1683650519.242 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:59.493Z,1683650519.493 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:59.493Z,1683650519.493 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:41:59.494Z,1683650519.494 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:41:59.494Z,1683650519.494 [DATMMP](INFO): Handled
2023-05-09T16:41:59.494Z,1683650519.494 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:59.745Z,1683650519.745 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:41:59.746Z,1683650519.746 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x29	 x39	 x1719
2023-05-09T16:41:59.746Z,1683650519.746 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:41:59.746Z,1683650519.746 [DATMMP](INFO): Handled
2023-05-09T16:41:59.746Z,1683650519.746 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:41:59.996Z,1683650519.996 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:00.248Z,1683650520.248 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:00.504Z,1683650520.504 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:00.756Z,1683650520.756 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:01.008Z,1683650521.008 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:01.260Z,1683650521.260 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:01.512Z,1683650521.512 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:01.764Z,1683650521.764 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:02.017Z,1683650522.017 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:02.017Z,1683650522.017 [DATMMP](INFO): doppler rx: 	 x0
2023-05-09T16:42:02.017Z,1683650522.017 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:42:02.017Z,1683650522.017 [DATMMP](INFO): Handled
2023-05-09T16:42:02.018Z,1683650522.018 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:02.268Z,1683650522.268 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:02.269Z,1683650522.269 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:42:02.269Z,1683650522.269 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:42:02.269Z,1683650522.269 [DATMMP](INFO): Handled
2023-05-09T16:42:02.270Z,1683650522.270 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:02.520Z,1683650522.520 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:02.522Z,1683650522.522 [DATMMP](INFO): directional_debug rx: 	 xE	 x1AE	 x22	 x128	 xF50	 x1131	 x10C2	 x14D3
2023-05-09T16:42:02.523Z,1683650522.523 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:42:02.523Z,1683650522.523 [DATMMP](INFO): Handled
2023-05-09T16:42:02.523Z,1683650522.523 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:02.772Z,1683650522.772 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:02.774Z,1683650522.774 [DATMMP](INFO): directional rx: 	 x6	 x160	 x5CE	 xFE52	 xBC2	 xFE57	 x6E32	 x605	 x5	 xFFEF	 x2318600	 x0
2023-05-09T16:42:02.776Z,1683650522.776 [DATMMP](INFO): Received message type: directional
2023-05-09T16:42:02.776Z,1683650522.776 [DATMMP](INFO): Handled
2023-05-09T16:42:02.776Z,1683650522.776 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:02.953Z,1683650522.953 [Reporter](INFO): DATMMP.acoustic_contact_range 2.821000 m
2023-05-09T16:42:03.025Z,1683650523.025 [DATMMP](INFO): GSXN notify for xid: 26
2023-05-09T16:42:03.025Z,1683650523.025 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x1	 x6
2023-05-09T16:42:03.025Z,1683650523.025 [DATMMP](INFO): Progress on cmd
2023-05-09T16:42:03.026Z,1683650523.026 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:42:03.026Z,1683650523.026 [DATMMP](INFO): Handled
2023-05-09T16:42:03.026Z,1683650523.026 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:03.277Z,1683650523.277 [DATMMP](INFO): GSXN notify for xid: 26
2023-05-09T16:42:03.277Z,1683650523.277 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x2	 x3
2023-05-09T16:42:03.278Z,1683650523.278 [DATMMP](ERROR): 3:COMPLETE
2023-05-09T16:42:03.278Z,1683650523.278 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:42:03.278Z,1683650523.278 [DATMMP](INFO): Handled
2023-05-09T16:42:03.278Z,1683650523.278 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:03.532Z,1683650523.532 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:03.533Z,1683650523.533 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:42:03.533Z,1683650523.533 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:42:03.533Z,1683650523.533 [DATMMP](INFO): Handled
2023-05-09T16:42:03.533Z,1683650523.533 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:03.780Z,1683650523.780 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:04.032Z,1683650524.032 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:04.284Z,1683650524.284 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:04.536Z,1683650524.536 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:04.788Z,1683650524.788 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:05.040Z,1683650525.040 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:05.292Z,1683650525.292 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:05.544Z,1683650525.544 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:05.796Z,1683650525.796 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:06.048Z,1683650526.048 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:06.300Z,1683650526.300 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:06.552Z,1683650526.552 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:06.804Z,1683650526.804 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:07.056Z,1683650527.056 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:07.311Z,1683650527.311 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:07.564Z,1683650527.564 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:07.744Z,1683650527.744 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-09T16:42:07.816Z,1683650527.816 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:08.068Z,1683650528.068 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:08.320Z,1683650528.320 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:08.572Z,1683650528.572 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:08.824Z,1683650528.824 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:09.076Z,1683650529.076 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:09.329Z,1683650529.329 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:09.580Z,1683650529.580 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:09.833Z,1683650529.833 [DATMMP](INFO): ****** received valid address query ******
2023-05-09T16:42:09.833Z,1683650529.833 [DATMMP](INFO): ****** received valid ping request ******
2023-05-09T16:42:09.833Z,1683650529.833 [DATMMP](INFO): Querying Benthos address 9
2023-05-09T16:42:10.085Z,1683650530.085 [DATMMP](INFO): GSXN notify for xid: 27
2023-05-09T16:42:10.086Z,1683650530.086 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x0	 x2
2023-05-09T16:42:10.086Z,1683650530.086 [DATMMP](INFO): Progress on cmd
2023-05-09T16:42:10.086Z,1683650530.086 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:42:10.086Z,1683650530.086 [DATMMP](INFO): Handled
2023-05-09T16:42:10.086Z,1683650530.086 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:10.337Z,1683650530.337 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:10.338Z,1683650530.338 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:42:10.338Z,1683650530.338 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:42:10.338Z,1683650530.338 [DATMMP](INFO): Handled
2023-05-09T16:42:10.338Z,1683650530.338 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:10.589Z,1683650530.589 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:10.590Z,1683650530.590 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x2A	 x8	 x113D
2023-05-09T16:42:10.590Z,1683650530.590 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:42:10.590Z,1683650530.590 [DATMMP](INFO): Handled
2023-05-09T16:42:10.590Z,1683650530.590 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:10.840Z,1683650530.840 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:11.093Z,1683650531.093 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:11.344Z,1683650531.344 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:11.597Z,1683650531.597 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:11.848Z,1683650531.848 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:12.100Z,1683650532.100 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:12.352Z,1683650532.352 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:12.604Z,1683650532.604 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:12.857Z,1683650532.857 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:12.857Z,1683650532.857 [DATMMP](INFO): doppler rx: 	 x0
2023-05-09T16:42:12.857Z,1683650532.857 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:42:12.858Z,1683650532.858 [DATMMP](INFO): Handled
2023-05-09T16:42:12.858Z,1683650532.858 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:13.109Z,1683650533.109 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:13.110Z,1683650533.110 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:42:13.110Z,1683650533.110 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:42:13.110Z,1683650533.110 [DATMMP](INFO): Handled
2023-05-09T16:42:13.110Z,1683650533.110 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:13.371Z,1683650533.371 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:13.372Z,1683650533.372 [DATMMP](INFO): directional_debug rx: 	 x4	 x1A5	 x23	 x127	 xF40	 x1141	 x10B2	 x1483
2023-05-09T16:42:13.373Z,1683650533.373 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:42:13.373Z,1683650533.373 [DATMMP](INFO): Handled
2023-05-09T16:42:13.374Z,1683650533.374 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:13.624Z,1683650533.624 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:13.626Z,1683650533.626 [DATMMP](INFO): directional rx: 	 xE0B	 x156	 x5D8	 xFE5B	 xBC3	 xFE60	 x6E32	 x5FB	 x5	 xFFEE	 x2318600	 x0
2023-05-09T16:42:13.628Z,1683650533.628 [DATMMP](INFO): Received message type: directional
2023-05-09T16:42:13.628Z,1683650533.628 [DATMMP](INFO): Handled
2023-05-09T16:42:13.628Z,1683650533.628 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:13.804Z,1683650533.804 [Reporter](INFO): DATMMP.acoustic_contact_range 2.821000 m
2023-05-09T16:42:13.877Z,1683650533.877 [DATMMP](INFO): GSXN notify for xid: 27
2023-05-09T16:42:13.877Z,1683650533.877 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x1	 x6
2023-05-09T16:42:13.878Z,1683650533.878 [DATMMP](INFO): Progress on cmd
2023-05-09T16:42:13.878Z,1683650533.878 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:42:13.878Z,1683650533.878 [DATMMP](INFO): Handled
2023-05-09T16:42:13.878Z,1683650533.878 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:14.129Z,1683650534.129 [DATMMP](INFO): GSXN notify for xid: 27
2023-05-09T16:42:14.129Z,1683650534.129 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x2	 x3
2023-05-09T16:42:14.130Z,1683650534.130 [DATMMP](ERROR): 3:COMPLETE
2023-05-09T16:42:14.130Z,1683650534.130 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:42:14.130Z,1683650534.130 [DATMMP](INFO): Handled
2023-05-09T16:42:14.130Z,1683650534.130 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:14.381Z,1683650534.381 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:14.381Z,1683650534.381 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:42:14.381Z,1683650534.381 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:42:14.382Z,1683650534.382 [DATMMP](INFO): Handled
2023-05-09T16:42:14.382Z,1683650534.382 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:14.632Z,1683650534.632 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:14.885Z,1683650534.885 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:15.137Z,1683650535.137 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:15.396Z,1683650535.396 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:15.648Z,1683650535.648 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:15.900Z,1683650535.900 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:16.152Z,1683650536.152 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:16.404Z,1683650536.404 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:16.656Z,1683650536.656 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:16.909Z,1683650536.909 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:17.160Z,1683650537.160 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:17.417Z,1683650537.417 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:17.668Z,1683650537.668 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:17.921Z,1683650537.921 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:18.172Z,1683650538.172 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:18.424Z,1683650538.424 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:18.677Z,1683650538.677 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:18.928Z,1683650538.928 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:19.180Z,1683650539.180 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:19.437Z,1683650539.437 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:19.688Z,1683650539.688 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:19.940Z,1683650539.940 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:20.192Z,1683650540.192 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:20.444Z,1683650540.444 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:22.282Z,1683650542.282 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting.
2023-05-09T16:42:22.282Z,1683650542.282 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-09T16:42:22.282Z,1683650542.282 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-09T16:42:22.282Z,1683650542.282 [senddata_direct_and_track_test:DirectData:B] Running Loop=1
2023-05-09T16:42:22.687Z,1683650542.687 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:9:_.pressure
2023-05-09T16:42:22.687Z,1683650542.687 [senddata_direct_and_track_test:DirectData:B] Stopped
2023-05-09T16:42:22.687Z,1683650542.687 [senddata_direct_and_track_test:DirectData:C] Running Loop=1
2023-05-09T16:42:22.728Z,1683650542.728 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-09T16:42:22.729Z,1683650542.729 [DATMMP](INFO): modem://9: set _.pressure 0.745784 atmosphere
2023-05-09T16:42:22.730Z,1683650542.730 [DATMMP](INFO): #Outgoing data=1
2023-05-09T16:42:22.730Z,1683650542.730 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-09T16:42:22.730Z,1683650542.730 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-09T16:42:22.980Z,1683650542.980 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-09T16:42:22.980Z,1683650542.980 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-09T16:42:23.095Z,1683650543.095 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:9:_.temperature
2023-05-09T16:42:23.095Z,1683650543.095 [senddata_direct_and_track_test:DirectData:C] Stopped
2023-05-09T16:42:23.095Z,1683650543.095 [senddata_direct_and_track_test:DirectData:D] Running Loop=1
2023-05-09T16:42:23.095Z,1683650543.095 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-09T16:42:23.232Z,1683650543.232 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-09T16:42:23.233Z,1683650543.233 [DATMMP](INFO): Tx to 9 len 34 xid 28
2023-05-09T16:42:23.233Z,1683650543.233 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-09T16:42:23.233Z,1683650543.233 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-09T16:42:23.234Z,1683650543.234 [DATMMP](INFO): ****** received valid address query ******
2023-05-09T16:42:23.234Z,1683650543.234 [DATMMP](INFO): ****** received valid ping request ******
2023-05-09T16:42:23.234Z,1683650543.234 [DATMMP](INFO): Querying Benthos address 9
2023-05-09T16:42:23.485Z,1683650543.485 [DATMMP](INFO): GSXN notify for xid: 28
2023-05-09T16:42:23.486Z,1683650543.486 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-09T16:42:23.486Z,1683650543.486 [DATMMP](DEBUG): Command complete send
2023-05-09T16:42:23.486Z,1683650543.486 [DATMMP](ERROR): 1:COMPLETE
2023-05-09T16:42:23.486Z,1683650543.486 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:42:23.486Z,1683650543.486 [DATMMP](INFO): Handled
2023-05-09T16:42:23.486Z,1683650543.486 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:23.487Z,1683650543.487 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:23.492Z,1683650543.492 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:9:_.humidity
2023-05-09T16:42:23.492Z,1683650543.492 [senddata_direct_and_track_test:DirectData:D] Stopped
2023-05-09T16:42:23.493Z,1683650543.493 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData
2023-05-09T16:42:23.493Z,1683650543.493 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-09T16:42:23.493Z,1683650543.493 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-09T16:42:23.493Z,1683650543.493 [senddata_direct_and_track_test:DirectData](INFO): Running loop #3
2023-05-09T16:42:23.493Z,1683650543.493 [senddata_direct_and_track_test:DirectData] Running Loop=3
2023-05-09T16:42:23.493Z,1683650543.493 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-09T16:42:23.493Z,1683650543.493 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-09T16:42:23.493Z,1683650543.493 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-09T16:42:23.737Z,1683650543.737 [DATMMP](INFO): GSXN notify for xid: 29
2023-05-09T16:42:23.737Z,1683650543.737 [DATMMP](INFO): cmd_result rx: 	 x2	 x19	 x0	 x2
2023-05-09T16:42:23.738Z,1683650543.738 [DATMMP](INFO): Progress on cmd
2023-05-09T16:42:23.738Z,1683650543.738 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:42:23.738Z,1683650543.738 [DATMMP](INFO): Handled
2023-05-09T16:42:23.738Z,1683650543.738 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:23.738Z,1683650543.738 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:23.989Z,1683650543.989 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:23.989Z,1683650543.989 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:42:23.989Z,1683650543.989 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:42:23.990Z,1683650543.990 [DATMMP](INFO): Handled
2023-05-09T16:42:23.990Z,1683650543.990 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:23.990Z,1683650543.990 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:24.240Z,1683650544.240 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:24.241Z,1683650544.241 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x2A	 x15	 x20DC
2023-05-09T16:42:24.242Z,1683650544.242 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:42:24.242Z,1683650544.242 [DATMMP](INFO): Handled
2023-05-09T16:42:24.242Z,1683650544.242 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:24.242Z,1683650544.242 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:24.492Z,1683650544.492 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:24.493Z,1683650544.493 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x2A	 x15	 x24B6
2023-05-09T16:42:24.494Z,1683650544.494 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:42:24.494Z,1683650544.494 [DATMMP](INFO): Handled
2023-05-09T16:42:24.494Z,1683650544.494 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:24.494Z,1683650544.494 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:24.744Z,1683650544.744 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:24.745Z,1683650544.745 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:24.996Z,1683650544.996 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:24.996Z,1683650544.996 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:25.248Z,1683650545.248 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:25.249Z,1683650545.249 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:25.500Z,1683650545.500 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:25.501Z,1683650545.501 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:25.752Z,1683650545.752 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:25.752Z,1683650545.752 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:26.004Z,1683650546.004 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:26.005Z,1683650546.005 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:26.256Z,1683650546.256 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:26.257Z,1683650546.257 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:26.508Z,1683650546.508 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:26.508Z,1683650546.508 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:26.760Z,1683650546.760 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:26.760Z,1683650546.760 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:27.013Z,1683650547.013 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:27.013Z,1683650547.013 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:27.264Z,1683650547.264 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:27.265Z,1683650547.265 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:27.516Z,1683650547.516 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:27.517Z,1683650547.517 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:27.768Z,1683650547.768 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:27.768Z,1683650547.768 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:28.020Z,1683650548.020 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:28.020Z,1683650548.020 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:28.272Z,1683650548.272 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:28.272Z,1683650548.272 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:28.524Z,1683650548.524 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:28.525Z,1683650548.525 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:28.776Z,1683650548.776 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:28.777Z,1683650548.777 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:29.029Z,1683650549.029 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:29.029Z,1683650549.029 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:29.280Z,1683650549.280 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:29.280Z,1683650549.280 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:29.532Z,1683650549.532 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:29.533Z,1683650549.533 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:29.784Z,1683650549.784 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:29.785Z,1683650549.785 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:30.036Z,1683650550.036 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:30.037Z,1683650550.037 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:30.288Z,1683650550.288 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:30.288Z,1683650550.288 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:30.540Z,1683650550.540 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:30.540Z,1683650550.540 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:30.792Z,1683650550.792 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:30.793Z,1683650550.793 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:31.044Z,1683650551.044 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:31.045Z,1683650551.045 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:31.296Z,1683650551.296 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:31.297Z,1683650551.297 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:31.551Z,1683650551.551 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:31.551Z,1683650551.551 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:31.804Z,1683650551.804 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:31.804Z,1683650551.804 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:32.056Z,1683650552.056 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:32.057Z,1683650552.057 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:32.308Z,1683650552.308 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:32.309Z,1683650552.309 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:32.560Z,1683650552.560 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:32.560Z,1683650552.560 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:32.812Z,1683650552.812 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:32.812Z,1683650552.812 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:33.064Z,1683650553.064 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:33.064Z,1683650553.064 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:33.316Z,1683650553.316 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:33.317Z,1683650553.317 [DATMMP](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2023-05-09T16:42:33.317Z,1683650553.317 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:33.571Z,1683650553.571 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-09T16:42:33.572Z,1683650553.572 [DATMMP](INFO): modem://9: set _.temperature 23.977533 celsius
2023-05-09T16:42:33.573Z,1683650553.573 [DATMMP](INFO): #Outgoing data=1
2023-05-09T16:42:33.573Z,1683650553.573 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-09T16:42:33.573Z,1683650553.573 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-09T16:42:33.573Z,1683650553.573 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:33.824Z,1683650553.824 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-09T16:42:33.824Z,1683650553.824 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-09T16:42:33.825Z,1683650553.825 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:34.076Z,1683650554.076 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-09T16:42:34.077Z,1683650554.077 [DATMMP](INFO): Tx to 9 len 34 xid 30
2023-05-09T16:42:34.077Z,1683650554.077 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-09T16:42:34.078Z,1683650554.078 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-09T16:42:34.078Z,1683650554.078 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:34.328Z,1683650554.328 [DATMMP](INFO): GSXN notify for xid: 30
2023-05-09T16:42:34.329Z,1683650554.329 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-09T16:42:34.329Z,1683650554.329 [DATMMP](DEBUG): Command complete send
2023-05-09T16:42:34.330Z,1683650554.330 [DATMMP](ERROR): 1:COMPLETE
2023-05-09T16:42:34.330Z,1683650554.330 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:42:34.330Z,1683650554.330 [DATMMP](INFO): Handled
2023-05-09T16:42:34.330Z,1683650554.330 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:34.330Z,1683650554.330 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:34.581Z,1683650554.581 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:34.581Z,1683650554.581 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x2A	 x20	 x1AF2
2023-05-09T16:42:34.582Z,1683650554.582 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:42:34.582Z,1683650554.582 [DATMMP](INFO): Handled
2023-05-09T16:42:34.582Z,1683650554.582 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:34.582Z,1683650554.582 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:34.832Z,1683650554.832 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:34.833Z,1683650554.833 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:35.084Z,1683650555.084 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:35.084Z,1683650555.084 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:35.336Z,1683650555.336 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:35.336Z,1683650555.336 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:35.591Z,1683650555.591 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:35.591Z,1683650555.591 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:35.844Z,1683650555.844 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:35.845Z,1683650555.845 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:36.096Z,1683650556.096 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:36.097Z,1683650556.097 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:36.348Z,1683650556.348 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:36.348Z,1683650556.348 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:36.600Z,1683650556.600 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:36.600Z,1683650556.600 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:36.852Z,1683650556.852 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:36.853Z,1683650556.853 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:37.105Z,1683650557.105 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:37.105Z,1683650557.105 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:37.356Z,1683650557.356 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:37.357Z,1683650557.357 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:37.611Z,1683650557.611 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:37.611Z,1683650557.611 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:37.864Z,1683650557.864 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:37.865Z,1683650557.865 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:38.117Z,1683650558.117 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:38.117Z,1683650558.117 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:38.369Z,1683650558.369 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:38.370Z,1683650558.370 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:42:38.370Z,1683650558.370 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:42:38.370Z,1683650558.370 [DATMMP](INFO): Handled
2023-05-09T16:42:38.370Z,1683650558.370 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:38.370Z,1683650558.370 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:38.461Z,1683650558.461 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-09T16:42:38.621Z,1683650558.621 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:38.621Z,1683650558.621 [DATMMP](INFO): doppler rx: 	 x0
2023-05-09T16:42:38.621Z,1683650558.621 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:42:38.621Z,1683650558.621 [DATMMP](INFO): Handled
2023-05-09T16:42:38.622Z,1683650558.622 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:38.622Z,1683650558.622 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:38.873Z,1683650558.873 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:38.874Z,1683650558.874 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x2A	 x24	 x19A5
2023-05-09T16:42:38.874Z,1683650558.874 [DATMMP](INFO): Rx dataTimestamp_ set to:1683650556.116736
2023-05-09T16:42:38.875Z,1683650558.875 [DATMMP](INFO): Rx ping set to:1683650558.873889
2023-05-09T16:42:38.875Z,1683650558.875 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:42:38.875Z,1683650558.875 [DATMMP](INFO): Handled
2023-05-09T16:42:38.875Z,1683650558.875 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:38.875Z,1683650558.875 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:39.124Z,1683650559.124 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:39.125Z,1683650559.125 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:39.378Z,1683650559.378 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:39.379Z,1683650559.379 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 x5	 x9	 x0
2023-05-09T16:42:39.380Z,1683650559.380 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-09T16:42:39.380Z,1683650559.380 [DATMMP](INFO): Received message type: remote_header
2023-05-09T16:42:39.380Z,1683650559.380 [DATMMP](INFO): Handled
2023-05-09T16:42:39.380Z,1683650559.380 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:39.380Z,1683650559.380 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:39.631Z,1683650559.631 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:39.632Z,1683650559.632 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:42:39.633Z,1683650559.633 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:42:39.633Z,1683650559.633 [DATMMP](INFO): Handled
2023-05-09T16:42:39.633Z,1683650559.633 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:39.633Z,1683650559.633 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:39.885Z,1683650559.885 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:39.886Z,1683650559.886 [DATMMP](INFO): directional_debug rx: 	 xDCB	 x1D0	 x21	 x11C	 xF90	 x11D1	 x1152	 x1513
2023-05-09T16:42:39.887Z,1683650559.887 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:42:39.887Z,1683650559.887 [DATMMP](INFO): Handled
2023-05-09T16:42:39.887Z,1683650559.887 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:39.887Z,1683650559.887 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:40.137Z,1683650560.137 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:40.138Z,1683650560.138 [DATMMP](INFO): directional rx: 	 xDC2	 x18A	 x621	 xFE30	 xBF9	 xFE33	 x0	 x5EA	 x5	 xFFEE	 x2318600	 x0
2023-05-09T16:42:40.141Z,1683650560.141 [DATMMP](INFO): Received message type: directional
2023-05-09T16:42:40.141Z,1683650560.141 [DATMMP](INFO): Handled
2023-05-09T16:42:40.141Z,1683650560.141 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:40.141Z,1683650560.141 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:40.389Z,1683650560.389 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:40.390Z,1683650560.390 [DATMMP](INFO): acstats rx: 	 x9	 x5	 x0	 x2D0	 x22	 x90	 xB7	 xB4	 xD	 xFFFF	 xA8	 x23	 xD	 x0
2023-05-09T16:42:40.391Z,1683650560.391 [DATMMP](INFO): Received message type: acstats
2023-05-09T16:42:40.391Z,1683650560.391 [DATMMP](INFO): Handled
2023-05-09T16:42:40.391Z,1683650560.391 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:40.391Z,1683650560.391 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:40.470Z,1683650560.470 [Reporter](INFO): DATMMP.acoustic_contact_range 0.000000 m
2023-05-09T16:42:40.641Z,1683650560.641 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:40.641Z,1683650560.641 [DATMMP](INFO): data_rx rx: 	 x9	 x0	 x0	 x4
2023-05-09T16:42:40.642Z,1683650560.642 [DATMMP](INFO): Check CRC
2023-05-09T16:42:40.642Z,1683650560.642 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-09T16:42:40.642Z,1683650560.642 [DATMMP](INFO): Got DATA: len 4
2023-05-09T16:42:40.642Z,1683650560.642 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-09T16:42:40.642Z,1683650560.642 [DATMMP](INFO): Got ~~ ack, bytes left 2
2023-05-09T16:42:40.642Z,1683650560.642 [DATMMP](INFO): Received command: 

2023-05-09T16:42:40.643Z,1683650560.643 [DATMMP](INFO): Received message type: data_rx
2023-05-09T16:42:40.643Z,1683650560.643 [DATMMP](INFO): Handled
2023-05-09T16:42:40.643Z,1683650560.643 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-09T16:42:40.643Z,1683650560.643 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-09T16:42:40.643Z,1683650560.643 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:40.892Z,1683650560.892 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-09T16:42:40.893Z,1683650560.893 [DATMMP](INFO): modem://9: set _.humidity 12.947136 percent
2023-05-09T16:42:40.894Z,1683650560.894 [DATMMP](INFO): #Outgoing data=2
2023-05-09T16:42:40.894Z,1683650560.894 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-09T16:42:40.894Z,1683650560.894 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-09T16:42:40.894Z,1683650560.894 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:41.144Z,1683650561.144 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-09T16:42:41.145Z,1683650561.145 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-09T16:42:41.145Z,1683650561.145 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:41.396Z,1683650561.396 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-09T16:42:41.397Z,1683650561.397 [DATMMP](INFO): Tx to 9 len 35 xid 31
2023-05-09T16:42:41.397Z,1683650561.397 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-09T16:42:41.398Z,1683650561.398 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-09T16:42:41.398Z,1683650561.398 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:41.649Z,1683650561.649 [DATMMP](INFO): GSXN notify for xid: 31
2023-05-09T16:42:41.650Z,1683650561.650 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-09T16:42:41.650Z,1683650561.650 [DATMMP](DEBUG): Command complete send
2023-05-09T16:42:41.650Z,1683650561.650 [DATMMP](ERROR): 1:COMPLETE
2023-05-09T16:42:41.650Z,1683650561.650 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:42:41.650Z,1683650561.650 [DATMMP](INFO): Handled
2023-05-09T16:42:41.650Z,1683650561.650 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:41.650Z,1683650561.650 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:41.901Z,1683650561.901 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:41.902Z,1683650561.902 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x2A	 x28	 x18F
2023-05-09T16:42:41.902Z,1683650561.902 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:42:41.902Z,1683650561.902 [DATMMP](INFO): Handled
2023-05-09T16:42:41.902Z,1683650561.902 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:41.902Z,1683650561.902 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:42.153Z,1683650562.153 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:42.153Z,1683650562.153 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:42.404Z,1683650562.404 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:42.404Z,1683650562.404 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:42.656Z,1683650562.656 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:42.657Z,1683650562.657 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:42.909Z,1683650562.909 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:42.909Z,1683650562.909 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:43.057Z,1683650563.057 [CommandExec](IMPORTANT): got command stop
2023-05-09T16:42:43.057Z,1683650563.057 [CommandExec](IMPORTANT): Scheduling is paused
2023-05-09T16:42:43.057Z,1683650563.057 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-05-09T16:42:43.161Z,1683650563.161 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:43.161Z,1683650563.161 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:43.298Z,1683650563.298 [MissionManager](INFO): MissionManager is completed.
2023-05-09T16:42:43.298Z,1683650563.298 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test
2023-05-09T16:42:43.298Z,1683650563.298 [senddata_direct_and_track_test] Stopped
2023-05-09T16:42:43.298Z,1683650563.298 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test
2023-05-09T16:42:43.299Z,1683650563.299 [senddata_direct_and_track_test:TrackAC.] Stopped
2023-05-09T16:42:43.299Z,1683650563.299 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact.
2023-05-09T16:42:43.299Z,1683650563.299 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-09T16:42:43.299Z,1683650563.299 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-09T16:42:43.299Z,1683650563.299 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-09T16:42:43.299Z,1683650563.299 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-09T16:42:43.413Z,1683650563.413 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:43.413Z,1683650563.413 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:43.664Z,1683650563.664 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:43.665Z,1683650563.665 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:43.729Z,1683650563.729 [MissionManager](IMPORTANT): Started mission Default
2023-05-09T16:42:43.729Z,1683650563.729 [Default] Running Loop=1
2023-05-09T16:42:43.729Z,1683650563.729 [Default](DEBUG): Aggregate::initialize Default
2023-05-09T16:42:43.729Z,1683650563.729 [Default:B.GoToSurface] Running Loop=1
2023-05-09T16:42:43.729Z,1683650563.729 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-09T16:42:43.730Z,1683650563.730 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-09T16:42:43.730Z,1683650563.730 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-09T16:42:43.730Z,1683650563.730 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-09T16:42:43.731Z,1683650563.731 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-09T16:42:43.731Z,1683650563.731 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-09T16:42:43.731Z,1683650563.731 [Default:A.Wait] Running Loop=1
2023-05-09T16:42:43.731Z,1683650563.731 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-09T16:42:43.916Z,1683650563.916 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:43.916Z,1683650563.916 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:44.168Z,1683650564.168 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:44.169Z,1683650564.169 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:44.420Z,1683650564.420 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:44.421Z,1683650564.421 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:44.672Z,1683650564.672 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:44.673Z,1683650564.673 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:44.924Z,1683650564.924 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:45.176Z,1683650565.176 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:45.176Z,1683650565.176 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:45.428Z,1683650565.428 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:45.429Z,1683650565.429 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:45.680Z,1683650565.680 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:45.681Z,1683650565.681 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:45.932Z,1683650565.932 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:45.932Z,1683650565.932 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:46.185Z,1683650566.185 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:46.185Z,1683650566.185 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-09T16:42:46.185Z,1683650566.185 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:42:46.185Z,1683650566.185 [DATMMP](INFO): Handled
2023-05-09T16:42:46.186Z,1683650566.186 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:46.186Z,1683650566.186 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:46.437Z,1683650566.437 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:46.437Z,1683650566.437 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x2A	 x2C	 x810
2023-05-09T16:42:46.438Z,1683650566.438 [DATMMP](INFO): Rx dataTimestamp_ set to:1683650584.163840
2023-05-09T16:42:46.438Z,1683650566.438 [DATMMP](INFO): Rx ping set to:1683650566.437487
2023-05-09T16:42:46.438Z,1683650566.438 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:42:46.439Z,1683650566.439 [DATMMP](INFO): Handled
2023-05-09T16:42:46.439Z,1683650566.439 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:46.439Z,1683650566.439 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:46.688Z,1683650566.688 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:46.689Z,1683650566.689 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:46.949Z,1683650566.949 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:46.950Z,1683650566.950 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 x5	 x9	 x0
2023-05-09T16:42:46.950Z,1683650566.950 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-09T16:42:46.950Z,1683650566.950 [DATMMP](INFO): Received message type: remote_header
2023-05-09T16:42:46.950Z,1683650566.950 [DATMMP](INFO): Handled
2023-05-09T16:42:46.951Z,1683650566.951 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:46.951Z,1683650566.951 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:47.203Z,1683650567.203 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:47.203Z,1683650567.203 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:42:47.204Z,1683650567.204 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:42:47.204Z,1683650567.204 [DATMMP](INFO): Handled
2023-05-09T16:42:47.204Z,1683650567.204 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:47.204Z,1683650567.204 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:47.456Z,1683650567.456 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:47.458Z,1683650567.458 [DATMMP](INFO): directional_debug rx: 	 xDD8	 x1D3	 x21	 x11B	 xF70	 x1191	 x10F2	 x14C3
2023-05-09T16:42:47.459Z,1683650567.459 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:42:47.459Z,1683650567.459 [DATMMP](INFO): Handled
2023-05-09T16:42:47.459Z,1683650567.459 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:47.459Z,1683650567.459 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:47.711Z,1683650567.711 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:47.713Z,1683650567.713 [DATMMP](INFO): directional rx: 	 xDD0	 x18D	 x614	 xFE2D	 xBE6	 xFE30	 x0	 x5E5	 x5	 xFFEE	 x2318600	 x0
2023-05-09T16:42:47.714Z,1683650567.714 [DATMMP](INFO): Received message type: directional
2023-05-09T16:42:47.715Z,1683650567.715 [DATMMP](INFO): Handled
2023-05-09T16:42:47.715Z,1683650567.715 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:47.715Z,1683650567.715 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:47.795Z,1683650567.795 [Reporter](INFO): DATMMP.acoustic_contact_range 0.000000 m
2023-05-09T16:42:47.965Z,1683650567.965 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:47.966Z,1683650567.966 [DATMMP](INFO): acstats rx: 	 x9	 x5	 xFFFF	 x2D0	 x22	 x90	 xB7	 xC2	 xD	 xFFFF	 xA7	 x24	 xD	 x0
2023-05-09T16:42:47.967Z,1683650567.967 [DATMMP](INFO): Received message type: acstats
2023-05-09T16:42:47.967Z,1683650567.967 [DATMMP](INFO): Handled
2023-05-09T16:42:47.967Z,1683650567.967 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:47.967Z,1683650567.967 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:48.217Z,1683650568.217 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:48.217Z,1683650568.217 [DATMMP](INFO): data_rx rx: 	 x9	 x0	 x0	 x4
2023-05-09T16:42:48.218Z,1683650568.218 [DATMMP](INFO): Check CRC
2023-05-09T16:42:48.218Z,1683650568.218 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-09T16:42:48.218Z,1683650568.218 [DATMMP](INFO): Got DATA: len 4
2023-05-09T16:42:48.218Z,1683650568.218 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-09T16:42:48.218Z,1683650568.218 [DATMMP](INFO): Got ~~ ack, bytes left 2
2023-05-09T16:42:48.218Z,1683650568.218 [DATMMP](INFO): Received command: 

2023-05-09T16:42:48.219Z,1683650568.219 [DATMMP](INFO): Received message type: data_rx
2023-05-09T16:42:48.219Z,1683650568.219 [DATMMP](INFO): Handled
2023-05-09T16:42:48.219Z,1683650568.219 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-09T16:42:48.219Z,1683650568.219 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-09T16:42:48.219Z,1683650568.219 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:48.468Z,1683650568.468 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-09T16:42:48.469Z,1683650568.469 [DATMMP](ERROR): Waiting for previous to be ack'd
2023-05-09T16:42:48.469Z,1683650568.469 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-09T16:42:48.469Z,1683650568.469 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:48.720Z,1683650568.720 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-09T16:42:48.721Z,1683650568.721 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-09T16:42:48.721Z,1683650568.721 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:48.972Z,1683650568.972 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-09T16:42:48.973Z,1683650568.973 [DATMMP](INFO): Tx to 9 len 32 xid 32
2023-05-09T16:42:48.974Z,1683650568.974 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-09T16:42:48.974Z,1683650568.974 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-09T16:42:48.974Z,1683650568.974 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:49.225Z,1683650569.225 [DATMMP](INFO): GSXN notify for xid: 32
2023-05-09T16:42:49.226Z,1683650569.226 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-09T16:42:49.226Z,1683650569.226 [DATMMP](DEBUG): Command complete send
2023-05-09T16:42:49.226Z,1683650569.226 [DATMMP](ERROR): 1:COMPLETE
2023-05-09T16:42:49.226Z,1683650569.226 [DATMMP](INFO): Received message type: cmd_result
2023-05-09T16:42:49.226Z,1683650569.226 [DATMMP](INFO): Handled
2023-05-09T16:42:49.226Z,1683650569.226 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:49.227Z,1683650569.227 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:49.477Z,1683650569.477 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:49.478Z,1683650569.478 [DATMMP](INFO): timestamp rx: 	 x0	 x10	 x2A	 x2F	 x170B
2023-05-09T16:42:49.478Z,1683650569.478 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:42:49.478Z,1683650569.478 [DATMMP](INFO): Handled
2023-05-09T16:42:49.478Z,1683650569.478 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:49.478Z,1683650569.478 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:49.731Z,1683650569.731 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:49.731Z,1683650569.731 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:49.984Z,1683650569.984 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:49.984Z,1683650569.984 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:50.236Z,1683650570.236 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:50.237Z,1683650570.237 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:50.488Z,1683650570.488 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:50.489Z,1683650570.489 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:50.740Z,1683650570.740 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:50.741Z,1683650570.741 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:50.992Z,1683650570.992 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:50.993Z,1683650570.993 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:51.244Z,1683650571.244 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:51.245Z,1683650571.245 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:51.496Z,1683650571.496 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:51.497Z,1683650571.497 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:51.756Z,1683650571.756 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:51.757Z,1683650571.757 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:52.008Z,1683650572.008 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:52.008Z,1683650572.008 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:52.260Z,1683650572.260 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:52.261Z,1683650572.261 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:52.512Z,1683650572.512 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:52.512Z,1683650572.512 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:52.764Z,1683650572.764 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:52.765Z,1683650572.765 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:53.016Z,1683650573.016 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:53.017Z,1683650573.017 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:53.269Z,1683650573.269 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:53.269Z,1683650573.269 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:53.520Z,1683650573.520 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:53.521Z,1683650573.521 [DATMMP](INFO): doppler rx: 	 x0
2023-05-09T16:42:53.521Z,1683650573.521 [DATMMP](INFO): Received message type: doppler
2023-05-09T16:42:53.521Z,1683650573.521 [DATMMP](INFO): Handled
2023-05-09T16:42:53.522Z,1683650573.522 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:53.522Z,1683650573.522 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:53.775Z,1683650573.775 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:53.776Z,1683650573.776 [DATMMP](INFO): timestamp rx: 	 x1	 x10	 x2A	 x33	 x15BC
2023-05-09T16:42:53.777Z,1683650573.777 [DATMMP](INFO): Rx dataTimestamp_ set to:1683650625.352256
2023-05-09T16:42:53.777Z,1683650573.777 [DATMMP](INFO): Rx ping set to:1683650573.776424
2023-05-09T16:42:53.777Z,1683650573.777 [DATMMP](INFO): Received message type: timestamp
2023-05-09T16:42:53.777Z,1683650573.777 [DATMMP](INFO): Handled
2023-05-09T16:42:53.778Z,1683650573.778 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:53.778Z,1683650573.778 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:54.028Z,1683650574.028 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:54.029Z,1683650574.029 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:54.281Z,1683650574.281 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:54.282Z,1683650574.282 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 x5	 x9	 x0
2023-05-09T16:42:54.282Z,1683650574.282 [DATMMP](INFO): DATA Src=9, Dst=5
2023-05-09T16:42:54.282Z,1683650574.282 [DATMMP](INFO): Received message type: remote_header
2023-05-09T16:42:54.282Z,1683650574.282 [DATMMP](INFO): Handled
2023-05-09T16:42:54.283Z,1683650574.283 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:54.283Z,1683650574.283 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:54.533Z,1683650574.533 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:54.533Z,1683650574.533 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-09T16:42:54.534Z,1683650574.534 [DATMMP](INFO): Received message type: nav_stat
2023-05-09T16:42:54.534Z,1683650574.534 [DATMMP](INFO): Handled
2023-05-09T16:42:54.534Z,1683650574.534 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:54.534Z,1683650574.534 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:54.784Z,1683650574.784 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:54.786Z,1683650574.786 [DATMMP](INFO): directional_debug rx: 	 xDF6	 x1CD	 x23	 x13F	 xF80	 x11E1	 x1142	 x14D3
2023-05-09T16:42:54.787Z,1683650574.787 [DATMMP](INFO): Received message type: directional_debug
2023-05-09T16:42:54.787Z,1683650574.787 [DATMMP](INFO): Handled
2023-05-09T16:42:54.787Z,1683650574.787 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:54.787Z,1683650574.787 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:55.037Z,1683650575.037 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:55.038Z,1683650575.038 [DATMMP](INFO): directional rx: 	 xDED	 x185	 x5F6	 xFE33	 xBC7	 xFE38	 x0	 x5E3	 x5	 xFFEE	 x2318600	 x0
2023-05-09T16:42:55.040Z,1683650575.040 [DATMMP](INFO): Received message type: directional
2023-05-09T16:42:55.040Z,1683650575.040 [DATMMP](INFO): Handled
2023-05-09T16:42:55.040Z,1683650575.040 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:55.040Z,1683650575.040 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:55.289Z,1683650575.289 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:55.290Z,1683650575.290 [DATMMP](INFO): acstats rx: 	 x9	 x5	 x0	 x2D0	 x22	 x98	 xB8	 xC0	 xD	 xFFFF	 xAF	 x21	 xD	 x0
2023-05-09T16:42:55.290Z,1683650575.290 [DATMMP](INFO): Received message type: acstats
2023-05-09T16:42:55.291Z,1683650575.291 [DATMMP](INFO): Handled
2023-05-09T16:42:55.291Z,1683650575.291 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-09T16:42:55.291Z,1683650575.291 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:55.437Z,1683650575.437 [Reporter](INFO): DATMMP.acoustic_contact_range 0.000000 m
2023-05-09T16:42:55.541Z,1683650575.541 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-09T16:42:55.542Z,1683650575.542 [DATMMP](INFO): data_rx rx: 	 x9	 x0	 x0	 x4
2023-05-09T16:42:55.542Z,1683650575.542 [DATMMP](INFO): Check CRC
2023-05-09T16:42:55.542Z,1683650575.542 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-09T16:42:55.542Z,1683650575.542 [DATMMP](INFO): Got DATA: len 4
2023-05-09T16:42:55.542Z,1683650575.542 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-09T16:42:55.542Z,1683650575.542 [DATMMP](INFO): Got ~~ ack, bytes left 2
2023-05-09T16:42:55.543Z,1683650575.543 [DATMMP](INFO): Received command: 

2023-05-09T16:42:55.543Z,1683650575.543 [DATMMP](INFO): Received message type: data_rx
2023-05-09T16:42:55.543Z,1683650575.543 [DATMMP](INFO): Handled
2023-05-09T16:42:55.543Z,1683650575.543 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-09T16:42:55.543Z,1683650575.543 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-09T16:42:55.544Z,1683650575.544 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:55.795Z,1683650575.795 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:56.048Z,1683650576.048 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:56.300Z,1683650576.300 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:56.552Z,1683650576.552 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:56.804Z,1683650576.804 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:57.023Z,1683650577.023 [Default:A.Wait](INFO): Done Waiting.
2023-05-09T16:42:57.023Z,1683650577.023 [Default:A.Wait] Stopped
2023-05-09T16:42:57.023Z,1683650577.023 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-09T16:42:57.056Z,1683650577.056 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:57.308Z,1683650577.308 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:57.433Z,1683650577.433 [Default:CheckIn] Running Loop=1
2023-05-09T16:42:57.433Z,1683650577.433 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-09T16:42:57.433Z,1683650577.433 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-09T16:42:57.560Z,1683650577.560 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:57.815Z,1683650577.815 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:58.068Z,1683650578.068 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:58.321Z,1683650578.321 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:58.572Z,1683650578.572 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:58.824Z,1683650578.824 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:59.076Z,1683650579.076 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:42:59.328Z,1683650579.328 [DATMMP](INFO): Range requested while waiting for previous to complete.*
2023-05-09T16:43:30.139Z,1683650610.139 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-09T16:43:30.220Z,1683650610.220 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-05-09T16:45:42.344Z,1683650742.344 [CommandExec](IMPORTANT): got command failComponent hardware DATMMP
2023-05-09T16:45:42.344Z,1683650742.344 [DATMMP] Hardware Fault, FailCount= 1
2023-05-09T16:45:42.344Z,1683650742.344 [DATMMP](ERROR): Hardware Fault
2023-05-09T16:45:42.345Z,1683650742.345 [CommandExec](IMPORTANT): DATMMP failureMode is Hardware Fault
2023-05-09T16:45:42.383Z,1683650742.383 [CBIT](ERROR): Hardware Fault in component: DATMMP
2023-05-09T16:45:42.388Z,1683650742.388 [DATMMP](INFO): Stop
2023-05-09T16:45:42.389Z,1683650742.389 [DATMMP](INFO): uninitialize
2023-05-09T16:45:42.389Z,1683650742.389 [DATMMP](INFO): Powering down
2023-05-09T16:45:42.864Z,1683650742.864 [DATMMP](INFO): Stopping
2023-05-09T16:45:43.268Z,1683650743.268 [DATMMP](INFO): Stopped
2023-05-09T16:45:43.492Z,1683650743.492 [CBIT](INFO): Clearing failed state for component DATMMP
2023-05-09T16:45:43.492Z,1683650743.492 [DATMMP] No Fault, FailCount= 1
2023-05-09T16:45:43.673Z,1683650743.673 [DATMMP](INFO): Start
2023-05-09T16:45:43.924Z,1683650743.924 [DATMMP](INFO): Start
2023-05-09T16:45:44.176Z,1683650744.176 [DATMMP](INFO): Start
2023-05-09T16:45:44.428Z,1683650744.428 [DATMMP](INFO): Start
2023-05-09T16:45:44.680Z,1683650744.680 [DATMMP](INFO): Start
2023-05-09T16:45:44.932Z,1683650744.932 [DATMMP](INFO): Start
2023-05-09T16:45:45.184Z,1683650745.184 [DATMMP](INFO): Start
2023-05-09T16:45:45.436Z,1683650745.436 [DATMMP](INFO): Start
2023-05-09T16:45:45.436Z,1683650745.436 [DATMMP](INFO): Powering up
2023-05-09T16:45:45.436Z,1683650745.436 [DATMMP](DEBUG): Initializing DATMMP.
2023-05-09T16:45:45.688Z,1683650745.688 [DATMMP](INFO): in MMP mode: config complete going to runnable
2023-05-09T16:47:57.604Z,1683650877.604 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-09T16:42:57.4Z
2023-05-09T16:47:57.604Z,1683650877.604 [Default:CheckIn:Read_GPS] Stopped
2023-05-09T16:47:57.604Z,1683650877.604 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-09T16:48:01.225Z,1683650881.225 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-09T16:48:05.243Z,1683650885.243 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20230509T163230/Courier0007.lzma
2023-05-09T16:48:06.246Z,1683650886.246 [DataOverHttps](INFO): Moved sent file to Logs/20230509T163230/Courier0007.lzma.bak
2023-05-09T16:48:06.246Z,1683650886.246 [DataOverHttps](INFO): SBD MOMSN=18283411
2023-05-09T16:48:23.241Z,1683650903.241 [DataOverHttps](INFO): Sending 404 bytes from file Logs/20230509T163230/Express0008.lzma
2023-05-09T16:48:24.249Z,1683650904.249 [DataOverHttps](INFO): Moved sent file to Logs/20230509T163230/Express0008.lzma.bak
2023-05-09T16:48:24.249Z,1683650904.249 [DataOverHttps](INFO): SBD MOMSN=18283413
2023-05-09T16:48:26.732Z,1683650906.732 [Default:CheckIn:Read_Iridium] Stopped
2023-05-09T16:48:26.732Z,1683650906.732 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-09T16:48:26.732Z,1683650906.732 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-09T16:48:31.969Z,1683650911.969 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-09T16:49:47.765Z,1683650987.765 [CommandExec](IMPORTANT): got command show variable _rage
2023-05-09T16:49:51.205Z,1683650991.205 [CommandExec](IMPORTANT): got command show variable _range
2023-05-09T16:49:51.207Z,1683650991.207 [CommandExec](IMPORTANT): acoustic_contact_range (meter)
2023-05-09T16:49:51.361Z,1683650991.361 [CommandExec](IMPORTANT): DATMMP.acoustic_contact_range (meter)
2023-05-09T16:50:42.961Z,1683651042.961 [CommandExec](IMPORTANT): got command restart application
2023-05-09T16:50:43.964Z,1683651043.964 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:43.964Z,1683651043.964 [CommandExec](INFO): Uninitializing the command executive.
2023-05-09T16:50:43.964Z,1683651043.964 [CommandExec](INFO): Uninitializing the command scheduler.
2023-05-09T16:50:43.965Z,1683651043.965 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:43.997Z,1683651043.997 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-05-09T16:50:43.997Z,1683651043.997 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-05-09T16:50:43.998Z,1683651043.998 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:43.998Z,1683651043.998 [NavChartDb](INFO): Join timeout helper Thread ID is 5238
2023-05-09T16:50:44.052Z,1683651044.052 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:44.053Z,1683651044.053 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:44.056Z,1683651044.056 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-05-09T16:50:44.056Z,1683651044.056 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:44.057Z,1683651044.057 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 5239
2023-05-09T16:50:44.465Z,1683651044.465 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:44.465Z,1683651044.465 [WetLabsBB2FL](INFO): Powering down
2023-05-09T16:50:44.466Z,1683651044.466 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:44.468Z,1683651044.468 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-05-09T16:50:44.468Z,1683651044.468 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:44.468Z,1683651044.468 [CTD_Seabird](INFO): Join timeout helper Thread ID is 5240
2023-05-09T16:50:45.192Z,1683651045.192 [CTD_Seabird](INFO): Powering down
2023-05-09T16:50:45.204Z,1683651045.204 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:45.204Z,1683651045.204 [CTD_Seabird](INFO): Powering down
2023-05-09T16:50:45.216Z,1683651045.216 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:45.216Z,1683651045.216 [ComponentRegistry](INFO): Shutting down DATMMP ThreadHandler
2023-05-09T16:50:45.216Z,1683651045.216 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:45.217Z,1683651045.217 [DATMMP](INFO): Join timeout helper Thread ID is 5241
2023-05-09T16:50:45.220Z,1683651045.220 [DATMMP](INFO): Stop
2023-05-09T16:50:45.220Z,1683651045.220 [DATMMP](INFO): uninitialize
2023-05-09T16:50:45.220Z,1683651045.220 [DATMMP](INFO): Powering down
2023-05-09T16:50:45.289Z,1683651045.289 [DATMMP ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:45.289Z,1683651045.289 [DATMMP](INFO): uninitialize
2023-05-09T16:50:45.289Z,1683651045.289 [DATMMP](INFO): Powering down
2023-05-09T16:50:45.290Z,1683651045.290 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:45.300Z,1683651045.300 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-05-09T16:50:45.300Z,1683651045.300 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:45.301Z,1683651045.301 [Radio_Surface](INFO): Join timeout helper Thread ID is 5242
2023-05-09T16:50:45.412Z,1683651045.412 [Radio_Surface](INFO): Powering down
2023-05-09T16:50:45.413Z,1683651045.413 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:45.413Z,1683651045.413 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:45.425Z,1683651045.425 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-05-09T16:50:45.425Z,1683651045.425 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:45.426Z,1683651045.426 [Onboard](INFO): Join timeout helper Thread ID is 5243
2023-05-09T16:50:45.632Z,1683651045.632 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2023-05-09T16:50:47.532Z,1683651047.532 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:47.532Z,1683651047.532 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.541Z,1683651047.541 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-05-09T16:50:47.541Z,1683651047.541 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.541Z,1683651047.541 [DataOverHttps](INFO): Join timeout helper Thread ID is 5244
2023-05-09T16:50:47.640Z,1683651047.640 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:47.640Z,1683651047.640 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.645Z,1683651047.645 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-05-09T16:50:47.645Z,1683651047.645 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.645Z,1683651047.645 [BackseatComponent](INFO): Join timeout helper Thread ID is 5245
2023-05-09T16:50:47.809Z,1683651047.809 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:47.809Z,1683651047.809 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.821Z,1683651047.821 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-05-09T16:50:47.821Z,1683651047.821 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.821Z,1683651047.821 [logger](INFO): Join timeout helper Thread ID is 5246
2023-05-09T16:50:47.838Z,1683651047.838 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:47.838Z,1683651047.838 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.841Z,1683651047.841 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-05-09T16:50:47.841Z,1683651047.841 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.841Z,1683651047.841 [CommandLine](INFO): Join timeout helper Thread ID is 5247
2023-05-09T16:50:47.920Z,1683651047.920 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:47.921Z,1683651047.921 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.941Z,1683651047.941 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-05-09T16:50:47.941Z,1683651047.941 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.941Z,1683651047.941 [CommandExec](INFO): Join timeout helper Thread ID is 5248
2023-05-09T16:50:47.943Z,1683651047.943 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-05-09T16:50:47.943Z,1683651047.943 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:47.943Z,1683651047.943 [controlThread](INFO): Join timeout helper Thread ID is 5249
2023-05-09T16:50:48.112Z,1683651048.112 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-09T16:50:48.112Z,1683651048.112 [controlThread](DEBUG): Uninitializing ControlThread
2023-05-09T16:50:48.113Z,1683651048.113 [AHRS_M2](INFO): Powering down
2023-05-09T16:50:48.185Z,1683651048.185 [NAL9602](INFO): Powering down
2023-05-09T16:50:48.187Z,1683651048.187 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-05-09T16:50:48.188Z,1683651048.188 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-05-09T16:50:48.188Z,1683651048.188 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-05-09T16:50:48.189Z,1683651048.189 [MissionManager](INFO): Uninitializing Mission Default
2023-05-09T16:50:48.189Z,1683651048.189 [Default] Stopped
2023-05-09T16:50:48.189Z,1683651048.189 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-09T16:50:48.189Z,1683651048.189 [Default:B.GoToSurface] Stopped
2023-05-09T16:50:48.189Z,1683651048.189 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-09T16:50:48.189Z,1683651048.189 [Default:CheckIn] Stopped
2023-05-09T16:50:48.190Z,1683651048.190 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-09T16:50:48.190Z,1683651048.190 [Default:CheckIn:C.Wait] Stopped
2023-05-09T16:50:48.190Z,1683651048.190 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-09T16:50:48.192Z,1683651048.192 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-05-09T16:50:48.193Z,1683651048.193 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-05-09T16:50:48.193Z,1683651048.193 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-05-09T16:50:48.193Z,1683651048.193 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-05-09T16:50:48.194Z,1683651048.194 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-05-09T16:50:48.194Z,1683651048.194 [BuoyancyServo](INFO): Powering down
2023-05-09T16:50:48.208Z,1683651048.208 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-05-09T16:50:48.208Z,1683651048.208 [ElevatorServo](INFO): Powering down
2023-05-09T16:50:48.209Z,1683651048.209 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-05-09T16:50:48.209Z,1683651048.209 [MassServo](INFO): Powering down
2023-05-09T16:50:48.210Z,1683651048.210 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-09T16:50:48.210Z,1683651048.210 [RudderServo](INFO): Powering down
2023-05-09T16:50:48.211Z,1683651048.211 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-05-09T16:50:48.211Z,1683651048.211 [ThrusterHE](INFO): Powering down
2023-05-09T16:50:48.212Z,1683651048.212 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-05-09T16:50:48.212Z,1683651048.212 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-05-09T16:50:48.212Z,1683651048.212 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-05-09T16:50:48.213Z,1683651048.213 [CBIT](DEBUG): Powering off loads.
2023-05-09T16:50:48.224Z,1683651048.224 [CBIT](DEBUG): Disabling WDT.
2023-05-09T16:50:48.236Z,1683651048.236 [CBIT](DEBUG): Opening all GF detection circuits.
2023-05-09T16:50:48.237Z,1683651048.237 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:48.279Z,1683651048.279 [DATMMP ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:48.284Z,1683651048.284 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:48.286Z,1683651048.286 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:48.291Z,1683651048.291 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:48.335Z,1683651048.335 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:48.378Z,1683651048.378 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:48.383Z,1683651048.383 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:48.416Z,1683651048.416 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-09T16:50:48.477Z,1683651048.477 [logger ThreadHandler](INFO): Thread cancelled.