2023-05-10T22:21:24.112Z,1683757284.112 [Supervisor](DEBUG): Initializing supervisor.
2023-05-10T22:21:24.117Z,1683757284.117 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-05-10T22:21:24.117Z,1683757284.117 [SyncHandler](INFO): Protected caller Thread ID is 836
2023-05-10T22:21:24.118Z,1683757284.118 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-05-10T22:21:24.119Z,1683757284.119 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-05-10T22:21:24.119Z,1683757284.119 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 837
2023-05-10T22:21:24.123Z,1683757284.123 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-05-10T22:21:24.141Z,1683757284.141 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-05-10T22:21:24.142Z,1683757284.142 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-05-10T22:21:24.142Z,1683757284.142 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 838
2023-05-10T22:21:24.146Z,1683757284.146 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-05-10T22:21:24.147Z,1683757284.147 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-05-10T22:21:24.147Z,1683757284.147 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 839
2023-05-10T22:21:24.150Z,1683757284.150 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-05-10T22:21:24.150Z,1683757284.150 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-05-10T22:21:24.151Z,1683757284.151 [logger ThreadHandler](INFO): Protected caller Thread ID is 840
2023-05-10T22:21:24.154Z,1683757284.154 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-05-10T22:21:24.155Z,1683757284.155 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-05-10T22:21:24.159Z,1683757284.159 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-05-10T22:21:24.620Z,1683757284.620 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-05-10T22:21:24.622Z,1683757284.622 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-05-10T22:21:24.829Z,1683757284.829 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-05-10T22:21:24.830Z,1683757284.830 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-05-10T22:21:24.912Z,1683757284.912 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-05-10T22:21:25.124Z,1683757285.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-05-10T22:21:25.126Z,1683757285.126 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-05-10T22:21:25.206Z,1683757285.206 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-05-10T22:21:25.301Z,1683757285.301 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-05-10T22:21:25.302Z,1683757285.302 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-05-10T22:21:25.629Z,1683757285.629 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-05-10T22:21:25.630Z,1683757285.630 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-05-10T22:21:25.760Z,1683757285.760 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-05-10T22:21:25.760Z,1683757285.760 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-05-10T22:21:26.245Z,1683757286.245 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-05-10T22:21:26.246Z,1683757286.246 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-05-10T22:21:26.425Z,1683757286.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-05-10T22:21:26.427Z,1683757286.427 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-05-10T22:21:26.813Z,1683757286.813 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-05-10T22:21:26.815Z,1683757286.815 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-05-10T22:21:27.087Z,1683757287.087 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-05-10T22:21:27.089Z,1683757287.089 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-05-10T22:21:27.197Z,1683757287.197 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-05-10T22:21:27.199Z,1683757287.199 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-05-10T22:21:27.978Z,1683757287.978 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-05-10T22:21:28.016Z,1683757288.016 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-05-10T22:21:29.393Z,1683757289.393 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-05-10T22:21:29.395Z,1683757289.395 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-05-10T22:21:29.651Z,1683757289.651 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-05-10T22:21:29.653Z,1683757289.653 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-05-10T22:21:29.655Z,1683757289.655 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-05-10T22:21:29.852Z,1683757289.852 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-05-10T22:21:29.935Z,1683757289.935 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-05-10T22:21:30.067Z,1683757290.067 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-05-10T22:21:30.152Z,1683757290.152 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-05-10T22:21:30.413Z,1683757290.413 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-05-10T22:21:30.414Z,1683757290.414 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-05-10T22:21:30.518Z,1683757290.518 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-05-10T22:21:30.625Z,1683757290.625 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-05-10T22:21:30.738Z,1683757290.738 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-05-10T22:21:30.882Z,1683757290.882 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-05-10T22:21:30.981Z,1683757290.981 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-05-10T22:21:31.073Z,1683757291.073 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-05-10T22:21:31.090Z,1683757291.090 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-05-10T22:21:31.106Z,1683757291.106 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-05-10T22:21:31.107Z,1683757291.107 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-05-10T22:21:31.230Z,1683757291.230 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-05-10T22:21:31.231Z,1683757291.231 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-05-10T22:21:31.298Z,1683757291.298 [VerticalControl](DEBUG): Construct VerticalControl.
2023-05-10T22:21:31.358Z,1683757291.358 [VerticalControl] Loaded
2023-05-10T22:21:31.358Z,1683757291.358 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-05-10T22:21:31.361Z,1683757291.361 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-05-10T22:21:31.402Z,1683757291.402 [HorizontalControl] Loaded
2023-05-10T22:21:31.402Z,1683757291.402 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-05-10T22:21:31.405Z,1683757291.405 [SpeedControl](DEBUG): Construct SpeedControl.
2023-05-10T22:21:31.407Z,1683757291.407 [SpeedControl] Loaded
2023-05-10T22:21:31.408Z,1683757291.408 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-05-10T22:21:31.410Z,1683757291.410 [LoopControl](DEBUG): Construct LoopControl.
2023-05-10T22:21:31.411Z,1683757291.411 [LoopControl] Loaded
2023-05-10T22:21:31.411Z,1683757291.411 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-05-10T22:21:31.411Z,1683757291.411 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-05-10T22:21:31.412Z,1683757291.412 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-05-10T22:21:31.611Z,1683757291.611 [BuoyancyServo] Loaded
2023-05-10T22:21:31.612Z,1683757291.612 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-05-10T22:21:31.632Z,1683757291.632 [ElevatorServo] Loaded
2023-05-10T22:21:31.632Z,1683757291.632 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-05-10T22:21:31.651Z,1683757291.651 [MassServo] Loaded
2023-05-10T22:21:31.651Z,1683757291.651 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-05-10T22:21:31.669Z,1683757291.669 [RudderServo] Loaded
2023-05-10T22:21:31.669Z,1683757291.669 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-05-10T22:21:31.683Z,1683757291.683 [ThrusterHE] Loaded
2023-05-10T22:21:31.684Z,1683757291.684 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-05-10T22:21:31.684Z,1683757291.684 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-05-10T22:21:31.685Z,1683757291.685 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-05-10T22:21:31.755Z,1683757291.755 [DepthRateCalculator] Loaded
2023-05-10T22:21:31.755Z,1683757291.755 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-05-10T22:21:31.760Z,1683757291.760 [PitchRateCalculator] Loaded
2023-05-10T22:21:31.760Z,1683757291.760 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-05-10T22:21:31.770Z,1683757291.770 [SpeedCalculator] Loaded
2023-05-10T22:21:31.770Z,1683757291.770 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-05-10T22:21:31.774Z,1683757291.774 [YawRateCalculator] Loaded
2023-05-10T22:21:31.775Z,1683757291.775 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-05-10T22:21:31.793Z,1683757291.793 [ElevatorOffsetCalculator] Loaded
2023-05-10T22:21:31.793Z,1683757291.793 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-05-10T22:21:31.794Z,1683757291.794 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-05-10T22:21:31.794Z,1683757291.794 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-05-10T22:21:31.931Z,1683757291.931 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-05-10T22:21:31.932Z,1683757291.932 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-05-10T22:21:31.945Z,1683757291.945 [NavChart] Loaded
2023-05-10T22:21:31.945Z,1683757291.945 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-05-10T22:21:31.951Z,1683757291.951 [UniversalFixResidualReporter] Loaded
2023-05-10T22:21:31.951Z,1683757291.951 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-05-10T22:21:31.952Z,1683757291.952 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-05-10T22:21:31.954Z,1683757291.954 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-05-10T22:21:32.742Z,1683757292.742 [AHRS_M2] Loaded
2023-05-10T22:21:32.743Z,1683757292.743 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-05-10T22:21:32.993Z,1683757292.993 [BackseatComponent] Loaded
2023-05-10T22:21:32.993Z,1683757292.993 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-05-10T22:21:32.994Z,1683757292.994 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408F64E0
2023-05-10T22:21:32.994Z,1683757292.994 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 923
2023-05-10T22:21:32.997Z,1683757292.997 [LcmUniversalReporter] Loaded
2023-05-10T22:21:32.997Z,1683757292.997 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-05-10T22:21:33.817Z,1683757293.817 [BPC1] Loaded
2023-05-10T22:21:33.817Z,1683757293.817 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-05-10T22:21:33.907Z,1683757293.907 [DAT] Loaded
2023-05-10T22:21:33.907Z,1683757293.907 [ComponentRegistry](DEBUG): Component "DAT" handled in its own thread.
2023-05-10T22:21:33.908Z,1683757293.908 [DAT ThreadHandler](DEBUG): Created PCaller Thread at 409264E0
2023-05-10T22:21:33.909Z,1683757293.909 [DAT ThreadHandler](INFO): Protected caller Thread ID is 924
2023-05-10T22:21:34.050Z,1683757294.050 [DataOverHttps] Loaded
2023-05-10T22:21:34.050Z,1683757294.050 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-05-10T22:21:34.051Z,1683757294.051 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409564E0
2023-05-10T22:21:34.051Z,1683757294.051 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 925
2023-05-10T22:21:34.072Z,1683757294.072 [Depth_Keller] Loaded
2023-05-10T22:21:34.073Z,1683757294.073 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-05-10T22:21:34.134Z,1683757294.134 [NAL9602] Loaded
2023-05-10T22:21:34.134Z,1683757294.134 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-05-10T22:21:34.164Z,1683757294.164 [Onboard] Loaded
2023-05-10T22:21:34.164Z,1683757294.164 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-05-10T22:21:34.165Z,1683757294.165 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409864E0
2023-05-10T22:21:34.165Z,1683757294.165 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 926
2023-05-10T22:21:34.177Z,1683757294.177 [Power24vConverter] Loaded
2023-05-10T22:21:34.177Z,1683757294.177 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-05-10T22:21:34.191Z,1683757294.191 [Radio_Surface] Loaded
2023-05-10T22:21:34.191Z,1683757294.191 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-05-10T22:21:34.192Z,1683757294.192 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409B64E0
2023-05-10T22:21:34.192Z,1683757294.192 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 927
2023-05-10T22:21:34.193Z,1683757294.193 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-05-10T22:21:34.194Z,1683757294.194 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-05-10T22:21:34.651Z,1683757294.651 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-05-10T22:21:34.765Z,1683757294.765 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-05-10T22:21:34.950Z,1683757294.950 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-05-10T22:21:34.951Z,1683757294.951 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-05-10T22:21:34.993Z,1683757294.993 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-05-10T22:21:34.994Z,1683757294.994 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-05-10T22:21:35.210Z,1683757295.210 [CTD_Seabird] Loaded
2023-05-10T22:21:35.210Z,1683757295.210 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-05-10T22:21:35.211Z,1683757295.211 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AED4E0
2023-05-10T22:21:35.212Z,1683757295.212 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 928
2023-05-10T22:21:35.245Z,1683757295.245 [ESPComponent] Loaded
2023-05-10T22:21:35.245Z,1683757295.245 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2023-05-10T22:21:35.264Z,1683757295.264 [PAR_Licor] Loaded
2023-05-10T22:21:35.265Z,1683757295.265 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-05-10T22:21:35.297Z,1683757295.297 [WetLabsBB2FL] Loaded
2023-05-10T22:21:35.297Z,1683757295.297 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-05-10T22:21:35.298Z,1683757295.298 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B1D4E0
2023-05-10T22:21:35.298Z,1683757295.298 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 929
2023-05-10T22:21:35.299Z,1683757295.299 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-05-10T22:21:35.299Z,1683757295.299 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-05-10T22:21:35.655Z,1683757295.655 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-05-10T22:21:35.655Z,1683757295.655 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-05-10T22:21:35.821Z,1683757295.821 [SBIT](DEBUG): Construct Startup Built In Test.
2023-05-10T22:21:35.830Z,1683757295.830 [SBIT] Loaded
2023-05-10T22:21:35.830Z,1683757295.830 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-05-10T22:21:35.833Z,1683757295.833 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-05-10T22:21:35.846Z,1683757295.846 [IBIT] Loaded
2023-05-10T22:21:35.847Z,1683757295.847 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-05-10T22:21:35.852Z,1683757295.852 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-05-10T22:21:35.957Z,1683757295.957 [CBIT] Loaded
2023-05-10T22:21:35.957Z,1683757295.957 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-05-10T22:21:35.958Z,1683757295.958 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-05-10T22:21:35.964Z,1683757295.964 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-05-10T22:21:35.967Z,1683757295.967 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-05-10T22:21:35.978Z,1683757295.978 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-05-10T22:21:35.979Z,1683757295.979 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C004E0
2023-05-10T22:21:35.979Z,1683757295.979 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 930
2023-05-10T22:21:35.983Z,1683757295.983 [Supervisor](INFO): Main Thread ID is 831
2023-05-10T22:21:35.984Z,1683757295.984 [Supervisor](DEBUG): Running supervisor.
2023-05-10T22:21:35.984Z,1683757295.984 [CommandExec ThreadHandler](INFO): Handler Thread ID is 931
2023-05-10T22:21:35.985Z,1683757295.985 [CommandExec](INFO): Initializing the command executive.
2023-05-10T22:21:35.986Z,1683757295.986 [CommandLine ThreadHandler](INFO): Handler Thread ID is 932
2023-05-10T22:21:35.988Z,1683757295.988 [controlThread ThreadHandler](INFO): Handler Thread ID is 933
2023-05-10T22:21:35.989Z,1683757295.989 [controlThread](DEBUG): Initializing ControlThread
2023-05-10T22:21:35.990Z,1683757295.990 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-05-10T22:21:35.991Z,1683757295.991 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-05-10T22:21:35.992Z,1683757295.992 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-05-10T22:21:35.992Z,1683757295.992 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-05-10T22:21:35.994Z,1683757295.994 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-05-10T22:21:35.994Z,1683757295.994 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-05-10T22:21:35.995Z,1683757295.995 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-05-10T22:21:35.995Z,1683757295.995 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-05-10T22:21:35.995Z,1683757295.995 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-05-10T22:21:35.997Z,1683757295.997 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-05-10T22:21:35.997Z,1683757295.997 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-05-10T22:21:36.004Z,1683757296.004 [SBIT](INFO): Initialize SBIT Component.
2023-05-10T22:21:36.005Z,1683757296.005 [SBIT](IMPORTANT): git: 2023-04-26-68-gd8052d973
2023-05-10T22:21:36.005Z,1683757296.005 [SBIT](INFO): git hash: d8052d9734beefc1bd50265fa9cca972428f086c
2023-05-10T22:21:36.005Z,1683757296.005 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-05-10T22:21:36.006Z,1683757296.006 [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-10T22:21:36.007Z,1683757296.007 [SBIT](INFO): Beginning SBIT in 81.000000 seconds.
2023-05-10T22:21:36.008Z,1683757296.008 [IBIT](INFO): Initialize IBIT Component.
2023-05-10T22:21:36.009Z,1683757296.009 [CBIT](DEBUG): Initialize CBIT Component.
2023-05-10T22:21:36.010Z,1683757296.010 [logger ThreadHandler](INFO): Handler Thread ID is 934
2023-05-10T22:21:36.020Z,1683757296.020 [CBIT](DEBUG): Initialized mux pins.
2023-05-10T22:21:36.020Z,1683757296.020 [CBIT](DEBUG): Initializing the watchdog timer.
2023-05-10T22:21:36.028Z,1683757296.028 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 935
2023-05-10T22:21:36.040Z,1683757296.040 [DAT ThreadHandler](INFO): Handler Thread ID is 936
2023-05-10T22:21:36.041Z,1683757296.041 [DAT](INFO): Powering up
2023-05-10T22:21:36.041Z,1683757296.041 [DAT](DEBUG): Initializing DAT.
2023-05-10T22:21:36.044Z,1683757296.044 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-05-10T22:21:36.044Z,1683757296.044 [CBIT](DEBUG): Initializing heartbeat.
2023-05-10T22:21:36.046Z,1683757296.046 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 938
2023-05-10T22:21:36.047Z,1683757296.047 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-05-10T22:21:36.057Z,1683757296.057 [Onboard ThreadHandler](INFO): Handler Thread ID is 939
2023-05-10T22:21:36.074Z,1683757296.074 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 940
2023-05-10T22:21:36.096Z,1683757296.096 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 941
2023-05-10T22:21:36.097Z,1683757296.097 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-05-10T22:21:36.101Z,1683757296.101 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 943
2023-05-10T22:21:36.104Z,1683757296.104 [WetLabsBB2FL](INFO): Powering up
2023-05-10T22:21:36.105Z,1683757296.105 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 945
2023-05-10T22:21:36.113Z,1683757296.113 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2023-05-10T22:21:36.113Z,1683757296.113 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2023-05-10T22:21:36.113Z,1683757296.113 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2023-05-10T22:21:36.113Z,1683757296.113 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2023-05-10T22:21:36.114Z,1683757296.114 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2023-05-10T22:21:36.114Z,1683757296.114 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2023-05-10T22:21:36.114Z,1683757296.114 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2023-05-10T22:21:36.114Z,1683757296.114 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2023-05-10T22:21:36.116Z,1683757296.116 [CBIT](DEBUG): Deactivating GF circuits.
2023-05-10T22:21:36.116Z,1683757296.116 [CBIT](DEBUG): Deactivating emergency mode.
2023-05-10T22:21:36.156Z,1683757296.156 [CBIT](DEBUG): Backplane powered.
2023-05-10T22:21:36.157Z,1683757296.157 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-05-10T22:21:36.185Z,1683757296.185 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-10T22:21:36.233Z,1683757296.233 [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-10T22:21:36.233Z,1683757296.233 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-05-10T22:21:36.323Z,1683757296.323 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-05-10T22:21:36.341Z,1683757296.341 [Default:A.Wait](DEBUG): Construct Wait.
2023-05-10T22:21:36.343Z,1683757296.343 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-05-10T22:21:36.370Z,1683757296.370 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-05-10T22:21:36.392Z,1683757296.392 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-05-10T22:21:36.398Z,1683757296.398 [Default:E.Execute](DEBUG): Construct Execute.
2023-05-10T22:21:36.417Z,1683757296.417 [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-10T22:21:36.422Z,1683757296.422 [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-10T22:21:36.441Z,1683757296.441 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-05-10T22:21:36.480Z,1683757296.480 [Radio_Surface](INFO): Powering up
2023-05-10T22:21:36.598Z,1683757296.598 [Power24vConverter](INFO): Powering up.
2023-05-10T22:21:36.638Z,1683757296.638 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-05-10T22:21:36.644Z,1683757296.644 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-05-10T22:21:36.645Z,1683757296.645 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-05-10T22:21:36.652Z,1683757296.652 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-05-10T22:21:36.653Z,1683757296.653 [MassServo](DEBUG): Initializing EZServoServo.
2023-05-10T22:21:36.661Z,1683757296.661 [MassServo](DEBUG): Initializing MassServo.
2023-05-10T22:21:36.662Z,1683757296.662 [RudderServo](DEBUG): Initializing EZServoServo.
2023-05-10T22:21:36.668Z,1683757296.668 [RudderServo](DEBUG): Initializing RudderServo.
2023-05-10T22:21:36.669Z,1683757296.669 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-05-10T22:21:36.676Z,1683757296.676 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-05-10T22:21:38.212Z,1683757298.212 [WetLabsBB2FL](INFO): Powering down
2023-05-10T22:21:42.337Z,1683757302.337 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-05-10T22:21:48.388Z,1683757308.388 [DAT](INFO): DAT read: 

2023-05-10T22:21:48.390Z,1683757308.390 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-05-10T22:21:50.153Z,1683757310.153 [DAT](INFO): DAT read: MF Frequency Band

2023-05-10T22:21:50.154Z,1683757310.154 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-05-10T22:21:50.154Z,1683757310.154 [DAT](INFO): DAT read: Apr 10 2000 22:21:38 

2023-05-10T22:21:51.161Z,1683757311.161 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-05-10T22:21:51.162Z,1683757311.162 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T22:21:51.163Z,1683757311.163 [DAT](INFO): commRate: 800
2023-05-10T22:21:53.240Z,1683757313.240 [DAT](INFO): entering command mode
2023-05-10T22:21:53.240Z,1683757313.240 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:21:53.428Z,1683757313.428 [DAT](INFO): DAT read: 

2023-05-10T22:21:53.429Z,1683757313.429 [DAT](INFO): DAT read: user:1>

2023-05-10T22:21:53.429Z,1683757313.429 [DAT](INFO): setting verbose to 3
2023-05-10T22:21:53.680Z,1683757313.680 [DAT](INFO): DAT read: user:1>

2023-05-10T22:21:53.682Z,1683757313.682 [DAT](INFO): DAT read: Verbose         | 3           

2023-05-10T22:21:53.682Z,1683757313.682 [DAT](INFO): set verbose to 3
2023-05-10T22:21:53.682Z,1683757313.682 [DAT](INFO): setting DatVerbose to 27440
2023-05-10T22:21:53.934Z,1683757313.934 [DAT](INFO): DAT read: user:2>

2023-05-10T22:21:53.935Z,1683757313.935 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-05-10T22:21:53.935Z,1683757313.935 [DAT](INFO): set DatVerbose to 27440
2023-05-10T22:21:53.935Z,1683757313.935 [DAT](INFO): setting transmit power to 8
2023-05-10T22:21:54.184Z,1683757314.184 [DAT](INFO): DAT read: user:3>

2023-05-10T22:21:54.185Z,1683757314.185 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-05-10T22:21:54.186Z,1683757314.186 [DAT](INFO): set transmit power to 8
2023-05-10T22:21:54.186Z,1683757314.186 [DAT](INFO): setting local address to 12
2023-05-10T22:21:54.436Z,1683757314.436 [DAT](INFO): DAT read: user:4>

2023-05-10T22:21:54.437Z,1683757314.437 [DAT](INFO): DAT read: LocalAddr       | 12          

2023-05-10T22:21:54.438Z,1683757314.438 [DAT](INFO): set local address to 12
2023-05-10T22:21:54.439Z,1683757314.439 [DAT](INFO): Setting time to: 22:21:54 And date to:5/10/2023
2023-05-10T22:21:54.688Z,1683757314.688 [DAT](INFO): DAT read: user:5>

2023-05-10T22:21:54.689Z,1683757314.689 [DAT](INFO): DAT read: Wed May 10, 2023  22:21:54  

2023-05-10T22:21:54.690Z,1683757314.690 [DAT](INFO): Local DAT time set to Wed May 10, 2023  22:21:54  

2023-05-10T22:22:04.309Z,1683757324.309 [NAL9602](INFO): Powering up NAL9602
2023-05-10T22:22:15.222Z,1683757335.222 [NAL9602](INFO): NAL9602 initialized
2023-05-10T22:22:43.918Z,1683757363.918 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:22:43.958Z,1683757363.958 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:22:57.254Z,1683757377.254 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:22:57.292Z,1683757377.292 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:22:57.352Z,1683757377.352 [SBIT](IMPORTANT): Beginning Startup BIT
2023-05-10T22:22:57.365Z,1683757377.365 [CBIT](IMPORTANT): Beginning ground fault scan
2023-05-10T22:22:59.908Z,1683757379.908 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.latitude_fix 36.8 degree
2023-05-10T22:22:59.911Z,1683757379.911 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.latitude_fix" handled in the control thread.
2023-05-10T22:22:59.912Z,1683757379.912 [CommandExec](IMPORTANT): got command maintain sensor NAL9602.longitude_fix -121.9 degree
2023-05-10T22:22:59.915Z,1683757379.915 [ComponentRegistry](DEBUG): SyncComponent "Maintain_NAL9602.longitude_fix" handled in the control thread.
2023-05-10T22:22:59.932Z,1683757379.932 [CommandExec](IMPORTANT): got command maintain sensor Depth_Keller.depth 0.8 meter
2023-05-10T22:22:59.936Z,1683757379.936 [ComponentRegistry](DEBUG): SyncComponent "Maintain_Depth_Keller.depth" handled in the control thread.
2023-05-10T22:22:59.937Z,1683757379.937 [CommandExec](IMPORTANT): got command report touch 
2023-05-10T22:22:59.937Z,1683757379.937 [CommandExec](FAULT): Incomplete syntax. Try: help report
2023-05-10T22:23:00.298Z,1683757380.298 [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-10T22:23:08.193Z,1683757388.193 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.010296
CHAN A1 (24V): -0.008210
CHAN A2 (12V): -0.004901
CHAN A3 (5V): -0.003235
CHAN B0 (3.3V): -0.000539
CHAN B1 (3.15aV): -0.001405
CHAN B2 (3.15bV): -0.000766
CHAN B3 (GND): 0.000080
OPEN: 0.004361
Full Scale: +/- 1 mA
2023-05-10T22:23:10.593Z,1683757390.593 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:23:10.620Z,1683757390.620 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:23:23.513Z,1683757403.513 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:23:23.519Z,1683757403.519 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:23:36.441Z,1683757416.441 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:23:36.447Z,1683757416.447 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:23:49.773Z,1683757429.773 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:23:49.778Z,1683757429.778 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:23:51.445Z,1683757431.445 [SBIT](IMPORTANT): SBIT PASSED
2023-05-10T22:23:51.445Z,1683757431.445 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-05-10T22:23:51.446Z,1683757431.446 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2023-05-10T22:23:51.446Z,1683757431.446 [SBIT](IMPORTANT): BackseatComponent.alwaysOn=0 bool;

2023-05-10T22:23:51.446Z,1683757431.446 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2023-05-10T22:23:51.446Z,1683757431.446 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2023-05-10T22:23:51.446Z,1683757431.446 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2023-05-10T22:23:51.446Z,1683757431.446 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2023-05-10T22:23:51.447Z,1683757431.447 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-10T22:23:51.447Z,1683757431.447 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2023-05-10T22:23:51.447Z,1683757431.447 [SBIT](IMPORTANT): Express linearApproximation platform_roll_angle 5.000000 degree;

2023-05-10T22:23:51.447Z,1683757431.447 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=184.896478 cubic_centimeter;

2023-05-10T22:23:51.447Z,1683757431.447 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;

2023-05-10T22:23:51.447Z,1683757431.447 [SBIT](IMPORTANT): VerticalControl.massDefault=15.484465 millimeter;

2023-05-10T22:23:51.822Z,1683757431.822 [MissionManager](IMPORTANT): Started mission Startup
2023-05-10T22:23:51.822Z,1683757431.822 [Startup] Running Loop=1
2023-05-10T22:23:51.822Z,1683757431.822 [Startup](DEBUG): Aggregate::initialize Startup
2023-05-10T22:23:51.822Z,1683757431.822 [Startup:A.GoToSurface] Running Loop=1
2023-05-10T22:23:51.822Z,1683757431.822 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T22:23:51.823Z,1683757431.823 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T22:23:51.823Z,1683757431.823 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T22:23:51.824Z,1683757431.824 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T22:23:51.824Z,1683757431.824 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T22:23:51.825Z,1683757431.825 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T22:23:51.826Z,1683757431.826 [Startup:StartupSatComms] Running Loop=1
2023-05-10T22:23:51.826Z,1683757431.826 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-05-10T22:23:51.826Z,1683757431.826 [Startup:StartupSatComms:A] Running Loop=1
2023-05-10T22:23:52.245Z,1683757432.245 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-05-10T22:23:52.245Z,1683757432.245 [Startup:StartupSatComms:A] Stopped
2023-05-10T22:23:52.246Z,1683757432.246 [Startup:StartupSatComms:B] Running Loop=1
2023-05-10T22:23:52.641Z,1683757432.641 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-10T22:24:00.027Z,1683757440.027 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005061
2023-05-10T22:23:56.806Z,1683757436.806 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:23:56.832Z,1683757436.832 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:24:07.357Z,1683757447.357 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230510T195507/Courier0043.lzma
2023-05-10T22:24:08.359Z,1683757448.359 [DataOverHttps](INFO): Moved sent file to Logs/20230510T195507/Courier0043.lzma.bak
2023-05-10T22:24:08.360Z,1683757448.360 [DataOverHttps](INFO): SBD MOMSN=18289133
2023-05-10T22:24:10.145Z,1683757450.145 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:24:10.151Z,1683757450.151 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:24:23.471Z,1683757463.471 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:24:23.477Z,1683757463.477 [BPC1](ERROR): BPC1B: No match for serial number 0C29 in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:24:24.725Z,1683757464.725 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20230510T222124/Courier0000.lzma
2023-05-10T22:24:25.727Z,1683757465.727 [DataOverHttps](INFO): Moved sent file to Logs/20230510T222124/Courier0000.lzma.bak
2023-05-10T22:24:25.727Z,1683757465.727 [DataOverHttps](INFO): SBD MOMSN=18289137
2023-05-10T22:24:36.399Z,1683757476.399 [BPC1](ERROR): BPC1B: No match for serial number 0BEC in BPC1B's battery stick inventory (sticks 32-62 in onboard configuration file).
2023-05-10T22:24:43.185Z,1683757483.185 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20230510T195507/Express0044.lzma
2023-05-10T22:24:44.187Z,1683757484.187 [DataOverHttps](INFO): Moved sent file to Logs/20230510T195507/Express0044.lzma.bak
2023-05-10T22:24:44.187Z,1683757484.187 [DataOverHttps](INFO): SBD MOMSN=18289143
2023-05-10T22:24:52.590Z,1683757492.590 [Startup:StartupSatComms:B](INFO): Timed out from 2023-05-10T22:23:52.2Z
2023-05-10T22:24:52.590Z,1683757492.590 [Startup:StartupSatComms:B] Stopped
2023-05-10T22:24:52.590Z,1683757492.590 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-05-10T22:24:52.590Z,1683757492.590 [Startup:StartupSatComms] Stopped
2023-05-10T22:24:52.590Z,1683757492.590 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-05-10T22:24:52.591Z,1683757492.591 [Startup](INFO): Completed Startup
2023-05-10T22:24:52.591Z,1683757492.591 [MissionManager](INFO): Startup is completed.
2023-05-10T22:24:52.591Z,1683757492.591 [MissionManager](INFO): Uninitializing Mission Startup
2023-05-10T22:24:52.591Z,1683757492.591 [Startup] Stopped
2023-05-10T22:24:52.592Z,1683757492.592 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-05-10T22:24:52.592Z,1683757492.592 [Startup:A.GoToSurface] Stopped
2023-05-10T22:24:52.592Z,1683757492.592 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T22:24:52.974Z,1683757492.974 [MissionManager](IMPORTANT): Started mission Default
2023-05-10T22:24:52.975Z,1683757492.975 [Default] Running Loop=1
2023-05-10T22:24:52.975Z,1683757492.975 [Default](DEBUG): Aggregate::initialize Default
2023-05-10T22:24:52.975Z,1683757492.975 [Default:B.GoToSurface] Running Loop=1
2023-05-10T22:24:52.975Z,1683757492.975 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T22:24:52.975Z,1683757492.975 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T22:24:52.975Z,1683757492.975 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T22:24:52.976Z,1683757492.976 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T22:24:52.976Z,1683757492.976 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T22:24:52.976Z,1683757492.976 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T22:24:52.977Z,1683757492.977 [Default:A.Wait] Running Loop=1
2023-05-10T22:24:52.977Z,1683757492.977 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T22:25:01.751Z,1683757501.751 [DataOverHttps](INFO): Sending 1191 bytes from file Logs/20230510T222124/Express0001.lzma
2023-05-10T22:25:02.751Z,1683757502.751 [DataOverHttps](INFO): Moved sent file to Logs/20230510T222124/Express0001.lzma.bak
2023-05-10T22:25:02.751Z,1683757502.751 [DataOverHttps](INFO): SBD MOMSN=18289145
2023-05-10T22:25:06.310Z,1683757506.310 [Default:A.Wait](INFO): Done Waiting.
2023-05-10T22:25:06.310Z,1683757506.310 [Default:A.Wait] Stopped
2023-05-10T22:25:06.310Z,1683757506.310 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T22:25:06.721Z,1683757506.721 [Default:CheckIn] Running Loop=1
2023-05-10T22:25:06.721Z,1683757506.721 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T22:25:06.721Z,1683757506.721 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T22:25:07.114Z,1683757507.114 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-05-10T22:25:18.679Z,1683757518.679 [CommandExec](IMPORTANT): got command set NAL9602.time_fix 1683757502 second
2023-05-10T22:25:18.846Z,1683757518.846 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T22:25:18.846Z,1683757518.846 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T22:25:19.233Z,1683757519.233 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-05-10T22:25:36.177Z,1683757536.177 [DataOverHttps](INFO): Sending 155 bytes from file Logs/20230510T222124/Courier0004.lzma
2023-05-10T22:25:37.179Z,1683757537.179 [DataOverHttps](INFO): Moved sent file to Logs/20230510T222124/Courier0004.lzma.bak
2023-05-10T22:25:37.179Z,1683757537.179 [DataOverHttps](INFO): SBD MOMSN=18289173
2023-05-10T22:25:54.733Z,1683757554.733 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20230510T222124/Express0005.lzma
2023-05-10T22:25:55.735Z,1683757555.735 [DataOverHttps](INFO): Moved sent file to Logs/20230510T222124/Express0005.lzma.bak
2023-05-10T22:25:55.735Z,1683757555.735 [DataOverHttps](INFO): SBD MOMSN=18289178
2023-05-10T22:25:58.866Z,1683757558.866 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T22:25:58.866Z,1683757558.866 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T22:25:58.866Z,1683757558.866 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T22:27:18.002Z,1683757638.002 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T22:27:48.726Z,1683757668.726 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T22:29:34.156Z,1683757774.156 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2023-05-10T22:29:34.159Z,1683757774.159 [BPC1](INFO): Received data from all battery sticks.
2023-05-10T22:30:59.403Z,1683757859.403 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2023-05-10T22:30:59.403Z,1683757859.403 [Default:CheckIn:C.Wait] Stopped
2023-05-10T22:30:59.404Z,1683757859.404 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T22:30:59.404Z,1683757859.404 [Default:CheckIn:D] Running Loop=1
2023-05-10T22:30:59.810Z,1683757859.810 [Default:CheckIn:D] Stopped
2023-05-10T22:30:59.810Z,1683757859.810 [Default:CheckIn:E] Running Loop=1
2023-05-10T22:31:00.222Z,1683757860.222 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.113918 min 
2023-05-10T22:31:00.222Z,1683757860.222 [Default:CheckIn:E] Stopped
2023-05-10T22:31:00.222Z,1683757860.222 [Default:CheckIn](INFO): Completed Default:CheckIn
2023-05-10T22:31:00.222Z,1683757860.222 [Default:CheckIn] Stopped
2023-05-10T22:31:00.222Z,1683757860.222 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T22:31:00.223Z,1683757860.223 [Default:CheckIn](INFO): Running loop #2
2023-05-10T22:31:00.223Z,1683757860.223 [Default:CheckIn] Running Loop=2
2023-05-10T22:31:00.223Z,1683757860.223 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T22:31:00.223Z,1683757860.223 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T22:31:32.930Z,1683757892.930 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2023-05-10T22:31:33.010Z,1683757893.010 [NAL9602](ERROR): received: 
+CSQ:0

OK
2023-05-10T22:36:00.386Z,1683758160.386 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-10T22:31:00.2Z
2023-05-10T22:36:00.386Z,1683758160.386 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T22:36:00.387Z,1683758160.387 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-05-10T22:36:04.011Z,1683758164.011 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-05-10T22:36:07.749Z,1683758167.749 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20230510T222124/Courier0007.lzma
2023-05-10T22:36:08.751Z,1683758168.751 [DataOverHttps](INFO): Moved sent file to Logs/20230510T222124/Courier0007.lzma.bak
2023-05-10T22:36:08.751Z,1683758168.751 [DataOverHttps](INFO): SBD MOMSN=18289212
2023-05-10T22:36:25.893Z,1683758185.893 [DataOverHttps](INFO): Sending 260 bytes from file Logs/20230510T222124/Express0008.lzma
2023-05-10T22:36:26.895Z,1683758186.895 [DataOverHttps](INFO): Moved sent file to Logs/20230510T222124/Express0008.lzma.bak
2023-05-10T22:36:26.896Z,1683758186.896 [DataOverHttps](INFO): SBD MOMSN=18289214
2023-05-10T22:36:29.477Z,1683758189.477 [Default:CheckIn:Read_Iridium] Stopped
2023-05-10T22:36:29.497Z,1683758189.497 [Default:CheckIn:C.Wait] Running Loop=1
2023-05-10T22:36:29.498Z,1683758189.498 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-05-10T22:36:34.714Z,1683758194.714 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T22:39:13.248Z,1683758353.248 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T22:39:13.248Z,1683758353.248 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T22:39:13.304Z,1683758353.304 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 9.000000 count
2023-05-10T22:39:13.308Z,1683758353.308 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m
2023-05-10T22:39:13.311Z,1683758353.311 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s
2023-05-10T22:39:13.314Z,1683758353.314 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count
2023-05-10T22:39:13.316Z,1683758353.316 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count
2023-05-10T22:39:13.343Z,1683758353.343 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count
2023-05-10T22:39:13.346Z,1683758353.346 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min
2023-05-10T22:39:13.349Z,1683758353.349 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum
2023-05-10T22:39:13.356Z,1683758353.356 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum
2023-05-10T22:39:13.385Z,1683758353.385 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum
2023-05-10T22:39:13.522Z,1683758353.522 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait.
2023-05-10T22:39:13.548Z,1683758353.548 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Units="Tethys/Units"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                        Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                        Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd"
    Id="senddata_direct_and_track_test">


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

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

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

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

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

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

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


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



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

</Mission>


2023-05-10T22:39:13.551Z,1683758353.551 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T22:39:13.552Z,1683758353.552 [Default] Stopped
2023-05-10T22:39:13.552Z,1683758353.552 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-10T22:39:13.552Z,1683758353.552 [Default:B.GoToSurface] Stopped
2023-05-10T22:39:13.552Z,1683758353.552 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T22:39:13.553Z,1683758353.553 [Default:CheckIn] Stopped
2023-05-10T22:39:13.553Z,1683758353.553 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T22:39:13.553Z,1683758353.553 [Default:CheckIn:C.Wait] Stopped
2023-05-10T22:39:13.553Z,1683758353.553 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T22:39:13.553Z,1683758353.553 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test
2023-05-10T22:39:13.563Z,1683758353.563 [senddata_direct_and_track_test] Running Loop=1
2023-05-10T22:39:13.563Z,1683758353.563 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test
2023-05-10T22:39:13.563Z,1683758353.563 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T22:39:13.563Z,1683758353.563 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact.
2023-05-10T22:39:13.564Z,1683758353.564 [senddata_direct_and_track_test:DirectData] Running Loop=1
2023-05-10T22:39:13.564Z,1683758353.564 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-10T22:39:13.564Z,1683758353.564 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-10T22:39:13.564Z,1683758353.564 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T22:39:13.564Z,1683758353.564 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T22:39:25.151Z,1683758365.151 [CommandExec](IMPORTANT): got command report touch TrackAcousticContact.contact_latitude
2023-05-10T22:39:25.152Z,1683758365.152 [CommandExec](IMPORTANT): got command report touch TrackAcousticContact.contact_longitude
2023-05-10T22:39:28.861Z,1683758368.861 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T22:39:28.907Z,1683758368.907 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:39:28.907Z,1683758368.907 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:39:28.907Z,1683758368.907 [DAT](INFO): setting remote address to 0
2023-05-10T22:39:29.158Z,1683758369.158 [DAT](INFO): DAT read: user:6>

2023-05-10T22:39:29.159Z,1683758369.159 [DAT](INFO): DAT read: RemoteAddr      | 0           

2023-05-10T22:39:29.159Z,1683758369.159 [DAT](INFO): set remote address to 0
2023-05-10T22:39:29.160Z,1683758369.160 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:39:29.160Z,1683758369.160 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:39:29.160Z,1683758369.160 [DAT](INFO): Querying Benthos address 9 with one ping in standard two-way mode.
2023-05-10T22:39:29.410Z,1683758369.410 [DAT](INFO): DAT read: user:7>

2023-05-10T22:39:29.411Z,1683758369.411 [DAT](INFO): DAT read: Tx time:22:39:35.1958

2023-05-10T22:39:29.411Z,1683758369.411 [DAT](INFO): Ping request sent.
2023-05-10T22:39:29.411Z,1683758369.411 [DAT](INFO): transmitted an acoustic signal
2023-05-10T22:39:29.412Z,1683758369.412 [DAT](INFO): publishing transmit ping time
2023-05-10T22:39:29.412Z,1683758369.412 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000932
2023-05-10T22:39:29.662Z,1683758369.662 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250870
2023-05-10T22:39:29.914Z,1683758369.914 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503116
2023-05-10T22:39:30.166Z,1683758370.166 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754910
2023-05-10T22:39:30.418Z,1683758370.418 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006903
2023-05-10T22:39:30.670Z,1683758370.670 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258846
2023-05-10T22:39:30.922Z,1683758370.922 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510825
2023-05-10T22:39:31.174Z,1683758371.174 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762906
2023-05-10T22:39:31.426Z,1683758371.426 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014890
2023-05-10T22:39:31.678Z,1683758371.678 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266860
2023-05-10T22:39:31.930Z,1683758371.930 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518836
2023-05-10T22:39:32.182Z,1683758372.182 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770861
2023-05-10T22:39:32.434Z,1683758372.434 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022828
2023-05-10T22:39:32.686Z,1683758372.686 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274902
2023-05-10T22:39:32.938Z,1683758372.938 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526898
2023-05-10T22:39:33.190Z,1683758373.190 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778832
2023-05-10T22:39:33.442Z,1683758373.442 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030913
2023-05-10T22:39:33.694Z,1683758373.694 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.283028
2023-05-10T22:39:33.946Z,1683758373.946 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534884
2023-05-10T22:39:34.198Z,1683758374.198 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.786823
2023-05-10T22:39:34.450Z,1683758374.450 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038811
2023-05-10T22:39:34.702Z,1683758374.702 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290895
2023-05-10T22:39:34.967Z,1683758374.967 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.555797
2023-05-10T22:39:35.218Z,1683758375.218 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.806973
2023-05-10T22:39:35.470Z,1683758375.470 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.058805
2023-05-10T22:39:35.722Z,1683758375.722 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.310910
2023-05-10T22:39:35.974Z,1683758375.974 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.562847
2023-05-10T22:39:36.226Z,1683758376.226 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.814908
2023-05-10T22:39:36.478Z,1683758376.478 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.066984
2023-05-10T22:39:36.730Z,1683758376.730 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.319156
2023-05-10T22:39:36.982Z,1683758376.982 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.570836
2023-05-10T22:39:37.234Z,1683758377.234 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.822906
2023-05-10T22:39:37.486Z,1683758377.486 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.074969
2023-05-10T22:39:37.738Z,1683758377.738 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.326868
2023-05-10T22:39:37.990Z,1683758377.990 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.578788
2023-05-10T22:39:38.242Z,1683758378.242 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.831134
2023-05-10T22:39:38.494Z,1683758378.494 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.082811
2023-05-10T22:39:38.746Z,1683758378.746 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.334953
2023-05-10T22:39:38.998Z,1683758378.998 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.586902
2023-05-10T22:39:39.250Z,1683758379.250 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.838775
2023-05-10T22:39:41.283Z,1683758381.283 [CommandExec](IMPORTANT): got command stop
2023-05-10T22:39:41.283Z,1683758381.283 [CommandExec](IMPORTANT): Scheduling is paused
2023-05-10T22:39:41.283Z,1683758381.283 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-05-10T22:39:41.384Z,1683758381.384 [MissionManager](INFO): MissionManager is completed.
2023-05-10T22:39:41.384Z,1683758381.384 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test
2023-05-10T22:39:41.384Z,1683758381.384 [senddata_direct_and_track_test] Stopped
2023-05-10T22:39:41.384Z,1683758381.384 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test
2023-05-10T22:39:41.384Z,1683758381.384 [senddata_direct_and_track_test:TrackAC.] Stopped
2023-05-10T22:39:41.384Z,1683758381.384 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact.
2023-05-10T22:39:41.384Z,1683758381.384 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-10T22:39:41.384Z,1683758381.384 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-10T22:39:41.384Z,1683758381.384 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-10T22:39:41.384Z,1683758381.384 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T22:39:41.770Z,1683758381.770 [DAT](INFO): DAT read: Response Not Received

2023-05-10T22:39:41.770Z,1683758381.770 [DAT](INFO): response not received
2023-05-10T22:39:41.771Z,1683758381.771 [DAT](ERROR): No response from remote modem.
2023-05-10T22:39:41.827Z,1683758381.827 [MissionManager](IMPORTANT): Started mission Default
2023-05-10T22:39:41.827Z,1683758381.827 [Default] Running Loop=1
2023-05-10T22:39:41.827Z,1683758381.827 [Default](DEBUG): Aggregate::initialize Default
2023-05-10T22:39:41.827Z,1683758381.827 [Default:B.GoToSurface] Running Loop=1
2023-05-10T22:39:41.827Z,1683758381.827 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T22:39:41.828Z,1683758381.828 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T22:39:41.828Z,1683758381.828 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T22:39:41.828Z,1683758381.828 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T22:39:41.828Z,1683758381.828 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T22:39:41.829Z,1683758381.829 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T22:39:41.829Z,1683758381.829 [Default:A.Wait] Running Loop=1
2023-05-10T22:39:41.829Z,1683758381.829 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T22:39:55.108Z,1683758395.108 [Default:A.Wait](INFO): Done Waiting.
2023-05-10T22:39:55.109Z,1683758395.109 [Default:A.Wait] Stopped
2023-05-10T22:39:55.109Z,1683758395.109 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T22:39:55.515Z,1683758395.515 [Default:CheckIn] Running Loop=1
2023-05-10T22:39:55.515Z,1683758395.515 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T22:39:55.515Z,1683758395.515 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T22:39:56.558Z,1683758396.558 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T22:39:56.558Z,1683758396.558 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T22:39:56.622Z,1683758396.622 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 9.000000 count
2023-05-10T22:39:56.624Z,1683758396.624 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m
2023-05-10T22:39:56.627Z,1683758396.627 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s
2023-05-10T22:39:56.629Z,1683758396.629 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count
2023-05-10T22:39:56.631Z,1683758396.631 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count
2023-05-10T22:39:56.633Z,1683758396.633 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count
2023-05-10T22:39:56.635Z,1683758396.635 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min
2023-05-10T22:39:56.638Z,1683758396.638 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum
2023-05-10T22:39:56.641Z,1683758396.641 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum
2023-05-10T22:39:56.678Z,1683758396.678 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum
2023-05-10T22:39:56.748Z,1683758396.748 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait.
2023-05-10T22:39:56.781Z,1683758396.781 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Units="Tethys/Units"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                        Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                        Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd"
    Id="senddata_direct_and_track_test">


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

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

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

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

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

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

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


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



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

</Mission>


2023-05-10T22:39:56.790Z,1683758396.790 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T22:39:57.123Z,1683758397.123 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-05-10T22:39:57.123Z,1683758397.123 [NAL9602] Data Fault, FailCount= 1
2023-05-10T22:39:57.123Z,1683758397.123 [NAL9602](ERROR): Data Fault
2023-05-10T22:39:57.134Z,1683758397.134 [Default] Stopped
2023-05-10T22:39:57.134Z,1683758397.134 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-10T22:39:57.134Z,1683758397.134 [Default:B.GoToSurface] Stopped
2023-05-10T22:39:57.134Z,1683758397.134 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T22:39:57.134Z,1683758397.134 [Default:CheckIn] Stopped
2023-05-10T22:39:57.135Z,1683758397.135 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T22:39:57.135Z,1683758397.135 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T22:39:57.135Z,1683758397.135 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test
2023-05-10T22:39:57.135Z,1683758397.135 [senddata_direct_and_track_test] Running Loop=1
2023-05-10T22:39:57.135Z,1683758397.135 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test
2023-05-10T22:39:57.135Z,1683758397.135 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T22:39:57.135Z,1683758397.135 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact.
2023-05-10T22:39:57.136Z,1683758397.136 [senddata_direct_and_track_test:DirectData] Running Loop=1
2023-05-10T22:39:57.136Z,1683758397.136 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-10T22:39:57.136Z,1683758397.136 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-10T22:39:57.136Z,1683758397.136 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T22:39:57.136Z,1683758397.136 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T22:39:57.145Z,1683758397.145 [CBIT](ERROR): Data Fault in component: NAL9602
2023-05-10T22:39:57.522Z,1683758397.522 [NAL9602](INFO): Powering down
2023-05-10T22:39:58.353Z,1683758398.353 [CBIT](INFO): Clearing failed state for component NAL9602
2023-05-10T22:39:58.353Z,1683758398.353 [NAL9602] No Fault, FailCount= 1
2023-05-10T22:40:12.492Z,1683758412.492 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T22:40:12.526Z,1683758412.526 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:40:12.526Z,1683758412.526 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:40:12.526Z,1683758412.526 [DAT](INFO): Querying Benthos address 9 with one ping in standard two-way mode.
2023-05-10T22:40:12.779Z,1683758412.779 [DAT](INFO): DAT read: user:8>

2023-05-10T22:40:12.779Z,1683758412.779 [DAT](INFO): DAT read: Tx time:22:40:18.5456

2023-05-10T22:40:12.780Z,1683758412.780 [DAT](INFO): Ping request sent.
2023-05-10T22:40:12.780Z,1683758412.780 [DAT](INFO): transmitted an acoustic signal
2023-05-10T22:40:12.780Z,1683758412.780 [DAT](INFO): publishing transmit ping time
2023-05-10T22:40:12.781Z,1683758412.781 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000807
2023-05-10T22:40:13.030Z,1683758413.030 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250549
2023-05-10T22:40:13.282Z,1683758413.282 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502357
2023-05-10T22:40:13.534Z,1683758413.534 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754550
2023-05-10T22:40:13.786Z,1683758413.786 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006538
2023-05-10T22:40:14.039Z,1683758414.039 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258952
2023-05-10T22:40:14.290Z,1683758414.290 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510346
2023-05-10T22:40:14.542Z,1683758414.542 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762453
2023-05-10T22:40:14.794Z,1683758414.794 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014511
2023-05-10T22:40:15.046Z,1683758415.046 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266559
2023-05-10T22:40:15.298Z,1683758415.298 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518354
2023-05-10T22:40:15.550Z,1683758415.550 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770446
2023-05-10T22:40:15.802Z,1683758415.802 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022369
2023-05-10T22:40:16.054Z,1683758416.054 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274491
2023-05-10T22:40:16.306Z,1683758416.306 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526524
2023-05-10T22:40:16.558Z,1683758416.558 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778374
2023-05-10T22:40:16.810Z,1683758416.810 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030394
2023-05-10T22:40:17.062Z,1683758417.062 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282613
2023-05-10T22:40:17.314Z,1683758417.314 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534384
2023-05-10T22:40:17.566Z,1683758417.566 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.786504
2023-05-10T22:40:17.818Z,1683758417.818 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038385
2023-05-10T22:40:18.070Z,1683758418.070 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290397
2023-05-10T22:40:18.322Z,1683758418.322 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542473
2023-05-10T22:40:18.574Z,1683758418.574 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794497
2023-05-10T22:40:18.826Z,1683758418.826 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046465
2023-05-10T22:40:19.078Z,1683758419.078 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.298410
2023-05-10T22:40:19.330Z,1683758419.330 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.550651
2023-05-10T22:40:19.582Z,1683758419.582 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.802494
2023-05-10T22:40:19.834Z,1683758419.834 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.054474
2023-05-10T22:40:20.087Z,1683758420.087 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.307405
2023-05-10T22:40:20.338Z,1683758420.338 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.558386
2023-05-10T22:40:20.590Z,1683758420.590 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.810402
2023-05-10T22:40:20.842Z,1683758420.842 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.062464
2023-05-10T22:40:21.094Z,1683758421.094 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.314487
2023-05-10T22:40:21.347Z,1683758421.347 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.567230
2023-05-10T22:40:21.598Z,1683758421.598 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.818466
2023-05-10T22:40:21.850Z,1683758421.850 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.070394
2023-05-10T22:40:22.102Z,1683758422.102 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.322550
2023-05-10T22:40:22.354Z,1683758422.354 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.574492
2023-05-10T22:40:22.606Z,1683758422.606 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.826455
2023-05-10T22:40:25.126Z,1683758425.126 [DAT](INFO): DAT read: Response Not Received

2023-05-10T22:40:25.126Z,1683758425.126 [DAT](INFO): response not received
2023-05-10T22:40:25.127Z,1683758425.127 [DAT](ERROR): No response from remote modem.
2023-05-10T22:40:27.821Z,1683758427.821 [NAL9602](INFO): Powering up NAL9602
2023-05-10T22:40:27.833Z,1683758427.833 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T22:40:27.898Z,1683758427.898 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:40:27.898Z,1683758427.898 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:40:27.898Z,1683758427.898 [DAT](INFO): Querying Benthos address 9 with one ping in standard two-way mode.
2023-05-10T22:40:28.150Z,1683758428.150 [DAT](INFO): DAT read: user:9>

2023-05-10T22:40:28.151Z,1683758428.151 [DAT](INFO): DAT read: Tx time:22:40:33.9455

2023-05-10T22:40:28.151Z,1683758428.151 [DAT](INFO): Ping request sent.
2023-05-10T22:40:28.151Z,1683758428.151 [DAT](INFO): transmitted an acoustic signal
2023-05-10T22:40:28.151Z,1683758428.151 [DAT](INFO): publishing transmit ping time
2023-05-10T22:40:28.152Z,1683758428.152 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000725
2023-05-10T22:40:28.402Z,1683758428.402 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250857
2023-05-10T22:40:28.654Z,1683758428.654 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502830
2023-05-10T22:40:28.906Z,1683758428.906 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754772
2023-05-10T22:40:29.158Z,1683758429.158 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006791
2023-05-10T22:40:29.410Z,1683758429.410 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258775
2023-05-10T22:40:29.662Z,1683758429.662 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510858
2023-05-10T22:40:29.914Z,1683758429.914 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762783
2023-05-10T22:40:30.166Z,1683758430.166 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014776
2023-05-10T22:40:30.418Z,1683758430.418 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266910
2023-05-10T22:40:30.670Z,1683758430.670 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518963
2023-05-10T22:40:30.922Z,1683758430.922 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770841
2023-05-10T22:40:31.174Z,1683758431.174 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022763
2023-05-10T22:40:31.426Z,1683758431.426 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274751
2023-05-10T22:40:31.678Z,1683758431.678 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.526862
2023-05-10T22:40:31.930Z,1683758431.930 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.778795
2023-05-10T22:40:32.182Z,1683758432.182 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.030815
2023-05-10T22:40:32.434Z,1683758432.434 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.282754
2023-05-10T22:40:32.686Z,1683758432.686 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.534828
2023-05-10T22:40:32.938Z,1683758432.938 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.786835
2023-05-10T22:40:33.190Z,1683758433.190 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.038880
2023-05-10T22:40:33.442Z,1683758433.442 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.290846
2023-05-10T22:40:33.694Z,1683758433.694 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.542804
2023-05-10T22:40:33.946Z,1683758433.946 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.794758
2023-05-10T22:40:34.198Z,1683758434.198 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.046869
2023-05-10T22:40:34.452Z,1683758434.452 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.300414
2023-05-10T22:40:34.702Z,1683758434.702 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.551005
2023-05-10T22:40:34.954Z,1683758434.954 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.802755
2023-05-10T22:40:35.206Z,1683758435.206 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.054841
2023-05-10T22:40:35.458Z,1683758435.458 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.306745
2023-05-10T22:40:35.710Z,1683758435.710 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.558864
2023-05-10T22:40:35.962Z,1683758435.962 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.810781
2023-05-10T22:40:36.214Z,1683758436.214 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.063102
2023-05-10T22:40:36.466Z,1683758436.466 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.314854
2023-05-10T22:40:36.718Z,1683758436.718 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.566969
2023-05-10T22:40:36.970Z,1683758436.970 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.818850
2023-05-10T22:40:37.222Z,1683758437.222 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.070781
2023-05-10T22:40:37.474Z,1683758437.474 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.322753
2023-05-10T22:40:37.726Z,1683758437.726 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.574874
2023-05-10T22:40:37.978Z,1683758437.978 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.826847
2023-05-10T22:40:38.731Z,1683758438.731 [NAL9602](INFO): NAL9602 initialized
2023-05-10T22:40:40.502Z,1683758440.502 [DAT](INFO): DAT read: Response Not Received

2023-05-10T22:40:40.503Z,1683758440.503 [DAT](INFO): response not received
2023-05-10T22:40:40.503Z,1683758440.503 [DAT](ERROR): No response from remote modem.
2023-05-10T22:40:43.198Z,1683758443.198 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T22:40:43.278Z,1683758443.278 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:40:43.278Z,1683758443.278 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:40:43.278Z,1683758443.278 [DAT](INFO): Querying Benthos address 9 with one ping in standard two-way mode.
2023-05-10T22:40:43.530Z,1683758443.530 [DAT](INFO): DAT read: user:10>

2023-05-10T22:40:43.531Z,1683758443.531 [DAT](INFO): DAT read: Tx time:22:40:49.2953

2023-05-10T22:40:43.531Z,1683758443.531 [DAT](INFO): Ping request sent.
2023-05-10T22:40:43.531Z,1683758443.531 [DAT](INFO): transmitted an acoustic signal
2023-05-10T22:40:43.531Z,1683758443.531 [DAT](INFO): publishing transmit ping time
2023-05-10T22:40:43.532Z,1683758443.532 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000710
2023-05-10T22:40:43.782Z,1683758443.782 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250960
2023-05-10T22:40:44.034Z,1683758444.034 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503000
2023-05-10T22:40:44.289Z,1683758444.289 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.757745
2023-05-10T22:40:44.542Z,1683758444.542 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.010892
2023-05-10T22:40:44.794Z,1683758444.794 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.262933
2023-05-10T22:40:45.046Z,1683758445.046 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.514953
2023-05-10T22:40:45.298Z,1683758445.298 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.766958
2023-05-10T22:40:45.551Z,1683758445.551 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.019262
2023-05-10T22:40:45.802Z,1683758445.802 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.270878
2023-05-10T22:40:46.054Z,1683758446.054 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.523065
2023-05-10T22:40:46.309Z,1683758446.309 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.777305
2023-05-10T22:40:46.562Z,1683758446.562 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.030963
2023-05-10T22:40:46.814Z,1683758446.814 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.282935
2023-05-10T22:40:47.066Z,1683758447.066 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.534875
2023-05-10T22:40:47.318Z,1683758447.318 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.786872
2023-05-10T22:40:47.570Z,1683758447.570 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.039175
2023-05-10T22:40:47.822Z,1683758447.822 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.290961
2023-05-10T22:40:48.074Z,1683758448.074 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.542982
2023-05-10T22:40:48.329Z,1683758448.329 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.797600
2023-05-10T22:40:48.582Z,1683758448.582 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.051039
2023-05-10T22:40:48.834Z,1683758448.834 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.302820
2023-05-10T22:40:49.086Z,1683758449.086 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.555023
2023-05-10T22:40:49.338Z,1683758449.338 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.806918
2023-05-10T22:40:49.591Z,1683758449.591 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.059761
2023-05-10T22:40:49.842Z,1683758449.842 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.311043
2023-05-10T22:40:50.094Z,1683758450.094 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.563020
2023-05-10T22:40:50.346Z,1683758450.346 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.814971
2023-05-10T22:40:50.598Z,1683758450.598 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.066930
2023-05-10T22:40:50.850Z,1683758450.850 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.318832
2023-05-10T22:40:51.102Z,1683758451.102 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.570991
2023-05-10T22:40:51.354Z,1683758451.354 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.822995
2023-05-10T22:40:51.606Z,1683758451.606 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.075008
2023-05-10T22:40:51.858Z,1683758451.858 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.326855
2023-05-10T22:40:52.110Z,1683758452.110 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.578856
2023-05-10T22:40:52.370Z,1683758452.370 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.838326
2023-05-10T22:40:52.614Z,1683758452.614 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.082949
2023-05-10T22:40:52.866Z,1683758452.866 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.334940
2023-05-10T22:40:53.118Z,1683758453.118 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.586858
2023-05-10T22:40:53.370Z,1683758453.370 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.838990
2023-05-10T22:40:55.890Z,1683758455.890 [DAT](INFO): DAT read: Response Not Received

2023-05-10T22:40:55.891Z,1683758455.891 [DAT](INFO): response not received
2023-05-10T22:40:55.891Z,1683758455.891 [DAT](ERROR): No response from remote modem.
2023-05-10T22:40:57.329Z,1683758457.329 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting.
2023-05-10T22:40:57.329Z,1683758457.329 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-10T22:40:57.329Z,1683758457.329 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T22:40:57.330Z,1683758457.330 [senddata_direct_and_track_test:DirectData:B] Running Loop=1
2023-05-10T22:40:57.741Z,1683758457.741 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:9:_.pressure
2023-05-10T22:40:57.741Z,1683758457.741 [senddata_direct_and_track_test:DirectData:B] Stopped
2023-05-10T22:40:57.741Z,1683758457.741 [senddata_direct_and_track_test:DirectData:C] Running Loop=1
2023-05-10T22:40:57.907Z,1683758457.907 [DAT](INFO): modem://9: set _.pressure 0.742417 atmosphere
2023-05-10T22:40:57.907Z,1683758457.907 [DAT](INFO): #Outgoing data=1
2023-05-10T22:40:57.907Z,1683758457.907 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:40:58.132Z,1683758458.132 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:9:_.temperature
2023-05-10T22:40:58.132Z,1683758458.132 [senddata_direct_and_track_test:DirectData:C] Stopped
2023-05-10T22:40:58.132Z,1683758458.132 [senddata_direct_and_track_test:DirectData:D] Running Loop=1
2023-05-10T22:40:58.158Z,1683758458.158 [DAT](INFO): setting remote address to 9
2023-05-10T22:40:58.410Z,1683758458.410 [DAT](INFO): DAT read: user:11>

2023-05-10T22:40:58.411Z,1683758458.411 [DAT](INFO): DAT read: RemoteAddr      | 9           

2023-05-10T22:40:58.411Z,1683758458.411 [DAT](INFO): set remote address to 9
2023-05-10T22:40:58.412Z,1683758458.412 [DAT](INFO): entering online mode
2023-05-10T22:40:58.538Z,1683758458.538 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:9:_.humidity
2023-05-10T22:40:58.538Z,1683758458.538 [senddata_direct_and_track_test:DirectData:D] Stopped
2023-05-10T22:40:58.538Z,1683758458.538 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData
2023-05-10T22:40:58.538Z,1683758458.538 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-10T22:40:58.538Z,1683758458.538 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-10T22:40:58.538Z,1683758458.538 [senddata_direct_and_track_test:DirectData](INFO): Running loop #2
2023-05-10T22:40:58.539Z,1683758458.539 [senddata_direct_and_track_test:DirectData] Running Loop=2
2023-05-10T22:40:58.539Z,1683758458.539 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-10T22:40:58.539Z,1683758458.539 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-10T22:40:58.539Z,1683758458.539 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T22:40:58.539Z,1683758458.539 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T22:40:58.663Z,1683758458.663 [DAT](INFO): DAT read: user:12>

2023-05-10T22:40:58.663Z,1683758458.663 [DAT](INFO): DAT read: 

2023-05-10T22:40:58.665Z,1683758458.665 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T22:40:58.665Z,1683758458.665 [DAT](INFO): commRate: 800
2023-05-10T22:40:58.665Z,1683758458.665 [DAT](INFO): online mode acknowledged
2023-05-10T22:40:58.666Z,1683758458.666 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:40:58.667Z,1683758458.667 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:40:58.667Z,1683758458.667 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:40:58.914Z,1683758458.914 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:40:58.914Z,1683758458.914 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:40:59.166Z,1683758459.166 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:40:59.166Z,1683758459.166 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:40:59.418Z,1683758459.418 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:40:59.418Z,1683758459.418 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:40:59.670Z,1683758459.670 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:40:59.670Z,1683758459.670 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:40:59.922Z,1683758459.922 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:40:59.923Z,1683758459.923 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:00.174Z,1683758460.174 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:00.174Z,1683758460.174 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:00.426Z,1683758460.426 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:00.426Z,1683758460.426 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:00.678Z,1683758460.678 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:00.678Z,1683758460.678 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:00.742Z,1683758460.742 [DAT](INFO): entering command mode
2023-05-10T22:41:00.930Z,1683758460.930 [DAT](INFO): DAT read: 

2023-05-10T22:41:00.930Z,1683758460.930 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:00.930Z,1683758460.930 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:00.931Z,1683758460.931 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:01.182Z,1683758461.182 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:01.182Z,1683758461.182 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:01.182Z,1683758461.182 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:01.434Z,1683758461.434 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:01.434Z,1683758461.434 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:01.434Z,1683758461.434 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:01.686Z,1683758461.686 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:01.686Z,1683758461.686 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:01.686Z,1683758461.686 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:01.941Z,1683758461.941 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:01.941Z,1683758461.941 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:01.941Z,1683758461.941 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:02.190Z,1683758462.190 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:02.190Z,1683758462.190 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:02.190Z,1683758462.190 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:02.442Z,1683758462.442 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:02.442Z,1683758462.442 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:02.442Z,1683758462.442 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:02.694Z,1683758462.694 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:02.694Z,1683758462.694 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:02.694Z,1683758462.694 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:02.946Z,1683758462.946 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:02.946Z,1683758462.946 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:02.946Z,1683758462.946 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:03.198Z,1683758463.198 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:03.198Z,1683758463.198 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:03.198Z,1683758463.198 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:03.450Z,1683758463.450 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:03.450Z,1683758463.450 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:03.450Z,1683758463.450 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:03.702Z,1683758463.702 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:03.702Z,1683758463.702 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:03.702Z,1683758463.702 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:03.954Z,1683758463.954 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:03.954Z,1683758463.954 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:03.954Z,1683758463.954 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:04.206Z,1683758464.206 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:04.206Z,1683758464.206 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:04.206Z,1683758464.206 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:04.458Z,1683758464.458 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:04.458Z,1683758464.458 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:04.458Z,1683758464.458 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:04.710Z,1683758464.710 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:04.710Z,1683758464.710 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:04.710Z,1683758464.710 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:04.962Z,1683758464.962 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:04.962Z,1683758464.962 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:04.962Z,1683758464.962 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:05.214Z,1683758465.214 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:05.214Z,1683758465.214 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:05.214Z,1683758465.214 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:05.466Z,1683758465.466 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:05.466Z,1683758465.466 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:05.466Z,1683758465.466 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:05.718Z,1683758465.718 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:05.718Z,1683758465.718 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:05.718Z,1683758465.718 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:05.970Z,1683758465.970 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:05.970Z,1683758465.970 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:05.970Z,1683758465.970 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:06.222Z,1683758466.222 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:06.222Z,1683758466.222 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:06.222Z,1683758466.222 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:06.474Z,1683758466.474 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:06.474Z,1683758466.474 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:06.474Z,1683758466.474 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:06.726Z,1683758466.726 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:06.726Z,1683758466.726 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:06.726Z,1683758466.726 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:06.978Z,1683758466.978 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:06.978Z,1683758466.978 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:06.978Z,1683758466.978 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:07.230Z,1683758467.230 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:07.230Z,1683758467.230 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:07.230Z,1683758467.230 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:07.482Z,1683758467.482 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:07.482Z,1683758467.482 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:07.482Z,1683758467.482 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:07.734Z,1683758467.734 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:07.734Z,1683758467.734 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:07.734Z,1683758467.734 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:07.986Z,1683758467.986 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:07.986Z,1683758467.986 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:07.986Z,1683758467.986 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:08.238Z,1683758468.238 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:08.238Z,1683758468.238 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:08.238Z,1683758468.238 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:08.490Z,1683758468.490 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:08.490Z,1683758468.490 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:08.490Z,1683758468.490 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:08.742Z,1683758468.742 [DAT](FAULT): Buffer send receipt timeout failure.
2023-05-10T22:41:08.742Z,1683758468.742 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:41:08.742Z,1683758468.742 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:08.742Z,1683758468.742 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:08.742Z,1683758468.742 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:08.995Z,1683758468.995 [DAT](INFO): modem://9: set _.temperature 24.662439 celsius
2023-05-10T22:41:08.995Z,1683758468.995 [DAT](INFO): #Outgoing data=1
2023-05-10T22:41:08.995Z,1683758468.995 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:41:08.995Z,1683758468.995 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:08.995Z,1683758468.995 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:08.995Z,1683758468.995 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:41:09.246Z,1683758469.246 [DAT](INFO): entering online mode
2023-05-10T22:41:09.498Z,1683758469.498 [DAT](INFO): DAT read: user:13>

2023-05-10T22:41:09.499Z,1683758469.499 [DAT](INFO): DAT read: 

2023-05-10T22:41:09.500Z,1683758469.500 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T22:41:09.500Z,1683758469.500 [DAT](INFO): commRate: 800
2023-05-10T22:41:09.500Z,1683758469.500 [DAT](INFO): online mode acknowledged
2023-05-10T22:41:09.501Z,1683758469.501 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:41:09.501Z,1683758469.501 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:09.501Z,1683758469.501 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:09.750Z,1683758469.750 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:09.750Z,1683758469.750 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:09.838Z,1683758469.838 [NAL9602](INFO): Not Powering down - fast GPS
2023-05-10T22:41:10.002Z,1683758470.002 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:10.002Z,1683758470.002 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:10.254Z,1683758470.254 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:10.254Z,1683758470.254 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:10.506Z,1683758470.506 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:10.506Z,1683758470.506 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:10.758Z,1683758470.758 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:10.758Z,1683758470.758 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:11.010Z,1683758471.010 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:11.010Z,1683758471.010 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:11.262Z,1683758471.262 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:11.262Z,1683758471.262 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:11.514Z,1683758471.514 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:11.514Z,1683758471.514 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:11.578Z,1683758471.578 [DAT](INFO): entering command mode
2023-05-10T22:41:11.766Z,1683758471.766 [DAT](INFO): DAT read: 

2023-05-10T22:41:11.766Z,1683758471.766 [DAT](INFO): DAT read: user:14>

2023-05-10T22:41:11.767Z,1683758471.767 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:11.767Z,1683758471.767 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:11.767Z,1683758471.767 [DAT](INFO): setting remote address to 0
2023-05-10T22:41:12.018Z,1683758472.018 [DAT](INFO): DAT read: user:14>

2023-05-10T22:41:12.019Z,1683758472.019 [DAT](INFO): DAT read: RemoteAddr      | 0           

2023-05-10T22:41:12.019Z,1683758472.019 [DAT](INFO): set remote address to 0
2023-05-10T22:41:12.020Z,1683758472.020 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:12.020Z,1683758472.020 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:12.020Z,1683758472.020 [DAT](INFO): Querying Benthos address 9 with one ping in standard two-way mode.
2023-05-10T22:41:12.270Z,1683758472.270 [DAT](INFO): DAT read: user:15>

2023-05-10T22:41:12.271Z,1683758472.271 [DAT](INFO): DAT read: Tx time:22:41:18.0451

2023-05-10T22:41:12.271Z,1683758472.271 [DAT](INFO): Ping request sent.
2023-05-10T22:41:12.271Z,1683758472.271 [DAT](INFO): transmitted an acoustic signal
2023-05-10T22:41:12.272Z,1683758472.272 [DAT](INFO): publishing transmit ping time
2023-05-10T22:41:12.272Z,1683758472.272 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000906
2023-05-10T22:41:12.522Z,1683758472.522 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250817
2023-05-10T22:41:12.774Z,1683758472.774 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502635
2023-05-10T22:41:13.026Z,1683758473.026 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754729
2023-05-10T22:41:13.278Z,1683758473.278 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006718
2023-05-10T22:41:13.530Z,1683758473.530 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258730
2023-05-10T22:41:13.782Z,1683758473.782 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510682
2023-05-10T22:41:13.910Z,1683758473.910 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T22:41:14.034Z,1683758474.034 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762628
2023-05-10T22:41:14.290Z,1683758474.290 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.017494
2023-05-10T22:41:14.538Z,1683758474.538 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266709
2023-05-10T22:41:14.790Z,1683758474.790 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518651
2023-05-10T22:41:15.042Z,1683758475.042 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770625
2023-05-10T22:41:15.294Z,1683758475.294 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022714
2023-05-10T22:41:15.546Z,1683758475.546 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274719
2023-05-10T22:41:15.801Z,1683758475.801 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.529363
2023-05-10T22:41:16.054Z,1683758476.054 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.782807
2023-05-10T22:41:16.306Z,1683758476.306 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.034714
2023-05-10T22:41:16.558Z,1683758476.558 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.286714
2023-05-10T22:41:16.811Z,1683758476.811 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.539278
2023-05-10T22:41:17.062Z,1683758477.062 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=4.790875
2023-05-10T22:41:17.314Z,1683758477.314 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.042637
2023-05-10T22:41:17.566Z,1683758477.566 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.294638
2023-05-10T22:41:17.821Z,1683758477.821 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.549660
2023-05-10T22:41:18.074Z,1683758478.074 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=5.802742
2023-05-10T22:41:18.327Z,1683758478.327 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.055061
2023-05-10T22:41:18.578Z,1683758478.578 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.306623
2023-05-10T22:41:18.830Z,1683758478.830 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.558632
2023-05-10T22:41:19.082Z,1683758479.082 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=6.810663
2023-05-10T22:41:19.334Z,1683758479.334 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.062702
2023-05-10T22:41:19.586Z,1683758479.586 [DAT](FAULT): Buffer send receipt timeout failure.
2023-05-10T22:41:19.586Z,1683758479.586 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:41:19.587Z,1683758479.587 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.315049
2023-05-10T22:41:19.839Z,1683758479.839 [DAT](INFO): modem://9: set _.humidity 12.879990 percent
2023-05-10T22:41:19.839Z,1683758479.839 [DAT](INFO): #Outgoing data=2
2023-05-10T22:41:19.839Z,1683758479.839 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:41:19.839Z,1683758479.839 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.567987
2023-05-10T22:41:20.090Z,1683758480.090 [DAT](INFO): setting remote address to 9
2023-05-10T22:41:20.091Z,1683758480.091 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=7.819044
2023-05-10T22:41:20.342Z,1683758480.342 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:20.342Z,1683758480.342 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.070803
2023-05-10T22:41:20.594Z,1683758480.594 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:20.595Z,1683758480.595 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.323162
2023-05-10T22:41:20.866Z,1683758480.866 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:20.866Z,1683758480.866 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.594839
2023-05-10T22:41:21.118Z,1683758481.118 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:21.118Z,1683758481.118 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=8.846917
2023-05-10T22:41:21.370Z,1683758481.370 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:21.370Z,1683758481.370 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.098989
2023-05-10T22:41:21.622Z,1683758481.622 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:21.622Z,1683758481.622 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.350915
2023-05-10T22:41:21.875Z,1683758481.875 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:21.875Z,1683758481.875 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.603489
2023-05-10T22:41:22.126Z,1683758482.126 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:22.126Z,1683758482.126 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=9.854966
2023-05-10T22:41:22.242Z,1683758482.242 [CommandExec](IMPORTANT): got command stop
2023-05-10T22:41:22.242Z,1683758482.242 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-05-10T22:41:22.378Z,1683758482.378 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:22.378Z,1683758482.378 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:41:22.378Z,1683758482.378 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:41:22.378Z,1683758482.378 [DAT](INFO): setting remote address to 0
2023-05-10T22:41:22.382Z,1683758482.382 [MissionManager](INFO): MissionManager is completed.
2023-05-10T22:41:22.382Z,1683758482.382 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test
2023-05-10T22:41:22.383Z,1683758482.383 [senddata_direct_and_track_test] Stopped
2023-05-10T22:41:22.383Z,1683758482.383 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test
2023-05-10T22:41:22.383Z,1683758482.383 [senddata_direct_and_track_test:TrackAC.] Stopped
2023-05-10T22:41:22.383Z,1683758482.383 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact.
2023-05-10T22:41:22.383Z,1683758482.383 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-10T22:41:22.383Z,1683758482.383 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-10T22:41:22.383Z,1683758482.383 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-10T22:41:22.383Z,1683758482.383 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T22:41:22.630Z,1683758482.630 [DAT](INFO): setting remote address to 9
2023-05-10T22:41:22.796Z,1683758482.796 [MissionManager](IMPORTANT): Started mission Default
2023-05-10T22:41:22.796Z,1683758482.796 [Default] Running Loop=1
2023-05-10T22:41:22.796Z,1683758482.796 [Default](DEBUG): Aggregate::initialize Default
2023-05-10T22:41:22.796Z,1683758482.796 [Default:B.GoToSurface] Running Loop=1
2023-05-10T22:41:22.796Z,1683758482.796 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T22:41:22.797Z,1683758482.797 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T22:41:22.797Z,1683758482.797 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T22:41:22.797Z,1683758482.797 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T22:41:22.798Z,1683758482.798 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T22:41:22.798Z,1683758482.798 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T22:41:22.798Z,1683758482.798 [Default:A.Wait] Running Loop=1
2023-05-10T22:41:22.798Z,1683758482.798 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T22:41:22.882Z,1683758482.882 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:23.134Z,1683758483.134 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:23.386Z,1683758483.386 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:23.638Z,1683758483.638 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:23.898Z,1683758483.898 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:24.150Z,1683758484.150 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:24.402Z,1683758484.402 [DAT](DEBUG): checking for remote address setting acknowledgment
2023-05-10T22:41:24.655Z,1683758484.655 [DAT](INFO): DAT read: Response Not Received

2023-05-10T22:41:24.655Z,1683758484.655 [DAT](INFO): response not received
2023-05-10T22:41:24.655Z,1683758484.655 [DAT](INFO): DAT read: user:16>

2023-05-10T22:41:24.656Z,1683758484.656 [DAT](INFO): DAT read: RemoteAddr      | 9           

2023-05-10T22:41:24.657Z,1683758484.657 [DAT](INFO): set remote address to 9
2023-05-10T22:41:24.657Z,1683758484.657 [DAT](INFO): DAT read: user:17>

2023-05-10T22:41:24.658Z,1683758484.658 [DAT](INFO): DAT read: RemoteAddr      | 0           

2023-05-10T22:41:24.659Z,1683758484.659 [DAT](INFO): DAT read: user:18>

2023-05-10T22:41:24.660Z,1683758484.660 [DAT](INFO): DAT read: RemoteAddr      | 9           

2023-05-10T22:41:24.660Z,1683758484.660 [DAT](INFO): entering online mode
2023-05-10T22:41:24.906Z,1683758484.906 [DAT](INFO): DAT read: user:19>

2023-05-10T22:41:24.907Z,1683758484.907 [DAT](INFO): DAT read: 

2023-05-10T22:41:24.908Z,1683758484.908 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T22:41:24.908Z,1683758484.908 [DAT](INFO): commRate: 800
2023-05-10T22:41:24.908Z,1683758484.908 [DAT](INFO): online mode acknowledged
2023-05-10T22:41:24.909Z,1683758484.909 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:41:28.195Z,1683758488.195 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:41:34.0438

2023-05-10T22:41:28.195Z,1683758488.195 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2023-05-10T22:41:35.835Z,1683758495.835 [Default:A.Wait](INFO): Done Waiting.
2023-05-10T22:41:35.835Z,1683758495.835 [Default:A.Wait] Stopped
2023-05-10T22:41:35.835Z,1683758495.835 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T22:41:36.188Z,1683758496.188 [Default:CheckIn] Running Loop=1
2023-05-10T22:41:36.188Z,1683758496.188 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-05-10T22:41:36.188Z,1683758496.188 [Default:CheckIn:Read_GPS] Running Loop=1
2023-05-10T22:41:38.278Z,1683758498.278 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:41:38.530Z,1683758498.530 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:41:38.782Z,1683758498.782 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:41:48.862Z,1683758508.862 [DAT](FAULT): Buffer send receipt timeout failure.
2023-05-10T22:41:48.862Z,1683758508.862 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:41:49.114Z,1683758509.114 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:41:49.366Z,1683758509.366 [DAT](INFO): entering online mode
2023-05-10T22:41:49.618Z,1683758509.618 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:49.870Z,1683758509.870 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:50.122Z,1683758510.122 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:50.374Z,1683758510.374 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:50.626Z,1683758510.626 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:50.878Z,1683758510.878 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:51.382Z,1683758511.382 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:51.634Z,1683758511.634 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:51.886Z,1683758511.886 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:52.140Z,1683758512.140 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:52.390Z,1683758512.390 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:52.642Z,1683758512.642 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:52.894Z,1683758512.894 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:53.147Z,1683758513.147 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:53.398Z,1683758513.398 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:53.650Z,1683758513.650 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:53.902Z,1683758513.902 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:54.154Z,1683758514.154 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:54.415Z,1683758514.415 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:54.666Z,1683758514.666 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:54.918Z,1683758514.918 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:55.170Z,1683758515.170 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:55.422Z,1683758515.422 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:55.674Z,1683758515.674 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:55.926Z,1683758515.926 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:56.178Z,1683758516.178 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:56.430Z,1683758516.430 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:56.682Z,1683758516.682 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:56.934Z,1683758516.934 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:57.438Z,1683758517.438 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:57.690Z,1683758517.690 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:57.942Z,1683758517.942 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:58.194Z,1683758518.194 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:58.446Z,1683758518.446 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:58.698Z,1683758518.698 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:58.950Z,1683758518.950 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:59.202Z,1683758519.202 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:59.454Z,1683758519.454 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:59.710Z,1683758519.710 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:41:59.958Z,1683758519.958 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:00.210Z,1683758520.210 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:00.462Z,1683758520.462 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:00.714Z,1683758520.714 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:00.966Z,1683758520.966 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:01.470Z,1683758521.470 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:01.722Z,1683758521.722 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:01.974Z,1683758521.974 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:02.226Z,1683758522.226 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:02.478Z,1683758522.478 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:02.730Z,1683758522.730 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:02.982Z,1683758522.982 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:03.234Z,1683758523.234 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:03.486Z,1683758523.486 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:03.738Z,1683758523.738 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:03.990Z,1683758523.990 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:04.242Z,1683758524.242 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:04.494Z,1683758524.494 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:42:04.494Z,1683758524.494 [DAT](FAULT): failed to enter online mode
2023-05-10T22:42:04.494Z,1683758524.494 [DAT](FAULT): Failure returning to online mode
2023-05-10T22:42:04.494Z,1683758524.494 [DAT] Communications Fault, FailCount= 1
2023-05-10T22:42:04.494Z,1683758524.494 [DAT](ERROR): Communications Fault
2023-05-10T22:42:04.880Z,1683758524.880 [CBIT](ERROR): Communications Fault in component: DAT
2023-05-10T22:42:04.898Z,1683758524.898 [DAT](INFO): Powering down
2023-05-10T22:42:06.124Z,1683758526.124 [CBIT](INFO): Clearing failed state for component DAT
2023-05-10T22:42:06.124Z,1683758526.124 [DAT] No Fault, FailCount= 1
2023-05-10T22:42:08.030Z,1683758528.030 [DAT](INFO): Powering up
2023-05-10T22:42:08.030Z,1683758528.030 [DAT](DEBUG): Initializing DAT.
2023-05-10T22:42:20.146Z,1683758540.146 [DAT](INFO): DAT read: 

2023-05-10T22:42:20.147Z,1683758540.147 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-05-10T22:42:21.914Z,1683758541.914 [DAT](INFO): DAT read: MF Frequency Band

2023-05-10T22:42:21.915Z,1683758541.915 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-05-10T22:42:21.916Z,1683758541.916 [DAT](INFO): DAT read: May 10 2023 22:42:22 

2023-05-10T22:42:23.174Z,1683758543.174 [DAT](INFO): DAT read: Features enabled [Bearing]

2023-05-10T22:42:23.176Z,1683758543.176 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T22:42:23.176Z,1683758543.176 [DAT](INFO): commRate: 800
2023-05-10T22:42:25.253Z,1683758545.253 [DAT](INFO): entering command mode
2023-05-10T22:42:25.253Z,1683758545.253 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:25.450Z,1683758545.450 [DAT](INFO): DAT read: 

2023-05-10T22:42:25.450Z,1683758545.450 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:25.450Z,1683758545.450 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:25.702Z,1683758545.702 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:25.702Z,1683758545.702 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:25.954Z,1683758545.954 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:25.954Z,1683758545.954 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:26.206Z,1683758546.206 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:26.206Z,1683758546.206 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:26.458Z,1683758546.458 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:26.458Z,1683758546.458 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:26.710Z,1683758546.710 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:26.710Z,1683758546.710 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:26.962Z,1683758546.962 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:26.962Z,1683758546.962 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:27.214Z,1683758547.214 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:27.214Z,1683758547.214 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:27.466Z,1683758547.466 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:27.466Z,1683758547.466 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:27.718Z,1683758547.718 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:27.718Z,1683758547.718 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:27.970Z,1683758547.970 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:27.970Z,1683758547.970 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:28.222Z,1683758548.222 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:28.222Z,1683758548.222 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:28.474Z,1683758548.474 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:28.474Z,1683758548.474 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:28.726Z,1683758548.726 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:28.726Z,1683758548.726 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:28.978Z,1683758548.978 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:28.978Z,1683758548.978 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:29.230Z,1683758549.230 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:29.230Z,1683758549.230 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:29.484Z,1683758549.484 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:29.484Z,1683758549.484 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:29.734Z,1683758549.734 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:29.734Z,1683758549.734 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:29.987Z,1683758549.987 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:29.987Z,1683758549.987 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:30.238Z,1683758550.238 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:30.238Z,1683758550.238 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:30.490Z,1683758550.490 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:30.490Z,1683758550.490 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:30.742Z,1683758550.742 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:30.742Z,1683758550.742 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:30.994Z,1683758550.994 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:30.994Z,1683758550.994 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:31.246Z,1683758551.246 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:31.246Z,1683758551.246 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:31.510Z,1683758551.510 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:31.510Z,1683758551.510 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:31.750Z,1683758551.750 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:31.750Z,1683758551.750 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:32.002Z,1683758552.002 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:32.002Z,1683758552.002 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:32.254Z,1683758552.254 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:32.254Z,1683758552.254 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:32.506Z,1683758552.506 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:32.506Z,1683758552.506 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:32.758Z,1683758552.758 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:32.758Z,1683758552.758 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:33.010Z,1683758553.010 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:33.010Z,1683758553.010 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:33.262Z,1683758553.262 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:33.262Z,1683758553.262 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:33.514Z,1683758553.514 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:33.514Z,1683758553.514 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:33.766Z,1683758553.766 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:33.766Z,1683758553.766 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:34.018Z,1683758554.018 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:34.018Z,1683758554.018 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:34.270Z,1683758554.270 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:34.270Z,1683758554.270 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:34.522Z,1683758554.522 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:34.522Z,1683758554.522 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:34.774Z,1683758554.774 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:34.774Z,1683758554.774 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:35.026Z,1683758555.026 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:35.026Z,1683758555.026 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:35.278Z,1683758555.278 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:35.278Z,1683758555.278 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:35.530Z,1683758555.530 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:35.530Z,1683758555.530 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:35.782Z,1683758555.782 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:35.782Z,1683758555.782 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:36.034Z,1683758556.034 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:36.034Z,1683758556.034 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:36.286Z,1683758556.286 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:36.286Z,1683758556.286 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:36.538Z,1683758556.538 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:36.538Z,1683758556.538 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:36.790Z,1683758556.790 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:36.790Z,1683758556.790 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:37.042Z,1683758557.042 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:37.042Z,1683758557.042 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:37.294Z,1683758557.294 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:37.294Z,1683758557.294 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:37.546Z,1683758557.546 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:37.546Z,1683758557.546 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:37.798Z,1683758557.798 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:37.798Z,1683758557.798 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:38.050Z,1683758558.050 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:38.050Z,1683758558.050 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:38.302Z,1683758558.302 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:38.302Z,1683758558.302 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:38.554Z,1683758558.554 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:38.554Z,1683758558.554 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:38.806Z,1683758558.806 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:38.806Z,1683758558.806 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:39.058Z,1683758559.058 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:39.058Z,1683758559.058 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:39.310Z,1683758559.310 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:39.310Z,1683758559.310 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:39.562Z,1683758559.562 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:39.562Z,1683758559.562 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:39.814Z,1683758559.814 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:39.814Z,1683758559.814 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:40.071Z,1683758560.071 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:40.071Z,1683758560.071 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:40.322Z,1683758560.322 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:40.322Z,1683758560.322 [DAT](FAULT): failed to enter command mode
2023-05-10T22:42:40.638Z,1683758560.638 [DAT](INFO): entering command mode
2023-05-10T22:42:40.638Z,1683758560.638 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:42:40.826Z,1683758560.826 [DAT](INFO): DAT read: 

2023-05-10T22:42:40.827Z,1683758560.827 [DAT](INFO): DAT read: Command '+++' not found

2023-05-10T22:42:40.827Z,1683758560.827 [DAT](INFO): DAT read: Error

2023-05-10T22:42:40.827Z,1683758560.827 [DAT](INFO): setting verbose to 3
2023-05-10T22:42:41.078Z,1683758561.078 [DAT](INFO): DAT read: user:2>

2023-05-10T22:42:41.079Z,1683758561.079 [DAT](INFO): DAT read: Verbose         | 3           

2023-05-10T22:42:41.079Z,1683758561.079 [DAT](INFO): set verbose to 3
2023-05-10T22:42:41.080Z,1683758561.080 [DAT](INFO): setting DatVerbose to 27440
2023-05-10T22:42:41.330Z,1683758561.330 [DAT](INFO): DAT read: user:3>

2023-05-10T22:42:41.331Z,1683758561.331 [DAT](INFO): DAT read: DatVerbose      | 27440       

2023-05-10T22:42:41.331Z,1683758561.331 [DAT](INFO): set DatVerbose to 27440
2023-05-10T22:42:41.332Z,1683758561.332 [DAT](INFO): setting transmit power to 8
2023-05-10T22:42:41.582Z,1683758561.582 [DAT](INFO): DAT read: user:4>

2023-05-10T22:42:41.583Z,1683758561.583 [DAT](INFO): DAT read: TxPower         | 8 (Max)     

2023-05-10T22:42:41.583Z,1683758561.583 [DAT](INFO): set transmit power to 8
2023-05-10T22:42:41.583Z,1683758561.583 [DAT](INFO): setting local address to 12
2023-05-10T22:42:41.834Z,1683758561.834 [DAT](INFO): DAT read: user:5>

2023-05-10T22:42:41.835Z,1683758561.835 [DAT](INFO): DAT read: LocalAddr       | 12          

2023-05-10T22:42:41.836Z,1683758561.836 [DAT](INFO): set local address to 12
2023-05-10T22:42:41.836Z,1683758561.836 [DAT](INFO): Setting time to: 22:42:41 And date to:5/10/2023
2023-05-10T22:42:42.086Z,1683758562.086 [DAT](INFO): DAT read: user:6>

2023-05-10T22:42:42.087Z,1683758562.087 [DAT](INFO): DAT read: Wed May 10, 2023  22:42:41  

2023-05-10T22:42:42.088Z,1683758562.088 [DAT](INFO): Local DAT time set to Wed May 10, 2023  22:42:41  

2023-05-10T22:42:42.088Z,1683758562.088 [DAT](INFO): setting remote address to 9
2023-05-10T22:42:42.338Z,1683758562.338 [DAT](INFO): DAT read: user:7>

2023-05-10T22:42:42.339Z,1683758562.339 [DAT](INFO): DAT read: RemoteAddr      | 9           

2023-05-10T22:42:42.340Z,1683758562.340 [DAT](INFO): set remote address to 9
2023-05-10T22:42:42.340Z,1683758562.340 [DAT](INFO): entering online mode
2023-05-10T22:42:42.590Z,1683758562.590 [DAT](INFO): DAT read: user:8>

2023-05-10T22:42:42.591Z,1683758562.591 [DAT](INFO): DAT read: 

2023-05-10T22:42:42.592Z,1683758562.592 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T22:42:42.592Z,1683758562.592 [DAT](INFO): commRate: 800
2023-05-10T22:42:42.592Z,1683758562.592 [DAT](INFO): online mode acknowledged
2023-05-10T22:42:42.593Z,1683758562.593 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:42:45.871Z,1683758565.871 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:42:45.0341

2023-05-10T22:42:45.872Z,1683758565.872 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2023-05-10T22:42:55.958Z,1683758575.958 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:42:56.210Z,1683758576.210 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:42:56.462Z,1683758576.462 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:43:06.562Z,1683758586.562 [DAT](FAULT): Buffer send receipt timeout failure.
2023-05-10T22:43:06.562Z,1683758586.562 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:43:06.814Z,1683758586.814 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:43:07.318Z,1683758587.318 [DAT](INFO): entering online mode
2023-05-10T22:43:07.570Z,1683758587.570 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:07.822Z,1683758587.822 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:08.074Z,1683758588.074 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:08.326Z,1683758588.326 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:08.580Z,1683758588.580 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:08.834Z,1683758588.834 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:09.086Z,1683758589.086 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:09.338Z,1683758589.338 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:09.590Z,1683758589.590 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:09.842Z,1683758589.842 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:10.094Z,1683758590.094 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:10.346Z,1683758590.346 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:10.598Z,1683758590.598 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:10.850Z,1683758590.850 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:11.102Z,1683758591.102 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:11.354Z,1683758591.354 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:11.606Z,1683758591.606 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:11.858Z,1683758591.858 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:12.110Z,1683758592.110 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:12.362Z,1683758592.362 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:12.616Z,1683758592.616 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:12.866Z,1683758592.866 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:13.118Z,1683758593.118 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:13.370Z,1683758593.370 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:13.622Z,1683758593.622 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:13.874Z,1683758593.874 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:14.126Z,1683758594.126 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:14.386Z,1683758594.386 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:14.640Z,1683758594.640 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:14.894Z,1683758594.894 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:15.146Z,1683758595.146 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:15.398Z,1683758595.398 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:43:15.650Z,1683758595.650 [DAT](INFO): DAT read: Response Not Received

2023-05-10T22:43:15.651Z,1683758595.651 [DAT](INFO): response not received
2023-05-10T22:43:15.651Z,1683758595.651 [DAT](INFO): DAT read: user:11>

2023-05-10T22:43:15.652Z,1683758595.652 [DAT](INFO): DAT read: 

2023-05-10T22:43:15.653Z,1683758595.653 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T22:43:15.653Z,1683758595.653 [DAT](INFO): commRate: 800
2023-05-10T22:43:15.653Z,1683758595.653 [DAT](INFO): online mode acknowledged
2023-05-10T22:43:15.654Z,1683758595.654 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:43:15.654Z,1683758595.654 [DAT](ERROR): No response from remote modem.
2023-05-10T22:43:18.935Z,1683758598.935 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:43:18.0840

2023-05-10T22:43:18.935Z,1683758598.935 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2023-05-10T22:43:29.030Z,1683758609.030 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:43:29.284Z,1683758609.284 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:43:29.534Z,1683758609.534 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:43:32.811Z,1683758612.811 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:43:31.9352

2023-05-10T22:43:32.811Z,1683758612.811 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2023-05-10T22:43:42.938Z,1683758622.938 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:43:43.190Z,1683758623.190 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:43:43.694Z,1683758623.694 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:43:46.987Z,1683758626.987 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:43:46.1337

2023-05-10T22:43:46.987Z,1683758626.987 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2023-05-10T22:43:57.082Z,1683758637.082 [DAT](DEBUG): In sendingAckWaiting, hit max timeouts so set commsState_ = SENDING_VERIFIED
2023-05-10T22:43:57.082Z,1683758637.082 [DAT](ERROR): Ack receipt timeout failure.
2023-05-10T22:43:57.334Z,1683758637.334 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:43:57.586Z,1683758637.586 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:43:57.838Z,1683758637.838 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:44:01.115Z,1683758641.115 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:44:00.2336

2023-05-10T22:44:01.115Z,1683758641.115 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2023-05-10T22:44:11.222Z,1683758651.222 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:44:11.404Z,1683758651.404 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T22:44:11.404Z,1683758651.404 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T22:44:11.457Z,1683758651.457 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 9.000000 count
2023-05-10T22:44:11.459Z,1683758651.459 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m
2023-05-10T22:44:11.461Z,1683758651.461 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s
2023-05-10T22:44:11.464Z,1683758651.464 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count
2023-05-10T22:44:11.466Z,1683758651.466 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count
2023-05-10T22:44:11.468Z,1683758651.468 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count
2023-05-10T22:44:11.470Z,1683758651.470 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min
2023-05-10T22:44:11.472Z,1683758651.472 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum
2023-05-10T22:44:11.474Z,1683758651.474 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:44:11.475Z,1683758651.475 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum
2023-05-10T22:44:11.506Z,1683758651.506 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum
2023-05-10T22:44:11.532Z,1683758651.532 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait.
2023-05-10T22:44:11.548Z,1683758651.548 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Units="Tethys/Units"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                        Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                        Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd"
    Id="senddata_direct_and_track_test">


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

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

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

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

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

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

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


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



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

</Mission>


2023-05-10T22:44:11.554Z,1683758651.554 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml
2023-05-10T22:44:11.724Z,1683758651.724 [Default] Stopped
2023-05-10T22:44:11.724Z,1683758651.724 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-10T22:44:11.725Z,1683758651.725 [Default:B.GoToSurface] Stopped
2023-05-10T22:44:11.725Z,1683758651.725 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T22:44:11.725Z,1683758651.725 [Default:CheckIn] Stopped
2023-05-10T22:44:11.725Z,1683758651.725 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-05-10T22:44:11.725Z,1683758651.725 [Default:CheckIn:Read_GPS] Stopped
2023-05-10T22:44:11.725Z,1683758651.725 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test
2023-05-10T22:44:11.726Z,1683758651.726 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:44:11.726Z,1683758651.726 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:11.726Z,1683758651.726 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:11.728Z,1683758651.728 [senddata_direct_and_track_test] Running Loop=1
2023-05-10T22:44:11.728Z,1683758651.728 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test
2023-05-10T22:44:11.729Z,1683758651.729 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T22:44:11.729Z,1683758651.729 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact.
2023-05-10T22:44:11.731Z,1683758651.731 [senddata_direct_and_track_test:DirectData] Running Loop=1
2023-05-10T22:44:11.731Z,1683758651.731 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-05-10T22:44:11.731Z,1683758651.731 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-05-10T22:44:11.731Z,1683758651.731 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T22:44:11.731Z,1683758651.731 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-05-10T22:44:11.789Z,1683758651.789 [DAT](INFO): entering command mode
2023-05-10T22:44:11.978Z,1683758651.978 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:11.978Z,1683758651.978 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:11.978Z,1683758651.978 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:12.230Z,1683758652.230 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:12.230Z,1683758652.230 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:12.230Z,1683758652.230 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:12.482Z,1683758652.482 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:12.482Z,1683758652.482 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:12.482Z,1683758652.482 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:12.734Z,1683758652.734 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:12.734Z,1683758652.734 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:12.734Z,1683758652.734 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:12.986Z,1683758652.986 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:12.986Z,1683758652.986 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:12.986Z,1683758652.986 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:13.238Z,1683758653.238 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:13.238Z,1683758653.238 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:13.238Z,1683758653.238 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:13.490Z,1683758653.490 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:13.490Z,1683758653.490 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:13.490Z,1683758653.490 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:13.742Z,1683758653.742 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:13.742Z,1683758653.742 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:13.742Z,1683758653.742 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:13.994Z,1683758653.994 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:13.994Z,1683758653.994 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:13.994Z,1683758653.994 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:14.246Z,1683758654.246 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:14.246Z,1683758654.246 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:14.246Z,1683758654.246 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:14.498Z,1683758654.498 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:14.498Z,1683758654.498 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:14.498Z,1683758654.498 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:14.750Z,1683758654.750 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:14.750Z,1683758654.750 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:14.750Z,1683758654.750 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:15.003Z,1683758655.003 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:44:14.1835

2023-05-10T22:44:15.003Z,1683758655.003 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2023-05-10T22:44:15.003Z,1683758655.003 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:15.003Z,1683758655.003 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:15.004Z,1683758655.004 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:15.254Z,1683758655.254 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:15.254Z,1683758655.254 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:15.254Z,1683758655.254 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:15.507Z,1683758655.507 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:15.508Z,1683758655.508 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:15.508Z,1683758655.508 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:15.758Z,1683758655.758 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:15.758Z,1683758655.758 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:15.758Z,1683758655.758 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:16.010Z,1683758656.010 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:16.010Z,1683758656.010 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:16.010Z,1683758656.010 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:16.262Z,1683758656.262 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:16.262Z,1683758656.262 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:16.262Z,1683758656.262 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:16.514Z,1683758656.514 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:16.514Z,1683758656.514 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:16.514Z,1683758656.514 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:16.766Z,1683758656.766 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:16.766Z,1683758656.766 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:16.766Z,1683758656.766 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:17.018Z,1683758657.018 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:17.018Z,1683758657.018 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:17.018Z,1683758657.018 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:17.270Z,1683758657.270 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:17.270Z,1683758657.270 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:17.270Z,1683758657.270 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:17.522Z,1683758657.522 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:17.522Z,1683758657.522 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:17.522Z,1683758657.522 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:17.774Z,1683758657.774 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:17.774Z,1683758657.774 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:17.774Z,1683758657.774 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:18.026Z,1683758658.026 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:18.026Z,1683758658.026 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:18.026Z,1683758658.026 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:18.278Z,1683758658.278 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:18.278Z,1683758658.278 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:18.278Z,1683758658.278 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:18.530Z,1683758658.530 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:18.530Z,1683758658.530 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:18.530Z,1683758658.530 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:18.782Z,1683758658.782 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:18.782Z,1683758658.782 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:18.782Z,1683758658.782 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:19.034Z,1683758659.034 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:19.034Z,1683758659.034 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:19.034Z,1683758659.034 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:19.286Z,1683758659.286 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:19.286Z,1683758659.286 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:19.286Z,1683758659.286 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:19.538Z,1683758659.538 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:19.538Z,1683758659.538 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:19.538Z,1683758659.538 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:19.790Z,1683758659.790 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:19.790Z,1683758659.790 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:19.790Z,1683758659.790 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:20.042Z,1683758660.042 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:20.042Z,1683758660.042 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:20.042Z,1683758660.042 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:20.294Z,1683758660.294 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:20.294Z,1683758660.294 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:20.294Z,1683758660.294 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:20.546Z,1683758660.546 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:20.546Z,1683758660.546 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:20.546Z,1683758660.546 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:20.798Z,1683758660.798 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:20.798Z,1683758660.798 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:20.798Z,1683758660.798 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:21.050Z,1683758661.050 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:21.050Z,1683758661.050 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:21.050Z,1683758661.050 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:21.302Z,1683758661.302 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:21.302Z,1683758661.302 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:21.302Z,1683758661.302 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:21.554Z,1683758661.554 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:21.554Z,1683758661.554 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:21.554Z,1683758661.554 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:21.806Z,1683758661.806 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:21.806Z,1683758661.806 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:21.806Z,1683758661.806 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:22.058Z,1683758662.058 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:22.058Z,1683758662.058 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:22.058Z,1683758662.058 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:22.310Z,1683758662.310 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:22.310Z,1683758662.310 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:22.310Z,1683758662.310 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:22.562Z,1683758662.562 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:22.562Z,1683758662.562 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:22.562Z,1683758662.562 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:22.814Z,1683758662.814 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:22.814Z,1683758662.814 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:22.814Z,1683758662.814 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:23.066Z,1683758663.066 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:23.066Z,1683758663.066 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:23.066Z,1683758663.066 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:23.319Z,1683758663.319 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:23.319Z,1683758663.319 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:23.319Z,1683758663.319 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:23.570Z,1683758663.570 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:23.570Z,1683758663.570 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:23.570Z,1683758663.570 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:23.822Z,1683758663.822 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:23.822Z,1683758663.822 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:23.822Z,1683758663.822 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:24.074Z,1683758664.074 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:24.074Z,1683758664.074 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:24.074Z,1683758664.074 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:24.328Z,1683758664.328 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:24.328Z,1683758664.328 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:24.328Z,1683758664.328 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:24.578Z,1683758664.578 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:24.578Z,1683758664.578 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:24.578Z,1683758664.578 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:24.830Z,1683758664.830 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:24.830Z,1683758664.830 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:24.830Z,1683758664.830 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:25.082Z,1683758665.082 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:25.082Z,1683758665.082 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:25.082Z,1683758665.082 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:25.334Z,1683758665.334 [DAT](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:44:25.334Z,1683758665.334 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:25.334Z,1683758665.334 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:25.334Z,1683758665.334 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:25.586Z,1683758665.586 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:44:25.586Z,1683758665.586 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:25.586Z,1683758665.586 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:25.586Z,1683758665.586 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:25.838Z,1683758665.838 [DAT](INFO): entering online mode
2023-05-10T22:44:26.090Z,1683758666.090 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:26.342Z,1683758666.342 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:26.594Z,1683758666.594 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:26.846Z,1683758666.846 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:27.085Z,1683758667.085 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T22:44:27.098Z,1683758667.098 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:27.350Z,1683758667.350 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:27.602Z,1683758667.602 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:27.854Z,1683758667.854 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:28.106Z,1683758668.106 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:28.359Z,1683758668.359 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:28.610Z,1683758668.610 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:28.862Z,1683758668.862 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:29.115Z,1683758669.115 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:44:28.2334

2023-05-10T22:44:29.115Z,1683758669.115 [DAT](INFO): unknown deviceResponse_: Forwarding Delay UpTx time:22:44:28.2334

2023-05-10T22:44:29.115Z,1683758669.115 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:29.366Z,1683758669.366 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:29.618Z,1683758669.618 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:29.870Z,1683758669.870 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:30.122Z,1683758670.122 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:30.374Z,1683758670.374 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:30.626Z,1683758670.626 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:30.878Z,1683758670.878 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:31.130Z,1683758671.130 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:31.382Z,1683758671.382 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:31.634Z,1683758671.634 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:31.886Z,1683758671.886 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:32.138Z,1683758672.138 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:32.390Z,1683758672.390 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:32.642Z,1683758672.642 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:32.894Z,1683758672.894 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:33.146Z,1683758673.146 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:33.398Z,1683758673.398 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:33.650Z,1683758673.650 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:33.902Z,1683758673.902 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:34.154Z,1683758674.154 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:34.406Z,1683758674.406 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:34.658Z,1683758674.658 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:34.910Z,1683758674.910 [DAT](DEBUG): checking for online mode acknowledgment
2023-05-10T22:44:35.162Z,1683758675.162 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:35.162Z,1683758675.162 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:35.225Z,1683758675.225 [DAT](INFO): entering command mode
2023-05-10T22:44:35.414Z,1683758675.414 [DAT](INFO): DAT read: 

2023-05-10T22:44:35.415Z,1683758675.415 [DAT](INFO): DAT read: user:12>

2023-05-10T22:44:35.415Z,1683758675.415 [DAT](INFO): entering online mode
2023-05-10T22:44:35.666Z,1683758675.666 [DAT](INFO): DAT read: user:12>

2023-05-10T22:44:35.667Z,1683758675.667 [DAT](INFO): DAT read: 

2023-05-10T22:44:35.668Z,1683758675.668 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T22:44:35.668Z,1683758675.668 [DAT](INFO): commRate: 800
2023-05-10T22:44:35.668Z,1683758675.668 [DAT](INFO): online mode acknowledged
2023-05-10T22:44:35.669Z,1683758675.669 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:44:35.669Z,1683758675.669 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:35.669Z,1683758675.669 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:35.918Z,1683758675.918 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:35.918Z,1683758675.918 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:36.170Z,1683758676.170 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:36.170Z,1683758676.170 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:36.422Z,1683758676.422 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:36.422Z,1683758676.422 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:36.677Z,1683758676.677 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:36.677Z,1683758676.677 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:36.926Z,1683758676.926 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:36.926Z,1683758676.926 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:37.178Z,1683758677.178 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:37.178Z,1683758677.178 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:37.430Z,1683758677.430 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:37.430Z,1683758677.430 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:37.682Z,1683758677.682 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:37.682Z,1683758677.682 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:37.745Z,1683758677.745 [DAT](INFO): entering command mode
2023-05-10T22:44:37.934Z,1683758677.934 [DAT](INFO): DAT read: 

2023-05-10T22:44:37.934Z,1683758677.934 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:37.934Z,1683758677.934 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:37.935Z,1683758677.935 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:38.186Z,1683758678.186 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:38.186Z,1683758678.186 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:38.186Z,1683758678.186 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:38.438Z,1683758678.438 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:38.438Z,1683758678.438 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:38.438Z,1683758678.438 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:38.690Z,1683758678.690 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:38.690Z,1683758678.690 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:38.690Z,1683758678.690 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:38.942Z,1683758678.942 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:38.942Z,1683758678.942 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:38.942Z,1683758678.942 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:39.194Z,1683758679.194 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:39.194Z,1683758679.194 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:39.194Z,1683758679.194 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:39.446Z,1683758679.446 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:39.446Z,1683758679.446 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:39.446Z,1683758679.446 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:39.698Z,1683758679.698 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:39.698Z,1683758679.698 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:39.698Z,1683758679.698 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:39.950Z,1683758679.950 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:39.950Z,1683758679.950 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:39.950Z,1683758679.950 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:40.202Z,1683758680.202 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:40.202Z,1683758680.202 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:40.202Z,1683758680.202 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:40.454Z,1683758680.454 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:40.454Z,1683758680.454 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:40.454Z,1683758680.454 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:40.706Z,1683758680.706 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:40.706Z,1683758680.706 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:40.706Z,1683758680.706 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:40.958Z,1683758680.958 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:40.959Z,1683758680.959 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:40.959Z,1683758680.959 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:41.210Z,1683758681.210 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:41.210Z,1683758681.210 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:41.210Z,1683758681.210 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:41.462Z,1683758681.462 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:41.462Z,1683758681.462 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:41.462Z,1683758681.462 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:41.714Z,1683758681.714 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:41.714Z,1683758681.714 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:41.714Z,1683758681.714 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:41.966Z,1683758681.966 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:41.966Z,1683758681.966 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:41.966Z,1683758681.966 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:42.218Z,1683758682.218 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:42.218Z,1683758682.218 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:42.218Z,1683758682.218 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:42.440Z,1683758682.440 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-05-10T22:44:42.470Z,1683758682.470 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:42.470Z,1683758682.470 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:42.470Z,1683758682.470 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:42.722Z,1683758682.722 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:42.722Z,1683758682.722 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:42.722Z,1683758682.722 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:42.974Z,1683758682.974 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:42.974Z,1683758682.974 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:42.974Z,1683758682.974 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:43.226Z,1683758683.226 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:43.226Z,1683758683.226 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:43.226Z,1683758683.226 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:43.478Z,1683758683.478 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:43.478Z,1683758683.478 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:43.478Z,1683758683.478 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:43.730Z,1683758683.730 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:43.730Z,1683758683.730 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:43.730Z,1683758683.730 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:43.982Z,1683758683.982 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:43.982Z,1683758683.982 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:43.982Z,1683758683.982 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:44.234Z,1683758684.234 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:44.234Z,1683758684.234 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:44.234Z,1683758684.234 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:44.486Z,1683758684.486 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:44.486Z,1683758684.486 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:44.486Z,1683758684.486 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:44.738Z,1683758684.738 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:44.738Z,1683758684.738 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:44.738Z,1683758684.738 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:44.990Z,1683758684.990 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:44.990Z,1683758684.990 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:44.990Z,1683758684.990 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:45.250Z,1683758685.250 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:45.250Z,1683758685.250 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:45.250Z,1683758685.250 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:45.502Z,1683758685.502 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:45.502Z,1683758685.502 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:45.502Z,1683758685.502 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:45.754Z,1683758685.754 [DAT](FAULT): Buffer send receipt timeout failure.
2023-05-10T22:44:45.754Z,1683758685.754 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:44:45.754Z,1683758685.754 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:45.754Z,1683758685.754 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:45.754Z,1683758685.754 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:46.006Z,1683758686.006 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:44:46.006Z,1683758686.006 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:46.006Z,1683758686.006 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:46.006Z,1683758686.006 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:46.258Z,1683758686.258 [DAT](INFO): entering online mode
2023-05-10T22:44:46.511Z,1683758686.511 [DAT](INFO): DAT read: user:13>

2023-05-10T22:44:46.511Z,1683758686.511 [DAT](INFO): DAT read: 

2023-05-10T22:44:46.512Z,1683758686.512 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T22:44:46.513Z,1683758686.513 [DAT](INFO): commRate: 800
2023-05-10T22:44:46.513Z,1683758686.513 [DAT](INFO): online mode acknowledged
2023-05-10T22:44:46.513Z,1683758686.513 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:44:46.514Z,1683758686.514 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:46.515Z,1683758686.515 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:46.762Z,1683758686.762 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:46.762Z,1683758686.762 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:47.014Z,1683758687.014 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:47.014Z,1683758687.014 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:47.266Z,1683758687.266 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:47.266Z,1683758687.266 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:47.518Z,1683758687.518 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:47.518Z,1683758687.518 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:47.770Z,1683758687.770 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:47.770Z,1683758687.770 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:48.022Z,1683758688.022 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:48.022Z,1683758688.022 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:48.274Z,1683758688.274 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:48.274Z,1683758688.274 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:48.526Z,1683758688.526 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:48.526Z,1683758688.526 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:48.589Z,1683758688.589 [DAT](INFO): entering command mode
2023-05-10T22:44:48.778Z,1683758688.778 [DAT](INFO): DAT read: 

2023-05-10T22:44:48.779Z,1683758688.779 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:48.779Z,1683758688.779 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:48.779Z,1683758688.779 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:49.030Z,1683758689.030 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:49.030Z,1683758689.030 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:49.030Z,1683758689.030 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:49.286Z,1683758689.286 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:49.286Z,1683758689.286 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:49.286Z,1683758689.286 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:49.538Z,1683758689.538 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:49.538Z,1683758689.538 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:49.538Z,1683758689.538 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:49.790Z,1683758689.790 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:49.790Z,1683758689.790 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:49.790Z,1683758689.790 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:50.042Z,1683758690.042 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:50.042Z,1683758690.042 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:50.042Z,1683758690.042 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:50.294Z,1683758690.294 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:50.294Z,1683758690.294 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:50.294Z,1683758690.294 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:50.546Z,1683758690.546 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:50.546Z,1683758690.546 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:50.546Z,1683758690.546 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:50.798Z,1683758690.798 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:50.798Z,1683758690.798 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:50.798Z,1683758690.798 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:51.050Z,1683758691.050 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:51.050Z,1683758691.050 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:51.050Z,1683758691.050 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:51.302Z,1683758691.302 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:51.302Z,1683758691.302 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:51.302Z,1683758691.302 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:51.554Z,1683758691.554 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:51.554Z,1683758691.554 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:51.554Z,1683758691.554 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:51.806Z,1683758691.806 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:51.806Z,1683758691.806 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:51.806Z,1683758691.806 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:52.058Z,1683758692.058 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:52.058Z,1683758692.058 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:52.058Z,1683758692.058 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:52.310Z,1683758692.310 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:52.310Z,1683758692.310 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:52.310Z,1683758692.310 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:52.562Z,1683758692.562 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:52.562Z,1683758692.562 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:52.562Z,1683758692.562 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:52.814Z,1683758692.814 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:52.814Z,1683758692.814 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:52.814Z,1683758692.814 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:53.066Z,1683758693.066 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:53.066Z,1683758693.066 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:53.066Z,1683758693.066 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:53.318Z,1683758693.318 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:53.318Z,1683758693.318 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:53.318Z,1683758693.318 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:53.570Z,1683758693.570 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:53.570Z,1683758693.570 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:53.570Z,1683758693.570 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:53.791Z,1683758693.791 [CommandExec](IMPORTANT): got command stop
2023-05-10T22:44:53.791Z,1683758693.791 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop
2023-05-10T22:44:53.822Z,1683758693.822 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:53.822Z,1683758693.822 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:53.822Z,1683758693.822 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:54.074Z,1683758694.074 [DAT](INFO): ****** received valid address query ******
2023-05-10T22:44:54.074Z,1683758694.074 [DAT](INFO): ****** received valid ping request ******
2023-05-10T22:44:54.074Z,1683758694.074 [DAT](DEBUG): checking for command mode acknowledgment
2023-05-10T22:44:54.165Z,1683758694.165 [MissionManager](INFO): MissionManager is completed.
2023-05-10T22:44:54.165Z,1683758694.165 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test
2023-05-10T22:44:54.165Z,1683758694.165 [senddata_direct_and_track_test] Stopped
2023-05-10T22:44:54.165Z,1683758694.165 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test
2023-05-10T22:44:54.165Z,1683758694.165 [senddata_direct_and_track_test:TrackAC.] Stopped
2023-05-10T22:44:54.166Z,1683758694.166 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact.
2023-05-10T22:44:54.166Z,1683758694.166 [senddata_direct_and_track_test:DirectData] Stopped
2023-05-10T22:44:54.166Z,1683758694.166 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-05-10T22:44:54.166Z,1683758694.166 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-05-10T22:44:54.166Z,1683758694.166 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T22:44:54.584Z,1683758694.584 [MissionManager](IMPORTANT): Started mission Default
2023-05-10T22:44:54.584Z,1683758694.584 [Default] Running Loop=1
2023-05-10T22:44:54.584Z,1683758694.584 [Default](DEBUG): Aggregate::initialize Default
2023-05-10T22:44:54.584Z,1683758694.584 [Default:B.GoToSurface] Running Loop=1
2023-05-10T22:44:54.584Z,1683758694.584 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-05-10T22:44:54.585Z,1683758694.585 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-05-10T22:44:54.585Z,1683758694.585 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-05-10T22:44:54.585Z,1683758694.585 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-05-10T22:44:54.586Z,1683758694.586 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-05-10T22:44:54.586Z,1683758694.586 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-05-10T22:44:54.587Z,1683758694.587 [Default:A.Wait] Running Loop=1
2023-05-10T22:44:54.587Z,1683758694.587 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-05-10T22:44:56.602Z,1683758696.602 [DAT](FAULT): Buffer send receipt timeout failure.
2023-05-10T22:44:56.602Z,1683758696.602 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER
2023-05-10T22:44:56.811Z,1683758696.811 [CommandExec](IMPORTANT): got command restart application
2023-05-10T22:44:56.854Z,1683758696.854 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT
2023-05-10T22:44:57.106Z,1683758697.106 [DAT](INFO): entering online mode
2023-05-10T22:44:57.358Z,1683758697.358 [DAT](INFO): DAT read: user:14>

2023-05-10T22:44:57.359Z,1683758697.359 [DAT](INFO): DAT read: 

2023-05-10T22:44:57.360Z,1683758697.360 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-05-10T22:44:57.360Z,1683758697.360 [DAT](INFO): commRate: 800
2023-05-10T22:44:57.360Z,1683758697.360 [DAT](INFO): online mode acknowledged
2023-05-10T22:44:57.361Z,1683758697.361 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY
2023-05-10T22:44:57.813Z,1683758697.813 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:44:57.814Z,1683758697.814 [CommandExec](INFO): Uninitializing the command executive.
2023-05-10T22:44:57.814Z,1683758697.814 [CommandExec](INFO): Uninitializing the command scheduler.
2023-05-10T22:44:57.814Z,1683758697.814 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:44:57.814Z,1683758697.814 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2023-05-10T22:44:57.815Z,1683758697.815 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2023-05-10T22:44:57.815Z,1683758697.815 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:44:57.815Z,1683758697.815 [NavChartDb](INFO): Join timeout helper Thread ID is 990
2023-05-10T22:44:58.058Z,1683758698.058 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:44:58.058Z,1683758698.058 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:44:58.061Z,1683758698.061 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2023-05-10T22:44:58.062Z,1683758698.062 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:44:58.062Z,1683758698.062 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 991
2023-05-10T22:44:58.542Z,1683758698.542 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:44:58.542Z,1683758698.542 [WetLabsBB2FL](INFO): Powering down
2023-05-10T22:44:58.543Z,1683758698.543 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:44:58.561Z,1683758698.561 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2023-05-10T22:44:58.561Z,1683758698.561 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:44:58.562Z,1683758698.562 [CTD_Seabird](INFO): Join timeout helper Thread ID is 992
2023-05-10T22:44:58.798Z,1683758698.798 [CTD_Seabird](INFO): Powering down
2023-05-10T22:44:58.810Z,1683758698.810 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:44:58.810Z,1683758698.810 [CTD_Seabird](INFO): Powering down
2023-05-10T22:44:58.822Z,1683758698.822 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:44:58.826Z,1683758698.826 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2023-05-10T22:44:58.826Z,1683758698.826 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:44:58.826Z,1683758698.826 [Radio_Surface](INFO): Join timeout helper Thread ID is 993
2023-05-10T22:44:59.126Z,1683758699.126 [Radio_Surface](INFO): Powering down
2023-05-10T22:44:59.126Z,1683758699.126 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:44:59.127Z,1683758699.127 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:44:59.138Z,1683758699.138 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2023-05-10T22:44:59.138Z,1683758699.138 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:44:59.138Z,1683758699.138 [Onboard](INFO): Join timeout helper Thread ID is 994
2023-05-10T22:45:00.635Z,1683758700.635 [DAT](INFO): DAT read: Forwarding Delay UpTx time:22:44:59.7832

2023-05-10T22:45:00.635Z,1683758700.635 [DAT](DEBUG): In parseResponses, set commsState_ = SENDING_ACK_WAITING
2023-05-10T22:45:00.962Z,1683758700.962 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:45:00.962Z,1683758700.962 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:00.970Z,1683758700.970 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2023-05-10T22:45:00.970Z,1683758700.970 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:00.971Z,1683758700.971 [DataOverHttps](INFO): Join timeout helper Thread ID is 995
2023-05-10T22:45:01.122Z,1683758701.122 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:45:01.126Z,1683758701.126 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.146Z,1683758701.146 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler
2023-05-10T22:45:01.146Z,1683758701.146 [DAT ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.147Z,1683758701.147 [DAT](INFO): Join timeout helper Thread ID is 996
2023-05-10T22:45:01.390Z,1683758701.390 [DAT](INFO): Powering down
2023-05-10T22:45:01.462Z,1683758701.462 [DAT ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:45:01.462Z,1683758701.462 [DAT](INFO): Powering down
2023-05-10T22:45:01.463Z,1683758701.463 [DAT ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.478Z,1683758701.478 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler
2023-05-10T22:45:01.478Z,1683758701.478 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.479Z,1683758701.479 [BackseatComponent](INFO): Join timeout helper Thread ID is 997
2023-05-10T22:45:01.562Z,1683758701.562 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:45:01.562Z,1683758701.562 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.582Z,1683758701.582 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2023-05-10T22:45:01.582Z,1683758701.582 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.583Z,1683758701.583 [logger](INFO): Join timeout helper Thread ID is 998
2023-05-10T22:45:01.626Z,1683758701.626 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:45:01.626Z,1683758701.626 [logger ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.630Z,1683758701.630 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2023-05-10T22:45:01.630Z,1683758701.630 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.631Z,1683758701.631 [CommandLine](INFO): Join timeout helper Thread ID is 999
2023-05-10T22:45:01.654Z,1683758701.654 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:45:01.654Z,1683758701.654 [CommandLine ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.670Z,1683758701.670 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler
2023-05-10T22:45:01.670Z,1683758701.670 [CommandExec ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.671Z,1683758701.671 [CommandExec](INFO): Join timeout helper Thread ID is 1000
2023-05-10T22:45:01.672Z,1683758701.672 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2023-05-10T22:45:01.672Z,1683758701.672 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.672Z,1683758701.672 [controlThread](INFO): Join timeout helper Thread ID is 1001
2023-05-10T22:45:01.806Z,1683758701.806 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2023-05-10T22:45:01.806Z,1683758701.806 [controlThread](DEBUG): Uninitializing ControlThread
2023-05-10T22:45:01.806Z,1683758701.806 [AHRS_M2](INFO): Powering down
2023-05-10T22:45:01.878Z,1683758701.878 [NAL9602](INFO): Powering down
2023-05-10T22:45:01.881Z,1683758701.881 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2023-05-10T22:45:01.882Z,1683758701.882 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2023-05-10T22:45:01.882Z,1683758701.882 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2023-05-10T22:45:01.883Z,1683758701.883 [MissionManager](INFO): Uninitializing Mission Default
2023-05-10T22:45:01.883Z,1683758701.883 [Default] Stopped
2023-05-10T22:45:01.883Z,1683758701.883 [Default](DEBUG): Aggregate::uninitialize Default
2023-05-10T22:45:01.883Z,1683758701.883 [Default:A.Wait] Stopped
2023-05-10T22:45:01.883Z,1683758701.883 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-05-10T22:45:01.883Z,1683758701.883 [Default:B.GoToSurface] Stopped
2023-05-10T22:45:01.883Z,1683758701.883 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-05-10T22:45:01.886Z,1683758701.886 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2023-05-10T22:45:01.886Z,1683758701.886 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2023-05-10T22:45:01.886Z,1683758701.886 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2023-05-10T22:45:01.887Z,1683758701.887 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2023-05-10T22:45:01.887Z,1683758701.887 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2023-05-10T22:45:01.887Z,1683758701.887 [BuoyancyServo](INFO): Powering down
2023-05-10T22:45:01.902Z,1683758701.902 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2023-05-10T22:45:01.902Z,1683758701.902 [ElevatorServo](INFO): Powering down
2023-05-10T22:45:01.903Z,1683758701.903 [MassServo](DEBUG): Uninitialize Mass Servo.
2023-05-10T22:45:01.903Z,1683758701.903 [MassServo](INFO): Powering down
2023-05-10T22:45:01.904Z,1683758701.904 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2023-05-10T22:45:01.904Z,1683758701.904 [RudderServo](INFO): Powering down
2023-05-10T22:45:01.906Z,1683758701.906 [ThrusterHE](DEBUG): Uninitialize Thruster Servo.
2023-05-10T22:45:01.906Z,1683758701.906 [ThrusterHE](INFO): Powering down
2023-05-10T22:45:01.906Z,1683758701.906 [SBIT](DEBUG): Uninitialize SBIT Component.
2023-05-10T22:45:01.907Z,1683758701.907 [IBIT](DEBUG): Uninitialize IBIT Component.
2023-05-10T22:45:01.907Z,1683758701.907 [CBIT](DEBUG): Uninitialize CBIT Component.
2023-05-10T22:45:01.907Z,1683758701.907 [CBIT](DEBUG): Powering off loads.
2023-05-10T22:45:01.921Z,1683758701.921 [CBIT](DEBUG): Disabling WDT.
2023-05-10T22:45:01.933Z,1683758701.933 [CBIT](DEBUG): Opening all GF detection circuits.
2023-05-10T22:45:01.934Z,1683758701.934 [controlThread ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.989Z,1683758701.989 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.992Z,1683758701.992 [Onboard ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:01.997Z,1683758701.997 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:02.003Z,1683758702.003 [DAT ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:02.044Z,1683758702.044 [BackseatComponent ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:02.083Z,1683758702.083 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:02.087Z,1683758702.087 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:02.120Z,1683758702.120 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2023-05-10T22:45:02.184Z,1683758702.184 [logger ThreadHandler](INFO): Thread cancelled.