2023-05-12T19:16:52.684Z,1683919012.684 [Supervisor](DEBUG): Initializing supervisor.
2023-05-12T19:16:52.689Z,1683919012.689 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-05-12T19:16:52.689Z,1683919012.689 [SyncHandler](INFO): Protected caller Thread ID is 1131
2023-05-12T19:16:52.690Z,1683919012.690 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-05-12T19:16:52.691Z,1683919012.691 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-05-12T19:16:52.692Z,1683919012.692 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1132
2023-05-12T19:16:52.696Z,1683919012.696 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-05-12T19:16:52.713Z,1683919012.713 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-05-12T19:16:52.714Z,1683919012.714 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-05-12T19:16:52.714Z,1683919012.714 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 1133
2023-05-12T19:16:52.718Z,1683919012.718 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-05-12T19:16:52.719Z,1683919012.719 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-05-12T19:16:52.720Z,1683919012.720 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1134
2023-05-12T19:16:52.722Z,1683919012.722 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-05-12T19:16:52.723Z,1683919012.723 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-05-12T19:16:52.723Z,1683919012.723 [logger ThreadHandler](INFO): Protected caller Thread ID is 1135
2023-05-12T19:16:52.727Z,1683919012.727 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-05-12T19:16:52.727Z,1683919012.727 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-05-12T19:16:52.729Z,1683919012.729 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-05-12T19:16:53.177Z,1683919013.177 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-05-12T19:16:53.177Z,1683919013.177 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-05-12T19:16:53.384Z,1683919013.384 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-05-12T19:16:53.384Z,1683919013.384 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-05-12T19:16:53.466Z,1683919013.466 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-05-12T19:16:53.678Z,1683919013.678 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-05-12T19:16:53.678Z,1683919013.678 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-05-12T19:16:53.758Z,1683919013.758 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-05-12T19:16:53.853Z,1683919013.853 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-05-12T19:16:53.854Z,1683919013.854 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-05-12T19:16:54.179Z,1683919014.179 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-05-12T19:16:54.180Z,1683919014.180 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-05-12T19:16:54.309Z,1683919014.309 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-05-12T19:16:54.310Z,1683919014.310 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-05-12T19:16:54.791Z,1683919014.791 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-05-12T19:16:54.792Z,1683919014.792 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-05-12T19:16:54.970Z,1683919014.970 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-05-12T19:16:54.971Z,1683919014.971 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-05-12T19:16:55.356Z,1683919015.356 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-05-12T19:16:55.356Z,1683919015.356 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-05-12T19:16:55.628Z,1683919015.628 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-05-12T19:16:55.629Z,1683919015.629 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-05-12T19:16:55.737Z,1683919015.737 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-05-12T19:16:55.738Z,1683919015.738 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-05-12T19:16:56.487Z,1683919016.487 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-05-12T19:16:56.488Z,1683919016.488 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-05-12T19:16:56.841Z,1683919016.841 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-05-12T19:16:56.841Z,1683919016.841 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-05-12T19:16:57.361Z,1683919017.361 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-05-12T19:16:57.364Z,1683919017.364 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-05-12T19:16:57.365Z,1683919017.365 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-05-12T19:16:57.000Z,1683919018.000 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-05-12T19:16:58.084Z,1683919018.084 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-05-12T19:16:58.216Z,1683919018.216 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-05-12T19:16:58.302Z,1683919018.302 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-05-12T19:16:58.561Z,1683919018.561 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-05-12T19:16:58.562Z,1683919018.562 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-05-12T19:16:58.666Z,1683919018.666 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-05-12T19:16:58.773Z,1683919018.773 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-05-12T19:16:58.885Z,1683919018.885 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-05-12T19:16:59.032Z,1683919019.032 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-05-12T19:16:59.131Z,1683919019.131 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-05-12T19:16:59.226Z,1683919019.226 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/root/
2023-05-12T19:16:59.226Z,1683919019.226 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-05-12T19:16:59.238Z,1683919019.238 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-05-12T19:16:59.249Z,1683919019.249 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-05-12T19:16:59.249Z,1683919019.249 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-05-12T19:16:59.344Z,1683919019.344 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-05-12T19:16:59.345Z,1683919019.345 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-05-12T19:16:59.392Z,1683919019.392 [VerticalControl](DEBUG): Construct VerticalControl.
2023-05-12T19:16:59.451Z,1683919019.451 [VerticalControl] Loaded
2023-05-12T19:16:59.451Z,1683919019.451 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-05-12T19:16:59.454Z,1683919019.454 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-05-12T19:16:59.494Z,1683919019.494 [HorizontalControl] Loaded
2023-05-12T19:16:59.494Z,1683919019.494 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-05-12T19:16:59.497Z,1683919019.497 [SpeedControl](DEBUG): Construct SpeedControl.
2023-05-12T19:16:59.499Z,1683919019.499 [SpeedControl] Loaded
2023-05-12T19:16:59.500Z,1683919019.500 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-05-12T19:16:59.502Z,1683919019.502 [LoopControl](DEBUG): Construct LoopControl.
2023-05-12T19:16:59.503Z,1683919019.503 [LoopControl] Loaded
2023-05-12T19:16:59.503Z,1683919019.503 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-05-12T19:16:59.504Z,1683919019.504 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-05-12T19:16:59.504Z,1683919019.504 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-05-12T19:16:59.656Z,1683919019.656 [BuoyancyServo] Loaded
2023-05-12T19:16:59.656Z,1683919019.656 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-05-12T19:16:59.675Z,1683919019.675 [ElevatorServo] Loaded
2023-05-12T19:16:59.676Z,1683919019.676 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-05-12T19:16:59.694Z,1683919019.694 [MassServo] Loaded
2023-05-12T19:16:59.695Z,1683919019.695 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-05-12T19:16:59.713Z,1683919019.713 [RudderServo] Loaded
2023-05-12T19:16:59.713Z,1683919019.713 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-05-12T19:16:59.727Z,1683919019.727 [ThrusterHE] Loaded
2023-05-12T19:16:59.727Z,1683919019.727 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-05-12T19:16:59.728Z,1683919019.728 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-05-12T19:16:59.728Z,1683919019.728 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-05-12T19:16:59.778Z,1683919019.778 [DepthRateCalculator] Loaded
2023-05-12T19:16:59.778Z,1683919019.778 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-05-12T19:16:59.783Z,1683919019.783 [PitchRateCalculator] Loaded
2023-05-12T19:16:59.783Z,1683919019.783 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-05-12T19:16:59.792Z,1683919019.792 [SpeedCalculator] Loaded
2023-05-12T19:16:59.793Z,1683919019.793 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-05-12T19:16:59.797Z,1683919019.797 [YawRateCalculator] Loaded
2023-05-12T19:16:59.797Z,1683919019.797 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-05-12T19:16:59.815Z,1683919019.815 [ElevatorOffsetCalculator] Loaded
2023-05-12T19:16:59.815Z,1683919019.815 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-05-12T19:16:59.816Z,1683919019.816 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-05-12T19:16:59.816Z,1683919019.816 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-05-12T19:16:59.926Z,1683919019.926 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-05-12T19:16:59.926Z,1683919019.926 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-05-12T19:16:59.939Z,1683919019.939 [NavChart] Loaded
2023-05-12T19:16:59.940Z,1683919019.940 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-05-12T19:16:59.945Z,1683919019.945 [UniversalFixResidualReporter] Loaded
2023-05-12T19:16:59.945Z,1683919019.945 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-05-12T19:16:59.946Z,1683919019.946 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-05-12T19:16:59.946Z,1683919019.946 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-05-12T19:17:00.396Z,1683919020.396 [AHRS_M2] Loaded
2023-05-12T19:17:00.397Z,1683919020.397 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-05-12T19:17:00.431Z,1683919020.431 [BackseatComponent] Loaded
2023-05-12T19:17:00.431Z,1683919020.431 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-05-12T19:17:00.433Z,1683919020.433 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408F74E0
2023-05-12T19:17:00.433Z,1683919020.433 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 1217
2023-05-12T19:17:00.436Z,1683919020.436 [LcmUniversalReporter] Loaded
2023-05-12T19:17:00.436Z,1683919020.436 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-05-12T19:17:01.977Z,1683919021.977 [BPC1] Loaded
2023-05-12T19:17:01.977Z,1683919021.977 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-05-12T19:17:03.183Z,1683919023.182 [DATMMP] Loaded
2023-05-12T19:17:03.183Z,1683919023.183 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2023-05-12T19:17:03.185Z,1683919023.185 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 409284E0
2023-05-12T19:17:03.185Z,1683919023.185 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 1218
2023-05-12T19:17:03.369Z,1683919023.369 [DataOverHttps] Loaded
2023-05-12T19:17:03.369Z,1683919023.369 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-05-12T19:17:03.370Z,1683919023.370 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409584E0
2023-05-12T19:17:03.370Z,1683919023.370 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1219
2023-05-12T19:17:03.410Z,1683919023.410 [Depth_Keller] Loaded
2023-05-12T19:17:03.410Z,1683919023.410 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-05-12T19:17:03.472Z,1683919023.472 [NAL9602] Loaded
2023-05-12T19:17:03.472Z,1683919023.472 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-05-12T19:17:03.501Z,1683919023.501 [Onboard] Loaded
2023-05-12T19:17:03.501Z,1683919023.501 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-05-12T19:17:03.502Z,1683919023.502 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409884E0
2023-05-12T19:17:03.502Z,1683919023.502 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 1220
2023-05-12T19:17:03.514Z,1683919023.514 [Power24vConverter] Loaded
2023-05-12T19:17:03.514Z,1683919023.514 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-05-12T19:17:03.527Z,1683919023.527 [Radio_Surface] Loaded
2023-05-12T19:17:03.528Z,1683919023.528 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-05-12T19:17:03.529Z,1683919023.529 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409B84E0
2023-05-12T19:17:03.529Z,1683919023.529 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1221
2023-05-12T19:17:03.530Z,1683919023.530 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-05-12T19:17:03.531Z,1683919023.531 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-05-12T19:17:03.601Z,1683919023.601 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-05-12T19:17:03.602Z,1683919023.602 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-05-12T19:17:03.747Z,1683919023.747 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-05-12T19:17:03.748Z,1683919023.748 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-05-12T19:17:03.773Z,1683919023.773 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-05-12T19:17:03.774Z,1683919023.774 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-05-12T19:17:03.938Z,1683919023.938 [CTD_Seabird] Loaded
2023-05-12T19:17:03.938Z,1683919023.938 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-05-12T19:17:03.939Z,1683919023.939 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AEF4E0
2023-05-12T19:17:03.940Z,1683919023.940 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1222
2023-05-12T19:17:03.972Z,1683919023.972 [ESPComponent] Loaded
2023-05-12T19:17:03.972Z,1683919023.972 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-05-12T19:17:03.991Z,1683919023.991 [PAR_Licor] Loaded
2023-05-12T19:17:03.992Z,1683919023.992 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-05-12T19:17:04.022Z,1683919024.022 [WetLabsBB2FL] Loaded
2023-05-12T19:17:04.023Z,1683919024.023 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-05-12T19:17:04.024Z,1683919024.024 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B1F4E0
2023-05-12T19:17:04.024Z,1683919024.024 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1223
2023-05-12T19:17:04.025Z,1683919024.025 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-05-12T19:17:04.025Z,1683919024.025 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-05-12T19:17:04.324Z,1683919024.324 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-05-12T19:17:04.325Z,1683919024.325 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-05-12T19:17:04.458Z,1683919024.458 [SBIT](DEBUG): Construct Startup Built In Test.
2023-05-12T19:17:04.467Z,1683919024.467 [SBIT] Loaded
2023-05-12T19:17:04.468Z,1683919024.468 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-05-12T19:17:04.471Z,1683919024.471 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-05-12T19:17:04.483Z,1683919024.483 [IBIT] Loaded
2023-05-12T19:17:04.484Z,1683919024.484 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-05-12T19:17:04.489Z,1683919024.489 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-05-12T19:17:04.593Z,1683919024.593 [CBIT] Loaded
2023-05-12T19:17:04.593Z,1683919024.593 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-05-12T19:17:04.593Z,1683919024.593 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-05-12T19:17:04.599Z,1683919024.599 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-05-12T19:17:04.602Z,1683919024.602 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-05-12T19:17:04.613Z,1683919024.613 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-05-12T19:17:04.614Z,1683919024.614 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C024E0
2023-05-12T19:17:04.615Z,1683919024.615 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1224
2023-05-12T19:17:04.619Z,1683919024.619 [Supervisor](INFO): Main Thread ID is 671
2023-05-12T19:17:04.619Z,1683919024.619 [Supervisor](DEBUG): Running supervisor.
2023-05-12T19:17:04.620Z,1683919024.620 [CommandExec ThreadHandler](INFO): Handler Thread ID is 1225
2023-05-12T19:17:04.620Z,1683919024.620 [CommandExec](INFO): Initializing the command executive.
2023-05-12T19:17:04.622Z,1683919024.622 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1226
2023-05-12T19:17:04.624Z,1683919024.624 [controlThread ThreadHandler](INFO): Handler Thread ID is 1227
2023-05-12T19:17:04.624Z,1683919024.624 [controlThread](DEBUG): Initializing ControlThread
2023-05-12T19:17:04.625Z,1683919024.625 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-05-12T19:17:04.627Z,1683919024.627 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-05-12T19:17:04.627Z,1683919024.627 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-05-12T19:17:04.628Z,1683919024.628 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-05-12T19:17:04.629Z,1683919024.629 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-05-12T19:17:04.630Z,1683919024.630 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-05-12T19:17:04.630Z,1683919024.630 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-05-12T19:17:04.630Z,1683919024.630 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-05-12T19:17:04.631Z,1683919024.631 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-05-12T19:17:04.632Z,1683919024.632 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-05-12T19:17:04.632Z,1683919024.632 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-05-12T19:17:04.640Z,1683919024.640 [SBIT](INFO): Initialize SBIT Component.
2023-05-12T19:17:04.641Z,1683919024.641 [SBIT](IMPORTANT): git: 2023-04-26-68-gd8052d973
2023-05-12T19:17:04.641Z,1683919024.641 [SBIT](INFO): git hash: d8052d9734beefc1bd50265fa9cca972428f086c
2023-05-12T19:17:04.641Z,1683919024.641 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-05-12T19:17:04.642Z,1683919024.642 [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-12T19:17:04.643Z,1683919024.643 [SBIT](INFO): Beginning SBIT in 81.000000 seconds.
2023-05-12T19:17:04.644Z,1683919024.644 [IBIT](INFO): Initialize IBIT Component.
2023-05-12T19:17:04.645Z,1683919024.645 [CBIT](DEBUG): Initialize CBIT Component.
2023-05-12T19:17:04.646Z,1683919024.646 [logger ThreadHandler](INFO): Handler Thread ID is 1228
2023-05-12T19:17:04.656Z,1683919024.656 [CBIT](DEBUG): Initialized mux pins.
2023-05-12T19:17:04.656Z,1683919024.656 [CBIT](DEBUG): Initializing the watchdog timer.
2023-05-12T19:17:04.664Z,1683919024.664 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 1229
2023-05-12T19:17:04.676Z,1683919024.676 [DATMMP ThreadHandler](INFO): Handler Thread ID is 1230
2023-05-12T19:17:04.677Z,1683919024.677 [DATMMP](INFO): Start
2023-05-12T19:17:04.677Z,1683919024.677 [DATMMP](INFO): Powering up
2023-05-12T19:17:04.677Z,1683919024.677 [DATMMP](DEBUG): Initializing DATMMP.
2023-05-12T19:17:04.680Z,1683919024.680 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-05-12T19:17:04.681Z,1683919024.681 [CBIT](DEBUG): Initializing heartbeat.
2023-05-12T19:17:04.682Z,1683919024.682 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1232
2023-05-12T19:17:04.683Z,1683919024.683 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-05-12T19:17:04.693Z,1683919024.693 [Onboard ThreadHandler](INFO): Handler Thread ID is 1233
2023-05-12T19:17:04.710Z,1683919024.710 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1234
2023-05-12T19:17:04.732Z,1683919024.732 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1235
2023-05-12T19:17:04.733Z,1683919024.733 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-05-12T19:17:04.737Z,1683919024.737 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1237
2023-05-12T19:17:04.740Z,1683919024.740 [WetLabsBB2FL](INFO): Powering up
2023-05-12T19:17:04.742Z,1683919024.742 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1239
2023-05-12T19:17:04.745Z,1683919024.745 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-05-12T19:17:04.745Z,1683919024.745 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-05-12T19:17:04.745Z,1683919024.745 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-05-12T19:17:04.745Z,1683919024.745 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-05-12T19:17:04.746Z,1683919024.746 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-05-12T19:17:04.746Z,1683919024.746 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-05-12T19:17:04.746Z,1683919024.746 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-05-12T19:17:04.746Z,1683919024.746 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-05-12T19:17:04.752Z,1683919024.752 [CBIT](DEBUG): Deactivating GF circuits.
2023-05-12T19:17:04.752Z,1683919024.752 [CBIT](DEBUG): Deactivating emergency mode.
2023-05-12T19:17:04.792Z,1683919024.792 [CBIT](DEBUG): Backplane powered.
2023-05-12T19:17:04.793Z,1683919024.793 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-05-12T19:17:04.806Z,1683919024.806 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-12T19:17:04.829Z,1683919024.829 [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-12T19:17:04.830Z,1683919024.830 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-05-12T19:17:04.908Z,1683919024.908 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-05-12T19:17:04.909Z,1683919024.909 [Default:A.Wait](DEBUG): Construct Wait.
2023-05-12T19:17:04.912Z,1683919024.912 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-12T19:17:04.928Z,1683919024.928 [DATMMP](INFO): Starting
2023-05-12T19:17:04.970Z,1683919024.970 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-05-12T19:17:04.972Z,1683919024.972 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-05-12T19:17:04.994Z,1683919024.994 [Default:E.Execute](DEBUG): Construct Execute.
2023-05-12T19:17:04.997Z,1683919024.997 [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-12T19:17:05.016Z,1683919025.016 [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-12T19:17:05.023Z,1683919025.023 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-05-12T19:17:05.094Z,1683919025.094 [Power24vConverter](INFO): Powering up.
2023-05-12T19:17:05.116Z,1683919025.116 [Radio_Surface](INFO): Powering up
2023-05-12T19:17:05.180Z,1683919025.180 [DATMMP](INFO): Starting
2023-05-12T19:17:05.190Z,1683919025.190 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-05-12T19:17:05.196Z,1683919025.196 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-05-12T19:17:05.197Z,1683919025.197 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-05-12T19:17:05.204Z,1683919025.204 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-05-12T19:17:05.205Z,1683919025.205 [MassServo](DEBUG): Initializing EZServoServo.
2023-05-12T19:17:05.212Z,1683919025.212 [MassServo](DEBUG): Initializing MassServo.
2023-05-12T19:17:05.213Z,1683919025.213 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-12T19:17:05.220Z,1683919025.220 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-12T19:17:05.221Z,1683919025.221 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-05-12T19:17:05.228Z,1683919025.228 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-05-12T19:17:05.432Z,1683919025.432 [DATMMP](INFO): Starting
2023-05-12T19:17:05.685Z,1683919025.685 [DATMMP](INFO): Starting
2023-05-12T19:17:05.936Z,1683919025.936 [DATMMP](INFO): Starting
2023-05-12T19:17:06.188Z,1683919026.188 [DATMMP](INFO): Starting
2023-05-12T19:17:06.440Z,1683919026.440 [DATMMP](INFO): Starting
2023-05-12T19:17:06.692Z,1683919026.692 [DATMMP](INFO): Starting
2023-05-12T19:17:06.848Z,1683919026.848 [WetLabsBB2FL](INFO): Powering down
2023-05-12T19:17:06.944Z,1683919026.944 [DATMMP](INFO): Starting
2023-05-12T19:17:07.196Z,1683919027.196 [DATMMP](INFO): Starting
2023-05-12T19:17:07.448Z,1683919027.448 [DATMMP](INFO): Starting
2023-05-12T19:17:07.700Z,1683919027.700 [DATMMP](INFO): Starting
2023-05-12T19:17:07.952Z,1683919027.952 [DATMMP](INFO): Starting
2023-05-12T19:17:08.204Z,1683919028.204 [DATMMP](INFO): Starting
2023-05-12T19:17:08.456Z,1683919028.456 [DATMMP](INFO): Starting
2023-05-12T19:17:08.708Z,1683919028.708 [DATMMP](INFO): Starting
2023-05-12T19:17:08.960Z,1683919028.960 [DATMMP](INFO): Starting
2023-05-12T19:17:09.212Z,1683919029.212 [DATMMP](INFO): Starting
2023-05-12T19:17:09.464Z,1683919029.464 [DATMMP](INFO): Starting
2023-05-12T19:17:09.717Z,1683919029.717 [DATMMP](INFO): Starting
2023-05-12T19:17:09.968Z,1683919029.968 [DATMMP](INFO): Starting
2023-05-12T19:17:10.220Z,1683919030.220 [DATMMP](INFO): Starting
2023-05-12T19:17:10.472Z,1683919030.472 [DATMMP](INFO): Starting
2023-05-12T19:17:10.724Z,1683919030.724 [DATMMP](INFO): Starting
2023-05-12T19:17:10.941Z,1683919030.941 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-05-12T19:17:10.978Z,1683919030.978 [DATMMP](INFO): Starting
2023-05-12T19:17:11.228Z,1683919031.228 [DATMMP](INFO): Starting
2023-05-12T19:17:11.480Z,1683919031.480 [DATMMP](INFO): Starting
2023-05-12T19:17:11.732Z,1683919031.732 [DATMMP](INFO): Starting
2023-05-12T19:17:11.984Z,1683919031.984 [DATMMP](INFO): Starting
2023-05-12T19:17:12.236Z,1683919032.236 [DATMMP](INFO): Starting
2023-05-12T19:17:12.488Z,1683919032.488 [DATMMP](INFO): Starting
2023-05-12T19:17:12.740Z,1683919032.740 [DATMMP](INFO): Starting
2023-05-12T19:17:12.992Z,1683919032.992 [DATMMP](INFO): Starting
2023-05-12T19:17:13.244Z,1683919033.244 [DATMMP](INFO): Starting
2023-05-12T19:17:13.496Z,1683919033.496 [DATMMP](INFO): Starting
2023-05-12T19:17:13.748Z,1683919033.748 [DATMMP](INFO): Starting
2023-05-12T19:17:14.000Z,1683919034.000 [DATMMP](INFO): Starting
2023-05-12T19:17:14.252Z,1683919034.252 [DATMMP](INFO): Starting
2023-05-12T19:17:14.504Z,1683919034.504 [DATMMP](INFO): Starting
2023-05-12T19:17:14.756Z,1683919034.756 [DATMMP](INFO): Starting
2023-05-12T19:17:15.008Z,1683919035.008 [DATMMP](INFO): Starting
2023-05-12T19:17:15.260Z,1683919035.260 [DATMMP](INFO): Starting
2023-05-12T19:17:15.513Z,1683919035.513 [DATMMP](INFO): Starting
2023-05-12T19:17:15.764Z,1683919035.764 [DATMMP](INFO): Starting
2023-05-12T19:17:16.016Z,1683919036.016 [DATMMP](INFO): Starting
2023-05-12T19:17:16.268Z,1683919036.268 [DATMMP](INFO): Starting
2023-05-12T19:17:16.520Z,1683919036.520 [DATMMP](INFO): Starting
2023-05-12T19:17:16.772Z,1683919036.772 [DATMMP](INFO): Starting
2023-05-12T19:17:17.024Z,1683919037.024 [DATMMP](INFO): Starting
2023-05-12T19:17:17.025Z,1683919037.025 [DATMMP](INFO): DAT read: 

2023-05-12T19:17:17.026Z,1683919037.026 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-05-12T19:17:17.276Z,1683919037.276 [DATMMP](INFO): Starting
2023-05-12T19:17:17.528Z,1683919037.528 [DATMMP](INFO): Starting
2023-05-12T19:17:17.780Z,1683919037.780 [DATMMP](INFO): Starting
2023-05-12T19:17:18.032Z,1683919038.032 [DATMMP](INFO): Starting
2023-05-12T19:17:18.284Z,1683919038.284 [DATMMP](INFO): Starting
2023-05-12T19:17:18.536Z,1683919038.536 [DATMMP](INFO): Starting
2023-05-12T19:17:18.537Z,1683919038.537 [DATMMP](INFO): DAT read: MF Frequency Band

2023-05-12T19:17:18.538Z,1683919038.538 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-05-12T19:17:18.538Z,1683919038.538 [DATMMP](INFO): DAT read: Apr 12 2000 19:17:13 

2023-05-12T19:17:18.788Z,1683919038.788 [DATMMP](INFO): Starting
2023-05-12T19:17:19.040Z,1683919039.040 [DATMMP](INFO): Starting
2023-05-12T19:17:19.292Z,1683919039.292 [DATMMP](INFO): Starting
2023-05-12T19:17:19.544Z,1683919039.544 [DATMMP](INFO): Starting
2023-05-12T19:17:19.796Z,1683919039.796 [DATMMP](INFO): Starting
2023-05-12T19:17:19.797Z,1683919039.797 [DATMMP](INFO): DAT read: Features enabled [Bearing]

2023-05-12T19:17:19.798Z,1683919039.798 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-12T19:17:19.799Z,1683919039.799 [DATMMP](INFO): commRate: 800
2023-05-12T19:17:20.048Z,1683919040.048 [DATMMP](INFO): Starting
2023-05-12T19:17:20.300Z,1683919040.300 [DATMMP](INFO): Starting
2023-05-12T19:17:20.552Z,1683919040.552 [DATMMP](INFO): Starting
2023-05-12T19:17:20.804Z,1683919040.804 [DATMMP](INFO): Starting
2023-05-12T19:17:21.056Z,1683919041.056 [DATMMP](INFO): Starting
2023-05-12T19:17:21.308Z,1683919041.308 [DATMMP](INFO): Starting
2023-05-12T19:17:21.560Z,1683919041.560 [DATMMP](INFO): Starting
2023-05-12T19:17:21.812Z,1683919041.812 [DATMMP](INFO): Starting
2023-05-12T19:17:21.864Z,1683919041.864 [DATMMP](INFO): entering command mode
2023-05-12T19:17:22.064Z,1683919042.064 [DATMMP](INFO): Starting
2023-05-12T19:17:22.065Z,1683919042.065 [DATMMP](INFO): DAT read: 

2023-05-12T19:17:22.065Z,1683919042.065 [DATMMP](INFO): DAT read: user:1>

2023-05-12T19:17:22.066Z,1683919042.066 [DATMMP](DEBUG): read user prompt 1: user:1>

2023-05-12T19:17:22.066Z,1683919042.066 [DATMMP](INFO): entering MMP mode
2023-05-12T19:17:22.316Z,1683919042.316 [DATMMP](INFO): Starting
2023-05-12T19:17:22.317Z,1683919042.317 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:17:22.318Z,1683919042.318 [DATMMP](INFO): status rx: 	 x1
2023-05-12T19:17:22.319Z,1683919042.319 [DATMMP](INFO): MMP status: 1: started
2023-05-12T19:17:22.319Z,1683919042.319 [DATMMP](INFO): Received message type: status
2023-05-12T19:17:22.319Z,1683919042.319 [DATMMP](INFO): Handled
2023-05-12T19:17:22.568Z,1683919042.568 [DATMMP](INFO): Starting
2023-05-12T19:17:22.570Z,1683919042.570 [DATMMP](INFO): Sent Tx Power Config 8
2023-05-12T19:17:22.570Z,1683919042.570 [DATMMP](INFO): Setting local address: 12
2023-05-12T19:17:22.572Z,1683919042.572 [DATMMP](INFO): Setting time to: 19:17:22 And date to:5/12/2023
2023-05-12T19:17:22.820Z,1683919042.820 [DATMMP](INFO): Starting
2023-05-12T19:17:22.820Z,1683919042.820 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:17:22.821Z,1683919042.821 [DATMMP](INFO): mdmpower rx: 	 x8	 x0	 x5	 x0
2023-05-12T19:17:22.821Z,1683919042.821 [DATMMP](INFO): Received message type: mdmpower
2023-05-12T19:17:22.822Z,1683919042.822 [DATMMP](INFO): Handled
2023-05-12T19:17:23.072Z,1683919043.072 [DATMMP](INFO): Starting
2023-05-12T19:17:23.072Z,1683919043.072 [DATMMP](INFO): GSXN notify for xid: 10
2023-05-12T19:17:23.073Z,1683919043.073 [DATMMP](INFO): sreg_txpower rx: 	 x8
2023-05-12T19:17:23.073Z,1683919043.073 [DATMMP](INFO): Received message type: sreg_txpower
2023-05-12T19:17:23.073Z,1683919043.073 [DATMMP](INFO): Match for : sreg_txpower
2023-05-12T19:17:23.074Z,1683919043.074 [DATMMP](INFO): ACK
2023-05-12T19:17:23.324Z,1683919043.324 [DATMMP](INFO): Starting
2023-05-12T19:17:23.325Z,1683919043.325 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:17:23.325Z,1683919043.325 [DATMMP](INFO): mdmlocal rx: 	 xC	 x0	 x0	 x0
2023-05-12T19:17:23.326Z,1683919043.326 [DATMMP](INFO): Received message type: mdmlocal
2023-05-12T19:17:23.326Z,1683919043.326 [DATMMP](INFO): Handled
2023-05-12T19:17:23.576Z,1683919043.576 [DATMMP](INFO): Starting
2023-05-12T19:17:23.576Z,1683919043.576 [DATMMP](INFO): GSXN notify for xid: 11
2023-05-12T19:17:23.577Z,1683919043.577 [DATMMP](INFO): sreg_locaddr rx: 	 xC
2023-05-12T19:17:23.577Z,1683919043.577 [DATMMP](INFO): Received message type: sreg_locaddr
2023-05-12T19:17:23.577Z,1683919043.577 [DATMMP](INFO): Match for : sreg_locaddr
2023-05-12T19:17:23.577Z,1683919043.577 [DATMMP](INFO): ACK
2023-05-12T19:17:23.828Z,1683919043.828 [DATMMP](INFO): Starting
2023-05-12T19:17:23.829Z,1683919043.829 [DATMMP](INFO): GSXN notify for xid: 12
2023-05-12T19:17:23.830Z,1683919043.830 [DATMMP](INFO): timedate rx: 	 x0	 x13	 x11	 x16	 x4	 xC	 x7B	 x0
2023-05-12T19:17:23.830Z,1683919043.830 [DATMMP](INFO): Received message type: timedate
2023-05-12T19:17:23.830Z,1683919043.830 [DATMMP](INFO): Match for : timedate
2023-05-12T19:17:23.830Z,1683919043.830 [DATMMP](INFO): ACK
2023-05-12T19:17:24.080Z,1683919044.080 [DATMMP](INFO): Starting
2023-05-12T19:17:24.081Z,1683919044.081 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:17:24.081Z,1683919044.081 [DATMMP](INFO): sys_verb rx: 	 x0	 x0	 x0	 x0
2023-05-12T19:17:24.082Z,1683919044.082 [DATMMP](INFO): Received message type: sys_verb
2023-05-12T19:17:24.082Z,1683919044.082 [DATMMP](INFO): Handled
2023-05-12T19:17:24.332Z,1683919044.332 [DATMMP](INFO): Starting
2023-05-12T19:17:24.332Z,1683919044.332 [DATMMP](INFO): GSXN notify for xid: 13
2023-05-12T19:17:24.333Z,1683919044.333 [DATMMP](INFO): sreg_verbosity rx: 	 x0
2023-05-12T19:17:24.333Z,1683919044.333 [DATMMP](INFO): Received message type: sreg_verbosity
2023-05-12T19:17:24.333Z,1683919044.333 [DATMMP](INFO): Match for : sreg_verbosity
2023-05-12T19:17:24.333Z,1683919044.333 [DATMMP](INFO): ACK
2023-05-12T19:17:24.584Z,1683919044.584 [DATMMP](INFO): Starting
2023-05-12T19:17:24.585Z,1683919044.585 [DATMMP](INFO): GSXN notify for xid: 14
2023-05-12T19:17:24.585Z,1683919044.585 [DATMMP](INFO): version rx: 	 x2	 x5
2023-05-12T19:17:24.586Z,1683919044.586 [DATMMP](INFO): DatMMPVersion: 2.5
2023-05-12T19:17:24.586Z,1683919044.586 [DATMMP](INFO): Received message type: version
2023-05-12T19:17:24.586Z,1683919044.586 [DATMMP](INFO): Match for : version
2023-05-12T19:17:24.586Z,1683919044.586 [DATMMP](INFO): ACK
2023-05-12T19:17:24.586Z,1683919044.586 [DATMMP](INFO): in MMP mode: config complete going to runnable
2023-05-12T19:17:33.713Z,1683919053.713 [NAL9602](INFO): Powering up NAL9602
2023-05-12T19:17:39.217Z,1683919059.217 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:17:39.218Z,1683919059.218 [DATMMP](INFO): timesync rx: 	 x0	 x1	 x1	 x0
2023-05-12T19:17:39.218Z,1683919059.218 [DATMMP](INFO): Received message type: timesync
2023-05-12T19:17:39.218Z,1683919059.218 [DATMMP](INFO): Handled
2023-05-12T19:17:42.523Z,1683919062.523 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.8 degree
2023-05-12T19:17:42.527Z,1683919062.527 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2023-05-12T19:17:42.527Z,1683919062.527 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.9 degree
2023-05-12T19:17:42.530Z,1683919062.530 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2023-05-12T19:17:42.531Z,1683919062.531 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.8 meter
2023-05-12T19:17:42.547Z,1683919062.547 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2023-05-12T19:17:42.547Z,1683919062.547 [CommandExec](IMPORTANT): got command report touch DATMMP.acoustic_contact_range
2023-05-12T19:17:42.548Z,1683919062.548 [CommandExec](IMPORTANT): got command report touch acoustic_contact_range
2023-05-12T19:17:42.686Z,1683919062.686 [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-12T19:17:44.641Z,1683919064.641 [NAL9602](INFO): NAL9602 initialized
2023-05-12T19:17:49.057Z,1683919069.057 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:17:49.058Z,1683919069.058 [DATMMP](INFO): timesync rx: 	 x1	 x0	 x1	 x0
2023-05-12T19:17:49.058Z,1683919069.058 [DATMMP](INFO): Received message type: timesync
2023-05-12T19:17:49.058Z,1683919069.058 [DATMMP](INFO): Handled
2023-05-12T19:18:01.142Z,1683919081.142 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.8 degree
2023-05-12T19:18:01.143Z,1683919081.143 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.9 degree
2023-05-12T19:18:01.143Z,1683919081.143 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.8 meter
2023-05-12T19:18:01.204Z,1683919081.204 [CommandExec](IMPORTANT): got command report touch DATMMP.acoustic_contact_range
2023-05-12T19:18:01.205Z,1683919081.205 [CommandExec](IMPORTANT): got command report touch acoustic_contact_range
2023-05-12T19:18:15.737Z,1683919095.737 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T19:18:17.541Z,1683919097.541 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1683919081 second
2023-05-12T19:18:26.300Z,1683919106.300 [SBIT](IMPORTANT): Beginning Startup BIT
2023-05-12T19:18:26.317Z,1683919106.317 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-12T19:18:37.168Z,1683919117.168 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.010399
CHAN A1 (24V): -0.007755
CHAN A2 (12V): -0.005181
CHAN A3 (5V): -0.003134
CHAN B0 (3.3V): -0.001229
CHAN B1 (3.15aV): -0.000979
CHAN B2 (3.15bV): -0.000923
CHAN B3 (GND): -0.000082
OPEN: 0.004390
Full Scale: +/- 1 mA
2023-05-12T19:19:20.011Z,1683919160.011 [SBIT](IMPORTANT): SBIT PASSED
2023-05-12T19:19:20.011Z,1683919160.011 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-05-12T19:19:20.012Z,1683919160.012 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2023-05-12T19:19:20.012Z,1683919160.012 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;

2023-05-12T19:19:20.012Z,1683919160.012 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2023-05-12T19:19:20.012Z,1683919160.012 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2023-05-12T19:19:20.012Z,1683919160.012 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2023-05-12T19:19:20.012Z,1683919160.012 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2023-05-12T19:19:20.013Z,1683919160.013 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-12T19:19:20.013Z,1683919160.013 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-12T19:19:20.013Z,1683919160.013 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;

2023-05-12T19:19:20.013Z,1683919160.013 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=184.896478 cubic_centimeter;

2023-05-12T19:19:20.013Z,1683919160.013 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;

2023-05-12T19:19:20.013Z,1683919160.013 [SBIT](IMPORTANT): VerticalControl.massDefault=15.484465 millimeter;

2023-05-12T19:19:20.411Z,1683919160.411 [MissionManager](IMPORTANT): Started mission Startup
2023-05-12T19:19:20.411Z,1683919160.411 [Startup] Running Loop=1
2023-05-12T19:19:20.412Z,1683919160.412 [Startup](DEBUG): Aggregate::initialize Startup
2023-05-12T19:19:20.412Z,1683919160.412 [Startup:A.GoToSurface] Running Loop=1
2023-05-12T19:19:20.412Z,1683919160.412 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-12T19:19:20.412Z,1683919160.412 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-12T19:19:20.413Z,1683919160.413 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-12T19:19:20.413Z,1683919160.413 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-12T19:19:20.413Z,1683919160.413 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-12T19:19:20.414Z,1683919160.414 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-12T19:19:20.415Z,1683919160.415 [Startup:StartupSatComms] Running Loop=1
2023-05-12T19:19:20.415Z,1683919160.415 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-05-12T19:19:20.415Z,1683919160.415 [Startup:StartupSatComms:A] Running Loop=1
2023-05-12T19:19:20.807Z,1683919160.807 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-05-12T19:19:20.808Z,1683919160.808 [Startup:StartupSatComms:A] Stopped
2023-05-12T19:19:20.808Z,1683919160.808 [Startup:StartupSatComms:B] Running Loop=1
2023-05-12T19:19:21.199Z,1683919161.199 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-12T19:19:31.898Z,1683919171.898 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:19:33.618Z,1683919173.618 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1683919160 second
2023-05-12T19:19:33.654Z,1683919173.654 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004752
2023-05-12T19:19:42.539Z,1683919182.539 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20230512T184143/Courier0007.lzma
2023-05-12T19:19:43.518Z,1683919183.518 [DataOverHttps](INFO): Moved sent file to Logs/20230512T184143/Courier0007.lzma.bak
2023-05-12T19:19:43.518Z,1683919183.518 [DataOverHttps](INFO): SBD MOMSN=18300495
2023-05-12T19:19:43.000Z,1683919184.000 [CommandExec](IMPORTANT): got command set NAL9602.platform_communications 1 bool
2023-05-12T19:19:44.077Z,1683919184.077 [Startup:StartupSatComms:B] Stopped
2023-05-12T19:19:44.077Z,1683919184.077 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-05-12T19:19:44.077Z,1683919184.077 [Startup:StartupSatComms] Stopped
2023-05-12T19:19:44.077Z,1683919184.077 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-05-12T19:19:44.078Z,1683919184.078 [Startup](INFO): Completed Startup
2023-05-12T19:19:44.078Z,1683919184.078 [MissionManager](INFO): Startup is completed.
2023-05-12T19:19:44.078Z,1683919184.078 [MissionManager](INFO): Uninitializing Mission Startup
2023-05-12T19:19:44.078Z,1683919184.078 [Startup] Stopped
2023-05-12T19:19:44.078Z,1683919184.078 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-05-12T19:19:44.078Z,1683919184.078 [Startup:A.GoToSurface] Stopped
2023-05-12T19:19:44.078Z,1683919184.078 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-12T19:19:44.468Z,1683919184.468 [MissionManager](IMPORTANT): Started mission Default
2023-05-12T19:19:44.468Z,1683919184.468 [Default] Running Loop=1
2023-05-12T19:19:44.468Z,1683919184.468 [Default](DEBUG): Aggregate::initialize Default
2023-05-12T19:19:44.468Z,1683919184.468 [Default:B.GoToSurface] Running Loop=1
2023-05-12T19:19:44.468Z,1683919184.468 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-12T19:19:44.469Z,1683919184.469 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-12T19:19:44.469Z,1683919184.469 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-12T19:19:44.469Z,1683919184.469 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-12T19:19:44.470Z,1683919184.470 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-12T19:19:44.470Z,1683919184.470 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-12T19:19:44.470Z,1683919184.470 [Default:A.Wait] Running Loop=1
2023-05-12T19:19:44.470Z,1683919184.470 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-12T19:19:45.265Z,1683919185.265 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:19:45.271Z,1683919185.271 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:19:50.575Z,1683919190.575 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-12T19:19:50.575Z,1683919190.575 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-12T19:19:50.637Z,1683919190.637 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 10.000000 count
2023-05-12T19:19:50.639Z,1683919190.639 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m
2023-05-12T19:19:50.642Z,1683919190.642 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s
2023-05-12T19:19:50.645Z,1683919190.645 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count
2023-05-12T19:19:50.648Z,1683919190.648 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count
2023-05-12T19:19:50.650Z,1683919190.650 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count
2023-05-12T19:19:50.697Z,1683919190.697 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.BeingInterrogatedTimeout = 1.000000 h
2023-05-12T19:19:50.700Z,1683919190.700 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min
2023-05-12T19:19:50.703Z,1683919190.703 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum
2023-05-12T19:19:50.706Z,1683919190.706 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum
2023-05-12T19:19:50.734Z,1683919190.734 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum
2023-05-12T19:19:50.734Z,1683919190.734 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/AbortDrift.xml
2023-05-12T19:19:50.763Z,1683919190.763 [MissionManager](INFO): DefineArg senddata_direct_and_track_test:AbortDrift.AcousticTimeout = 96.000000 h
2023-05-12T19:19:50.779Z,1683919190.779 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](DEBUG): Construct AbortDrift.
2023-05-12T19:19:50.782Z,1683919190.782 [senddata_direct_and_track_test:AbortDrift:C.Execute](DEBUG): Construct Execute.
2023-05-12T19:19:50.784Z,1683919190.784 [MissionManager](INFO): RedefineArg senddata_direct_and_track_test:AbortDrift.AcousticTimeout = reader:senddata_direct_and_track_test.BeingInterrogatedTimeout
2023-05-12T19:19:50.939Z,1683919190.939 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait.
2023-05-12T19:19:50.979Z,1683919190.979 [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>10</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="BeingInterrogatedTimeout"><Description>
        If the vehicle does not receive an acoustic signal for more than this
        length of time, it will surface for communications. Set longer than
        MissionTimeout to effectively disable.
    </Description><Units:hour/><Value>1</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>            

    <Insert Filename="Insert/AbortDrift.xml">
        <RedefineArg Name="AcousticTimeout"><Arg Name="BeingInterrogatedTimeout"/></RedefineArg>
    </Insert>
    
    
    <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="2"/>
    
      <Guidance:Wait>
          <Sequence/>
          <Setting><Guidance:Wait.duration/><Arg Name="AcommsInterval"/></Setting>
      </Guidance:Wait>
                  
      <SendData Service="Direct" Destination="modem:10:_.pressure">
          <Sensor:Onboard.Pressure/><Units:atmosphere/>
      </SendData>
    
      <SendData Service="Direct" Destination="modem:10:_.temperature">
          <Sensor:Onboard.Temperature/><Units:celsius/>
      </SendData>
    
      <SendData Service="Direct" Destination="modem:10:_.humidity">
          <Sensor:Onboard.Humidity/><Units:percent/>
      </SendData>
    
    </Aggregate>

</Mission>


2023-05-12T19:19:50.989Z,1683919190.989 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-12T19:19:51.341Z,1683919191.341 [Default] Stopped
2023-05-12T19:19:51.341Z,1683919191.341 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-12T19:19:51.342Z,1683919191.342 [Default:A.Wait] Stopped
2023-05-12T19:19:51.342Z,1683919191.342 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T19:19:51.342Z,1683919191.342 [Default:B.GoToSurface] Stopped
2023-05-12T19:19:51.342Z,1683919191.342 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-12T19:19:51.342Z,1683919191.342 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test
2023-05-12T19:19:51.342Z,1683919191.342 [senddata_direct_and_track_test] Running Loop=1
2023-05-12T19:19:51.342Z,1683919191.342 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test
2023-05-12T19:19:51.342Z,1683919191.342 [senddata_direct_and_track_test:AbortDrift] Running Loop=1
2023-05-12T19:19:51.342Z,1683919191.342 [senddata_direct_and_track_test:AbortDrift](DEBUG): Aggregate::initialize senddata_direct_and_track_test:AbortDrift
2023-05-12T19:19:51.343Z,1683919191.343 [senddata_direct_and_track_test:AbortDrift:A] Running Loop=1
2023-05-12T19:19:51.343Z,1683919191.343 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-12T19:19:51.343Z,1683919191.343 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact.
2023-05-12T19:19:51.343Z,1683919191.343 [senddata_direct_and_track_test:DirectData] Running Loop=1
2023-05-12T19:19:51.343Z,1683919191.343 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-12T19:19:51.343Z,1683919191.343 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-12T19:19:51.343Z,1683919191.343 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-12T19:19:51.344Z,1683919191.344 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-12T19:19:51.345Z,1683919191.345 [senddata_direct_and_track_test:AbortDrift] Running Loop=1
2023-05-12T19:19:51.345Z,1683919191.345 [senddata_direct_and_track_test:AbortDrift:A](INFO): Insert acoustic timeout set to 1.000000 h .
2023-05-12T19:19:51.345Z,1683919191.345 [senddata_direct_and_track_test:AbortDrift:A] Stopped
2023-05-12T19:19:51.346Z,1683919191.346 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift] Running Loop=1
2023-05-12T19:19:51.346Z,1683919191.346 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Initializing AbortDrift.
2023-05-12T19:19:51.346Z,1683919191.346 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](IMPORTANT): Acoustic timeout set to: 1.00 hours.
2023-05-12T19:19:51.747Z,1683919191.747 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid gps time fix: 1683919104.00. Resetting abort timer.
2023-05-12T19:19:59.001Z,1683919199.001 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:19:59.006Z,1683919199.006 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:20:04.257Z,1683919204.257 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-12T19:20:06.719Z,1683919206.719 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-12T19:20:06.809Z,1683919206.809 [DATMMP](INFO): ****** received valid address query ******
2023-05-12T19:20:06.809Z,1683919206.809 [DATMMP](INFO): ****** received valid ping request ******
2023-05-12T19:20:06.809Z,1683919206.809 [DATMMP](INFO): Querying Benthos address 10
2023-05-12T19:20:07.061Z,1683919207.061 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:07.061Z,1683919207.061 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x14	 x5	 x1034
2023-05-12T19:20:07.062Z,1683919207.062 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:20:07.062Z,1683919207.062 [DATMMP](INFO): Handled
2023-05-12T19:20:07.062Z,1683919207.062 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:07.312Z,1683919207.312 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:07.564Z,1683919207.564 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:07.817Z,1683919207.817 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:08.068Z,1683919208.068 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:08.321Z,1683919208.321 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:08.572Z,1683919208.572 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:08.824Z,1683919208.824 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:09.076Z,1683919209.076 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:09.330Z,1683919209.330 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:09.413Z,1683919209.413 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:20:09.413Z,1683919209.413 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:20:09.413Z,1683919209.413 [DATMMP](INFO): Handled
2023-05-12T19:20:09.414Z,1683919209.414 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:09.581Z,1683919209.581 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:09.582Z,1683919209.582 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x14	 x7	 x1164
2023-05-12T19:20:09.582Z,1683919209.582 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919250.499712
2023-05-12T19:20:09.583Z,1683919209.583 [DATMMP](INFO): Rx ping set to:1683919209.581601
2023-05-12T19:20:09.583Z,1683919209.583 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:20:09.583Z,1683919209.583 [DATMMP](INFO): Handled
2023-05-12T19:20:09.583Z,1683919209.583 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:09.832Z,1683919209.832 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:10.085Z,1683919210.085 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:10.086Z,1683919210.086 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-05-12T19:20:10.086Z,1683919210.086 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:20:10.086Z,1683919210.086 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:20:10.086Z,1683919210.086 [DATMMP](INFO): Handled
2023-05-12T19:20:10.087Z,1683919210.087 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:10.337Z,1683919210.337 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:10.337Z,1683919210.337 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:20:10.338Z,1683919210.338 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:20:10.338Z,1683919210.338 [DATMMP](INFO): Handled
2023-05-12T19:20:10.338Z,1683919210.338 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:10.589Z,1683919210.589 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:10.590Z,1683919210.590 [DATMMP](INFO): directional_debug rx: 	 xD2	 x210	 x23	 x564	 x1020	 x1361	 x1252	 x16E3
2023-05-12T19:20:10.591Z,1683919210.591 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:20:10.591Z,1683919210.591 [DATMMP](INFO): Handled
2023-05-12T19:20:10.591Z,1683919210.591 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:10.734Z,1683919210.734 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:20:10.841Z,1683919210.841 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:10.842Z,1683919210.842 [DATMMP](INFO): directional rx: 	 xCD	 x1CA	 x50A	 xFDF0	 x9C1	 xFDFC	 x0	 x4C7	 x2	 xFFEF	 x27B5966	 x-43569E0
2023-05-12T19:20:10.844Z,1683919210.844 [DATMMP](INFO): Received message type: directional
2023-05-12T19:20:10.844Z,1683919210.844 [DATMMP](INFO): Handled
2023-05-12T19:20:10.844Z,1683919210.844 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:11.092Z,1683919211.092 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:11.094Z,1683919211.094 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x29E	 x23	 x89	 xC8	 xB5	 xD	 xFFFF	 xB8	 x1F	 xC	 x0
2023-05-12T19:20:11.094Z,1683919211.094 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:20:11.094Z,1683919211.094 [DATMMP](INFO): Handled
2023-05-12T19:20:11.095Z,1683919211.095 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:11.165Z,1683919211.165 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:20:11.345Z,1683919211.345 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:11.346Z,1683919211.346 [DATMMP](INFO): range_update rx: 	 xA	 x2	 x9	 xC
2023-05-12T19:20:11.346Z,1683919211.346 [DATMMP](INFO): Received message type: range_update
2023-05-12T19:20:11.346Z,1683919211.346 [DATMMP](INFO): Handled
2023-05-12T19:20:11.347Z,1683919211.347 [DATMMP](INFO): direction in FSK: [0.847101,0.489074,0.207911]
2023-05-12T19:20:11.561Z,1683919211.561 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m
2023-05-12T19:20:11.562Z,1683919211.562 [Reporter](INFO): acoustic_contact_range 0.900000 m
2023-05-12T19:20:11.597Z,1683919211.597 [DATMMP](INFO): GSXN notify for xid: 15
2023-05-12T19:20:11.598Z,1683919211.598 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-05-12T19:20:11.598Z,1683919211.598 [DATMMP](ERROR): 4:Command error: data
2023-05-12T19:20:11.598Z,1683919211.598 [DATMMP](DEBUG): Command complete rang
2023-05-12T19:20:11.598Z,1683919211.598 [DATMMP](ERROR): 4:COMPLETE
2023-05-12T19:20:12.332Z,1683919212.332 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:20:12.338Z,1683919212.338 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:20:22.043Z,1683919222.043 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-12T19:20:22.184Z,1683919222.184 [DATMMP](INFO): ****** received valid address query ******
2023-05-12T19:20:22.185Z,1683919222.185 [DATMMP](INFO): ****** received valid ping request ******
2023-05-12T19:20:22.185Z,1683919222.185 [DATMMP](INFO): Querying Benthos address 10
2023-05-12T19:20:22.436Z,1683919222.436 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:22.437Z,1683919222.437 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x14	 x14	 x1DDF
2023-05-12T19:20:22.438Z,1683919222.438 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:20:22.438Z,1683919222.438 [DATMMP](INFO): Handled
2023-05-12T19:20:22.438Z,1683919222.438 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:22.688Z,1683919222.688 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:22.940Z,1683919222.940 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:23.192Z,1683919223.192 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:23.444Z,1683919223.444 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:23.697Z,1683919223.697 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:23.948Z,1683919223.948 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:24.201Z,1683919224.201 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:24.452Z,1683919224.452 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:24.705Z,1683919224.705 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:24.705Z,1683919224.705 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:20:24.705Z,1683919224.705 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:20:24.705Z,1683919224.705 [DATMMP](INFO): Handled
2023-05-12T19:20:24.706Z,1683919224.706 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:24.957Z,1683919224.957 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:24.958Z,1683919224.958 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x14	 x16	 x1F10
2023-05-12T19:20:24.958Z,1683919224.958 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919235.688128
2023-05-12T19:20:24.958Z,1683919224.958 [DATMMP](INFO): Rx ping set to:1683919224.957636
2023-05-12T19:20:24.959Z,1683919224.959 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:20:24.959Z,1683919224.959 [DATMMP](INFO): Handled
2023-05-12T19:20:24.959Z,1683919224.959 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:25.208Z,1683919225.208 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:25.461Z,1683919225.461 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:25.462Z,1683919225.462 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-05-12T19:20:25.462Z,1683919225.462 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:20:25.462Z,1683919225.462 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:20:25.462Z,1683919225.462 [DATMMP](INFO): Handled
2023-05-12T19:20:25.463Z,1683919225.463 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:25.665Z,1683919225.665 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:20:25.671Z,1683919225.671 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:20:25.713Z,1683919225.713 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:25.713Z,1683919225.713 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:20:25.714Z,1683919225.714 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:20:25.714Z,1683919225.714 [DATMMP](INFO): Handled
2023-05-12T19:20:25.714Z,1683919225.714 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:25.965Z,1683919225.965 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:25.966Z,1683919225.966 [DATMMP](INFO): directional_debug rx: 	 x83	 x1D4	 x24	 xB4	 x1070	 x13D1	 x1242	 x16F3
2023-05-12T19:20:25.967Z,1683919225.967 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:20:25.967Z,1683919225.967 [DATMMP](INFO): Handled
2023-05-12T19:20:25.967Z,1683919225.967 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:26.127Z,1683919226.127 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:20:26.217Z,1683919226.217 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:26.218Z,1683919226.218 [DATMMP](INFO): directional rx: 	 x7C	 x186	 x559	 xFE2C	 x9E1	 xFE37	 x0	 x499	 x3	 xFFED	 x27B5966	 x-43569E0
2023-05-12T19:20:26.220Z,1683919226.220 [DATMMP](INFO): Received message type: directional
2023-05-12T19:20:26.220Z,1683919226.220 [DATMMP](INFO): Handled
2023-05-12T19:20:26.220Z,1683919226.220 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:26.468Z,1683919226.468 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:26.470Z,1683919226.470 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x2CC	 x22	 x9A	 xA6	 xA9	 xD	 xFFFF	 xBE	 x1D	 xC	 x0
2023-05-12T19:20:26.470Z,1683919226.470 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:20:26.470Z,1683919226.470 [DATMMP](INFO): Handled
2023-05-12T19:20:26.471Z,1683919226.471 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:26.527Z,1683919226.527 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:20:26.721Z,1683919226.721 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:26.721Z,1683919226.721 [DATMMP](INFO): range_update rx: 	 xA	 x2	 x9	 xD
2023-05-12T19:20:26.722Z,1683919226.722 [DATMMP](INFO): Received message type: range_update
2023-05-12T19:20:26.722Z,1683919226.722 [DATMMP](INFO): Handled
2023-05-12T19:20:26.723Z,1683919226.723 [DATMMP](INFO): direction in FSK: [-0.100606,0.292182,0.951056]
2023-05-12T19:20:26.920Z,1683919226.920 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m
2023-05-12T19:20:26.921Z,1683919226.921 [Reporter](INFO): acoustic_contact_range 0.900000 m
2023-05-12T19:20:26.973Z,1683919226.973 [DATMMP](INFO): GSXN notify for xid: 16
2023-05-12T19:20:26.974Z,1683919226.974 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-05-12T19:20:26.974Z,1683919226.974 [DATMMP](ERROR): 4:Command error: data
2023-05-12T19:20:26.974Z,1683919226.974 [DATMMP](DEBUG): Command complete rang
2023-05-12T19:20:26.974Z,1683919226.974 [DATMMP](ERROR): 4:COMPLETE
2023-05-12T19:20:37.393Z,1683919237.393 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-12T19:20:37.556Z,1683919237.556 [DATMMP](INFO): ****** received valid address query ******
2023-05-12T19:20:37.557Z,1683919237.557 [DATMMP](INFO): ****** received valid ping request ******
2023-05-12T19:20:37.557Z,1683919237.557 [DATMMP](INFO): Querying Benthos address 10
2023-05-12T19:20:37.809Z,1683919237.809 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:37.810Z,1683919237.810 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x14	 x24	 x66E
2023-05-12T19:20:37.810Z,1683919237.810 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:20:37.810Z,1683919237.810 [DATMMP](INFO): Handled
2023-05-12T19:20:37.810Z,1683919237.810 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:38.060Z,1683919238.060 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:38.312Z,1683919238.312 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:38.564Z,1683919238.564 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:38.816Z,1683919238.816 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:39.068Z,1683919239.068 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:39.320Z,1683919239.320 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:39.401Z,1683919239.401 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:20:39.406Z,1683919239.406 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:20:39.572Z,1683919239.572 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:39.828Z,1683919239.828 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:40.077Z,1683919240.077 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:40.077Z,1683919240.077 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:20:40.077Z,1683919240.077 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:20:40.078Z,1683919240.078 [DATMMP](INFO): Handled
2023-05-12T19:20:40.078Z,1683919240.078 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:40.329Z,1683919240.329 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:40.330Z,1683919240.330 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x14	 x26	 x79F
2023-05-12T19:20:40.330Z,1683919240.330 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919257.055296
2023-05-12T19:20:40.330Z,1683919240.330 [DATMMP](INFO): Rx ping set to:1683919240.329589
2023-05-12T19:20:40.331Z,1683919240.331 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:20:40.331Z,1683919240.331 [DATMMP](INFO): Handled
2023-05-12T19:20:40.331Z,1683919240.331 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:40.580Z,1683919240.580 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:40.833Z,1683919240.833 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:40.834Z,1683919240.834 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-05-12T19:20:40.834Z,1683919240.834 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:20:40.834Z,1683919240.834 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:20:40.834Z,1683919240.834 [DATMMP](INFO): Handled
2023-05-12T19:20:40.834Z,1683919240.834 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:41.087Z,1683919241.087 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:41.088Z,1683919241.088 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:20:41.088Z,1683919241.088 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:20:41.088Z,1683919241.088 [DATMMP](INFO): Handled
2023-05-12T19:20:41.088Z,1683919241.088 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:41.337Z,1683919241.337 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:41.338Z,1683919241.338 [DATMMP](INFO): directional_debug rx: 	 x21C	 x1E5	 x24	 x1B1	 x1010	 x1331	 x11E2	 x1653
2023-05-12T19:20:41.339Z,1683919241.339 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:20:41.339Z,1683919241.339 [DATMMP](INFO): Handled
2023-05-12T19:20:41.339Z,1683919241.339 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:41.441Z,1683919241.441 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:20:41.589Z,1683919241.589 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:41.590Z,1683919241.590 [DATMMP](INFO): directional rx: 	 x225	 x192	 x3C0	 xFE1B	 x832	 xFE2C	 x0	 x479	 x4	 xFFEE	 x27B5966	 x-43569E0
2023-05-12T19:20:41.592Z,1683919241.592 [DATMMP](INFO): Received message type: directional
2023-05-12T19:20:41.592Z,1683919241.592 [DATMMP](INFO): Handled
2023-05-12T19:20:41.592Z,1683919241.592 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:41.841Z,1683919241.841 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:41.842Z,1683919241.842 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x2CC	 x23	 x9B	 xCA	 xB7	 xD	 xFFFF	 xA7	 x1D	 xC	 x0
2023-05-12T19:20:41.842Z,1683919241.842 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:20:41.842Z,1683919241.842 [DATMMP](INFO): Handled
2023-05-12T19:20:41.843Z,1683919241.843 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:41.891Z,1683919241.891 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:20:42.093Z,1683919242.093 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:42.093Z,1683919242.093 [DATMMP](INFO): range_update rx: 	 xA	 x2	 x9	 xD
2023-05-12T19:20:42.094Z,1683919242.094 [DATMMP](INFO): Received message type: range_update
2023-05-12T19:20:42.094Z,1683919242.094 [DATMMP](INFO): Handled
2023-05-12T19:20:42.095Z,1683919242.095 [DATMMP](INFO): direction in FSK: [0.286788,0.496732,0.819152]
2023-05-12T19:20:42.272Z,1683919242.272 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m
2023-05-12T19:20:42.273Z,1683919242.273 [Reporter](INFO): acoustic_contact_range 0.900000 m
2023-05-12T19:20:42.345Z,1683919242.345 [DATMMP](INFO): GSXN notify for xid: 17
2023-05-12T19:20:42.345Z,1683919242.345 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-05-12T19:20:42.346Z,1683919242.346 [DATMMP](ERROR): 4:Command error: data
2023-05-12T19:20:42.346Z,1683919242.346 [DATMMP](DEBUG): Command complete rang
2023-05-12T19:20:42.346Z,1683919242.346 [DATMMP](ERROR): 4:COMPLETE
2023-05-12T19:20:51.533Z,1683919251.533 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting.
2023-05-12T19:20:51.533Z,1683919251.533 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-12T19:20:51.533Z,1683919251.533 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T19:20:51.534Z,1683919251.534 [senddata_direct_and_track_test:DirectData:B] Running Loop=1
2023-05-12T19:20:52.001Z,1683919252.001 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:10:_.pressure
2023-05-12T19:20:52.001Z,1683919252.001 [senddata_direct_and_track_test:DirectData:B] Stopped
2023-05-12T19:20:52.001Z,1683919252.001 [senddata_direct_and_track_test:DirectData:C] Running Loop=1
2023-05-12T19:20:52.172Z,1683919252.172 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-12T19:20:52.173Z,1683919252.173 [DATMMP](INFO): modem://10: set _.pressure 0.742117 atmosphere
2023-05-12T19:20:52.174Z,1683919252.174 [DATMMP](INFO): #Outgoing data=1
2023-05-12T19:20:52.174Z,1683919252.174 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-12T19:20:52.328Z,1683919252.328 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:20:52.334Z,1683919252.334 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:20:52.372Z,1683919252.372 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:10:_.temperature
2023-05-12T19:20:52.373Z,1683919252.373 [senddata_direct_and_track_test:DirectData:C] Stopped
2023-05-12T19:20:52.373Z,1683919252.373 [senddata_direct_and_track_test:DirectData:D] Running Loop=1
2023-05-12T19:20:52.424Z,1683919252.424 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-12T19:20:52.425Z,1683919252.425 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-12T19:20:52.676Z,1683919252.676 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-12T19:20:52.678Z,1683919252.678 [DATMMP](INFO): Tx to 10 len 34 xid 18
2023-05-12T19:20:52.678Z,1683919252.678 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-12T19:20:52.678Z,1683919252.678 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:20:52.778Z,1683919252.778 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:10:_.humidity
2023-05-12T19:20:52.778Z,1683919252.778 [senddata_direct_and_track_test:DirectData:D] Stopped
2023-05-12T19:20:52.778Z,1683919252.778 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData
2023-05-12T19:20:52.778Z,1683919252.778 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-12T19:20:52.779Z,1683919252.779 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-12T19:20:52.779Z,1683919252.779 [senddata_direct_and_track_test:DirectData](INFO): Running loop #2
2023-05-12T19:20:52.779Z,1683919252.779 [senddata_direct_and_track_test:DirectData] Running Loop=2
2023-05-12T19:20:52.779Z,1683919252.779 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-12T19:20:52.779Z,1683919252.779 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-12T19:20:52.779Z,1683919252.779 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-12T19:20:52.779Z,1683919252.779 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-12T19:20:52.929Z,1683919252.929 [DATMMP](INFO): GSXN notify for xid: 18
2023-05-12T19:20:52.930Z,1683919252.930 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-12T19:20:52.930Z,1683919252.930 [DATMMP](DEBUG): Command complete send
2023-05-12T19:20:52.930Z,1683919252.930 [DATMMP](ERROR): 1:COMPLETE
2023-05-12T19:20:52.930Z,1683919252.930 [DATMMP](INFO): Received message type: cmd_result
2023-05-12T19:20:52.930Z,1683919252.930 [DATMMP](INFO): Handled
2023-05-12T19:20:52.930Z,1683919252.930 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:52.931Z,1683919252.931 [DATMMP](INFO): ****** received valid address query ******
2023-05-12T19:20:52.931Z,1683919252.931 [DATMMP](INFO): ****** received valid ping request ******
2023-05-12T19:20:52.931Z,1683919252.931 [DATMMP](INFO): Querying Benthos address 10
2023-05-12T19:20:53.181Z,1683919253.181 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:53.182Z,1683919253.182 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x14	 x33	 xC3D
2023-05-12T19:20:53.182Z,1683919253.182 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:20:53.182Z,1683919253.182 [DATMMP](INFO): Handled
2023-05-12T19:20:53.182Z,1683919253.182 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:53.182Z,1683919253.182 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:53.435Z,1683919253.435 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:53.437Z,1683919253.437 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x14	 x33	 x1419
2023-05-12T19:20:53.438Z,1683919253.438 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:20:53.438Z,1683919253.438 [DATMMP](INFO): Handled
2023-05-12T19:20:53.438Z,1683919253.438 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:53.438Z,1683919253.438 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:53.684Z,1683919253.684 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:53.684Z,1683919253.684 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:53.936Z,1683919253.936 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:53.937Z,1683919253.937 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:54.188Z,1683919254.188 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:54.188Z,1683919254.188 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:54.440Z,1683919254.440 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:54.441Z,1683919254.441 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:54.692Z,1683919254.692 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:54.692Z,1683919254.692 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:54.945Z,1683919254.945 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:54.945Z,1683919254.945 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:55.196Z,1683919255.196 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:55.197Z,1683919255.197 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:55.448Z,1683919255.448 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:55.448Z,1683919255.448 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:55.700Z,1683919255.700 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:55.701Z,1683919255.701 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:55.954Z,1683919255.954 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:55.954Z,1683919255.954 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:56.204Z,1683919256.204 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:56.205Z,1683919256.205 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:56.456Z,1683919256.456 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:56.456Z,1683919256.456 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:56.708Z,1683919256.708 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:56.708Z,1683919256.708 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:56.961Z,1683919256.961 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:56.961Z,1683919256.961 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:20:56.961Z,1683919256.961 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:20:56.962Z,1683919256.962 [DATMMP](INFO): Handled
2023-05-12T19:20:56.962Z,1683919256.962 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:56.962Z,1683919256.962 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:57.213Z,1683919257.213 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:57.214Z,1683919257.214 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x14	 x37	 x134
2023-05-12T19:20:57.214Z,1683919257.214 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919258.008192
2023-05-12T19:20:57.215Z,1683919257.215 [DATMMP](INFO): Rx ping set to:1683919257.213799
2023-05-12T19:20:57.215Z,1683919257.215 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:20:57.215Z,1683919257.215 [DATMMP](INFO): Handled
2023-05-12T19:20:57.215Z,1683919257.215 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:57.215Z,1683919257.215 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:57.465Z,1683919257.465 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:57.465Z,1683919257.465 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:57.717Z,1683919257.717 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:57.718Z,1683919257.718 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-05-12T19:20:57.718Z,1683919257.718 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:20:57.718Z,1683919257.718 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:20:57.718Z,1683919257.718 [DATMMP](INFO): Handled
2023-05-12T19:20:57.718Z,1683919257.718 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:57.719Z,1683919257.719 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:57.969Z,1683919257.969 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:57.969Z,1683919257.969 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:20:57.970Z,1683919257.970 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:20:57.970Z,1683919257.970 [DATMMP](INFO): Handled
2023-05-12T19:20:57.970Z,1683919257.970 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:57.970Z,1683919257.970 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:58.221Z,1683919258.221 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:58.222Z,1683919258.222 [DATMMP](INFO): directional_debug rx: 	 x63	 x1DA	 x24	 xD1	 x1070	 x13A1	 x1222	 x16B3
2023-05-12T19:20:58.223Z,1683919258.223 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:20:58.223Z,1683919258.223 [DATMMP](INFO): Handled
2023-05-12T19:20:58.223Z,1683919258.223 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:58.223Z,1683919258.223 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:58.421Z,1683919258.421 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:20:58.473Z,1683919258.473 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:58.475Z,1683919258.475 [DATMMP](INFO): directional rx: 	 x5D	 x18F	 x579	 xFE26	 x9B1	 xFE2E	 x0	 x44A	 x5	 xFFEF	 x27B5966	 x-43569E0
2023-05-12T19:20:58.477Z,1683919258.477 [DATMMP](INFO): Received message type: directional
2023-05-12T19:20:58.477Z,1683919258.477 [DATMMP](INFO): Handled
2023-05-12T19:20:58.477Z,1683919258.477 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:58.477Z,1683919258.477 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:58.725Z,1683919258.725 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:58.726Z,1683919258.726 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x28D	 x22	 x99	 xB5	 xB0	 xD	 xFFFF	 xB9	 x20	 xB	 x0
2023-05-12T19:20:58.727Z,1683919258.727 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:20:58.727Z,1683919258.727 [DATMMP](INFO): Handled
2023-05-12T19:20:58.727Z,1683919258.727 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:58.727Z,1683919258.727 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:20:58.854Z,1683919258.854 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:20:58.977Z,1683919258.977 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:58.977Z,1683919258.977 [DATMMP](INFO): range_update rx: 	 xA	 x2	 x2B92	 x3A19
2023-05-12T19:20:58.978Z,1683919258.978 [DATMMP](INFO): Received message type: range_update
2023-05-12T19:20:58.978Z,1683919258.978 [DATMMP](INFO): Handled
2023-05-12T19:20:58.978Z,1683919258.978 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:58.979Z,1683919258.979 [DATMMP](INFO): direction in FSK: [-0.316094,0.255968,0.913546]
2023-05-12T19:20:59.229Z,1683919259.229 [DATMMP](INFO): GSXN notify for xid: 19
2023-05-12T19:20:59.230Z,1683919259.230 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-05-12T19:20:59.230Z,1683919259.230 [DATMMP](ERROR): 4:Command error: data
2023-05-12T19:20:59.230Z,1683919259.230 [DATMMP](DEBUG): Command complete rang
2023-05-12T19:20:59.230Z,1683919259.230 [DATMMP](ERROR): 4:COMPLETE
2023-05-12T19:20:59.230Z,1683919259.230 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:59.276Z,1683919259.276 [Reporter](INFO): DATMMP.acoustic_contact_range 1115.400024 m
2023-05-12T19:20:59.292Z,1683919259.292 [Reporter](INFO): acoustic_contact_range 1115.400024 m
2023-05-12T19:20:59.481Z,1683919259.481 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:59.481Z,1683919259.481 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:20:59.481Z,1683919259.481 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:20:59.482Z,1683919259.482 [DATMMP](INFO): Handled
2023-05-12T19:20:59.482Z,1683919259.482 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:59.733Z,1683919259.733 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:20:59.734Z,1683919259.734 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x14	 x38	 x133D
2023-05-12T19:20:59.734Z,1683919259.734 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919304.100352
2023-05-12T19:20:59.734Z,1683919259.734 [DATMMP](INFO): Rx ping set to:1683919259.733614
2023-05-12T19:20:59.735Z,1683919259.735 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:20:59.735Z,1683919259.735 [DATMMP](INFO): Handled
2023-05-12T19:20:59.735Z,1683919259.735 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:20:59.987Z,1683919259.987 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:00.004Z,1683919260.004 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 xC	 xA	 x0
2023-05-12T19:21:00.005Z,1683919260.005 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:21:00.005Z,1683919260.005 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:21:00.005Z,1683919260.005 [DATMMP](INFO): Handled
2023-05-12T19:21:00.005Z,1683919260.005 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:00.241Z,1683919260.241 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:00.241Z,1683919260.241 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:21:00.242Z,1683919260.242 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:21:00.242Z,1683919260.242 [DATMMP](INFO): Handled
2023-05-12T19:21:00.242Z,1683919260.242 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:00.493Z,1683919260.493 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:00.494Z,1683919260.494 [DATMMP](INFO): directional_debug rx: 	 x8D	 x1D4	 x24	 xAE	 xFF0	 x1341	 x1192	 x1613
2023-05-12T19:21:00.495Z,1683919260.495 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:21:00.495Z,1683919260.495 [DATMMP](INFO): Handled
2023-05-12T19:21:00.495Z,1683919260.495 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:00.745Z,1683919260.745 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:00.747Z,1683919260.747 [DATMMP](INFO): directional rx: 	 x86	 x186	 x54F	 xFE2C	 x985	 xFE36	 x0	 x446	 x4	 xFFEF	 x27B5966	 x-43569E0
2023-05-12T19:21:00.748Z,1683919260.748 [DATMMP](INFO): Received message type: directional
2023-05-12T19:21:00.748Z,1683919260.748 [DATMMP](INFO): Handled
2023-05-12T19:21:00.748Z,1683919260.748 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:00.885Z,1683919260.885 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:21:00.997Z,1683919260.997 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:00.998Z,1683919260.998 [DATMMP](INFO): acstats rx: 	 xA	 x5	 xFFFF	 x2D0	 x22	 x8B	 xB8	 xC0	 xD	 xFFFF	 xAE	 x24	 xC	 x0
2023-05-12T19:21:00.998Z,1683919260.998 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:21:00.999Z,1683919260.999 [DATMMP](INFO): Handled
2023-05-12T19:21:00.999Z,1683919260.999 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:01.248Z,1683919261.248 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:01.249Z,1683919261.249 [DATMMP](INFO): data_rx rx: 	 xA	 x0	 x0	 x4
2023-05-12T19:21:01.250Z,1683919261.250 [DATMMP](INFO): Check CRC
2023-05-12T19:21:01.250Z,1683919261.250 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-12T19:21:01.250Z,1683919261.250 [DATMMP](INFO): Got DATA: len 4
2023-05-12T19:21:01.250Z,1683919261.250 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-12T19:21:01.250Z,1683919261.250 [DATMMP](INFO): Got ~~ ack, bytes left 0
2023-05-12T19:21:01.251Z,1683919261.251 [DATMMP](INFO): Received command: 

2023-05-12T19:21:01.251Z,1683919261.251 [DATMMP](INFO): Received message type: data_rx
2023-05-12T19:21:01.251Z,1683919261.251 [DATMMP](INFO): Handled
2023-05-12T19:21:01.251Z,1683919261.251 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-12T19:21:01.251Z,1683919261.251 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-12T19:21:01.500Z,1683919261.500 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-12T19:21:01.501Z,1683919261.501 [DATMMP](INFO): modem://10: set _.temperature 24.219263 celsius
2023-05-12T19:21:01.502Z,1683919261.502 [DATMMP](INFO): #Outgoing data=1
2023-05-12T19:21:01.502Z,1683919261.502 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-12T19:21:01.752Z,1683919261.752 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-12T19:21:01.753Z,1683919261.753 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-12T19:21:02.004Z,1683919262.004 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-12T19:21:02.005Z,1683919262.005 [DATMMP](INFO): Tx to 10 len 35 xid 20
2023-05-12T19:21:02.005Z,1683919262.005 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-12T19:21:02.005Z,1683919262.005 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:02.257Z,1683919262.257 [DATMMP](INFO): GSXN notify for xid: 20
2023-05-12T19:21:02.257Z,1683919262.257 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-12T19:21:02.258Z,1683919262.258 [DATMMP](DEBUG): Command complete send
2023-05-12T19:21:02.258Z,1683919262.258 [DATMMP](ERROR): 1:COMPLETE
2023-05-12T19:21:02.258Z,1683919262.258 [DATMMP](INFO): Received message type: cmd_result
2023-05-12T19:21:02.258Z,1683919262.258 [DATMMP](INFO): Handled
2023-05-12T19:21:02.258Z,1683919262.258 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:02.509Z,1683919262.509 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:02.510Z,1683919262.510 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x15	 x0	 x19E8
2023-05-12T19:21:02.510Z,1683919262.510 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:02.510Z,1683919262.510 [DATMMP](INFO): Handled
2023-05-12T19:21:02.510Z,1683919262.510 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:02.760Z,1683919262.760 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:03.012Z,1683919263.012 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:03.264Z,1683919263.264 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:03.516Z,1683919263.516 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:03.769Z,1683919263.769 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:04.020Z,1683919264.020 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:04.272Z,1683919264.272 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:04.524Z,1683919264.524 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:04.776Z,1683919264.776 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:05.028Z,1683919265.028 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:05.281Z,1683919265.281 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:05.532Z,1683919265.532 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:05.660Z,1683919265.660 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:21:05.666Z,1683919265.666 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:21:05.786Z,1683919265.786 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:06.036Z,1683919266.036 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:06.288Z,1683919266.288 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:06.540Z,1683919266.540 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:06.792Z,1683919266.792 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:07.045Z,1683919267.045 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:07.045Z,1683919267.045 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:21:07.045Z,1683919267.045 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:21:07.045Z,1683919267.045 [DATMMP](INFO): Handled
2023-05-12T19:21:07.046Z,1683919267.046 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:07.297Z,1683919267.297 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:07.298Z,1683919267.298 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x15	 x4	 x25FC
2023-05-12T19:21:07.298Z,1683919267.298 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919295.007616
2023-05-12T19:21:07.298Z,1683919267.298 [DATMMP](INFO): Rx ping set to:1683919267.297658
2023-05-12T19:21:07.299Z,1683919267.299 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:07.299Z,1683919267.299 [DATMMP](INFO): Handled
2023-05-12T19:21:07.299Z,1683919267.299 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:07.549Z,1683919267.549 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:07.550Z,1683919267.550 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 xC	 xA	 x0
2023-05-12T19:21:07.550Z,1683919267.550 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:21:07.550Z,1683919267.550 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:21:07.550Z,1683919267.550 [DATMMP](INFO): Handled
2023-05-12T19:21:07.550Z,1683919267.550 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:07.801Z,1683919267.801 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:07.801Z,1683919267.801 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:21:07.802Z,1683919267.802 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:21:07.802Z,1683919267.802 [DATMMP](INFO): Handled
2023-05-12T19:21:07.802Z,1683919267.802 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:08.053Z,1683919268.053 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:08.054Z,1683919268.054 [DATMMP](INFO): directional_debug rx: 	 x10	 x1FF	 x23	 xBA	 x1050	 x1391	 x1212	 x1663
2023-05-12T19:21:08.055Z,1683919268.055 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:21:08.055Z,1683919268.055 [DATMMP](INFO): Handled
2023-05-12T19:21:08.055Z,1683919268.055 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:08.121Z,1683919268.121 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-12T19:21:08.121Z,1683919268.121 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:21:08.305Z,1683919268.305 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:08.306Z,1683919268.306 [DATMMP](INFO): directional rx: 	 x9	 x1BE	 x5CC	 xFE01	 x9EA	 xFE07	 x0	 x434	 x4	 xFFED	 x27B5966	 x-43569E0
2023-05-12T19:21:08.308Z,1683919268.308 [DATMMP](INFO): Received message type: directional
2023-05-12T19:21:08.308Z,1683919268.308 [DATMMP](INFO): Handled
2023-05-12T19:21:08.308Z,1683919268.308 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:08.308Z,1683919268.308 [DATMMP](INFO): ****** received valid address query ******
2023-05-12T19:21:08.308Z,1683919268.308 [DATMMP](INFO): ****** received valid ping request ******
2023-05-12T19:21:08.309Z,1683919268.309 [DATMMP](INFO): Querying Benthos address 10
2023-05-12T19:21:08.557Z,1683919268.557 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:08.558Z,1683919268.558 [DATMMP](INFO): acstats rx: 	 xA	 x5	 xFFFF	 x2D0	 x22	 x8B	 xBF	 xB8	 xD	 xFFFF	 xA9	 x25	 xC	 x0
2023-05-12T19:21:08.559Z,1683919268.559 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:21:08.559Z,1683919268.559 [DATMMP](INFO): Handled
2023-05-12T19:21:08.559Z,1683919268.559 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:08.570Z,1683919268.570 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:21:08.808Z,1683919268.808 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:08.809Z,1683919268.809 [DATMMP](INFO): data_rx rx: 	 xA	 x0	 x0	 x4
2023-05-12T19:21:08.809Z,1683919268.809 [DATMMP](INFO): Check CRC
2023-05-12T19:21:08.810Z,1683919268.810 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-12T19:21:08.810Z,1683919268.810 [DATMMP](INFO): Got DATA: len 4
2023-05-12T19:21:08.810Z,1683919268.810 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-12T19:21:08.810Z,1683919268.810 [DATMMP](INFO): Got ~~ ack, bytes left 2
2023-05-12T19:21:08.810Z,1683919268.810 [DATMMP](INFO): Received command: 

2023-05-12T19:21:08.810Z,1683919268.810 [DATMMP](INFO): Received message type: data_rx
2023-05-12T19:21:08.811Z,1683919268.811 [DATMMP](INFO): Handled
2023-05-12T19:21:08.811Z,1683919268.811 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-12T19:21:08.811Z,1683919268.811 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-12T19:21:08.811Z,1683919268.811 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:09.061Z,1683919269.061 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:09.062Z,1683919269.062 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x15	 x6	 x23B8
2023-05-12T19:21:09.062Z,1683919269.062 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:09.062Z,1683919269.062 [DATMMP](INFO): Handled
2023-05-12T19:21:09.062Z,1683919269.062 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-12T19:21:09.063Z,1683919269.063 [DATMMP](INFO): modem://10: set _.humidity 12.867782 percent
2023-05-12T19:21:09.063Z,1683919269.063 [DATMMP](INFO): #Outgoing data=1
2023-05-12T19:21:09.063Z,1683919269.063 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-12T19:21:09.063Z,1683919269.063 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:09.312Z,1683919269.312 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:09.564Z,1683919269.564 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-12T19:21:09.564Z,1683919269.564 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-12T19:21:09.565Z,1683919269.565 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:09.816Z,1683919269.816 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-12T19:21:09.817Z,1683919269.817 [DATMMP](INFO): Tx to 10 len 32 xid 22
2023-05-12T19:21:09.817Z,1683919269.817 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-12T19:21:09.817Z,1683919269.817 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:09.818Z,1683919269.818 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:10.069Z,1683919270.069 [DATMMP](INFO): GSXN notify for xid: 22
2023-05-12T19:21:10.070Z,1683919270.070 [DATMMP](INFO): iface_err rx: 	 x1	 x7	 xA
2023-05-12T19:21:10.070Z,1683919270.070 [DATMMP](ERROR): 10:Error talking to DAT device_busy
2023-05-12T19:21:10.070Z,1683919270.070 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:10.070Z,1683919270.070 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:10.320Z,1683919270.320 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:10.320Z,1683919270.320 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:10.572Z,1683919270.572 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:10.573Z,1683919270.573 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:10.825Z,1683919270.825 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:10.825Z,1683919270.825 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:21:10.825Z,1683919270.825 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:21:10.825Z,1683919270.825 [DATMMP](INFO): Handled
2023-05-12T19:21:10.826Z,1683919270.826 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:10.826Z,1683919270.826 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:11.077Z,1683919271.077 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:11.077Z,1683919271.077 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x15	 x8	 x24E9
2023-05-12T19:21:11.078Z,1683919271.078 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919296.288768
2023-05-12T19:21:11.078Z,1683919271.078 [DATMMP](INFO): Rx ping set to:1683919271.077515
2023-05-12T19:21:11.078Z,1683919271.078 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:11.079Z,1683919271.079 [DATMMP](INFO): Handled
2023-05-12T19:21:11.079Z,1683919271.079 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:11.079Z,1683919271.079 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:11.328Z,1683919271.328 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:11.329Z,1683919271.329 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:11.580Z,1683919271.580 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:11.582Z,1683919271.582 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-05-12T19:21:11.582Z,1683919271.582 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:21:11.582Z,1683919271.582 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:21:11.582Z,1683919271.582 [DATMMP](INFO): Handled
2023-05-12T19:21:11.582Z,1683919271.582 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:11.582Z,1683919271.582 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:11.833Z,1683919271.833 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:11.833Z,1683919271.833 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:21:11.833Z,1683919271.833 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:21:11.834Z,1683919271.834 [DATMMP](INFO): Handled
2023-05-12T19:21:11.834Z,1683919271.834 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:11.834Z,1683919271.834 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:12.085Z,1683919272.085 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:12.086Z,1683919272.086 [DATMMP](INFO): directional_debug rx: 	 x31	 x1FA	 x25	 xBD	 x1020	 x1321	 x11F2	 x1663
2023-05-12T19:21:12.087Z,1683919272.087 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:21:12.087Z,1683919272.087 [DATMMP](INFO): Handled
2023-05-12T19:21:12.087Z,1683919272.087 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:12.087Z,1683919272.087 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:12.168Z,1683919272.168 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:21:12.337Z,1683919272.337 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:12.338Z,1683919272.338 [DATMMP](INFO): directional rx: 	 x2A	 x1B7	 x5AB	 xFE06	 x9C2	 xFE0D	 x0	 x42B	 x4	 xFFEE	 x27B5966	 x-43569E0
2023-05-12T19:21:12.340Z,1683919272.340 [DATMMP](INFO): Received message type: directional
2023-05-12T19:21:12.340Z,1683919272.340 [DATMMP](INFO): Handled
2023-05-12T19:21:12.340Z,1683919272.340 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:12.340Z,1683919272.340 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:12.541Z,1683919272.541 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:21:12.589Z,1683919272.589 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:12.590Z,1683919272.590 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x2C9	 x22	 x9B	 xCA	 xB8	 xD	 xFFFF	 xB9	 x1D	 xC	 x0
2023-05-12T19:21:12.590Z,1683919272.590 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:21:12.591Z,1683919272.591 [DATMMP](INFO): Handled
2023-05-12T19:21:12.591Z,1683919272.591 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:12.591Z,1683919272.591 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:12.840Z,1683919272.840 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:12.841Z,1683919272.841 [DATMMP](INFO): range_update rx: 	 xA	 x2	 x9	 xD
2023-05-12T19:21:12.842Z,1683919272.842 [DATMMP](INFO): Received message type: range_update
2023-05-12T19:21:12.842Z,1683919272.842 [DATMMP](INFO): Handled
2023-05-12T19:21:12.842Z,1683919272.842 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:12.843Z,1683919272.843 [DATMMP](INFO): direction in FSK: [-0.813805,-0.158188,0.559193]
2023-05-12T19:21:12.990Z,1683919272.990 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m
2023-05-12T19:21:12.991Z,1683919272.991 [Reporter](INFO): acoustic_contact_range 0.900000 m
2023-05-12T19:21:13.093Z,1683919273.093 [DATMMP](INFO): GSXN notify for xid: 21
2023-05-12T19:21:13.094Z,1683919273.094 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-05-12T19:21:13.094Z,1683919273.094 [DATMMP](ERROR): 4:Command error: data
2023-05-12T19:21:13.094Z,1683919273.094 [DATMMP](DEBUG): Command complete rang
2023-05-12T19:21:13.094Z,1683919273.094 [DATMMP](ERROR): 4:COMPLETE
2023-05-12T19:21:13.094Z,1683919273.094 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:13.596Z,1683919273.596 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:13.848Z,1683919273.848 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:14.100Z,1683919274.100 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:14.352Z,1683919274.352 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:14.604Z,1683919274.604 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:14.856Z,1683919274.856 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:15.108Z,1683919275.108 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:15.360Z,1683919275.360 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:15.612Z,1683919275.612 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:15.864Z,1683919275.864 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:16.116Z,1683919276.116 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:16.368Z,1683919276.368 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:16.625Z,1683919276.625 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:16.876Z,1683919276.876 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:17.128Z,1683919277.128 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:17.632Z,1683919277.632 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:17.884Z,1683919277.884 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:18.138Z,1683919278.138 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:18.388Z,1683919278.388 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:18.641Z,1683919278.641 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:18.892Z,1683919278.892 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:18.996Z,1683919278.996 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:21:19.002Z,1683919279.002 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:21:19.144Z,1683919279.144 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:19.396Z,1683919279.396 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:19.648Z,1683919279.648 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:19.900Z,1683919279.900 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:19.901Z,1683919279.901 [DATMMP](FAULT): Buffer send receipt timeout failure.
2023-05-12T19:21:19.901Z,1683919279.901 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER
2023-05-12T19:21:20.152Z,1683919280.152 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-12T19:21:20.153Z,1683919280.153 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-12T19:21:20.404Z,1683919280.404 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-12T19:21:20.404Z,1683919280.404 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-12T19:21:20.656Z,1683919280.656 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-12T19:21:20.657Z,1683919280.657 [DATMMP](INFO): Tx to 10 len 32 xid 23
2023-05-12T19:21:20.657Z,1683919280.657 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-12T19:21:20.658Z,1683919280.658 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:20.909Z,1683919280.909 [DATMMP](INFO): GSXN notify for xid: 23
2023-05-12T19:21:20.909Z,1683919280.909 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-12T19:21:20.909Z,1683919280.909 [DATMMP](DEBUG): Command complete send
2023-05-12T19:21:20.910Z,1683919280.910 [DATMMP](ERROR): 1:COMPLETE
2023-05-12T19:21:20.910Z,1683919280.910 [DATMMP](INFO): Received message type: cmd_result
2023-05-12T19:21:20.910Z,1683919280.910 [DATMMP](INFO): Handled
2023-05-12T19:21:20.910Z,1683919280.910 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:21.161Z,1683919281.161 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:21.162Z,1683919281.162 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x15	 x13	 xC3B
2023-05-12T19:21:21.162Z,1683919281.162 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:21.162Z,1683919281.162 [DATMMP](INFO): Handled
2023-05-12T19:21:21.162Z,1683919281.162 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:21.412Z,1683919281.412 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:21.664Z,1683919281.664 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:21.916Z,1683919281.916 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:22.168Z,1683919282.168 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:22.420Z,1683919282.420 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:22.672Z,1683919282.672 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:22.925Z,1683919282.925 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:23.176Z,1683919283.176 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:23.428Z,1683919283.428 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:23.484Z,1683919283.484 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-12T19:21:23.681Z,1683919283.681 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:23.681Z,1683919283.681 [DATMMP](INFO): ****** received valid address query ******
2023-05-12T19:21:23.681Z,1683919283.681 [DATMMP](INFO): ****** received valid ping request ******
2023-05-12T19:21:23.682Z,1683919283.682 [DATMMP](INFO): Querying Benthos address 10
2023-05-12T19:21:23.933Z,1683919283.933 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:23.934Z,1683919283.934 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x15	 x16	 xA53
2023-05-12T19:21:23.934Z,1683919283.934 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:23.934Z,1683919283.934 [DATMMP](INFO): Handled
2023-05-12T19:21:23.934Z,1683919283.934 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:23.934Z,1683919283.934 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:24.185Z,1683919284.185 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:24.185Z,1683919284.185 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:24.436Z,1683919284.436 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:24.437Z,1683919284.437 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:24.688Z,1683919284.688 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:24.689Z,1683919284.689 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:24.941Z,1683919284.941 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:24.941Z,1683919284.941 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:25.193Z,1683919285.193 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:25.193Z,1683919285.193 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:25.445Z,1683919285.445 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:25.445Z,1683919285.445 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:25.696Z,1683919285.696 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:25.697Z,1683919285.697 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:25.949Z,1683919285.949 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:25.949Z,1683919285.949 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:26.201Z,1683919286.201 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:26.201Z,1683919286.201 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:21:26.201Z,1683919286.201 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:21:26.202Z,1683919286.202 [DATMMP](INFO): Handled
2023-05-12T19:21:26.202Z,1683919286.202 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:26.202Z,1683919286.202 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:26.453Z,1683919286.453 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:26.454Z,1683919286.454 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x15	 x18	 x4CC
2023-05-12T19:21:26.454Z,1683919286.454 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919296.040384
2023-05-12T19:21:26.454Z,1683919286.454 [DATMMP](INFO): Rx ping set to:1683919286.453722
2023-05-12T19:21:26.455Z,1683919286.455 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:26.455Z,1683919286.455 [DATMMP](INFO): Handled
2023-05-12T19:21:26.455Z,1683919286.455 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:26.455Z,1683919286.455 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:26.705Z,1683919286.705 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:26.706Z,1683919286.706 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 xC	 xA	 x0
2023-05-12T19:21:26.706Z,1683919286.706 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:21:26.706Z,1683919286.706 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:21:26.706Z,1683919286.706 [DATMMP](INFO): Handled
2023-05-12T19:21:26.706Z,1683919286.706 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:26.707Z,1683919286.707 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:26.957Z,1683919286.957 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:26.957Z,1683919286.957 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:21:26.958Z,1683919286.958 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:21:26.958Z,1683919286.958 [DATMMP](INFO): Handled
2023-05-12T19:21:26.958Z,1683919286.958 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:26.958Z,1683919286.958 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:27.209Z,1683919287.209 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:27.210Z,1683919287.210 [DATMMP](INFO): directional_debug rx: 	 x225	 x1E3	 x23	 x19F	 xFF0	 x1341	 x11F2	 x1663
2023-05-12T19:21:27.211Z,1683919287.211 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:21:27.211Z,1683919287.211 [DATMMP](INFO): Handled
2023-05-12T19:21:27.211Z,1683919287.211 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:27.211Z,1683919287.211 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:27.461Z,1683919287.461 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:27.462Z,1683919287.462 [DATMMP](INFO): directional rx: 	 x22F	 x18F	 x3B7	 xFE1D	 x7B2	 xFE32	 x0	 x400	 x3	 xFFEB	 x27B5966	 x-43569E0
2023-05-12T19:21:27.464Z,1683919287.464 [DATMMP](INFO): Received message type: directional
2023-05-12T19:21:27.464Z,1683919287.464 [DATMMP](INFO): Handled
2023-05-12T19:21:27.464Z,1683919287.464 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:27.464Z,1683919287.464 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:27.553Z,1683919287.553 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:21:27.713Z,1683919287.713 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:27.715Z,1683919287.715 [DATMMP](INFO): acstats rx: 	 xA	 x5	 xFFFF	 x1E9	 x23	 x86	 xD7	 xC4	 xD	 xFFFF	 xAF	 x26	 xC	 x0
2023-05-12T19:21:27.715Z,1683919287.715 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:21:27.715Z,1683919287.715 [DATMMP](INFO): Handled
2023-05-12T19:21:27.715Z,1683919287.715 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:21:27.715Z,1683919287.715 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:27.965Z,1683919287.965 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:27.966Z,1683919287.966 [DATMMP](INFO): data_rx rx: 	 xA	 x0	 x0	 x4
2023-05-12T19:21:27.966Z,1683919287.966 [DATMMP](INFO): Check CRC
2023-05-12T19:21:27.966Z,1683919287.966 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-12T19:21:27.966Z,1683919287.966 [DATMMP](INFO): Got DATA: len 4
2023-05-12T19:21:27.966Z,1683919287.966 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-12T19:21:27.966Z,1683919287.966 [DATMMP](INFO): Got ~~ ack, bytes left 2
2023-05-12T19:21:27.966Z,1683919287.966 [DATMMP](INFO): Received command: 

2023-05-12T19:21:27.967Z,1683919287.967 [DATMMP](INFO): Received message type: data_rx
2023-05-12T19:21:27.967Z,1683919287.967 [DATMMP](INFO): Handled
2023-05-12T19:21:27.967Z,1683919287.967 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-12T19:21:27.967Z,1683919287.967 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-12T19:21:27.967Z,1683919287.967 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:28.217Z,1683919288.217 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:28.217Z,1683919288.217 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:21:28.217Z,1683919288.217 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:21:28.218Z,1683919288.218 [DATMMP](INFO): Handled
2023-05-12T19:21:28.218Z,1683919288.218 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:28.469Z,1683919288.469 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:28.470Z,1683919288.470 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x15	 x19	 x549
2023-05-12T19:21:28.470Z,1683919288.470 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919298.223232
2023-05-12T19:21:28.471Z,1683919288.471 [DATMMP](INFO): Rx ping set to:1683919288.469782
2023-05-12T19:21:28.471Z,1683919288.471 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:28.471Z,1683919288.471 [DATMMP](INFO): Handled
2023-05-12T19:21:28.471Z,1683919288.471 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:28.721Z,1683919288.721 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:28.722Z,1683919288.722 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-05-12T19:21:28.722Z,1683919288.722 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:21:28.722Z,1683919288.722 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:21:28.722Z,1683919288.722 [DATMMP](INFO): Handled
2023-05-12T19:21:28.723Z,1683919288.723 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:28.973Z,1683919288.973 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:28.973Z,1683919288.973 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:21:28.974Z,1683919288.974 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:21:28.974Z,1683919288.974 [DATMMP](INFO): Handled
2023-05-12T19:21:28.974Z,1683919288.974 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:29.225Z,1683919289.225 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:29.226Z,1683919289.226 [DATMMP](INFO): directional_debug rx: 	 x21D	 x1E5	 x22	 x1AB	 x1040	 x1361	 x1222	 x1683
2023-05-12T19:21:29.227Z,1683919289.227 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:21:29.227Z,1683919289.227 [DATMMP](INFO): Handled
2023-05-12T19:21:29.227Z,1683919289.227 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:29.477Z,1683919289.477 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:29.478Z,1683919289.478 [DATMMP](INFO): directional rx: 	 x225	 x191	 x3BF	 xFE1B	 x7B6	 xFE30	 x0	 x3FC	 x3	 xFFEB	 x27B5966	 x-43569E0
2023-05-12T19:21:29.480Z,1683919289.480 [DATMMP](INFO): Received message type: directional
2023-05-12T19:21:29.480Z,1683919289.480 [DATMMP](INFO): Handled
2023-05-12T19:21:29.480Z,1683919289.480 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:29.573Z,1683919289.573 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919232.00. Resetting abort timer.
2023-05-12T19:21:29.729Z,1683919289.729 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:29.730Z,1683919289.730 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x1E9	 x23	 x8C	 xCB	 xB5	 xD	 xFFFF	 xB3	 x1E	 xB	 x0
2023-05-12T19:21:29.731Z,1683919289.731 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:21:29.731Z,1683919289.731 [DATMMP](INFO): Handled
2023-05-12T19:21:29.731Z,1683919289.731 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:29.981Z,1683919289.981 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:29.982Z,1683919289.982 [DATMMP](INFO): range_update rx: 	 xA	 x2	 x18AA	 x20E3
2023-05-12T19:21:29.982Z,1683919289.982 [DATMMP](INFO): Received message type: range_update
2023-05-12T19:21:29.982Z,1683919289.982 [DATMMP](INFO): Handled
2023-05-12T19:21:29.983Z,1683919289.983 [DATMMP](INFO): direction in FSK: [0.295414,0.491651,0.819152]
2023-05-12T19:21:30.020Z,1683919290.020 [Reporter](INFO): DATMMP.acoustic_contact_range 631.400024 m
2023-05-12T19:21:30.021Z,1683919290.021 [Reporter](INFO): acoustic_contact_range 631.400024 m
2023-05-12T19:21:30.233Z,1683919290.233 [DATMMP](INFO): GSXN notify for xid: 24
2023-05-12T19:21:30.234Z,1683919290.234 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-05-12T19:21:30.234Z,1683919290.234 [DATMMP](ERROR): 4:Command error: data
2023-05-12T19:21:30.234Z,1683919290.234 [DATMMP](DEBUG): Command complete rang
2023-05-12T19:21:30.234Z,1683919290.234 [DATMMP](ERROR): 4:COMPLETE
2023-05-12T19:21:32.344Z,1683919292.344 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:21:32.372Z,1683919292.372 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:21:38.845Z,1683919298.845 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-12T19:21:39.052Z,1683919299.052 [DATMMP](INFO): ****** received valid address query ******
2023-05-12T19:21:39.052Z,1683919299.052 [DATMMP](INFO): ****** received valid ping request ******
2023-05-12T19:21:39.053Z,1683919299.053 [DATMMP](INFO): Querying Benthos address 10
2023-05-12T19:21:39.305Z,1683919299.305 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:39.306Z,1683919299.306 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x15	 x25	 x19F1
2023-05-12T19:21:39.306Z,1683919299.306 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:39.306Z,1683919299.306 [DATMMP](INFO): Handled
2023-05-12T19:21:39.306Z,1683919299.306 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:39.556Z,1683919299.556 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:39.808Z,1683919299.808 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:40.072Z,1683919300.072 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:40.324Z,1683919300.324 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:40.576Z,1683919300.576 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:40.828Z,1683919300.828 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:41.081Z,1683919301.081 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:41.332Z,1683919301.332 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:41.585Z,1683919301.585 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:41.585Z,1683919301.585 [DATMMP](INFO): doppler rx: 	 x0
2023-05-12T19:21:41.585Z,1683919301.585 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:21:41.585Z,1683919301.585 [DATMMP](INFO): Handled
2023-05-12T19:21:41.586Z,1683919301.586 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:41.837Z,1683919301.837 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:41.838Z,1683919301.838 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x15	 x27	 x1B21
2023-05-12T19:21:41.838Z,1683919301.838 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919302.862208
2023-05-12T19:21:41.838Z,1683919301.838 [DATMMP](INFO): Rx ping set to:1683919301.837619
2023-05-12T19:21:41.839Z,1683919301.839 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:41.839Z,1683919301.839 [DATMMP](INFO): Handled
2023-05-12T19:21:41.839Z,1683919301.839 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:42.088Z,1683919302.088 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:42.341Z,1683919302.341 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:42.342Z,1683919302.342 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-05-12T19:21:42.342Z,1683919302.342 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:21:42.342Z,1683919302.342 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:21:42.342Z,1683919302.342 [DATMMP](INFO): Handled
2023-05-12T19:21:42.343Z,1683919302.343 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:42.593Z,1683919302.593 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:42.593Z,1683919302.593 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:21:42.593Z,1683919302.593 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:21:42.594Z,1683919302.594 [DATMMP](INFO): Handled
2023-05-12T19:21:42.594Z,1683919302.594 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:42.857Z,1683919302.857 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:42.858Z,1683919302.858 [DATMMP](INFO): directional_debug rx: 	 xD1	 x194	 x24	 xB7	 x1050	 x13A1	 x1232	 x1663
2023-05-12T19:21:42.859Z,1683919302.859 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:21:42.859Z,1683919302.859 [DATMMP](INFO): Handled
2023-05-12T19:21:42.859Z,1683919302.859 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:43.019Z,1683919303.019 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919360.00. Resetting abort timer.
2023-05-12T19:21:43.109Z,1683919303.109 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:43.110Z,1683919303.110 [DATMMP](INFO): directional rx: 	 xCA	 x137	 x50B	 xFE6C	 x8CC	 xFE77	 x0	 x3CD	 x5	 xFFEE	 x27B5966	 x-43569E0
2023-05-12T19:21:43.113Z,1683919303.113 [DATMMP](INFO): Received message type: directional
2023-05-12T19:21:43.113Z,1683919303.113 [DATMMP](INFO): Handled
2023-05-12T19:21:43.113Z,1683919303.113 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:43.315Z,1683919303.315 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919360.00. Resetting abort timer.
2023-05-12T19:21:43.368Z,1683919303.368 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:43.369Z,1683919303.369 [DATMMP](INFO): acstats rx: 	 xA	 x0	 x0	 x2C0	 x23	 x90	 xC8	 xBA	 xD	 xFFFF	 xB5	 x1F	 xB	 x0
2023-05-12T19:21:43.370Z,1683919303.370 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:21:43.370Z,1683919303.370 [DATMMP](INFO): Handled
2023-05-12T19:21:43.370Z,1683919303.370 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:43.621Z,1683919303.621 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:43.622Z,1683919303.622 [DATMMP](INFO): range_update rx: 	 xA	 x2	 x9	 xC
2023-05-12T19:21:43.622Z,1683919303.622 [DATMMP](INFO): Received message type: range_update
2023-05-12T19:21:43.622Z,1683919303.622 [DATMMP](INFO): Handled
2023-05-12T19:21:43.623Z,1683919303.623 [DATMMP](INFO): direction in FSK: [-0.616595,-0.370487,0.694658]
2023-05-12T19:21:43.787Z,1683919303.787 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m
2023-05-12T19:21:43.796Z,1683919303.796 [Reporter](INFO): acoustic_contact_range 0.900000 m
2023-05-12T19:21:43.873Z,1683919303.873 [DATMMP](INFO): GSXN notify for xid: 25
2023-05-12T19:21:43.873Z,1683919303.873 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-05-12T19:21:43.874Z,1683919303.874 [DATMMP](ERROR): 4:Command error: data
2023-05-12T19:21:43.874Z,1683919303.874 [DATMMP](DEBUG): Command complete rang
2023-05-12T19:21:43.874Z,1683919303.874 [DATMMP](ERROR): 4:COMPLETE
2023-05-12T19:21:45.677Z,1683919305.677 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:21:45.683Z,1683919305.683 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-12T19:21:53.363Z,1683919313.363 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting.
2023-05-12T19:21:53.363Z,1683919313.363 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-12T19:21:53.363Z,1683919313.363 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T19:21:53.364Z,1683919313.364 [senddata_direct_and_track_test:DirectData:B] Running Loop=1
2023-05-12T19:21:53.776Z,1683919313.776 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:10:_.pressure
2023-05-12T19:21:53.776Z,1683919313.776 [senddata_direct_and_track_test:DirectData:B] Stopped
2023-05-12T19:21:53.777Z,1683919313.777 [senddata_direct_and_track_test:DirectData:C] Running Loop=1
2023-05-12T19:21:53.952Z,1683919313.952 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-12T19:21:53.953Z,1683919313.953 [DATMMP](INFO): modem://10: set _.pressure 0.743841 atmosphere
2023-05-12T19:21:53.953Z,1683919313.953 [DATMMP](INFO): #Outgoing data=1
2023-05-12T19:21:53.954Z,1683919313.954 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-12T19:21:54.183Z,1683919314.183 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:10:_.temperature
2023-05-12T19:21:54.183Z,1683919314.183 [senddata_direct_and_track_test:DirectData:C] Stopped
2023-05-12T19:21:54.183Z,1683919314.183 [senddata_direct_and_track_test:DirectData:D] Running Loop=1
2023-05-12T19:21:54.184Z,1683919314.184 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-12T19:21:54.204Z,1683919314.204 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-12T19:21:54.204Z,1683919314.204 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-12T19:21:54.205Z,1683919314.205 [DATMMP](INFO): ****** received valid address query ******
2023-05-12T19:21:54.205Z,1683919314.205 [DATMMP](INFO): ****** received valid ping request ******
2023-05-12T19:21:54.205Z,1683919314.205 [DATMMP](INFO): Querying Benthos address 10
2023-05-12T19:21:54.457Z,1683919314.457 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:54.458Z,1683919314.458 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x15	 x34	 x1FCC
2023-05-12T19:21:54.458Z,1683919314.458 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:54.458Z,1683919314.458 [DATMMP](INFO): Handled
2023-05-12T19:21:54.458Z,1683919314.458 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-12T19:21:54.458Z,1683919314.458 [DATMMP](INFO): Tx to 10 len 34 xid 27
2023-05-12T19:21:54.459Z,1683919314.459 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-12T19:21:54.459Z,1683919314.459 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:54.459Z,1683919314.459 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:54.584Z,1683919314.584 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:10:_.humidity
2023-05-12T19:21:54.584Z,1683919314.584 [senddata_direct_and_track_test:DirectData:D] Stopped
2023-05-12T19:21:54.585Z,1683919314.585 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData
2023-05-12T19:21:54.585Z,1683919314.585 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-12T19:21:54.585Z,1683919314.585 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-12T19:21:54.585Z,1683919314.585 [senddata_direct_and_track_test](INFO): Completed senddata_direct_and_track_test
2023-05-12T19:21:54.586Z,1683919314.586 [MissionManager](INFO): senddata_direct_and_track_test is completed.
2023-05-12T19:21:54.586Z,1683919314.586 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test
2023-05-12T19:21:54.586Z,1683919314.586 [senddata_direct_and_track_test] Stopped
2023-05-12T19:21:54.586Z,1683919314.586 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test
2023-05-12T19:21:54.586Z,1683919314.586 [senddata_direct_and_track_test:AbortDrift] Stopped
2023-05-12T19:21:54.586Z,1683919314.586 [senddata_direct_and_track_test:AbortDrift](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:AbortDrift
2023-05-12T19:21:54.586Z,1683919314.586 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift] Stopped
2023-05-12T19:21:54.586Z,1683919314.586 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Uninitializing AbortDrift.
2023-05-12T19:21:54.586Z,1683919314.586 [senddata_direct_and_track_test:TrackAC.] Stopped
2023-05-12T19:21:54.586Z,1683919314.586 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact.
2023-05-12T19:21:54.709Z,1683919314.709 [DATMMP](INFO): GSXN notify for xid: 27
2023-05-12T19:21:54.709Z,1683919314.709 [DATMMP](INFO): iface_err rx: 	 x1	 x7	 xA
2023-05-12T19:21:54.710Z,1683919314.710 [DATMMP](ERROR): 10:Error talking to DAT device_busy
2023-05-12T19:21:54.710Z,1683919314.710 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:54.710Z,1683919314.710 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:54.964Z,1683919314.964 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:54.965Z,1683919314.965 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:55.034Z,1683919315.034 [MissionManager](IMPORTANT): Started mission Default
2023-05-12T19:21:55.034Z,1683919315.034 [Default] Running Loop=1
2023-05-12T19:21:55.034Z,1683919315.034 [Default](DEBUG): Aggregate::initialize Default
2023-05-12T19:21:55.034Z,1683919315.034 [Default:B.GoToSurface] Running Loop=1
2023-05-12T19:21:55.034Z,1683919315.034 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-12T19:21:55.034Z,1683919315.034 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-12T19:21:55.035Z,1683919315.035 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-12T19:21:55.035Z,1683919315.035 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-12T19:21:55.035Z,1683919315.035 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-12T19:21:55.036Z,1683919315.036 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-12T19:21:55.036Z,1683919315.036 [Default:A.Wait] Running Loop=1
2023-05-12T19:21:55.036Z,1683919315.036 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-12T19:21:55.216Z,1683919315.216 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:55.217Z,1683919315.217 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:55.468Z,1683919315.468 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:55.468Z,1683919315.468 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:55.720Z,1683919315.720 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:55.721Z,1683919315.721 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:55.972Z,1683919315.972 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:55.972Z,1683919315.972 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:56.224Z,1683919316.224 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:56.225Z,1683919316.225 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:56.476Z,1683919316.476 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:56.476Z,1683919316.476 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:56.729Z,1683919316.729 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:56.729Z,1683919316.729 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:21:56.729Z,1683919316.729 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:21:56.729Z,1683919316.729 [DATMMP](INFO): Handled
2023-05-12T19:21:56.730Z,1683919316.730 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:56.730Z,1683919316.730 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:56.981Z,1683919316.981 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:56.981Z,1683919316.981 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x15	 x36	 x20FD
2023-05-12T19:21:56.982Z,1683919316.982 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919332.493568
2023-05-12T19:21:56.982Z,1683919316.982 [DATMMP](INFO): Rx ping set to:1683919316.981529
2023-05-12T19:21:56.983Z,1683919316.983 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:21:56.983Z,1683919316.983 [DATMMP](INFO): Handled
2023-05-12T19:21:56.983Z,1683919316.983 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:56.983Z,1683919316.983 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:57.232Z,1683919317.232 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:57.232Z,1683919317.232 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:57.485Z,1683919317.485 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:57.486Z,1683919317.486 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-05-12T19:21:57.486Z,1683919317.486 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:21:57.486Z,1683919317.486 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:21:57.486Z,1683919317.486 [DATMMP](INFO): Handled
2023-05-12T19:21:57.487Z,1683919317.487 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:57.487Z,1683919317.487 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:57.737Z,1683919317.737 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:57.737Z,1683919317.737 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:21:57.738Z,1683919317.738 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:21:57.738Z,1683919317.738 [DATMMP](INFO): Handled
2023-05-12T19:21:57.738Z,1683919317.738 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:57.738Z,1683919317.738 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:57.989Z,1683919317.989 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:57.990Z,1683919317.990 [DATMMP](INFO): directional_debug rx: 	 x4A	 x1F0	 x24	 xC9	 x1040	 x1371	 x1222	 x16B3
2023-05-12T19:21:57.991Z,1683919317.991 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:21:57.991Z,1683919317.991 [DATMMP](INFO): Handled
2023-05-12T19:21:57.991Z,1683919317.991 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:57.991Z,1683919317.991 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:58.241Z,1683919318.241 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:58.242Z,1683919318.242 [DATMMP](INFO): directional rx: 	 x44	 x1AA	 x592	 xFE10	 x914	 xFE19	 x0	 x395	 x2	 xFFEE	 x27B5966	 x-43569E0
2023-05-12T19:21:58.244Z,1683919318.244 [DATMMP](INFO): Received message type: directional
2023-05-12T19:21:58.244Z,1683919318.244 [DATMMP](INFO): Handled
2023-05-12T19:21:58.244Z,1683919318.244 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:58.244Z,1683919318.244 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:58.492Z,1683919318.492 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:58.494Z,1683919318.494 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x29E	 x22	 x9A	 xA6	 xA9	 xD	 xFFFF	 xB0	 x1D	 xB	 x0
2023-05-12T19:21:58.495Z,1683919318.495 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:21:58.495Z,1683919318.495 [DATMMP](INFO): Handled
2023-05-12T19:21:58.495Z,1683919318.495 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:58.495Z,1683919318.495 [DATMMP](INFO): Range requested while waiting for previous to complete.
2023-05-12T19:21:58.745Z,1683919318.745 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:21:58.746Z,1683919318.746 [DATMMP](INFO): range_update rx: 	 xA	 x2	 x9	 xD
2023-05-12T19:21:58.746Z,1683919318.746 [DATMMP](INFO): Received message type: range_update
2023-05-12T19:21:58.746Z,1683919318.746 [DATMMP](INFO): Handled
2023-05-12T19:21:58.747Z,1683919318.747 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:58.747Z,1683919318.747 [DATMMP](INFO): direction in FSK: [-0.697972,0.174024,0.694659]
2023-05-12T19:21:58.997Z,1683919318.997 [DATMMP](INFO): GSXN notify for xid: 26
2023-05-12T19:21:58.998Z,1683919318.998 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-05-12T19:21:58.999Z,1683919318.999 [DATMMP](ERROR): 4:Command error: data
2023-05-12T19:21:58.999Z,1683919318.999 [DATMMP](DEBUG): Command complete rang
2023-05-12T19:21:58.999Z,1683919318.999 [DATMMP](ERROR): 4:COMPLETE
2023-05-12T19:21:58.999Z,1683919318.999 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:59.178Z,1683919319.178 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m
2023-05-12T19:21:59.179Z,1683919319.179 [Reporter](INFO): acoustic_contact_range 0.900000 m
2023-05-12T19:21:59.249Z,1683919319.249 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:59.500Z,1683919319.500 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:21:59.752Z,1683919319.752 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:00.005Z,1683919320.005 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:00.256Z,1683919320.256 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:00.508Z,1683919320.508 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:00.762Z,1683919320.762 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:01.012Z,1683919321.012 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:01.264Z,1683919321.264 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:01.516Z,1683919321.516 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:01.768Z,1683919321.768 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:02.020Z,1683919322.020 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:02.284Z,1683919322.284 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:02.536Z,1683919322.536 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:02.788Z,1683919322.788 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:03.040Z,1683919323.040 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:03.292Z,1683919323.292 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:03.544Z,1683919323.544 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:03.796Z,1683919323.796 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:04.048Z,1683919324.048 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:04.301Z,1683919324.301 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:04.552Z,1683919324.552 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:04.552Z,1683919324.552 [DATMMP](FAULT): Buffer send receipt timeout failure.
2023-05-12T19:22:04.553Z,1683919324.553 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER
2023-05-12T19:22:04.804Z,1683919324.804 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-12T19:22:04.805Z,1683919324.805 [DATMMP](INFO): modem://10: set _.temperature 24.219263 celsius
2023-05-12T19:22:04.806Z,1683919324.806 [DATMMP](INFO): #Outgoing data=1
2023-05-12T19:22:04.806Z,1683919324.806 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-12T19:22:05.064Z,1683919325.064 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-12T19:22:05.064Z,1683919325.064 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-12T19:22:05.316Z,1683919325.316 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-12T19:22:05.317Z,1683919325.317 [DATMMP](INFO): Tx to 10 len 34 xid 28
2023-05-12T19:22:05.317Z,1683919325.317 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-12T19:22:05.317Z,1683919325.317 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:05.569Z,1683919325.569 [DATMMP](INFO): GSXN notify for xid: 28
2023-05-12T19:22:05.570Z,1683919325.570 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-12T19:22:05.570Z,1683919325.570 [DATMMP](DEBUG): Command complete send
2023-05-12T19:22:05.570Z,1683919325.570 [DATMMP](ERROR): 1:COMPLETE
2023-05-12T19:22:05.570Z,1683919325.570 [DATMMP](INFO): Received message type: cmd_result
2023-05-12T19:22:05.570Z,1683919325.570 [DATMMP](INFO): Handled
2023-05-12T19:22:05.570Z,1683919325.570 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:05.821Z,1683919325.821 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:05.821Z,1683919325.821 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x16	 x3	 x259C
2023-05-12T19:22:05.822Z,1683919325.822 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:22:05.822Z,1683919325.822 [DATMMP](INFO): Handled
2023-05-12T19:22:05.822Z,1683919325.822 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:06.072Z,1683919326.072 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:06.324Z,1683919326.324 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:06.576Z,1683919326.576 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:06.828Z,1683919326.828 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:07.080Z,1683919327.080 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:07.332Z,1683919327.332 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:07.584Z,1683919327.584 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:07.837Z,1683919327.837 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:08.088Z,1683919328.088 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:08.334Z,1683919328.334 [Default:A.Wait](INFO): Done Waiting.
2023-05-12T19:22:08.334Z,1683919328.334 [Default:A.Wait] Stopped
2023-05-12T19:22:08.334Z,1683919328.334 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-12T19:22:08.340Z,1683919328.340 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:08.592Z,1683919328.592 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:08.737Z,1683919328.737 [Default:CheckIn] Running Loop=1
2023-05-12T19:22:08.737Z,1683919328.737 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-12T19:22:08.737Z,1683919328.737 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-12T19:22:08.845Z,1683919328.845 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:09.096Z,1683919329.096 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:09.152Z,1683919329.152 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-05-12T19:22:09.348Z,1683919329.348 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:09.600Z,1683919329.600 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:09.852Z,1683919329.852 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:10.105Z,1683919330.105 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:10.105Z,1683919330.105 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:22:10.105Z,1683919330.105 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:22:10.105Z,1683919330.105 [DATMMP](INFO): Handled
2023-05-12T19:22:10.106Z,1683919330.106 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:10.357Z,1683919330.357 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:10.358Z,1683919330.358 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x16	 x8	 x2D0
2023-05-12T19:22:10.358Z,1683919330.358 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919335.032768
2023-05-12T19:22:10.358Z,1683919330.358 [DATMMP](INFO): Rx ping set to:1683919330.357560
2023-05-12T19:22:10.359Z,1683919330.359 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:22:10.359Z,1683919330.359 [DATMMP](INFO): Handled
2023-05-12T19:22:10.359Z,1683919330.359 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:10.609Z,1683919330.609 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:10.610Z,1683919330.610 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 xC	 xA	 x0
2023-05-12T19:22:10.610Z,1683919330.610 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:22:10.610Z,1683919330.610 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:22:10.610Z,1683919330.610 [DATMMP](INFO): Handled
2023-05-12T19:22:10.610Z,1683919330.610 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:10.861Z,1683919330.861 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:10.862Z,1683919330.862 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:22:10.862Z,1683919330.862 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:22:10.862Z,1683919330.862 [DATMMP](INFO): Handled
2023-05-12T19:22:10.862Z,1683919330.862 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:11.113Z,1683919331.113 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:11.114Z,1683919331.114 [DATMMP](INFO): directional_debug rx: 	 x18	 x1F6	 x23	 xBF	 x1020	 x1351	 x11D2	 x1673
2023-05-12T19:22:11.115Z,1683919331.115 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:22:11.115Z,1683919331.115 [DATMMP](INFO): Handled
2023-05-12T19:22:11.115Z,1683919331.115 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:11.365Z,1683919331.365 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:11.366Z,1683919331.366 [DATMMP](INFO): directional rx: 	 x11	 x1B3	 x5C4	 xFE0A	 x91E	 xFE10	 x0	 x36F	 x4	 xFFEE	 x27B5966	 x-43569E0
2023-05-12T19:22:11.368Z,1683919331.368 [DATMMP](INFO): Received message type: directional
2023-05-12T19:22:11.368Z,1683919331.368 [DATMMP](INFO): Handled
2023-05-12T19:22:11.368Z,1683919331.368 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:11.617Z,1683919331.617 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:11.618Z,1683919331.618 [DATMMP](INFO): acstats rx: 	 xA	 x5	 xFFFF	 x276	 x22	 x8B	 xB5	 xBD	 xD	 xFFFF	 xA8	 x25	 xC	 x0
2023-05-12T19:22:11.618Z,1683919331.618 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:22:11.619Z,1683919331.619 [DATMMP](INFO): Handled
2023-05-12T19:22:11.619Z,1683919331.619 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:11.869Z,1683919331.869 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:11.870Z,1683919331.870 [DATMMP](INFO): data_rx rx: 	 xA	 x0	 x0	 x4
2023-05-12T19:22:11.870Z,1683919331.870 [DATMMP](INFO): Check CRC
2023-05-12T19:22:11.870Z,1683919331.870 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-12T19:22:11.870Z,1683919331.870 [DATMMP](INFO): Got DATA: len 4
2023-05-12T19:22:11.870Z,1683919331.870 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-12T19:22:11.870Z,1683919331.870 [DATMMP](INFO): Got ~~ ack, bytes left 2
2023-05-12T19:22:11.870Z,1683919331.870 [DATMMP](INFO): Received command: 

2023-05-12T19:22:11.871Z,1683919331.871 [DATMMP](INFO): Received message type: data_rx
2023-05-12T19:22:11.871Z,1683919331.871 [DATMMP](INFO): Handled
2023-05-12T19:22:11.871Z,1683919331.871 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-12T19:22:11.871Z,1683919331.871 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-12T19:22:12.120Z,1683919332.120 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-12T19:22:12.121Z,1683919332.121 [DATMMP](INFO): modem://10: set _.humidity 12.892199 percent
2023-05-12T19:22:12.121Z,1683919332.121 [DATMMP](INFO): #Outgoing data=2
2023-05-12T19:22:12.122Z,1683919332.122 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-12T19:22:12.624Z,1683919332.624 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-12T19:22:12.625Z,1683919332.625 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-12T19:22:12.876Z,1683919332.876 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-12T19:22:12.877Z,1683919332.877 [DATMMP](INFO): Tx to 10 len 35 xid 29
2023-05-12T19:22:12.877Z,1683919332.877 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-12T19:22:12.878Z,1683919332.878 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:13.129Z,1683919333.129 [DATMMP](INFO): GSXN notify for xid: 29
2023-05-12T19:22:13.129Z,1683919333.129 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-12T19:22:13.130Z,1683919333.130 [DATMMP](DEBUG): Command complete send
2023-05-12T19:22:13.130Z,1683919333.130 [DATMMP](ERROR): 1:COMPLETE
2023-05-12T19:22:13.130Z,1683919333.130 [DATMMP](INFO): Received message type: cmd_result
2023-05-12T19:22:13.130Z,1683919333.130 [DATMMP](INFO): Handled
2023-05-12T19:22:13.130Z,1683919333.130 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:13.381Z,1683919333.381 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:13.381Z,1683919333.381 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x16	 xB	 x1407
2023-05-12T19:22:13.382Z,1683919333.382 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:22:13.382Z,1683919333.382 [DATMMP](INFO): Handled
2023-05-12T19:22:13.382Z,1683919333.382 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:13.632Z,1683919333.632 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:13.884Z,1683919333.884 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:14.136Z,1683919334.136 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:14.388Z,1683919334.388 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:14.640Z,1683919334.640 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:14.892Z,1683919334.892 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:15.144Z,1683919335.144 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:15.396Z,1683919335.396 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:15.648Z,1683919335.648 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:15.902Z,1683919335.902 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:16.152Z,1683919336.152 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:16.404Z,1683919336.404 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:16.656Z,1683919336.656 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:16.908Z,1683919336.908 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:17.160Z,1683919337.160 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:17.412Z,1683919337.412 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:17.665Z,1683919337.665 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:17.665Z,1683919337.665 [DATMMP](INFO): doppler rx: 	 x0
2023-05-12T19:22:17.665Z,1683919337.665 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:22:17.665Z,1683919337.665 [DATMMP](INFO): Handled
2023-05-12T19:22:17.666Z,1683919337.666 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:17.917Z,1683919337.917 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:17.917Z,1683919337.917 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x16	 xF	 x1A40
2023-05-12T19:22:17.918Z,1683919337.918 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919336.655360
2023-05-12T19:22:17.918Z,1683919337.918 [DATMMP](INFO): Rx ping set to:1683919337.917504
2023-05-12T19:22:17.918Z,1683919337.918 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:22:17.919Z,1683919337.919 [DATMMP](INFO): Handled
2023-05-12T19:22:17.919Z,1683919337.919 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:18.180Z,1683919338.180 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:18.181Z,1683919338.181 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 xC	 xA	 x0
2023-05-12T19:22:18.182Z,1683919338.182 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:22:18.185Z,1683919338.185 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:22:18.186Z,1683919338.186 [DATMMP](INFO): Handled
2023-05-12T19:22:18.186Z,1683919338.186 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:18.420Z,1683919338.420 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:18.421Z,1683919338.421 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:22:18.421Z,1683919338.421 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:22:18.421Z,1683919338.421 [DATMMP](INFO): Handled
2023-05-12T19:22:18.673Z,1683919338.673 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:18.674Z,1683919338.674 [DATMMP](INFO): directional_debug rx: 	 x35	 x201	 x22	 xBD	 xFE0	 x1301	 x11C2	 x1633
2023-05-12T19:22:18.675Z,1683919338.675 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:22:18.675Z,1683919338.675 [DATMMP](INFO): Handled
2023-05-12T19:22:18.675Z,1683919338.675 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:18.924Z,1683919338.924 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:18.926Z,1683919338.926 [DATMMP](INFO): directional rx: 	 x2F	 x1BF	 x5A7	 xFDFF	 x8EE	 xFE06	 x0	 x35D	 x5	 xFFEE	 x27B5966	 x-43569E0
2023-05-12T19:22:18.928Z,1683919338.928 [DATMMP](INFO): Received message type: directional
2023-05-12T19:22:18.928Z,1683919338.928 [DATMMP](INFO): Handled
2023-05-12T19:22:18.928Z,1683919338.928 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:19.177Z,1683919339.177 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:19.178Z,1683919339.178 [DATMMP](INFO): acstats rx: 	 xA	 x5	 x0	 x287	 x22	 x87	 xCF	 xBA	 xD	 xFFFF	 xA8	 x24	 xD	 x0
2023-05-12T19:22:19.179Z,1683919339.179 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:22:19.179Z,1683919339.179 [DATMMP](INFO): Handled
2023-05-12T19:22:19.179Z,1683919339.179 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:19.429Z,1683919339.429 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:19.430Z,1683919339.430 [DATMMP](INFO): data_rx rx: 	 xA	 x0	 x0	 x4
2023-05-12T19:22:19.430Z,1683919339.430 [DATMMP](INFO): Check CRC
2023-05-12T19:22:19.430Z,1683919339.430 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-12T19:22:19.430Z,1683919339.430 [DATMMP](INFO): Got DATA: len 4
2023-05-12T19:22:19.430Z,1683919339.430 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-12T19:22:19.430Z,1683919339.430 [DATMMP](INFO): Got ~~ ack, bytes left 2
2023-05-12T19:22:19.431Z,1683919339.431 [DATMMP](INFO): Received command: 

2023-05-12T19:22:19.431Z,1683919339.431 [DATMMP](INFO): Received message type: data_rx
2023-05-12T19:22:19.431Z,1683919339.431 [DATMMP](INFO): Handled
2023-05-12T19:22:19.431Z,1683919339.431 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-12T19:22:19.431Z,1683919339.431 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-12T19:22:19.684Z,1683919339.684 [DATMMP](INFO): *** SENDING_FILL_BUFFER ***
2023-05-12T19:22:19.685Z,1683919339.685 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA
2023-05-12T19:22:19.936Z,1683919339.936 [DATMMP](INFO): *** SENDING_NAV_DATA ***
2023-05-12T19:22:19.936Z,1683919339.936 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT
2023-05-12T19:22:20.188Z,1683919340.188 [DATMMP](INFO): *** SENDING_TRANSMIT ***
2023-05-12T19:22:20.189Z,1683919340.189 [DATMMP](INFO): Tx to 10 len 32 xid 30
2023-05-12T19:22:20.189Z,1683919340.189 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-12T19:22:20.189Z,1683919340.189 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY ***
2023-05-12T19:22:20.441Z,1683919340.441 [DATMMP](INFO): GSXN notify for xid: 30
2023-05-12T19:22:20.442Z,1683919340.442 [DATMMP](INFO): cmd_result rx: 	 x1	 x7	 x0	 x1
2023-05-12T19:22:20.442Z,1683919340.442 [DATMMP](DEBUG): Command complete send
2023-05-12T19:22:20.442Z,1683919340.442 [DATMMP](ERROR): 1:COMPLETE
2023-05-12T19:22:20.442Z,1683919340.442 [DATMMP](INFO): Received message type: cmd_result
2023-05-12T19:22:20.442Z,1683919340.442 [DATMMP](INFO): Handled
2023-05-12T19:22:20.443Z,1683919340.443 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:20.693Z,1683919340.693 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:20.693Z,1683919340.693 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x16	 x12	 x1FBF
2023-05-12T19:22:20.694Z,1683919340.694 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:22:20.694Z,1683919340.694 [DATMMP](INFO): Handled
2023-05-12T19:22:20.694Z,1683919340.694 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:20.944Z,1683919340.944 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:21.197Z,1683919341.197 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:21.448Z,1683919341.448 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:21.700Z,1683919341.700 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:21.952Z,1683919341.952 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:22.204Z,1683919342.204 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:22.708Z,1683919342.708 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:22.960Z,1683919342.960 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:23.212Z,1683919343.212 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:23.464Z,1683919343.464 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:23.716Z,1683919343.716 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:23.968Z,1683919343.968 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:24.221Z,1683919344.221 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:24.472Z,1683919344.472 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:24.724Z,1683919344.724 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:24.977Z,1683919344.977 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:24.977Z,1683919344.977 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-05-12T19:22:24.978Z,1683919344.978 [DATMMP](INFO): Received message type: doppler
2023-05-12T19:22:24.978Z,1683919344.978 [DATMMP](INFO): Handled
2023-05-12T19:22:24.978Z,1683919344.978 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:25.228Z,1683919345.228 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:25.229Z,1683919345.229 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x16	 x16	 x25F7
2023-05-12T19:22:25.230Z,1683919345.230 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919372.956416
2023-05-12T19:22:25.230Z,1683919345.230 [DATMMP](INFO): Rx ping set to:1683919345.229497
2023-05-12T19:22:25.230Z,1683919345.230 [DATMMP](INFO): Received message type: timestamp
2023-05-12T19:22:25.231Z,1683919345.231 [DATMMP](INFO): Handled
2023-05-12T19:22:25.231Z,1683919345.231 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:25.481Z,1683919345.481 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:25.482Z,1683919345.482 [DATMMP](INFO): remote_header rx: 	 xF	 x4	 x5	 x4	 x0	 xC	 xA	 x0
2023-05-12T19:22:25.482Z,1683919345.482 [DATMMP](INFO): DATA Src=10, Dst=12
2023-05-12T19:22:25.482Z,1683919345.482 [DATMMP](INFO): Received message type: remote_header
2023-05-12T19:22:25.482Z,1683919345.482 [DATMMP](INFO): Handled
2023-05-12T19:22:25.482Z,1683919345.482 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:25.733Z,1683919345.733 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:25.733Z,1683919345.733 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-05-12T19:22:25.734Z,1683919345.734 [DATMMP](INFO): Received message type: nav_stat
2023-05-12T19:22:25.734Z,1683919345.734 [DATMMP](INFO): Handled
2023-05-12T19:22:25.734Z,1683919345.734 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:25.985Z,1683919345.985 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:25.986Z,1683919345.986 [DATMMP](INFO): directional_debug rx: 	 x21D	 x1E5	 x24	 x1B1	 x1010	 x1351	 x11F2	 x15F3
2023-05-12T19:22:25.987Z,1683919345.987 [DATMMP](INFO): Received message type: directional_debug
2023-05-12T19:22:25.987Z,1683919345.987 [DATMMP](INFO): Handled
2023-05-12T19:22:25.987Z,1683919345.987 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:26.237Z,1683919346.237 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:26.238Z,1683919346.238 [DATMMP](INFO): directional rx: 	 x225	 x192	 x3BF	 xFE1B	 x6FF	 xFE2D	 x0	 x348	 x6	 xFFED	 x27B5966	 x-43569E0
2023-05-12T19:22:26.240Z,1683919346.240 [DATMMP](INFO): Received message type: directional
2023-05-12T19:22:26.240Z,1683919346.240 [DATMMP](INFO): Handled
2023-05-12T19:22:26.240Z,1683919346.240 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:26.489Z,1683919346.489 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:26.490Z,1683919346.490 [DATMMP](INFO): acstats rx: 	 xA	 x5	 xFFFF	 x2CE	 x23	 x90	 xC1	 xBF	 xD	 xFFFF	 xA8	 x23	 xC	 x0
2023-05-12T19:22:26.491Z,1683919346.491 [DATMMP](INFO): Received message type: acstats
2023-05-12T19:22:26.491Z,1683919346.491 [DATMMP](INFO): Handled
2023-05-12T19:22:26.491Z,1683919346.491 [DATMMP](INFO): *** SENDING_ACK_WAITING ***
2023-05-12T19:22:26.741Z,1683919346.741 [DATMMP](INFO): GSXN notify for xid: 0
2023-05-12T19:22:26.742Z,1683919346.742 [DATMMP](INFO): data_rx rx: 	 xA	 x0	 x0	 x4
2023-05-12T19:22:26.742Z,1683919346.742 [DATMMP](INFO): Check CRC
2023-05-12T19:22:26.742Z,1683919346.742 [DATMMP](INFO): data rx parseDataResponse 4
2023-05-12T19:22:26.742Z,1683919346.742 [DATMMP](INFO): Got DATA: len 4
2023-05-12T19:22:26.742Z,1683919346.742 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED
2023-05-12T19:22:26.742Z,1683919346.742 [DATMMP](INFO): Got ~~ ack, bytes left 2
2023-05-12T19:22:26.743Z,1683919346.743 [DATMMP](INFO): Received command: 

2023-05-12T19:22:26.743Z,1683919346.743 [DATMMP](INFO): Received message type: data_rx
2023-05-12T19:22:26.743Z,1683919346.743 [DATMMP](INFO): Handled
2023-05-12T19:22:26.743Z,1683919346.743 [DATMMP](INFO): *** SENDING_VERIFIED ***
2023-05-12T19:22:26.743Z,1683919346.743 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-12T19:23:16.605Z,1683919396.605 [CommandExec](IMPORTANT): got command show stack
2023-05-12T19:23:16.605Z,1683919396.605 [CommandExec](IMPORTANT): Behavior Stack:

2023-05-12T19:23:16.606Z,1683919396.606 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2023-05-12T19:23:16.606Z,1683919396.606 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS