2023-12-21T19:28:21.239Z,1703186901.239 [Supervisor](DEBUG): Initializing supervisor.
2023-12-21T19:28:21.244Z,1703186901.244 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2023-12-21T19:28:21.244Z,1703186901.244 [SyncHandler](INFO): Protected caller Thread ID is 836
2023-12-21T19:28:21.245Z,1703186901.245 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2023-12-21T19:28:21.246Z,1703186901.246 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2023-12-21T19:28:21.246Z,1703186901.246 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 837
2023-12-21T19:28:21.250Z,1703186901.250 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2023-12-21T19:28:21.267Z,1703186901.267 [ComponentRegistry](DEBUG): Component "CommandExec" handled in its own thread.
2023-12-21T19:28:21.268Z,1703186901.268 [CommandExec ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2023-12-21T19:28:21.268Z,1703186901.268 [CommandExec ThreadHandler](INFO): Protected caller Thread ID is 838
2023-12-21T19:28:21.273Z,1703186901.273 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2023-12-21T19:28:21.274Z,1703186901.274 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2023-12-21T19:28:21.274Z,1703186901.274 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 839
2023-12-21T19:28:21.276Z,1703186901.276 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2023-12-21T19:28:21.277Z,1703186901.277 [logger ThreadHandler](DEBUG): Created PCaller Thread at 405114E0
2023-12-21T19:28:21.277Z,1703186901.277 [logger ThreadHandler](INFO): Protected caller Thread ID is 840
2023-12-21T19:28:21.281Z,1703186901.281 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2023-12-21T19:28:21.281Z,1703186901.281 [Supervisor](INFO): Looking for Config files in directory: Config/
2023-12-21T19:28:21.285Z,1703186901.285 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2023-12-21T19:28:21.737Z,1703186901.737 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2023-12-21T19:28:21.739Z,1703186901.739 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2023-12-21T19:28:21.942Z,1703186901.942 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2023-12-21T19:28:21.944Z,1703186901.944 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2023-12-21T19:28:22.026Z,1703186902.026 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2023-12-21T19:28:22.246Z,1703186902.246 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2023-12-21T19:28:22.248Z,1703186902.248 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2023-12-21T19:28:22.328Z,1703186902.328 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2023-12-21T19:28:22.425Z,1703186902.425 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2023-12-21T19:28:22.425Z,1703186902.425 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2023-12-21T19:28:22.759Z,1703186902.759 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2023-12-21T19:28:22.760Z,1703186902.760 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2023-12-21T19:28:22.889Z,1703186902.889 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2023-12-21T19:28:22.890Z,1703186902.890 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2023-12-21T19:28:23.419Z,1703186903.419 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2023-12-21T19:28:23.419Z,1703186903.419 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2023-12-21T19:28:23.608Z,1703186903.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2023-12-21T19:28:23.609Z,1703186903.609 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2023-12-21T19:28:24.018Z,1703186904.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2023-12-21T19:28:24.020Z,1703186904.020 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2023-12-21T19:28:24.298Z,1703186904.298 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2023-12-21T19:28:24.299Z,1703186904.299 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2023-12-21T19:28:24.408Z,1703186904.408 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2023-12-21T19:28:24.409Z,1703186904.409 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2023-12-21T19:28:25.300Z,1703186905.300 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2023-12-21T19:28:25.301Z,1703186905.301 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2023-12-21T19:28:25.645Z,1703186905.645 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2023-12-21T19:28:25.646Z,1703186905.646 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2023-12-21T19:28:25.868Z,1703186905.868 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2023-12-21T19:28:25.870Z,1703186905.870 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2023-12-21T19:28:25.874Z,1703186905.874 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2023-12-21T19:28:25.995Z,1703186905.995 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2023-12-21T19:28:26.080Z,1703186906.080 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2023-12-21T19:28:26.215Z,1703186906.215 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2023-12-21T19:28:26.300Z,1703186906.300 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2023-12-21T19:28:26.563Z,1703186906.563 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2023-12-21T19:28:26.564Z,1703186906.564 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2023-12-21T19:28:26.665Z,1703186906.665 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2023-12-21T19:28:26.770Z,1703186906.770 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2023-12-21T19:28:26.885Z,1703186906.885 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2023-12-21T19:28:27.031Z,1703186907.031 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2023-12-21T19:28:27.127Z,1703186907.127 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2023-12-21T19:28:27.225Z,1703186907.225 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2023-12-21T19:28:27.251Z,1703186907.251 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2023-12-21T19:28:27.267Z,1703186907.267 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2023-12-21T19:28:27.267Z,1703186907.267 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2023-12-21T19:28:27.394Z,1703186907.394 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2023-12-21T19:28:27.396Z,1703186907.396 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2023-12-21T19:28:27.463Z,1703186907.463 [VerticalControl](DEBUG): Construct VerticalControl.
2023-12-21T19:28:27.522Z,1703186907.522 [VerticalControl] Loaded
2023-12-21T19:28:27.523Z,1703186907.523 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2023-12-21T19:28:27.525Z,1703186907.525 [HorizontalControl](DEBUG): Construct HorizontalControl.
2023-12-21T19:28:27.566Z,1703186907.566 [HorizontalControl] Loaded
2023-12-21T19:28:27.566Z,1703186907.566 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2023-12-21T19:28:27.569Z,1703186907.569 [SpeedControl](DEBUG): Construct SpeedControl.
2023-12-21T19:28:27.572Z,1703186907.572 [SpeedControl] Loaded
2023-12-21T19:28:27.572Z,1703186907.572 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2023-12-21T19:28:27.575Z,1703186907.575 [LoopControl](DEBUG): Construct LoopControl.
2023-12-21T19:28:27.575Z,1703186907.575 [LoopControl] Loaded
2023-12-21T19:28:27.575Z,1703186907.575 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2023-12-21T19:28:27.576Z,1703186907.576 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2023-12-21T19:28:27.578Z,1703186907.578 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2023-12-21T19:28:27.760Z,1703186907.760 [BuoyancyServo] Loaded
2023-12-21T19:28:27.761Z,1703186907.761 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2023-12-21T19:28:27.780Z,1703186907.780 [ElevatorServo] Loaded
2023-12-21T19:28:27.781Z,1703186907.781 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2023-12-21T19:28:27.799Z,1703186907.799 [MassServo] Loaded
2023-12-21T19:28:27.800Z,1703186907.800 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2023-12-21T19:28:27.818Z,1703186907.818 [RudderServo] Loaded
2023-12-21T19:28:27.818Z,1703186907.818 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2023-12-21T19:28:27.832Z,1703186907.832 [ThrusterHE] Loaded
2023-12-21T19:28:27.833Z,1703186907.833 [ComponentRegistry](DEBUG): SyncComponent "ThrusterHE" handled in the control thread.
2023-12-21T19:28:27.833Z,1703186907.833 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2023-12-21T19:28:27.834Z,1703186907.834 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2023-12-21T19:28:27.903Z,1703186907.903 [DepthRateCalculator] Loaded
2023-12-21T19:28:27.903Z,1703186907.903 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2023-12-21T19:28:27.908Z,1703186907.908 [PitchRateCalculator] Loaded
2023-12-21T19:28:27.908Z,1703186907.908 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2023-12-21T19:28:27.918Z,1703186907.918 [SpeedCalculator] Loaded
2023-12-21T19:28:27.918Z,1703186907.918 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2023-12-21T19:28:27.923Z,1703186907.923 [YawRateCalculator] Loaded
2023-12-21T19:28:27.923Z,1703186907.923 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2023-12-21T19:28:27.942Z,1703186907.942 [ElevatorOffsetCalculator] Loaded
2023-12-21T19:28:27.942Z,1703186907.942 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2023-12-21T19:28:27.942Z,1703186907.942 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2023-12-21T19:28:27.943Z,1703186907.943 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2023-12-21T19:28:28.083Z,1703186908.083 [DeadReckonUsingMultipleVelocitySources] Loaded
2023-12-21T19:28:28.084Z,1703186908.084 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2023-12-21T19:28:28.098Z,1703186908.098 [NavChart] Loaded
2023-12-21T19:28:28.098Z,1703186908.098 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2023-12-21T19:28:28.104Z,1703186908.104 [UniversalFixResidualReporter] Loaded
2023-12-21T19:28:28.104Z,1703186908.104 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2023-12-21T19:28:28.104Z,1703186908.104 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2023-12-21T19:28:28.105Z,1703186908.105 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2023-12-21T19:28:28.881Z,1703186908.881 [AHRS_M2] Loaded
2023-12-21T19:28:28.882Z,1703186908.882 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2023-12-21T19:28:29.132Z,1703186909.132 [BackseatComponent] Loaded
2023-12-21T19:28:29.132Z,1703186909.132 [ComponentRegistry](DEBUG): Component "BackseatComponent" handled in its own thread.
2023-12-21T19:28:29.133Z,1703186909.133 [BackseatComponent ThreadHandler](DEBUG): Created PCaller Thread at 408F94E0
2023-12-21T19:28:29.133Z,1703186909.133 [BackseatComponent ThreadHandler](INFO): Protected caller Thread ID is 922
2023-12-21T19:28:29.136Z,1703186909.136 [LcmUniversalReporter] Loaded
2023-12-21T19:28:29.137Z,1703186909.137 [ComponentRegistry](DEBUG): SyncComponent "LcmUniversalReporter" handled in the control thread.
2023-12-21T19:28:29.143Z,1703186909.143 [BioacousticsDataBridge] Loaded
2023-12-21T19:28:29.143Z,1703186909.143 [ComponentRegistry](DEBUG): SyncComponent "BioacousticsDataBridge" handled in the control thread.
2023-12-21T19:28:29.995Z,1703186909.995 [BPC1] Loaded
2023-12-21T19:28:29.995Z,1703186909.995 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2023-12-21T19:28:30.080Z,1703186910.080 [DATMMP] Loaded
2023-12-21T19:28:30.080Z,1703186910.080 [ComponentRegistry](DEBUG): Component "DATMMP" handled in its own thread.
2023-12-21T19:28:30.081Z,1703186910.081 [DATMMP ThreadHandler](DEBUG): Created PCaller Thread at 4092A4E0
2023-12-21T19:28:30.082Z,1703186910.082 [DATMMP ThreadHandler](INFO): Protected caller Thread ID is 923
2023-12-21T19:28:30.223Z,1703186910.223 [DataOverHttps] Loaded
2023-12-21T19:28:30.223Z,1703186910.223 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2023-12-21T19:28:30.224Z,1703186910.224 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4095A4E0
2023-12-21T19:28:30.225Z,1703186910.225 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 924
2023-12-21T19:28:30.245Z,1703186910.245 [Depth_Keller] Loaded
2023-12-21T19:28:30.246Z,1703186910.246 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2023-12-21T19:28:30.307Z,1703186910.307 [NAL9602] Loaded
2023-12-21T19:28:30.308Z,1703186910.308 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2023-12-21T19:28:30.338Z,1703186910.338 [Onboard] Loaded
2023-12-21T19:28:30.338Z,1703186910.338 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2023-12-21T19:28:30.339Z,1703186910.339 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 4098A4E0
2023-12-21T19:28:30.339Z,1703186910.339 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 925
2023-12-21T19:28:30.351Z,1703186910.351 [Power24vConverter] Loaded
2023-12-21T19:28:30.352Z,1703186910.352 [ComponentRegistry](DEBUG): SyncComponent "Power24vConverter" handled in the control thread.
2023-12-21T19:28:30.365Z,1703186910.365 [Radio_Surface] Loaded
2023-12-21T19:28:30.365Z,1703186910.365 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2023-12-21T19:28:30.366Z,1703186910.366 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409BA4E0
2023-12-21T19:28:30.367Z,1703186910.367 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 926
2023-12-21T19:28:30.380Z,1703186910.380 [Sonardyne_Nano] Loaded
2023-12-21T19:28:30.380Z,1703186910.380 [ComponentRegistry](DEBUG): SyncComponent "Sonardyne_Nano" handled in the control thread.
2023-12-21T19:28:30.381Z,1703186910.381 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2023-12-21T19:28:30.382Z,1703186910.382 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2023-12-21T19:28:30.526Z,1703186910.526 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2023-12-21T19:28:30.527Z,1703186910.527 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2023-12-21T19:28:30.710Z,1703186910.710 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2023-12-21T19:28:30.711Z,1703186910.711 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2023-12-21T19:28:30.754Z,1703186910.754 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2023-12-21T19:28:30.754Z,1703186910.754 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2023-12-21T19:28:30.981Z,1703186910.981 [CTD_Seabird] Loaded
2023-12-21T19:28:30.981Z,1703186910.981 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2023-12-21T19:28:30.982Z,1703186910.982 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40AF44E0
2023-12-21T19:28:30.983Z,1703186910.983 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 927
2023-12-21T19:28:31.003Z,1703186911.003 [PAR_Licor] Loaded
2023-12-21T19:28:31.003Z,1703186911.003 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2023-12-21T19:28:31.044Z,1703186911.044 [WetLabsBB2FL] Loaded
2023-12-21T19:28:31.044Z,1703186911.044 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2023-12-21T19:28:31.045Z,1703186911.045 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40B244E0
2023-12-21T19:28:31.046Z,1703186911.046 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 928
2023-12-21T19:28:31.046Z,1703186911.046 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2023-12-21T19:28:31.047Z,1703186911.047 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2023-12-21T19:28:31.436Z,1703186911.436 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2023-12-21T19:28:31.436Z,1703186911.436 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2023-12-21T19:28:31.604Z,1703186911.604 [SBIT](DEBUG): Construct Startup Built In Test.
2023-12-21T19:28:31.613Z,1703186911.613 [SBIT] Loaded
2023-12-21T19:28:31.613Z,1703186911.613 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2023-12-21T19:28:31.616Z,1703186911.616 [IBIT](DEBUG): Construct Initiated Built In Test.
2023-12-21T19:28:31.628Z,1703186911.628 [IBIT] Loaded
2023-12-21T19:28:31.629Z,1703186911.629 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2023-12-21T19:28:31.635Z,1703186911.635 [CBIT](DEBUG): Construct Continuous Built In Test.
2023-12-21T19:28:31.739Z,1703186911.739 [CBIT] Loaded
2023-12-21T19:28:31.739Z,1703186911.739 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2023-12-21T19:28:31.740Z,1703186911.740 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2023-12-21T19:28:31.746Z,1703186911.746 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2023-12-21T19:28:31.749Z,1703186911.749 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2023-12-21T19:28:31.760Z,1703186911.760 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2023-12-21T19:28:31.761Z,1703186911.761 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40C104E0
2023-12-21T19:28:31.761Z,1703186911.761 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 930
2023-12-21T19:28:31.766Z,1703186911.766 [Supervisor](INFO): Main Thread ID is 829
2023-12-21T19:28:31.766Z,1703186911.766 [Supervisor](DEBUG): Running supervisor.
2023-12-21T19:28:31.767Z,1703186911.767 [CommandExec ThreadHandler](INFO): Handler Thread ID is 931
2023-12-21T19:28:31.767Z,1703186911.767 [CommandExec](INFO): Initializing the command executive.
2023-12-21T19:28:31.768Z,1703186911.768 [CommandLine ThreadHandler](INFO): Handler Thread ID is 932
2023-12-21T19:28:31.771Z,1703186911.771 [controlThread ThreadHandler](INFO): Handler Thread ID is 933
2023-12-21T19:28:31.771Z,1703186911.771 [controlThread](DEBUG): Initializing ControlThread
2023-12-21T19:28:31.772Z,1703186911.772 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2023-12-21T19:28:31.774Z,1703186911.774 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2023-12-21T19:28:31.774Z,1703186911.774 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2023-12-21T19:28:31.775Z,1703186911.775 [LoopControl](DEBUG): Initialize LoopControlComponent.
2023-12-21T19:28:31.776Z,1703186911.776 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2023-12-21T19:28:31.777Z,1703186911.777 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2023-12-21T19:28:31.777Z,1703186911.777 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2023-12-21T19:28:31.777Z,1703186911.777 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2023-12-21T19:28:31.778Z,1703186911.778 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2023-12-21T19:28:31.779Z,1703186911.779 [NavChart](DEBUG): Initialize NavChart Navigation.
2023-12-21T19:28:31.779Z,1703186911.779 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2023-12-21T19:28:31.785Z,1703186911.785 [SBIT](INFO): Initialize SBIT Component.
2023-12-21T19:28:31.786Z,1703186911.786 [SBIT](IMPORTANT): git: 2023-09-19-129-gab521801b
2023-12-21T19:28:31.786Z,1703186911.786 [SBIT](INFO): git hash: ab521801bd358af2637988023b5df7aa0b099e2d
2023-12-21T19:28:31.786Z,1703186911.786 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2023-12-21T19:28:31.787Z,1703186911.787 [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-12-21T19:28:31.789Z,1703186911.789 [SBIT](INFO): Beginning SBIT in 120.000000 seconds.
2023-12-21T19:28:31.789Z,1703186911.789 [IBIT](INFO): Initialize IBIT Component.
2023-12-21T19:28:31.790Z,1703186911.790 [CBIT](DEBUG): Initialize CBIT Component.
2023-12-21T19:28:31.791Z,1703186911.791 [logger ThreadHandler](INFO): Handler Thread ID is 934
2023-12-21T19:28:31.801Z,1703186911.801 [CBIT](DEBUG): Initialized mux pins.
2023-12-21T19:28:31.801Z,1703186911.801 [CBIT](DEBUG): Initializing the watchdog timer.
2023-12-21T19:28:31.810Z,1703186911.810 [BackseatComponent ThreadHandler](INFO): Handler Thread ID is 935
2023-12-21T19:28:31.821Z,1703186911.821 [DATMMP ThreadHandler](INFO): Handler Thread ID is 936
2023-12-21T19:28:31.822Z,1703186911.822 [DATMMP](INFO): Start
2023-12-21T19:28:31.822Z,1703186911.822 [DATMMP](INFO): Powering up
2023-12-21T19:28:31.822Z,1703186911.822 [DATMMP](DEBUG): Initializing DATMMP.
2023-12-21T19:28:31.825Z,1703186911.825 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2023-12-21T19:28:31.826Z,1703186911.826 [CBIT](DEBUG): Initializing heartbeat.
2023-12-21T19:28:31.827Z,1703186911.827 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 938
2023-12-21T19:28:31.828Z,1703186911.828 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2023-12-21T19:28:31.838Z,1703186911.838 [Onboard ThreadHandler](INFO): Handler Thread ID is 939
2023-12-21T19:28:31.855Z,1703186911.855 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 940
2023-12-21T19:28:31.870Z,1703186911.870 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 941
2023-12-21T19:28:31.871Z,1703186911.871 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2023-12-21T19:28:31.874Z,1703186911.874 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 943
2023-12-21T19:28:31.878Z,1703186911.878 [WetLabsBB2FL](INFO): Powering up
2023-12-21T19:28:31.879Z,1703186911.879 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 945
2023-12-21T19:28:31.888Z,1703186911.888 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI01M.000
2023-12-21T19:28:31.889Z,1703186911.889 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI01M.000
2023-12-21T19:28:31.889Z,1703186911.889 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2MI80M.000
2023-12-21T19:28:31.889Z,1703186911.889 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2MI80M.000
2023-12-21T19:28:31.889Z,1703186911.889 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI57M.000
2023-12-21T19:28:31.889Z,1703186911.889 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI57M.000
2023-12-21T19:28:31.890Z,1703186911.890 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI56M.000
2023-12-21T19:28:31.890Z,1703186911.890 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI56M.000
2023-12-21T19:28:31.890Z,1703186911.890 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI90M.000
2023-12-21T19:28:31.890Z,1703186911.890 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI90M.000
2023-12-21T19:28:31.890Z,1703186911.890 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4MI89M.000
2023-12-21T19:28:31.890Z,1703186911.890 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4MI89M.000
2023-12-21T19:28:31.891Z,1703186911.891 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI03M.000
2023-12-21T19:28:31.891Z,1703186911.891 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4WI03M.000
2023-12-21T19:28:31.891Z,1703186911.891 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4WI06M.000
2023-12-21T19:28:31.891Z,1703186911.891 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4WI06M.000
2023-12-21T19:28:31.891Z,1703186911.891 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH01M.000
2023-12-21T19:28:31.891Z,1703186911.891 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4OH01M.000
2023-12-21T19:28:31.892Z,1703186911.892 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH04M.000
2023-12-21T19:28:31.892Z,1703186911.892 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4OH04M.000
2023-12-21T19:28:31.892Z,1703186911.892 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4OH02M.000
2023-12-21T19:28:31.892Z,1703186911.892 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4OH02M.000
2023-12-21T19:28:31.892Z,1703186911.892 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4PA20M.000
2023-12-21T19:28:31.892Z,1703186911.892 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4PA20M.000
2023-12-21T19:28:31.892Z,1703186911.892 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4PA21M.000
2023-12-21T19:28:31.893Z,1703186911.893 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4PA21M.000
2023-12-21T19:28:31.897Z,1703186911.897 [CBIT](DEBUG): Deactivating GF circuits.
2023-12-21T19:28:31.897Z,1703186911.897 [CBIT](DEBUG): Deactivating emergency mode.
2023-12-21T19:28:31.937Z,1703186911.937 [CBIT](DEBUG): Backplane powered.
2023-12-21T19:28:31.938Z,1703186911.938 [MissionManager](INFO): Loading Mission from file: Missions/Startup.xml
2023-12-21T19:28:31.978Z,1703186911.978 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2023-12-21T19:28:31.989Z,1703186911.989 [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-12-21T19:28:31.990Z,1703186911.990 [MissionManager](INFO): Loading Mission from file: Missions/Default.xml
2023-12-21T19:28:32.055Z,1703186912.055 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2023-12-21T19:28:32.056Z,1703186912.056 [Default:A.Wait](DEBUG): Construct Wait.
2023-12-21T19:28:32.058Z,1703186912.058 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2023-12-21T19:28:32.073Z,1703186912.073 [DATMMP](INFO): Starting
2023-12-21T19:28:32.102Z,1703186912.102 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2023-12-21T19:28:32.105Z,1703186912.105 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2023-12-21T19:28:32.114Z,1703186912.114 [Default:E.Execute](DEBUG): Construct Execute.
2023-12-21T19:28:32.146Z,1703186912.146 [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-12-21T19:28:32.150Z,1703186912.150 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,BioacousticsDataBridge,BPC1,Depth_Keller,NAL9602,Power24vConverter,Sonardyne_Nano,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-12-21T19:28:32.170Z,1703186912.170 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2023-12-21T19:28:32.261Z,1703186912.261 [Radio_Surface](INFO): Powering up
2023-12-21T19:28:32.319Z,1703186912.319 [Power24vConverter](INFO): Powering up.
2023-12-21T19:28:32.320Z,1703186912.320 [Sonardyne_Nano](INFO): Initializing.
2023-12-21T19:28:32.325Z,1703186912.325 [DATMMP](INFO): Starting
2023-12-21T19:28:32.388Z,1703186912.388 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2023-12-21T19:28:32.393Z,1703186912.393 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2023-12-21T19:28:32.394Z,1703186912.394 [ElevatorServo](DEBUG): Initializing EZServoServo.
2023-12-21T19:28:32.401Z,1703186912.401 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2023-12-21T19:28:32.402Z,1703186912.402 [MassServo](DEBUG): Initializing EZServoServo.
2023-12-21T19:28:32.409Z,1703186912.409 [MassServo](DEBUG): Initializing MassServo.
2023-12-21T19:28:32.410Z,1703186912.410 [RudderServo](DEBUG): Initializing EZServoServo.
2023-12-21T19:28:32.417Z,1703186912.417 [RudderServo](DEBUG): Initializing RudderServo.
2023-12-21T19:28:32.418Z,1703186912.418 [ThrusterHE](DEBUG): Initializing EZServoServo.
2023-12-21T19:28:32.425Z,1703186912.425 [ThrusterHE](DEBUG): Initializing ThrusterHE.
2023-12-21T19:28:32.577Z,1703186912.577 [DATMMP](INFO): Starting
2023-12-21T19:28:32.830Z,1703186912.830 [DATMMP](INFO): Starting
2023-12-21T19:28:33.081Z,1703186913.081 [DATMMP](INFO): Starting
2023-12-21T19:28:33.333Z,1703186913.333 [DATMMP](INFO): Starting
2023-12-21T19:28:33.585Z,1703186913.585 [DATMMP](INFO): Starting
2023-12-21T19:28:33.837Z,1703186913.837 [DATMMP](INFO): Starting
2023-12-21T19:28:33.985Z,1703186913.985 [WetLabsBB2FL](INFO): Powering down
2023-12-21T19:28:34.089Z,1703186914.089 [DATMMP](INFO): Starting
2023-12-21T19:28:34.341Z,1703186914.341 [DATMMP](INFO): Starting
2023-12-21T19:28:34.593Z,1703186914.593 [DATMMP](INFO): Starting
2023-12-21T19:28:34.845Z,1703186914.845 [DATMMP](INFO): Starting
2023-12-21T19:28:35.097Z,1703186915.097 [DATMMP](INFO): Starting
2023-12-21T19:28:35.349Z,1703186915.349 [DATMMP](INFO): Starting
2023-12-21T19:28:35.601Z,1703186915.601 [DATMMP](INFO): Starting
2023-12-21T19:28:35.853Z,1703186915.853 [DATMMP](INFO): Starting
2023-12-21T19:28:36.105Z,1703186916.105 [DATMMP](INFO): Starting
2023-12-21T19:28:36.358Z,1703186916.358 [DATMMP](INFO): Starting
2023-12-21T19:28:36.611Z,1703186916.611 [DATMMP](INFO): Starting
2023-12-21T19:28:36.862Z,1703186916.862 [DATMMP](INFO): Starting
2023-12-21T19:28:37.113Z,1703186917.113 [DATMMP](INFO): Starting
2023-12-21T19:28:37.365Z,1703186917.365 [DATMMP](INFO): Starting
2023-12-21T19:28:37.617Z,1703186917.617 [DATMMP](INFO): Starting
2023-12-21T19:28:37.869Z,1703186917.869 [DATMMP](INFO): Starting
2023-12-21T19:28:37.943Z,1703186917.943 [ThrusterHE](ERROR): Zero Speed Commanded.
2023-12-21T19:28:38.121Z,1703186918.121 [DATMMP](INFO): Starting
2023-12-21T19:28:38.373Z,1703186918.373 [DATMMP](INFO): Starting
2023-12-21T19:28:38.625Z,1703186918.625 [DATMMP](INFO): Starting
2023-12-21T19:28:38.877Z,1703186918.877 [DATMMP](INFO): Starting
2023-12-21T19:28:39.129Z,1703186919.129 [DATMMP](INFO): Starting
2023-12-21T19:28:39.381Z,1703186919.381 [DATMMP](INFO): Starting
2023-12-21T19:28:39.633Z,1703186919.633 [DATMMP](INFO): Starting
2023-12-21T19:28:39.885Z,1703186919.885 [DATMMP](INFO): Starting
2023-12-21T19:28:40.137Z,1703186920.137 [DATMMP](INFO): Starting
2023-12-21T19:28:40.389Z,1703186920.389 [DATMMP](INFO): Starting
2023-12-21T19:28:40.641Z,1703186920.641 [DATMMP](INFO): Starting
2023-12-21T19:28:40.893Z,1703186920.893 [DATMMP](INFO): Starting
2023-12-21T19:28:41.145Z,1703186921.145 [DATMMP](INFO): Starting
2023-12-21T19:28:41.397Z,1703186921.397 [DATMMP](INFO): Starting
2023-12-21T19:28:41.649Z,1703186921.649 [DATMMP](INFO): Starting
2023-12-21T19:28:41.901Z,1703186921.901 [DATMMP](INFO): Starting
2023-12-21T19:28:42.022Z,1703186922.022 [CBIT](CRITICAL): Environmental Failure. Press:14.877588 PSI. Humidity:41%. Temp:24 C. ABORTING MISSION
2023-12-21T19:28:42.022Z,1703186922.022 [Supervisor](INFO): Stop Mission called by CBIT::monitorEnvironmentals
2023-12-21T19:28:42.153Z,1703186922.153 [DATMMP](INFO): Starting
2023-12-21T19:28:42.392Z,1703186922.392 [CommandExec](FAULT): Scheduling is paused
2023-12-21T19:28:42.392Z,1703186922.392 [CBIT](INFO): Critical error at 20231221T192842
2023-12-21T19:28:42.405Z,1703186922.405 [DATMMP](INFO): Starting
2023-12-21T19:28:42.657Z,1703186922.657 [DATMMP](INFO): Starting
2023-12-21T19:28:42.909Z,1703186922.909 [DATMMP](INFO): Starting
2023-12-21T19:28:43.161Z,1703186923.161 [DATMMP](INFO): Starting
2023-12-21T19:28:43.413Z,1703186923.413 [DATMMP](INFO): Starting
2023-12-21T19:28:43.665Z,1703186923.665 [DATMMP](INFO): Starting
2023-12-21T19:28:43.917Z,1703186923.917 [DATMMP](INFO): Starting
2023-12-21T19:28:44.169Z,1703186924.169 [DATMMP](INFO): Starting
2023-12-21T19:28:44.170Z,1703186924.170 [DATMMP](INFO): DAT read: 

2023-12-21T19:28:44.171Z,1703186924.171 [DATMMP](INFO): DAT read: Teledyne Benthos DAT-900 Series

2023-12-21T19:28:44.421Z,1703186924.421 [DATMMP](INFO): Starting
2023-12-21T19:28:44.673Z,1703186924.673 [DATMMP](INFO): Starting
2023-12-21T19:28:44.925Z,1703186924.925 [DATMMP](INFO): Starting
2023-12-21T19:28:45.177Z,1703186925.177 [DATMMP](INFO): Starting
2023-12-21T19:28:45.430Z,1703186925.430 [DATMMP](INFO): Starting
2023-12-21T19:28:45.681Z,1703186925.681 [DATMMP](INFO): Starting
2023-12-21T19:28:45.933Z,1703186925.933 [DATMMP](INFO): Starting
2023-12-21T19:28:45.934Z,1703186925.934 [DATMMP](INFO): DAT read: MF Frequency Band

2023-12-21T19:28:45.935Z,1703186925.935 [DATMMP](INFO): DAT read: Directional Acoustic Transponder version 8.15.0

2023-12-21T19:28:45.936Z,1703186925.936 [DATMMP](INFO): DAT read: Nov 21 2000 19:28:40 

2023-12-21T19:28:46.185Z,1703186926.185 [DATMMP](INFO): Starting
2023-12-21T19:28:46.437Z,1703186926.437 [DATMMP](INFO): Starting
2023-12-21T19:28:46.689Z,1703186926.689 [DATMMP](INFO): Starting
2023-12-21T19:28:46.941Z,1703186926.941 [DATMMP](INFO): Starting
2023-12-21T19:28:46.942Z,1703186926.942 [DATMMP](INFO): DAT read: Features enabled [Bearing]

2023-12-21T19:28:46.944Z,1703186926.944 [DATMMP](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP

2023-12-21T19:28:46.944Z,1703186926.944 [DATMMP](INFO): commRate: 800
2023-12-21T19:28:47.194Z,1703186927.194 [DATMMP](INFO): Starting
2023-12-21T19:28:47.445Z,1703186927.445 [DATMMP](INFO): Starting
2023-12-21T19:28:47.697Z,1703186927.697 [DATMMP](INFO): Starting
2023-12-21T19:28:47.949Z,1703186927.949 [DATMMP](INFO): Starting
2023-12-21T19:28:48.201Z,1703186928.201 [DATMMP](INFO): Starting
2023-12-21T19:28:48.453Z,1703186928.453 [DATMMP](INFO): Starting
2023-12-21T19:28:48.705Z,1703186928.705 [DATMMP](INFO): Starting
2023-12-21T19:28:48.957Z,1703186928.957 [DATMMP](INFO): Starting
2023-12-21T19:28:49.009Z,1703186929.009 [DATMMP](INFO): entering command mode
2023-12-21T19:28:49.210Z,1703186929.210 [DATMMP](INFO): Starting
2023-12-21T19:28:49.210Z,1703186929.210 [DATMMP](INFO): DAT read: 

2023-12-21T19:28:49.211Z,1703186929.211 [DATMMP](INFO): DAT read: user:1>

2023-12-21T19:28:49.211Z,1703186929.211 [DATMMP](DEBUG): read user prompt 1: user:1>

2023-12-21T19:28:49.211Z,1703186929.211 [DATMMP](INFO): entering MMP mode
2023-12-21T19:28:49.461Z,1703186929.461 [DATMMP](INFO): Starting
2023-12-21T19:28:49.462Z,1703186929.462 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:28:49.464Z,1703186929.464 [DATMMP](INFO): status rx: 	 x1
2023-12-21T19:28:49.464Z,1703186929.464 [DATMMP](INFO): MMP status: 1: started
2023-12-21T19:28:49.465Z,1703186929.465 [DATMMP](INFO): Received message type: status
2023-12-21T19:28:49.465Z,1703186929.465 [DATMMP](INFO): Handled
2023-12-21T19:28:49.713Z,1703186929.713 [DATMMP](INFO): Starting
2023-12-21T19:28:49.715Z,1703186929.715 [DATMMP](INFO): Sent Tx Power Config 2
2023-12-21T19:28:49.715Z,1703186929.715 [DATMMP](INFO): Setting local address: 12
2023-12-21T19:28:49.718Z,1703186929.718 [DATMMP](INFO): Setting time to: 19:28:49 And date to:12/21/2023
2023-12-21T19:28:49.965Z,1703186929.965 [DATMMP](INFO): Starting
2023-12-21T19:28:49.966Z,1703186929.966 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:28:49.966Z,1703186929.966 [DATMMP](INFO): mdmpower rx: 	 x2	 x0	 x5	 x0
2023-12-21T19:28:49.967Z,1703186929.967 [DATMMP](INFO): Received message type: mdmpower
2023-12-21T19:28:49.967Z,1703186929.967 [DATMMP](INFO): Handled
2023-12-21T19:28:50.217Z,1703186930.217 [DATMMP](INFO): Starting
2023-12-21T19:28:50.218Z,1703186930.218 [DATMMP](INFO): GSXN notify for xid: 10
2023-12-21T19:28:50.218Z,1703186930.218 [DATMMP](INFO): sreg_txpower rx: 	 x2
2023-12-21T19:28:50.219Z,1703186930.219 [DATMMP](INFO): Received message type: sreg_txpower
2023-12-21T19:28:50.219Z,1703186930.219 [DATMMP](INFO): Match for : sreg_txpower
2023-12-21T19:28:50.219Z,1703186930.219 [DATMMP](INFO): ACK
2023-12-21T19:28:50.470Z,1703186930.470 [DATMMP](INFO): Starting
2023-12-21T19:28:50.470Z,1703186930.470 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:28:50.471Z,1703186930.471 [DATMMP](INFO): mdmlocal rx: 	 xC	 x0	 x0	 x0
2023-12-21T19:28:50.472Z,1703186930.472 [DATMMP](INFO): Received message type: mdmlocal
2023-12-21T19:28:50.472Z,1703186930.472 [DATMMP](INFO): Handled
2023-12-21T19:28:50.721Z,1703186930.721 [DATMMP](INFO): Starting
2023-12-21T19:28:50.722Z,1703186930.722 [DATMMP](INFO): GSXN notify for xid: 11
2023-12-21T19:28:50.722Z,1703186930.722 [DATMMP](INFO): sreg_locaddr rx: 	 xC
2023-12-21T19:28:50.722Z,1703186930.722 [DATMMP](INFO): Received message type: sreg_locaddr
2023-12-21T19:28:50.723Z,1703186930.723 [DATMMP](INFO): Match for : sreg_locaddr
2023-12-21T19:28:50.723Z,1703186930.723 [DATMMP](INFO): ACK
2023-12-21T19:28:50.973Z,1703186930.973 [DATMMP](INFO): Starting
2023-12-21T19:28:50.974Z,1703186930.974 [DATMMP](INFO): GSXN notify for xid: 12
2023-12-21T19:28:50.975Z,1703186930.975 [DATMMP](INFO): timedate rx: 	 x0	 x13	 x1C	 x31	 xB	 x15	 x7B	 x0
2023-12-21T19:28:50.975Z,1703186930.975 [DATMMP](INFO): Received message type: timedate
2023-12-21T19:28:50.975Z,1703186930.975 [DATMMP](INFO): Match for : timedate
2023-12-21T19:28:50.975Z,1703186930.975 [DATMMP](INFO): ACK
2023-12-21T19:28:51.226Z,1703186931.226 [DATMMP](INFO): Starting
2023-12-21T19:28:51.226Z,1703186931.226 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:28:51.227Z,1703186931.227 [DATMMP](INFO): sys_verb rx: 	 x0	 x0	 x0	 x0
2023-12-21T19:28:51.227Z,1703186931.227 [DATMMP](INFO): Received message type: sys_verb
2023-12-21T19:28:51.227Z,1703186931.227 [DATMMP](INFO): Handled
2023-12-21T19:28:51.477Z,1703186931.477 [DATMMP](INFO): Starting
2023-12-21T19:28:51.478Z,1703186931.478 [DATMMP](INFO): GSXN notify for xid: 13
2023-12-21T19:28:51.478Z,1703186931.478 [DATMMP](INFO): sreg_verbosity rx: 	 x0
2023-12-21T19:28:51.478Z,1703186931.478 [DATMMP](INFO): Received message type: sreg_verbosity
2023-12-21T19:28:51.479Z,1703186931.479 [DATMMP](INFO): Match for : sreg_verbosity
2023-12-21T19:28:51.479Z,1703186931.479 [DATMMP](INFO): ACK
2023-12-21T19:28:51.729Z,1703186931.729 [DATMMP](INFO): Starting
2023-12-21T19:28:51.730Z,1703186931.730 [DATMMP](INFO): GSXN notify for xid: 14
2023-12-21T19:28:51.730Z,1703186931.730 [DATMMP](INFO): version rx: 	 x2	 x5
2023-12-21T19:28:51.731Z,1703186931.731 [DATMMP](INFO): DatMMPVersion: 2.5
2023-12-21T19:28:51.731Z,1703186931.731 [DATMMP](INFO): Received message type: version
2023-12-21T19:28:51.731Z,1703186931.731 [DATMMP](INFO): Match for : version
2023-12-21T19:28:51.731Z,1703186931.731 [DATMMP](INFO): ACK
2023-12-21T19:28:51.731Z,1703186931.731 [DATMMP](INFO): in MMP mode: config complete going to runnable
2023-12-21T19:29:00.442Z,1703186940.442 [NAL9602](INFO): Powering up NAL9602
2023-12-21T19:29:06.350Z,1703186946.350 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:29:06.351Z,1703186946.351 [DATMMP](INFO): timesync rx: 	 x0	 x1	 x1	 x0
2023-12-21T19:29:06.351Z,1703186946.351 [DATMMP](INFO): Received message type: timesync
2023-12-21T19:29:06.351Z,1703186946.351 [DATMMP](INFO): Handled
2023-12-21T19:29:11.363Z,1703186951.363 [NAL9602](INFO): NAL9602 initialized
2023-12-21T19:29:16.197Z,1703186956.197 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:29:16.198Z,1703186956.198 [DATMMP](INFO): timesync rx: 	 x1	 x0	 x1	 x0
2023-12-21T19:29:16.198Z,1703186956.198 [DATMMP](INFO): Received message type: timesync
2023-12-21T19:29:16.198Z,1703186956.198 [DATMMP](INFO): Handled
2023-12-21T19:29:40.030Z,1703186980.030 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-12-21T19:29:54.979Z,1703186994.979 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-12-21T19:30:10.335Z,1703187010.335 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-12-21T19:30:25.745Z,1703187025.745 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-12-21T19:30:32.580Z,1703187032.580 [SBIT](IMPORTANT): Beginning Startup BIT
2023-12-21T19:30:32.585Z,1703187032.585 [CBIT](IMPORTANT): Beginning ground fault scan
2023-12-21T19:30:40.645Z,1703187040.645 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-12-21T19:30:43.515Z,1703187043.515 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.001443
CHAN A1 (24V): -0.005877
CHAN A2 (12V): -0.004064
CHAN A3 (5V): -0.003163
CHAN B0 (3.3V): -0.000283
CHAN B1 (3.15aV): -0.000990
CHAN B2 (3.15bV): -0.001153
CHAN B3 (GND): -0.000350
OPEN: 0.004217
Full Scale: +/- 1 mA
2023-12-21T19:30:55.983Z,1703187055.983 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-12-21T19:31:10.988Z,1703187070.988 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-12-21T19:31:26.339Z,1703187086.339 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2023-12-21T19:31:26.422Z,1703187086.422 [SBIT](IMPORTANT): SBIT PASSED
2023-12-21T19:31:26.422Z,1703187086.422 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2023-12-21T19:31:26.423Z,1703187086.423 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=6 count;

2023-12-21T19:31:26.423Z,1703187086.423 [SBIT](IMPORTANT): BuoyancyServo.deviationVolume=1 cubic_centimeter;

2023-12-21T19:31:26.423Z,1703187086.423 [SBIT](IMPORTANT): BuoyancyServo.fastPumpDepth=6 meter;

2023-12-21T19:31:26.423Z,1703187086.423 [SBIT](IMPORTANT): CBIT.runNavErrorCritical=1 bool;

2023-12-21T19:31:26.423Z,1703187086.423 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2023-12-21T19:31:26.424Z,1703187086.424 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=10 minute;

2023-12-21T19:31:26.424Z,1703187086.424 [SBIT](IMPORTANT): Express linearApproximation BackseatComponent.handled_message 1.000000 bool;

2023-12-21T19:31:26.424Z,1703187086.424 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_mean_sea_water_temperature 5.000000 celsius;

2023-12-21T19:31:26.424Z,1703187086.424 [SBIT](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;

2023-12-21T19:31:26.424Z,1703187086.424 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water;

2023-12-21T19:31:26.424Z,1703187086.424 [SBIT](IMPORTANT): Express none WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water;

2023-12-21T19:31:26.424Z,1703187086.424 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 50.000000 meter;

2023-12-21T19:31:26.424Z,1703187086.424 [SBIT](IMPORTANT): Express none platform_roll_angle;

2023-12-21T19:31:26.425Z,1703187086.425 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=0.001 ampere_hour;

2023-12-21T19:31:26.425Z,1703187086.425 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=10 volt;

2023-12-21T19:31:26.425Z,1703187086.425 [SBIT](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2023-12-21T19:31:26.425Z,1703187086.425 [SBIT](IMPORTANT): NAL9602.iridiumMTQueueTimeout=5 minute;

2023-12-21T19:31:26.425Z,1703187086.425 [SBIT](IMPORTANT): Sonardyne_Nano.loadAtStartup=1 bool;

2023-12-21T19:31:26.425Z,1703187086.425 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=90 cubic_centimeter;

2023-12-21T19:31:26.425Z,1703187086.425 [SBIT](IMPORTANT): VerticalControl.elevDeadband=0.1 angular_degree;

2023-12-21T19:31:26.425Z,1703187086.425 [SBIT](IMPORTANT): VerticalControl.kdDepthBuoy=1000 second;

2023-12-21T19:31:26.425Z,1703187086.425 [SBIT](IMPORTANT): VerticalControl.kiDepthBuoy=0.15 reciprocal_second;

2023-12-21T19:31:26.426Z,1703187086.426 [SBIT](IMPORTANT): VerticalControl.kiDepthOff=0.01 meter_per_second;

2023-12-21T19:31:26.434Z,1703187086.434 [SBIT](IMPORTANT): VerticalControl.kpDepthBuoy=120 ratio;

2023-12-21T19:31:26.434Z,1703187086.434 [SBIT](IMPORTANT): VerticalControl.massDefault=-2.5 centimeter;

2023-12-21T19:31:26.795Z,1703187086.795 [MissionManager](IMPORTANT): Started mission Startup
2023-12-21T19:31:26.796Z,1703187086.796 [Startup] Running Loop=1
2023-12-21T19:31:26.796Z,1703187086.796 [Startup](DEBUG): Aggregate::initialize Startup
2023-12-21T19:31:26.796Z,1703187086.796 [Startup:A.GoToSurface] Running Loop=1
2023-12-21T19:31:26.796Z,1703187086.796 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-12-21T19:31:26.797Z,1703187086.797 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-12-21T19:31:26.797Z,1703187086.797 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-12-21T19:31:26.797Z,1703187086.797 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-12-21T19:31:26.802Z,1703187086.802 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-12-21T19:31:26.802Z,1703187086.802 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-12-21T19:31:26.804Z,1703187086.804 [Startup:StartupSatComms] Running Loop=1
2023-12-21T19:31:26.804Z,1703187086.804 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2023-12-21T19:31:26.804Z,1703187086.804 [Startup:StartupSatComms:A] Running Loop=1
2023-12-21T19:31:27.197Z,1703187087.197 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2023-12-21T19:31:32.037Z,1703187092.037 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2023-12-21T19:31:32.037Z,1703187092.037 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-21T19:31:32.052Z,1703187092.052 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-21T19:31:32.517Z,1703187092.517 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-21T19:31:32.517Z,1703187092.517 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2023-12-21T19:31:32.602Z,1703187092.602 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005797
2023-12-21T19:31:43.727Z,1703187103.727 [CommandExec](IMPORTANT): got command failComponent
2023-12-21T19:31:43.727Z,1703187103.727 [CommandExec](IMPORTANT): Failed components:
2023-12-21T19:31:43.727Z,1703187103.727 [CommandExec](IMPORTANT): No failed Components.
2023-12-21T19:32:27.012Z,1703187147.012 [Startup:StartupSatComms:A](INFO): Timed out from 2023-12-21T19:31:26.8Z
2023-12-21T19:32:27.012Z,1703187147.012 [Startup:StartupSatComms:A] Stopped
2023-12-21T19:32:27.012Z,1703187147.012 [Startup:StartupSatComms:B] Running Loop=1
2023-12-21T19:32:27.405Z,1703187147.405 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-12-21T19:32:37.987Z,1703187157.987 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20231208T212038/Courier0007.lzma
2023-12-21T19:32:38.988Z,1703187158.988 [DataOverHttps](INFO): Moved sent file to Logs/20231208T212038/Courier0007.lzma.bak
2023-12-21T19:32:38.988Z,1703187158.988 [DataOverHttps](INFO): SBD MOMSN=19126644
2023-12-21T19:32:59.043Z,1703187179.043 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20231221T192357/Courier0000.lzma
2023-12-21T19:33:00.044Z,1703187180.044 [DataOverHttps](INFO): Moved sent file to Logs/20231221T192357/Courier0000.lzma.bak
2023-12-21T19:33:00.044Z,1703187180.044 [DataOverHttps](INFO): SBD MOMSN=19126646
2023-12-21T19:33:17.086Z,1703187197.086 [DataOverHttps](INFO): Sending 250 bytes from file Logs/20231221T192821/Courier0000.lzma
2023-12-21T19:33:18.088Z,1703187198.088 [DataOverHttps](INFO): Moved sent file to Logs/20231221T192821/Courier0000.lzma.bak
2023-12-21T19:33:18.088Z,1703187198.088 [DataOverHttps](INFO): SBD MOMSN=19126649
2023-12-21T19:33:27.344Z,1703187207.344 [Startup:StartupSatComms:B](INFO): Timed out from 2023-12-21T19:32:27.0Z
2023-12-21T19:33:27.344Z,1703187207.344 [Startup:StartupSatComms:B] Stopped
2023-12-21T19:33:27.344Z,1703187207.344 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2023-12-21T19:33:27.344Z,1703187207.344 [Startup:StartupSatComms] Stopped
2023-12-21T19:33:27.344Z,1703187207.344 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2023-12-21T19:33:27.345Z,1703187207.345 [Startup](INFO): Completed Startup
2023-12-21T19:33:27.345Z,1703187207.345 [MissionManager](INFO): Startup is completed.
2023-12-21T19:33:27.345Z,1703187207.345 [MissionManager](INFO): Uninitializing Mission Startup
2023-12-21T19:33:27.345Z,1703187207.345 [Startup] Stopped
2023-12-21T19:33:27.345Z,1703187207.345 [Startup](DEBUG): Aggregate::uninitialize Startup
2023-12-21T19:33:27.345Z,1703187207.345 [Startup:A.GoToSurface] Stopped
2023-12-21T19:33:27.345Z,1703187207.345 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-12-21T19:33:27.741Z,1703187207.741 [MissionManager](IMPORTANT): Started mission Default
2023-12-21T19:33:27.741Z,1703187207.741 [Default] Running Loop=1
2023-12-21T19:33:27.741Z,1703187207.741 [Default](DEBUG): Aggregate::initialize Default
2023-12-21T19:33:27.741Z,1703187207.741 [Default:B.GoToSurface] Running Loop=1
2023-12-21T19:33:27.742Z,1703187207.742 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-12-21T19:33:27.742Z,1703187207.742 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-12-21T19:33:27.742Z,1703187207.742 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-12-21T19:33:27.743Z,1703187207.743 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-12-21T19:33:27.743Z,1703187207.743 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-12-21T19:33:27.743Z,1703187207.743 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-12-21T19:33:27.743Z,1703187207.743 [Default:A.Wait] Running Loop=1
2023-12-21T19:33:27.744Z,1703187207.744 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-12-21T19:33:39.531Z,1703187219.531 [DataOverHttps](INFO): Sending 118 bytes from file Logs/20231208T212038/Express0008.lzma
2023-12-21T19:33:40.532Z,1703187220.532 [DataOverHttps](INFO): Moved sent file to Logs/20231208T212038/Express0008.lzma.bak
2023-12-21T19:33:40.532Z,1703187220.532 [DataOverHttps](INFO): SBD MOMSN=19126653
2023-12-21T19:33:41.054Z,1703187221.054 [Default:A.Wait](INFO): Done Waiting.
2023-12-21T19:33:41.054Z,1703187221.054 [Default:A.Wait] Stopped
2023-12-21T19:33:41.054Z,1703187221.054 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-12-21T19:33:41.473Z,1703187221.473 [Default:CheckIn] Running Loop=1
2023-12-21T19:33:41.473Z,1703187221.473 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-21T19:33:41.473Z,1703187221.473 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-21T19:33:41.860Z,1703187221.860 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2023-12-21T19:34:14.595Z,1703187254.595 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2023-12-21T19:34:33.179Z,1703187273.179 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2023-12-21T19:34:33.179Z,1703187273.179 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-21T19:34:33.190Z,1703187273.190 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-21T19:34:33.579Z,1703187273.579 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-21T19:34:33.579Z,1703187273.579 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2023-12-21T19:36:29.511Z,1703187389.511 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2023-12-21T19:36:29.515Z,1703187389.515 [BPC1](INFO): Received data from all battery sticks.
2023-12-21T19:37:34.163Z,1703187454.163 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2023-12-21T19:37:34.163Z,1703187454.163 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-21T19:37:34.179Z,1703187454.179 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-21T19:37:34.593Z,1703187454.593 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-21T19:37:34.593Z,1703187454.593 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2023-12-21T19:38:02.837Z,1703187482.837 [CommandExec](IMPORTANT): got command show variable address
2023-12-21T19:38:02.840Z,1703187482.840 [CommandExec](IMPORTANT): acoustic_contact_address (unknown)
2023-12-21T19:38:02.949Z,1703187482.949 [CommandExec](IMPORTANT): Config/workSite.beacon1Address (count)
2023-12-21T19:38:02.949Z,1703187482.949 [CommandExec](IMPORTANT): Config/workSite.beacon2Address (count)
2023-12-21T19:38:02.950Z,1703187482.950 [CommandExec](IMPORTANT): Config/workSite.beacon3Address (count)
2023-12-21T19:38:03.016Z,1703187483.016 [CommandExec](IMPORTANT): AcousticModem_Benthos_ATM900.localAddress (count)
2023-12-21T19:38:03.016Z,1703187483.016 [CommandExec](IMPORTANT): AcousticModem_Benthos_ATM900.sbdAddress (enum)
2023-12-21T19:38:03.016Z,1703187483.016 [CommandExec](IMPORTANT): AcousticModem_Benthos_ATM900.transponderAddress (enum)
2023-12-21T19:38:03.021Z,1703187483.021 [CommandExec](IMPORTANT): DAT.sbdAddress (enum)
2023-12-21T19:38:03.021Z,1703187483.021 [CommandExec](IMPORTANT): DAT.transponderAddress (enum)
2023-12-21T19:38:03.022Z,1703187483.022 [CommandExec](IMPORTANT): DATMMP.sbdAddress (enum)
2023-12-21T19:38:03.023Z,1703187483.023 [CommandExec](IMPORTANT): DATMMP.transponderAddress (enum)
2023-12-21T19:38:03.026Z,1703187483.026 [CommandExec](IMPORTANT): Micromodem.localAddress (enum)
2023-12-21T19:38:03.026Z,1703187483.026 [CommandExec](IMPORTANT): Micromodem.destinationAddress (enum)
2023-12-21T19:38:03.198Z,1703187483.198 [CommandExec](IMPORTANT): DATMMP.acoustic_contact_address (enum)
2023-12-21T19:38:03.201Z,1703187483.201 [CommandExec](IMPORTANT): DATMMP.localAddressReading (enum)
2023-12-21T19:38:19.616Z,1703187499.616 [CommandExec](IMPORTANT): got command get DATMMP.localAddressReading
2023-12-21T19:38:19.616Z,1703187499.616 [CommandExec](IMPORTANT): DATMMP.localAddressReading 0 enum
2023-12-21T19:38:33.888Z,1703187513.888 [CommandExec](IMPORTANT): got command get DATMMP.sbdAddress
2023-12-21T19:38:33.888Z,1703187513.888 [CommandExec](IMPORTANT): DATMMP.sbdAddress -1 enum
2023-12-21T19:38:41.669Z,1703187521.669 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-12-21T19:33:41.5Z
2023-12-21T19:38:41.669Z,1703187521.669 [Default:CheckIn:Read_GPS] Stopped
2023-12-21T19:38:41.669Z,1703187521.669 [Default:CheckIn:Read_Iridium] Running Loop=1
2023-12-21T19:38:42.076Z,1703187522.076 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2023-12-21T19:38:49.777Z,1703187529.777 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20231221T192821/Courier0004.lzma
2023-12-21T19:38:50.782Z,1703187530.782 [DataOverHttps](INFO): Moved sent file to Logs/20231221T192821/Courier0004.lzma.bak
2023-12-21T19:38:50.782Z,1703187530.782 [DataOverHttps](INFO): SBD MOMSN=19126690
2023-12-21T19:39:09.689Z,1703187549.689 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20231221T192357/Express0001.lzma
2023-12-21T19:39:10.692Z,1703187550.692 [DataOverHttps](INFO): Moved sent file to Logs/20231221T192357/Express0001.lzma.bak
2023-12-21T19:39:10.692Z,1703187550.692 [DataOverHttps](INFO): SBD MOMSN=19126692
2023-12-21T19:39:14.359Z,1703187554.359 [NAL9602](FAULT): GPS failed to acquire within timeout.
2023-12-21T19:39:14.359Z,1703187554.359 [NAL9602] Data Fault, FailCount= 1
2023-12-21T19:39:14.359Z,1703187554.359 [NAL9602](ERROR): Data Fault
2023-12-21T19:39:14.389Z,1703187554.389 [CBIT](ERROR): Data Fault in component: NAL9602
2023-12-21T19:39:14.763Z,1703187554.763 [NAL9602](INFO): Powering down
2023-12-21T19:39:15.589Z,1703187555.589 [CBIT](INFO): Clearing failed state for component NAL9602
2023-12-21T19:39:15.589Z,1703187555.589 [NAL9602] No Fault, FailCount= 1
2023-12-21T19:39:29.620Z,1703187569.620 [DataOverHttps](INFO): Sending 1274 bytes from file Logs/20231221T192821/Express0001.lzma
2023-12-21T19:39:30.620Z,1703187570.620 [DataOverHttps](INFO): Moved sent file to Logs/20231221T192821/Express0001.lzma.bak
2023-12-21T19:39:30.620Z,1703187570.620 [DataOverHttps](INFO): SBD MOMSN=19126695
2023-12-21T19:39:45.072Z,1703187585.072 [NAL9602](INFO): Powering up NAL9602
2023-12-21T19:39:49.902Z,1703187589.902 [DataOverHttps](INFO): Sending 478 bytes from file Logs/20231221T192821/Express0005.lzma
2023-12-21T19:39:50.904Z,1703187590.904 [DataOverHttps](INFO): Moved sent file to Logs/20231221T192821/Express0005.lzma.bak
2023-12-21T19:39:50.904Z,1703187590.904 [DataOverHttps](INFO): SBD MOMSN=19126735
2023-12-21T19:39:55.614Z,1703187595.614 [Default:CheckIn:Read_Iridium] Stopped
2023-12-21T19:39:55.614Z,1703187595.614 [Default:CheckIn:C.Wait] Running Loop=1
2023-12-21T19:39:55.615Z,1703187595.615 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2023-12-21T19:39:55.976Z,1703187595.976 [NAL9602](INFO): NAL9602 initialized
2023-12-21T19:40:35.191Z,1703187635.191 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2023-12-21T19:40:35.191Z,1703187635.191 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-21T19:40:35.203Z,1703187635.203 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-21T19:40:35.587Z,1703187635.587 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-21T19:40:35.588Z,1703187635.588 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2023-12-21T19:40:56.013Z,1703187656.013 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml
2023-12-21T19:40:56.014Z,1703187656.014 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml
2023-12-21T19:40:56.071Z,1703187656.071 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 10.000000 count
2023-12-21T19:40:56.074Z,1703187656.074 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m
2023-12-21T19:40:56.077Z,1703187656.077 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s
2023-12-21T19:40:56.080Z,1703187656.080 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count
2023-12-21T19:40:56.082Z,1703187656.082 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count
2023-12-21T19:40:56.085Z,1703187656.085 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count
2023-12-21T19:40:56.088Z,1703187656.088 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.BeingInterrogatedTimeout = 1.000000 h
2023-12-21T19:40:56.091Z,1703187656.091 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min
2023-12-21T19:40:56.093Z,1703187656.093 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum
2023-12-21T19:40:56.096Z,1703187656.096 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum
2023-12-21T19:40:56.142Z,1703187656.142 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum
2023-12-21T19:40:56.143Z,1703187656.143 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/AbortDrift.tl
2023-12-21T19:40:56.143Z,1703187656.143 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/AbortDrift.tx
2023-12-21T19:40:56.247Z,1703187656.247 [MissionManager](INFO): DefineArg senddata_direct_and_track_test:AbortDrift.AcousticTimeout = 96.000000 h
2023-12-21T19:40:56.249Z,1703187656.249 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](DEBUG): Construct AbortDrift.
2023-12-21T19:40:56.252Z,1703187656.252 [senddata_direct_and_track_test:AbortDrift:C.Execute](DEBUG): Construct Execute.
2023-12-21T19:40:56.270Z,1703187656.270 [MissionManager](INFO): RedefineArg senddata_direct_and_track_test:AbortDrift.AcousticTimeout = reader:senddata_direct_and_track_test.BeingInterrogatedTimeout
2023-12-21T19:40:56.420Z,1703187656.420 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait.
2023-12-21T19:40:56.442Z,1703187656.442 [senddata_direct_and_track_test:D.Wait](DEBUG): Construct Wait.
2023-12-21T19:40:56.452Z,1703187656.452 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
    xmlns:Sensor="Tethys/Sensor"
    xmlns:Units="Tethys/Units"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                        Tethys/Sensor http://okeanids.mbari.org/tethys/Xml/Sensor.xsd
                        Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd"
    Id="senddata_direct_and_track_test">


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

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

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

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

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

    <DefineArg Name="BeingInterrogatedTimeout"><Description>
        If the vehicle does not receive an acoustic signal for more than this
        length of time, it will surface for communications. Set longer than
        MissionTimeout to effectively disable.
    </Description><Units:hour/><Value>1</Value></DefineArg>
        
    <DefineArg Name="AcommsInterval"><Description></Description><Units:minute/><Value>1</Value></DefineArg>    
    
    <DefineArg Name="modemId1"><Description>
        Modem ID1.
    </Description><Units:enum/><Value>9</Value></DefineArg>

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

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

    <Insert Filename="Insert/AbortDrift.tl">
        <RedefineArg Name="AcousticTimeout"><Arg Name="BeingInterrogatedTimeout"/></RedefineArg>
    </Insert>
    
    
    <Estimation:TrackAcousticContact Id="TrackAC">
        <Parallel/>
        <Setting><Estimation:TrackAcousticContact.contactLabelSetting/><Arg Name="AcousticTargetContactLabel"/></Setting>
        <Setting><Estimation:TrackAcousticContact.numberOfSamplesSetting/><Arg Name="NumberOfPings"/></Setting>
        <Setting><Estimation:TrackAcousticContact.updatePeriodSetting/><Arg Name="TrackingUpdatePeriod"/></Setting>
    </Estimation:TrackAcousticContact>



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

    <Guidance:Wait>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Arg Name="AcommsInterval"/></Setting>
    </Guidance:Wait>

</Mission>


2023-12-21T19:40:56.459Z,1703187656.459 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml
2023-12-21T19:40:56.604Z,1703187656.604 [Default] Stopped
2023-12-21T19:40:56.604Z,1703187656.604 [Default](DEBUG): Aggregate::uninitialize Default
2023-12-21T19:40:56.604Z,1703187656.604 [Default:B.GoToSurface] Stopped
2023-12-21T19:40:56.605Z,1703187656.605 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2023-12-21T19:40:56.605Z,1703187656.605 [Default:CheckIn] Stopped
2023-12-21T19:40:56.605Z,1703187656.605 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2023-12-21T19:40:56.605Z,1703187656.605 [Default:CheckIn:C.Wait] Stopped
2023-12-21T19:40:56.605Z,1703187656.605 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2023-12-21T19:40:56.605Z,1703187656.605 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test
2023-12-21T19:40:56.605Z,1703187656.605 [senddata_direct_and_track_test] Running Loop=1
2023-12-21T19:40:56.605Z,1703187656.605 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test
2023-12-21T19:40:56.605Z,1703187656.605 [senddata_direct_and_track_test:AbortDrift] Running Loop=1
2023-12-21T19:40:56.606Z,1703187656.606 [senddata_direct_and_track_test:AbortDrift](DEBUG): Aggregate::initialize senddata_direct_and_track_test:AbortDrift
2023-12-21T19:40:56.610Z,1703187656.610 [senddata_direct_and_track_test:AbortDrift:A] Running Loop=1
2023-12-21T19:40:56.610Z,1703187656.610 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-12-21T19:40:56.610Z,1703187656.610 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact.
2023-12-21T19:40:56.610Z,1703187656.610 [senddata_direct_and_track_test:DirectData] Running Loop=1
2023-12-21T19:40:56.611Z,1703187656.611 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-12-21T19:40:56.611Z,1703187656.611 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-12-21T19:40:56.611Z,1703187656.611 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-12-21T19:40:56.611Z,1703187656.611 [senddata_direct_and_track_test:TrackAC.] Running Loop=1
2023-12-21T19:40:56.612Z,1703187656.612 [senddata_direct_and_track_test:AbortDrift] Running Loop=1
2023-12-21T19:40:56.612Z,1703187656.612 [senddata_direct_and_track_test:AbortDrift:A](INFO): Insert acoustic timeout set to 1.000000 h .
2023-12-21T19:40:56.612Z,1703187656.612 [senddata_direct_and_track_test:AbortDrift:A] Stopped
2023-12-21T19:40:56.613Z,1703187656.613 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift] Running Loop=1
2023-12-21T19:40:56.613Z,1703187656.613 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Initializing AbortDrift.
2023-12-21T19:40:56.613Z,1703187656.613 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](IMPORTANT): Acoustic timeout set to: 1.00 hours.
2023-12-21T19:41:04.275Z,1703187664.275 [CommandExec](IMPORTANT): got command show stack
2023-12-21T19:41:04.275Z,1703187664.275 [CommandExec](IMPORTANT): Behavior Stack:

2023-12-21T19:41:04.276Z,1703187664.276 [senddata_direct_and_track_test:AbortDrift](IMPORTANT): Priority 0: senddata_direct_and_track_test:AbortDrift:B.AbortDrift
2023-12-21T19:41:04.276Z,1703187664.276 [senddata_direct_and_track_test](IMPORTANT): Priority 1: senddata_direct_and_track_test:TrackAC.
2023-12-21T19:41:04.276Z,1703187664.276 [senddata_direct_and_track_test:DirectData](IMPORTANT): Priority 2: senddata_direct_and_track_test:DirectData:A.Wait
2023-12-21T19:41:11.944Z,1703187671.944 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:41:12.082Z,1703187672.082 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:41:12.083Z,1703187672.083 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:41:12.083Z,1703187672.083 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:41:12.334Z,1703187672.334 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:12.336Z,1703187672.336 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x29	 xA	 x27A
2023-12-21T19:41:12.336Z,1703187672.336 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:41:12.336Z,1703187672.336 [DATMMP](INFO): Handled
2023-12-21T19:41:14.611Z,1703187674.611 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:14.611Z,1703187674.611 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-12-21T19:41:14.611Z,1703187674.611 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:41:14.612Z,1703187674.612 [DATMMP](INFO): Handled
2023-12-21T19:41:14.863Z,1703187674.863 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:14.864Z,1703187674.864 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x29	 xC	 x3AF
2023-12-21T19:41:14.864Z,1703187674.864 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187681.219136
2023-12-21T19:41:14.865Z,1703187674.865 [DATMMP](INFO): Rx ping set to:1703187674.863683
2023-12-21T19:41:14.865Z,1703187674.865 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:41:14.865Z,1703187674.865 [DATMMP](INFO): Handled
2023-12-21T19:41:15.366Z,1703187675.366 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:15.368Z,1703187675.368 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:41:15.368Z,1703187675.368 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:41:15.369Z,1703187675.369 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:41:15.369Z,1703187675.369 [DATMMP](INFO): Handled
2023-12-21T19:41:15.619Z,1703187675.619 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:15.619Z,1703187675.619 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:41:15.620Z,1703187675.620 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:41:15.620Z,1703187675.620 [DATMMP](INFO): Handled
2023-12-21T19:41:15.871Z,1703187675.871 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:15.872Z,1703187675.872 [DATMMP](INFO): directional_debug rx: 	 xC77	 x26C	 x41	 x8	 x3590	 x2E61	 x2FF2	 x61F3
2023-12-21T19:41:15.873Z,1703187675.873 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:41:15.873Z,1703187675.873 [DATMMP](INFO): Handled
2023-12-21T19:41:16.004Z,1703187676.004 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:41:16.123Z,1703187676.123 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:16.124Z,1703187676.124 [DATMMP](INFO): directional rx: 	 xC67	 x244	 x775	 xFD94	 xAB	 xFD9A	 x0	 x741	 xFFFB	 x4	 x27B5966	 x-43569E0
2023-12-21T19:41:16.126Z,1703187676.126 [DATMMP](INFO): Received message type: directional
2023-12-21T19:41:16.126Z,1703187676.126 [DATMMP](INFO): Handled
2023-12-21T19:41:16.375Z,1703187676.375 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:16.377Z,1703187676.377 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x162	 x2A	 x54	 x10A	 xF6	 xD	 xFFFF	 xE3	 x42	 xD	 x0
2023-12-21T19:41:16.377Z,1703187676.377 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:41:16.377Z,1703187676.377 [DATMMP](INFO): Handled
2023-12-21T19:41:16.445Z,1703187676.445 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:41:16.626Z,1703187676.626 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:16.627Z,1703187676.627 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:41:16.628Z,1703187676.628 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:41:16.628Z,1703187676.628 [DATMMP](INFO): Handled
2023-12-21T19:41:16.629Z,1703187676.629 [DATMMP](INFO): direction in FSK: [0.056535,-0.164188,-0.984808]
2023-12-21T19:41:16.879Z,1703187676.879 [DATMMP](INFO): GSXN notify for xid: 15
2023-12-21T19:41:16.880Z,1703187676.880 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:41:16.880Z,1703187676.880 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:41:16.880Z,1703187676.880 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:41:26.556Z,1703187686.556 [CommandExec](IMPORTANT): got command show variable rangeTo
2023-12-21T19:41:27.305Z,1703187687.305 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:41:27.471Z,1703187687.471 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:41:27.471Z,1703187687.471 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:41:27.471Z,1703187687.471 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:41:27.727Z,1703187687.727 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:27.728Z,1703187687.728 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x29	 x19	 x1219
2023-12-21T19:41:27.728Z,1703187687.728 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:41:27.728Z,1703187687.728 [DATMMP](INFO): Handled
2023-12-21T19:41:30.003Z,1703187690.003 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:30.003Z,1703187690.003 [DATMMP](INFO): doppler rx: 	 x0
2023-12-21T19:41:30.004Z,1703187690.004 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:41:30.004Z,1703187690.004 [DATMMP](INFO): Handled
2023-12-21T19:41:30.255Z,1703187690.255 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:30.256Z,1703187690.256 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x29	 x1B	 x134E
2023-12-21T19:41:30.256Z,1703187690.256 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187735.274432
2023-12-21T19:41:30.257Z,1703187690.257 [DATMMP](INFO): Rx ping set to:1703187690.255841
2023-12-21T19:41:30.257Z,1703187690.257 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:41:30.257Z,1703187690.257 [DATMMP](INFO): Handled
2023-12-21T19:41:30.759Z,1703187690.759 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:30.760Z,1703187690.760 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:41:30.760Z,1703187690.760 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:41:30.761Z,1703187690.761 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:41:30.761Z,1703187690.761 [DATMMP](INFO): Handled
2023-12-21T19:41:31.011Z,1703187691.011 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:31.012Z,1703187691.012 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:41:31.012Z,1703187691.012 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:41:31.012Z,1703187691.012 [DATMMP](INFO): Handled
2023-12-21T19:41:31.263Z,1703187691.263 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:31.264Z,1703187691.264 [DATMMP](INFO): directional_debug rx: 	 x109	 x308	 x40	 x1C	 x2FC0	 x2391	 x2422	 x4BF3
2023-12-21T19:41:31.265Z,1703187691.265 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:41:31.265Z,1703187691.265 [DATMMP](INFO): Handled
2023-12-21T19:41:31.360Z,1703187691.360 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:41:31.515Z,1703187691.515 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:31.516Z,1703187691.516 [DATMMP](INFO): directional rx: 	 x108	 x2F0	 x4D3	 xFCF8	 xC2C	 xFCFA	 x0	 x73A	 xFFF9	 x2	 x27B5966	 x-43569E0
2023-12-21T19:41:31.518Z,1703187691.518 [DATMMP](INFO): Received message type: directional
2023-12-21T19:41:31.518Z,1703187691.518 [DATMMP](INFO): Handled
2023-12-21T19:41:31.765Z,1703187691.765 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:41:31.767Z,1703187691.767 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:31.769Z,1703187691.769 [DATMMP](INFO): acstats rx: 	 xA	 x0	 x0	 x176	 x2B	 x64	 x10B	 xF5	 xD	 xFFFF	 xEC	 x42	 xD	 x0
2023-12-21T19:41:31.769Z,1703187691.769 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:41:31.769Z,1703187691.769 [DATMMP](INFO): Handled
2023-12-21T19:41:32.019Z,1703187692.019 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:32.020Z,1703187692.020 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:41:32.020Z,1703187692.020 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:41:32.020Z,1703187692.020 [DATMMP](INFO): Handled
2023-12-21T19:41:32.021Z,1703187692.021 [DATMMP](INFO): direction in FSK: [-0.506801,0.236325,0.829037]
2023-12-21T19:41:32.271Z,1703187692.271 [DATMMP](INFO): GSXN notify for xid: 16
2023-12-21T19:41:32.272Z,1703187692.272 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:41:32.272Z,1703187692.272 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:41:32.272Z,1703187692.272 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:41:33.372Z,1703187693.372 [CommandExec](IMPORTANT): got command show variable range_to
2023-12-21T19:41:33.790Z,1703187693.790 [CommandExec](IMPORTANT): TrackAcousticContact.range_to_contact (meter)
2023-12-21T19:41:33.791Z,1703187693.791 [CommandExec](IMPORTANT): TrackAcousticContact.horizontal_range_to_contact_lowpass (meter)
2023-12-21T19:41:42.648Z,1703187702.648 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:41:42.859Z,1703187702.859 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:41:42.859Z,1703187702.859 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:41:42.937Z,1703187702.937 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:41:43.111Z,1703187703.111 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:43.112Z,1703187703.112 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x29	 x28	 x21B8
2023-12-21T19:41:43.112Z,1703187703.112 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:41:43.112Z,1703187703.112 [DATMMP](INFO): Handled
2023-12-21T19:41:45.379Z,1703187705.379 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:45.379Z,1703187705.379 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-12-21T19:41:45.379Z,1703187705.379 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:41:45.380Z,1703187705.380 [DATMMP](INFO): Handled
2023-12-21T19:41:45.631Z,1703187705.631 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:45.632Z,1703187705.632 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x29	 x2A	 x22ED
2023-12-21T19:41:45.633Z,1703187705.633 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187725.329728
2023-12-21T19:41:45.633Z,1703187705.633 [DATMMP](INFO): Rx ping set to:1703187705.632092
2023-12-21T19:41:45.633Z,1703187705.633 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:41:45.633Z,1703187705.633 [DATMMP](INFO): Handled
2023-12-21T19:41:46.135Z,1703187706.135 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:46.136Z,1703187706.136 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:41:46.136Z,1703187706.136 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:41:46.136Z,1703187706.136 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:41:46.137Z,1703187706.137 [DATMMP](INFO): Handled
2023-12-21T19:41:46.387Z,1703187706.387 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:46.387Z,1703187706.387 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:41:46.388Z,1703187706.388 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:41:46.388Z,1703187706.388 [DATMMP](INFO): Handled
2023-12-21T19:41:46.639Z,1703187706.639 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:46.640Z,1703187706.640 [DATMMP](INFO): directional_debug rx: 	 x1BD	 x25A	 x40	 x19	 x2F10	 x2471	 x25B2	 x4D73
2023-12-21T19:41:46.641Z,1703187706.641 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:41:46.641Z,1703187706.641 [DATMMP](INFO): Handled
2023-12-21T19:41:46.715Z,1703187706.715 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:41:46.891Z,1703187706.891 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:46.892Z,1703187706.892 [DATMMP](INFO): directional rx: 	 x1BD	 x21E	 x41F	 xFDA6	 xB72	 xFDA4	 x0	 x747	 xFFFA	 x4	 x27B5966	 x-43569E0
2023-12-21T19:41:46.894Z,1703187706.894 [DATMMP](INFO): Received message type: directional
2023-12-21T19:41:46.894Z,1703187706.894 [DATMMP](INFO): Handled
2023-12-21T19:41:47.123Z,1703187707.123 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:41:47.143Z,1703187707.143 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:47.145Z,1703187707.145 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x18B	 x2A	 x65	 x10F	 xF7	 xD	 xFFFF	 xE2	 x42	 xD	 x0
2023-12-21T19:41:47.145Z,1703187707.145 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:41:47.145Z,1703187707.145 [DATMMP](INFO): Handled
2023-12-21T19:41:47.395Z,1703187707.395 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:47.396Z,1703187707.396 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:41:47.396Z,1703187707.396 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:41:47.396Z,1703187707.396 [DATMMP](INFO): Handled
2023-12-21T19:41:47.397Z,1703187707.397 [DATMMP](INFO): direction in FSK: [-0.425486,0.198408,-0.882947]
2023-12-21T19:41:47.647Z,1703187707.647 [DATMMP](INFO): GSXN notify for xid: 17
2023-12-21T19:41:47.648Z,1703187707.648 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:41:47.648Z,1703187707.648 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:41:47.648Z,1703187707.648 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:41:52.527Z,1703187712.527 [CommandExec](IMPORTANT): got command report touch TrackAcousticContact.range_to_contact
2023-12-21T19:41:56.800Z,1703187716.800 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting.
2023-12-21T19:41:56.800Z,1703187716.800 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-12-21T19:41:56.800Z,1703187716.800 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-12-21T19:41:56.800Z,1703187716.800 [senddata_direct_and_track_test:DirectData:B] Running Loop=1
2023-12-21T19:41:57.247Z,1703187717.247 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:10:_.pressure
2023-12-21T19:41:57.247Z,1703187717.247 [senddata_direct_and_track_test:DirectData:B] Stopped
2023-12-21T19:41:57.247Z,1703187717.247 [senddata_direct_and_track_test:DirectData:C] Running Loop=1
2023-12-21T19:41:57.628Z,1703187717.628 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:10:_.temperature
2023-12-21T19:41:57.628Z,1703187717.628 [senddata_direct_and_track_test:DirectData:C] Stopped
2023-12-21T19:41:57.628Z,1703187717.628 [senddata_direct_and_track_test:DirectData:D] Running Loop=1
2023-12-21T19:41:58.032Z,1703187718.032 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:10:_.humidity
2023-12-21T19:41:58.032Z,1703187718.032 [senddata_direct_and_track_test:DirectData:D] Stopped
2023-12-21T19:41:58.032Z,1703187718.032 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData
2023-12-21T19:41:58.032Z,1703187718.032 [senddata_direct_and_track_test:DirectData] Stopped
2023-12-21T19:41:58.032Z,1703187718.032 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-12-21T19:41:58.032Z,1703187718.032 [senddata_direct_and_track_test:DirectData](INFO): Running loop #2
2023-12-21T19:41:58.033Z,1703187718.033 [senddata_direct_and_track_test:DirectData] Running Loop=2
2023-12-21T19:41:58.033Z,1703187718.033 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData
2023-12-21T19:41:58.033Z,1703187718.033 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1
2023-12-21T19:41:58.033Z,1703187718.033 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component.
2023-12-21T19:41:58.033Z,1703187718.033 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:41:58.231Z,1703187718.231 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:41:58.231Z,1703187718.231 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:41:58.231Z,1703187718.231 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:41:58.483Z,1703187718.483 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:41:58.484Z,1703187718.484 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x29	 x38	 x854
2023-12-21T19:41:58.484Z,1703187718.484 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:41:58.484Z,1703187718.484 [DATMMP](INFO): Handled
2023-12-21T19:42:00.751Z,1703187720.751 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:00.751Z,1703187720.751 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-12-21T19:42:00.751Z,1703187720.751 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:42:00.752Z,1703187720.752 [DATMMP](INFO): Handled
2023-12-21T19:42:01.003Z,1703187721.003 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:01.004Z,1703187721.004 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x29	 x3A	 x989
2023-12-21T19:42:01.004Z,1703187721.004 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187741.878592
2023-12-21T19:42:01.005Z,1703187721.005 [DATMMP](INFO): Rx ping set to:1703187721.003728
2023-12-21T19:42:01.005Z,1703187721.005 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:42:01.005Z,1703187721.005 [DATMMP](INFO): Handled
2023-12-21T19:42:01.509Z,1703187721.509 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:01.511Z,1703187721.511 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:42:01.511Z,1703187721.511 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:42:01.512Z,1703187721.512 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:42:01.512Z,1703187721.512 [DATMMP](INFO): Handled
2023-12-21T19:42:01.759Z,1703187721.759 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:01.759Z,1703187721.759 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:42:01.760Z,1703187721.760 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:42:01.760Z,1703187721.760 [DATMMP](INFO): Handled
2023-12-21T19:42:02.011Z,1703187722.011 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:02.012Z,1703187722.012 [DATMMP](INFO): directional_debug rx: 	 x1E4	 x25A	 x41	 x1E	 x3420	 x2921	 x2952	 x5553
2023-12-21T19:42:02.013Z,1703187722.013 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:42:02.013Z,1703187722.013 [DATMMP](INFO): Handled
2023-12-21T19:42:02.081Z,1703187722.081 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:42:02.263Z,1703187722.263 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:02.264Z,1703187722.264 [DATMMP](INFO): directional rx: 	 x1E6	 x21D	 x3F8	 xFDA6	 xB4E	 xFDA4	 x0	 x74C	 xFFFA	 x3	 x27B5966	 x-43569E0
2023-12-21T19:42:02.266Z,1703187722.266 [DATMMP](INFO): Received message type: directional
2023-12-21T19:42:02.266Z,1703187722.266 [DATMMP](INFO): Handled
2023-12-21T19:42:02.469Z,1703187722.469 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:42:02.515Z,1703187722.515 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:02.516Z,1703187722.516 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x149	 x19	 x62	 x112	 xF8	 xD	 xFFFF	 xE1	 x42	 xD	 x0
2023-12-21T19:42:02.517Z,1703187722.517 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:42:02.517Z,1703187722.517 [DATMMP](INFO): Handled
2023-12-21T19:42:02.766Z,1703187722.766 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:02.767Z,1703187722.767 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:42:02.768Z,1703187722.768 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:42:02.768Z,1703187722.768 [DATMMP](INFO): Handled
2023-12-21T19:42:02.769Z,1703187722.769 [DATMMP](INFO): direction in FSK: [-0.205803,0.421958,-0.882947]
2023-12-21T19:42:03.019Z,1703187723.019 [DATMMP](INFO): GSXN notify for xid: 18
2023-12-21T19:42:03.020Z,1703187723.020 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:42:03.020Z,1703187723.020 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:42:03.020Z,1703187723.020 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:42:13.362Z,1703187733.362 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:42:13.602Z,1703187733.602 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:42:13.602Z,1703187733.602 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:42:13.603Z,1703187733.603 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:42:13.855Z,1703187733.855 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:13.859Z,1703187733.859 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x2A	 xB	 x15FF
2023-12-21T19:42:13.860Z,1703187733.860 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:42:13.860Z,1703187733.860 [DATMMP](INFO): Handled
2023-12-21T19:42:16.122Z,1703187736.122 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:16.123Z,1703187736.123 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-12-21T19:42:16.123Z,1703187736.123 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:42:16.123Z,1703187736.123 [DATMMP](INFO): Handled
2023-12-21T19:42:16.375Z,1703187736.375 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:16.376Z,1703187736.376 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x2A	 xD	 x1734
2023-12-21T19:42:16.376Z,1703187736.376 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187791.008192
2023-12-21T19:42:16.377Z,1703187736.377 [DATMMP](INFO): Rx ping set to:1703187736.375691
2023-12-21T19:42:16.377Z,1703187736.377 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:42:16.377Z,1703187736.377 [DATMMP](INFO): Handled
2023-12-21T19:42:16.879Z,1703187736.879 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:16.880Z,1703187736.880 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:42:16.880Z,1703187736.880 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:42:16.880Z,1703187736.880 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:42:16.881Z,1703187736.881 [DATMMP](INFO): Handled
2023-12-21T19:42:17.131Z,1703187737.131 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:17.131Z,1703187737.131 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:42:17.132Z,1703187737.132 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:42:17.132Z,1703187737.132 [DATMMP](INFO): Handled
2023-12-21T19:42:17.385Z,1703187737.385 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:17.386Z,1703187737.386 [DATMMP](INFO): directional_debug rx: 	 x132	 x2CF	 x40	 x1D	 x3120	 x24C1	 x24D2	 x4D73
2023-12-21T19:42:17.387Z,1703187737.387 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:42:17.387Z,1703187737.387 [DATMMP](INFO): Handled
2023-12-21T19:42:17.395Z,1703187737.395 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:42:17.635Z,1703187737.635 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:17.636Z,1703187737.636 [DATMMP](INFO): directional rx: 	 x130	 x2AC	 x4AA	 xFD31	 xC0B	 xFD32	 x0	 x751	 xFFFB	 x2	 x27B5966	 x-43569E0
2023-12-21T19:42:17.638Z,1703187737.638 [DATMMP](INFO): Received message type: directional
2023-12-21T19:42:17.638Z,1703187737.638 [DATMMP](INFO): Handled
2023-12-21T19:42:17.817Z,1703187737.817 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:42:17.887Z,1703187737.887 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:17.888Z,1703187737.888 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x18E	 x17	 x61	 x109	 xF4	 xD	 xFFFF	 xE4	 x42	 xD	 x0
2023-12-21T19:42:17.889Z,1703187737.889 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:42:17.889Z,1703187737.889 [DATMMP](INFO): Handled
2023-12-21T19:42:18.139Z,1703187738.139 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:18.140Z,1703187738.140 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:42:18.140Z,1703187738.140 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:42:18.140Z,1703187738.140 [DATMMP](INFO): Handled
2023-12-21T19:42:18.141Z,1703187738.141 [DATMMP](INFO): direction in FSK: [-0.406675,0.913406,-0.017452]
2023-12-21T19:42:18.390Z,1703187738.390 [DATMMP](INFO): GSXN notify for xid: 19
2023-12-21T19:42:18.391Z,1703187738.391 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:42:18.392Z,1703187738.392 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:42:18.392Z,1703187738.392 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:42:25.559Z,1703187745.559 [CommandExec](IMPORTANT): got command show variable range
2023-12-21T19:42:25.561Z,1703187745.561 [CommandExec](IMPORTANT): acoustic_contact_range (meter)
2023-12-21T19:42:25.586Z,1703187745.586 [CommandExec](IMPORTANT): Docked.dockRange (meter)
2023-12-21T19:42:25.586Z,1703187745.586 [CommandExec](IMPORTANT): Docked.rangeTimeout (second)
2023-12-21T19:42:25.587Z,1703187745.587 [CommandExec](IMPORTANT): LineCapture.terminalRange (meter)
2023-12-21T19:42:25.588Z,1703187745.588 [CommandExec](IMPORTANT): LineCapture.armRange (meter)
2023-12-21T19:42:25.588Z,1703187745.588 [CommandExec](IMPORTANT): LineCapture.lockoutRange (meter)
2023-12-21T19:42:25.588Z,1703187745.588 [CommandExec](IMPORTANT): LineCapture.shortFinalRange (meter)
2023-12-21T19:42:25.631Z,1703187745.631 [CommandExec](IMPORTANT): SetNav.dockRange (meter)
2023-12-21T19:42:25.631Z,1703187745.631 [CommandExec](IMPORTANT): SetNav.rangeTimeout (minute)
2023-12-21T19:42:25.632Z,1703187745.632 [CommandExec](IMPORTANT): Undock.undockRange (meter)
2023-12-21T19:42:25.735Z,1703187745.735 [CommandExec](IMPORTANT): BR_Ping1D.minRange (meter)
2023-12-21T19:42:25.735Z,1703187745.735 [CommandExec](IMPORTANT): BR_Ping1D.maxRange (meter)
2023-12-21T19:42:25.742Z,1703187745.742 [CommandExec](IMPORTANT): Micromodem.rangeTxSeqCode (none)
2023-12-21T19:42:25.742Z,1703187745.742 [CommandExec](IMPORTANT): Micromodem.rangeTxFreq (hertz)
2023-12-21T19:42:25.743Z,1703187745.743 [CommandExec](IMPORTANT): Micromodem.rangeTxTime (millisecond)
2023-12-21T19:42:25.743Z,1703187745.743 [CommandExec](IMPORTANT): Micromodem.rangeRxTime (millisecond)
2023-12-21T19:42:25.744Z,1703187745.744 [CommandExec](IMPORTANT): Micromodem.rangeTAT (millisecond)
2023-12-21T19:42:25.847Z,1703187745.847 [CommandExec](IMPORTANT): DATMMP.acoustic_contact_range (meter)
2023-12-21T19:42:25.919Z,1703187745.919 [CommandExec](IMPORTANT): TrackAcousticContact.range_to_contact (meter)
2023-12-21T19:42:25.920Z,1703187745.920 [CommandExec](IMPORTANT): TrackAcousticContact.horizontal_range_to_contact_lowpass (meter)
2023-12-21T19:42:28.708Z,1703187748.708 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:42:28.730Z,1703187748.730 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:42:28.730Z,1703187748.730 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:42:28.731Z,1703187748.731 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:42:28.983Z,1703187748.983 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:28.984Z,1703187748.984 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x2A	 x1A	 x1BDB
2023-12-21T19:42:28.984Z,1703187748.984 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:42:28.984Z,1703187748.984 [DATMMP](INFO): Handled
2023-12-21T19:42:31.251Z,1703187751.251 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:31.251Z,1703187751.251 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-12-21T19:42:31.251Z,1703187751.251 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:42:31.252Z,1703187751.252 [DATMMP](INFO): Handled
2023-12-21T19:42:31.503Z,1703187751.503 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:31.504Z,1703187751.504 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x2A	 x1C	 x1D0F
2023-12-21T19:42:31.504Z,1703187751.504 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187756.677888
2023-12-21T19:42:31.505Z,1703187751.505 [DATMMP](INFO): Rx ping set to:1703187751.503740
2023-12-21T19:42:31.505Z,1703187751.505 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:42:31.505Z,1703187751.505 [DATMMP](INFO): Handled
2023-12-21T19:42:32.007Z,1703187752.007 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:32.008Z,1703187752.008 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:42:32.008Z,1703187752.008 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:42:32.009Z,1703187752.009 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:42:32.009Z,1703187752.009 [DATMMP](INFO): Handled
2023-12-21T19:42:32.259Z,1703187752.259 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:32.260Z,1703187752.260 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:42:32.260Z,1703187752.260 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:42:32.260Z,1703187752.260 [DATMMP](INFO): Handled
2023-12-21T19:42:32.511Z,1703187752.511 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:32.512Z,1703187752.512 [DATMMP](INFO): directional_debug rx: 	 x1FB	 x2DE	 x40	 x1D	 x31F0	 x24C1	 x26D2	 x4CB3
2023-12-21T19:42:32.513Z,1703187752.513 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:42:32.513Z,1703187752.513 [DATMMP](INFO): Handled
2023-12-21T19:42:32.761Z,1703187752.761 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:42:32.763Z,1703187752.763 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:32.765Z,1703187752.765 [DATMMP](INFO): directional rx: 	 x1FD	 x2BC	 x3E1	 xFD22	 xB49	 xFD1D	 x0	 x752	 xFFFA	 x6	 x27B5966	 x-43569E0
2023-12-21T19:42:32.767Z,1703187752.767 [DATMMP](INFO): Received message type: directional
2023-12-21T19:42:32.767Z,1703187752.767 [DATMMP](INFO): Handled
2023-12-21T19:42:33.014Z,1703187753.014 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:33.017Z,1703187753.017 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x18A	 x2A	 x5F	 x10F	 xF6	 xD	 xFFFF	 xDC	 x42	 xD	 x0
2023-12-21T19:42:33.017Z,1703187753.017 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:42:33.017Z,1703187753.017 [DATMMP](INFO): Handled
2023-12-21T19:42:33.177Z,1703187753.177 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:42:33.267Z,1703187753.267 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:33.268Z,1703187753.268 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:42:33.268Z,1703187753.268 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:42:33.268Z,1703187753.268 [DATMMP](INFO): Handled
2023-12-21T19:42:33.269Z,1703187753.269 [DATMMP](INFO): direction in FSK: [0.050781,-0.968966,0.241922]
2023-12-21T19:42:33.519Z,1703187753.519 [DATMMP](INFO): GSXN notify for xid: 20
2023-12-21T19:42:33.520Z,1703187753.520 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:42:33.520Z,1703187753.520 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:42:33.520Z,1703187753.520 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:42:38.369Z,1703187758.369 [CommandExec](IMPORTANT): got command report touch DATMMP.acoustic_contact_range
2023-12-21T19:42:44.059Z,1703187764.059 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:42:44.102Z,1703187764.102 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:42:44.103Z,1703187764.103 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:42:44.103Z,1703187764.103 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:42:44.355Z,1703187764.355 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:44.356Z,1703187764.356 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x2A	 x2A	 x46A
2023-12-21T19:42:44.356Z,1703187764.356 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:42:44.356Z,1703187764.356 [DATMMP](INFO): Handled
2023-12-21T19:42:46.631Z,1703187766.631 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:46.631Z,1703187766.631 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-12-21T19:42:46.631Z,1703187766.631 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:42:46.632Z,1703187766.632 [DATMMP](INFO): Handled
2023-12-21T19:42:46.883Z,1703187766.883 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:46.884Z,1703187766.884 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x2A	 x2C	 x59F
2023-12-21T19:42:46.884Z,1703187766.884 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187778.055296
2023-12-21T19:42:46.885Z,1703187766.885 [DATMMP](INFO): Rx ping set to:1703187766.883692
2023-12-21T19:42:46.885Z,1703187766.885 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:42:46.885Z,1703187766.885 [DATMMP](INFO): Handled
2023-12-21T19:42:47.387Z,1703187767.387 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:47.388Z,1703187767.388 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:42:47.388Z,1703187767.388 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:42:47.388Z,1703187767.388 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:42:47.389Z,1703187767.389 [DATMMP](INFO): Handled
2023-12-21T19:42:47.639Z,1703187767.639 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:47.639Z,1703187767.639 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:42:47.640Z,1703187767.640 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:42:47.640Z,1703187767.640 [DATMMP](INFO): Handled
2023-12-21T19:42:47.891Z,1703187767.891 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:47.892Z,1703187767.892 [DATMMP](INFO): directional_debug rx: 	 xA2	 x322	 x41	 x1D	 x3230	 x28C1	 x2BB2	 x5613
2023-12-21T19:42:47.893Z,1703187767.893 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:42:47.893Z,1703187767.893 [DATMMP](INFO): Handled
2023-12-21T19:42:48.131Z,1703187768.131 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:42:48.143Z,1703187768.143 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:48.144Z,1703187768.144 [DATMMP](INFO): directional rx: 	 xA0	 x310	 x53A	 xFCDE	 xCAC	 xFCDF	 x0	 x748	 xFFFB	 x5	 x27B5966	 x-43569E0
2023-12-21T19:42:48.146Z,1703187768.146 [DATMMP](INFO): Received message type: directional
2023-12-21T19:42:48.146Z,1703187768.146 [DATMMP](INFO): Handled
2023-12-21T19:42:48.395Z,1703187768.395 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:48.396Z,1703187768.396 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x18A	 x18	 x5E	 x111	 xF7	 xD	 xFFFF	 xD6	 x42	 xC	 x0
2023-12-21T19:42:48.397Z,1703187768.397 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:42:48.397Z,1703187768.397 [DATMMP](INFO): Handled
2023-12-21T19:42:48.529Z,1703187768.529 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187712.00. Resetting abort timer.
2023-12-21T19:42:48.647Z,1703187768.647 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:48.648Z,1703187768.648 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:42:48.648Z,1703187768.648 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:42:48.648Z,1703187768.648 [DATMMP](INFO): Handled
2023-12-21T19:42:48.649Z,1703187768.649 [DATMMP](INFO): direction in FSK: [-0.028936,-0.136132,0.990268]
2023-12-21T19:42:48.899Z,1703187768.899 [DATMMP](INFO): GSXN notify for xid: 21
2023-12-21T19:42:48.900Z,1703187768.900 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:42:48.900Z,1703187768.900 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:42:48.900Z,1703187768.900 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:42:48.987Z,1703187768.987 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m
2023-12-21T19:42:58.607Z,1703187778.606 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting.
2023-12-21T19:42:58.607Z,1703187778.607 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped
2023-12-21T19:42:58.607Z,1703187778.607 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component.
2023-12-21T19:42:58.607Z,1703187778.607 [senddata_direct_and_track_test:DirectData:B] Running Loop=1
2023-12-21T19:42:59.015Z,1703187779.015 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:10:_.pressure
2023-12-21T19:42:59.015Z,1703187779.015 [senddata_direct_and_track_test:DirectData:B] Stopped
2023-12-21T19:42:59.015Z,1703187779.015 [senddata_direct_and_track_test:DirectData:C] Running Loop=1
2023-12-21T19:42:59.412Z,1703187779.412 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:10:_.temperature
2023-12-21T19:42:59.412Z,1703187779.412 [senddata_direct_and_track_test:DirectData:C] Stopped
2023-12-21T19:42:59.412Z,1703187779.412 [senddata_direct_and_track_test:DirectData:D] Running Loop=1
2023-12-21T19:42:59.413Z,1703187779.413 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:42:59.486Z,1703187779.486 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:42:59.487Z,1703187779.487 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:42:59.487Z,1703187779.487 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:42:59.738Z,1703187779.738 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:42:59.740Z,1703187779.740 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x2A	 x39	 x1215
2023-12-21T19:42:59.740Z,1703187779.740 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:42:59.740Z,1703187779.740 [DATMMP](INFO): Handled
2023-12-21T19:42:59.861Z,1703187779.861 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:10:_.humidity
2023-12-21T19:42:59.861Z,1703187779.861 [senddata_direct_and_track_test:DirectData:D] Stopped
2023-12-21T19:42:59.862Z,1703187779.862 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData
2023-12-21T19:42:59.866Z,1703187779.866 [senddata_direct_and_track_test:DirectData] Stopped
2023-12-21T19:42:59.866Z,1703187779.866 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData
2023-12-21T19:42:59.866Z,1703187779.866 [senddata_direct_and_track_test:D.Wait] Running Loop=1
2023-12-21T19:42:59.866Z,1703187779.866 [senddata_direct_and_track_test:D.Wait](DEBUG): Initialize Wait Component.
2023-12-21T19:43:02.006Z,1703187782.006 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:02.007Z,1703187782.007 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-12-21T19:43:02.007Z,1703187782.007 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:43:02.007Z,1703187782.007 [DATMMP](INFO): Handled
2023-12-21T19:43:02.259Z,1703187782.259 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:02.260Z,1703187782.260 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x2A	 x3B	 x134A
2023-12-21T19:43:02.260Z,1703187782.260 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187827.233472
2023-12-21T19:43:02.261Z,1703187782.261 [DATMMP](INFO): Rx ping set to:1703187782.259754
2023-12-21T19:43:02.261Z,1703187782.261 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:43:02.261Z,1703187782.261 [DATMMP](INFO): Handled
2023-12-21T19:43:02.763Z,1703187782.763 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:02.764Z,1703187782.764 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:43:02.765Z,1703187782.765 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:43:02.765Z,1703187782.765 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:43:02.765Z,1703187782.765 [DATMMP](INFO): Handled
2023-12-21T19:43:03.015Z,1703187783.015 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:03.015Z,1703187783.015 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:43:03.016Z,1703187783.016 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:43:03.016Z,1703187783.016 [DATMMP](INFO): Handled
2023-12-21T19:43:03.267Z,1703187783.267 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:03.268Z,1703187783.268 [DATMMP](INFO): directional_debug rx: 	 x5AC	 x2E3	 x41	 x14	 x3710	 x2841	 x2B32	 x5923
2023-12-21T19:43:03.269Z,1703187783.269 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:43:03.269Z,1703187783.269 [DATMMP](INFO): Handled
2023-12-21T19:43:03.468Z,1703187783.468 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187840.00. Resetting abort timer.
2023-12-21T19:43:03.519Z,1703187783.519 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:03.520Z,1703187783.520 [DATMMP](INFO): directional rx: 	 x596	 x2B1	 x30	 xFD1D	 x754	 xFD18	 x0	 x72E	 xFFFC	 x3	 x27B5966	 x-43569E0
2023-12-21T19:43:03.522Z,1703187783.522 [DATMMP](INFO): Received message type: directional
2023-12-21T19:43:03.522Z,1703187783.522 [DATMMP](INFO): Handled
2023-12-21T19:43:03.771Z,1703187783.771 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:03.772Z,1703187783.772 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x18A	 x17	 x5F	 x10C	 xF8	 xD	 xFFFF	 xE1	 x42	 xD	 x0
2023-12-21T19:43:03.773Z,1703187783.773 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:43:03.773Z,1703187783.773 [DATMMP](INFO): Handled
2023-12-21T19:43:03.857Z,1703187783.857 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187840.00. Resetting abort timer.
2023-12-21T19:43:04.023Z,1703187784.023 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:04.024Z,1703187784.024 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:43:04.024Z,1703187784.024 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:43:04.024Z,1703187784.024 [DATMMP](INFO): Handled
2023-12-21T19:43:04.025Z,1703187784.025 [DATMMP](INFO): direction in FSK: [0.632675,0.702657,0.325569]
2023-12-21T19:43:04.275Z,1703187784.275 [DATMMP](INFO): GSXN notify for xid: 22
2023-12-21T19:43:04.276Z,1703187784.276 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:43:04.276Z,1703187784.276 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:43:04.276Z,1703187784.276 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:43:04.277Z,1703187784.277 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m
2023-12-21T19:43:14.767Z,1703187794.767 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:43:14.858Z,1703187794.858 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:43:14.859Z,1703187794.859 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:43:14.859Z,1703187794.859 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:43:15.111Z,1703187795.111 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:15.112Z,1703187795.112 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x2B	 xC	 x21B5
2023-12-21T19:43:15.112Z,1703187795.112 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:43:15.112Z,1703187795.112 [DATMMP](INFO): Handled
2023-12-21T19:43:17.379Z,1703187797.379 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:17.379Z,1703187797.379 [DATMMP](INFO): doppler rx: 	 x0
2023-12-21T19:43:17.379Z,1703187797.379 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:43:17.380Z,1703187797.380 [DATMMP](INFO): Handled
2023-12-21T19:43:17.631Z,1703187797.631 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:17.632Z,1703187797.632 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x2B	 xE	 x22E9
2023-12-21T19:43:17.632Z,1703187797.632 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187817.288768
2023-12-21T19:43:17.633Z,1703187797.633 [DATMMP](INFO): Rx ping set to:1703187797.631729
2023-12-21T19:43:17.633Z,1703187797.633 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:43:17.633Z,1703187797.633 [DATMMP](INFO): Handled
2023-12-21T19:43:18.135Z,1703187798.135 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:18.136Z,1703187798.136 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:43:18.136Z,1703187798.136 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:43:18.136Z,1703187798.136 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:43:18.137Z,1703187798.137 [DATMMP](INFO): Handled
2023-12-21T19:43:18.386Z,1703187798.386 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:18.387Z,1703187798.387 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:43:18.387Z,1703187798.387 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:43:18.388Z,1703187798.388 [DATMMP](INFO): Handled
2023-12-21T19:43:18.639Z,1703187798.639 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:18.640Z,1703187798.640 [DATMMP](INFO): directional_debug rx: 	 x102	 x2F8	 x40	 x1D	 x2ED0	 x2441	 x2672	 x4CD3
2023-12-21T19:43:18.641Z,1703187798.641 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:43:18.641Z,1703187798.641 [DATMMP](INFO): Handled
2023-12-21T19:43:18.845Z,1703187798.845 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187840.00. Resetting abort timer.
2023-12-21T19:43:18.891Z,1703187798.891 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:18.892Z,1703187798.892 [DATMMP](INFO): directional rx: 	 x100	 x2DE	 x4DA	 xFD08	 xC20	 xFD06	 x0	 x72E	 xFFFC	 x5	 x27B5966	 x-43569E0
2023-12-21T19:43:18.894Z,1703187798.894 [DATMMP](INFO): Received message type: directional
2023-12-21T19:43:18.894Z,1703187798.894 [DATMMP](INFO): Handled
2023-12-21T19:43:19.142Z,1703187799.142 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:19.144Z,1703187799.144 [DATMMP](INFO): acstats rx: 	 xA	 x0	 x0	 x18A	 x2A	 x62	 x10A	 xF7	 xD	 xFFFF	 xE3	 x42	 xD	 x0
2023-12-21T19:43:19.145Z,1703187799.145 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:43:19.145Z,1703187799.145 [DATMMP](INFO): Handled
2023-12-21T19:43:19.256Z,1703187799.256 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187840.00. Resetting abort timer.
2023-12-21T19:43:19.395Z,1703187799.395 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:19.396Z,1703187799.396 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:43:19.396Z,1703187799.396 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:43:19.396Z,1703187799.396 [DATMMP](INFO): Handled
2023-12-21T19:43:19.397Z,1703187799.397 [DATMMP](INFO): direction in FSK: [-0.728551,0.236721,0.642788]
2023-12-21T19:43:19.647Z,1703187799.647 [DATMMP](INFO): GSXN notify for xid: 23
2023-12-21T19:43:19.648Z,1703187799.648 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:43:19.648Z,1703187799.648 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:43:19.648Z,1703187799.648 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:43:19.649Z,1703187799.649 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m
2023-12-21T19:43:30.112Z,1703187810.112 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:43:30.230Z,1703187810.230 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:43:30.231Z,1703187810.231 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:43:30.231Z,1703187810.231 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:43:30.483Z,1703187810.483 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:30.484Z,1703187810.484 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x2B	 x1C	 x850
2023-12-21T19:43:30.484Z,1703187810.484 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:43:30.484Z,1703187810.484 [DATMMP](INFO): Handled
2023-12-21T19:43:32.751Z,1703187812.751 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:32.751Z,1703187812.751 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-12-21T19:43:32.751Z,1703187812.751 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:43:32.752Z,1703187812.752 [DATMMP](INFO): Handled
2023-12-21T19:43:33.003Z,1703187813.003 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:33.004Z,1703187813.004 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x2B	 x1E	 x985
2023-12-21T19:43:33.004Z,1703187813.004 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187833.837632
2023-12-21T19:43:33.005Z,1703187813.005 [DATMMP](INFO): Rx ping set to:1703187813.003755
2023-12-21T19:43:33.005Z,1703187813.005 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:43:33.005Z,1703187813.005 [DATMMP](INFO): Handled
2023-12-21T19:43:33.506Z,1703187813.506 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:33.508Z,1703187813.508 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:43:33.508Z,1703187813.508 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:43:33.508Z,1703187813.508 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:43:33.508Z,1703187813.508 [DATMMP](INFO): Handled
2023-12-21T19:43:33.759Z,1703187813.759 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:33.759Z,1703187813.759 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:43:33.760Z,1703187813.760 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:43:33.760Z,1703187813.760 [DATMMP](INFO): Handled
2023-12-21T19:43:34.011Z,1703187814.011 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:34.012Z,1703187814.012 [DATMMP](INFO): directional_debug rx: 	 x82	 x31F	 x41	 x1A	 x3340	 x28B1	 x28D2	 x54F3
2023-12-21T19:43:34.013Z,1703187814.013 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:43:34.013Z,1703187814.013 [DATMMP](INFO): Handled
2023-12-21T19:43:34.163Z,1703187814.163 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187840.00. Resetting abort timer.
2023-12-21T19:43:34.263Z,1703187814.263 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:34.264Z,1703187814.264 [DATMMP](INFO): directional rx: 	 x81	 x30D	 x55A	 xFCE1	 xCBC	 xFCE3	 x0	 x73E	 xFFFA	 x4	 x27B5966	 x-43569E0
2023-12-21T19:43:34.266Z,1703187814.266 [DATMMP](INFO): Received message type: directional
2023-12-21T19:43:34.266Z,1703187814.266 [DATMMP](INFO): Handled
2023-12-21T19:43:34.515Z,1703187814.515 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:34.516Z,1703187814.516 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x15D	 x18	 x62	 x115	 xF7	 xD	 xFFFF	 xE8	 x42	 xD	 x0
2023-12-21T19:43:34.517Z,1703187814.517 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:43:34.517Z,1703187814.517 [DATMMP](INFO): Handled
2023-12-21T19:43:34.608Z,1703187814.608 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187840.00. Resetting abort timer.
2023-12-21T19:43:34.767Z,1703187814.767 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:34.768Z,1703187814.768 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:43:34.768Z,1703187814.768 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:43:34.768Z,1703187814.768 [DATMMP](INFO): Handled
2023-12-21T19:43:34.769Z,1703187814.769 [DATMMP](INFO): direction in FSK: [0.065260,-0.179302,0.981627]
2023-12-21T19:43:34.000Z,1703187815.000 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m
2023-12-21T19:43:35.019Z,1703187815.019 [DATMMP](INFO): GSXN notify for xid: 24
2023-12-21T19:43:35.020Z,1703187815.020 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:43:35.020Z,1703187815.020 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:43:35.020Z,1703187815.020 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:43:36.186Z,1703187816.186 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2023-12-21T19:43:36.186Z,1703187816.186 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-21T19:43:36.199Z,1703187816.199 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-21T19:43:36.583Z,1703187816.583 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-21T19:43:36.584Z,1703187816.584 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2023-12-21T19:43:45.471Z,1703187825.471 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact ***
2023-12-21T19:43:45.603Z,1703187825.603 [DATMMP](INFO): ****** received valid address query ******
2023-12-21T19:43:45.603Z,1703187825.603 [DATMMP](INFO): ****** received valid ping request ******
2023-12-21T19:43:45.606Z,1703187825.606 [DATMMP](INFO): Querying Benthos address 10
2023-12-21T19:43:45.855Z,1703187825.855 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:45.856Z,1703187825.856 [DATMMP](INFO): timestamp rx: 	 x0	 x13	 x2B	 x2B	 x17EF
2023-12-21T19:43:45.856Z,1703187825.856 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:43:45.856Z,1703187825.856 [DATMMP](INFO): Handled
2023-12-21T19:43:48.123Z,1703187828.123 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:48.123Z,1703187828.123 [DATMMP](INFO): doppler rx: 	 xFFFF
2023-12-21T19:43:48.123Z,1703187828.123 [DATMMP](INFO): Received message type: doppler
2023-12-21T19:43:48.123Z,1703187828.123 [DATMMP](INFO): Handled
2023-12-21T19:43:48.375Z,1703187828.375 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:48.376Z,1703187828.376 [DATMMP](INFO): timestamp rx: 	 x1	 x13	 x2B	 x2D	 x1924
2023-12-21T19:43:48.376Z,1703187828.376 [DATMMP](INFO): Rx dataTimestamp_ set to:1703187887.892928
2023-12-21T19:43:48.376Z,1703187828.376 [DATMMP](INFO): Rx ping set to:1703187828.375655
2023-12-21T19:43:48.377Z,1703187828.377 [DATMMP](INFO): Received message type: timestamp
2023-12-21T19:43:48.377Z,1703187828.377 [DATMMP](INFO): Handled
2023-12-21T19:43:48.879Z,1703187828.879 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:48.880Z,1703187828.880 [DATMMP](INFO): remote_header rx: 	 x4	 x0	 x5	 x20	 x0	 xC	 xA	 x0
2023-12-21T19:43:48.880Z,1703187828.880 [DATMMP](INFO): DATA Src=10, Dst=12
2023-12-21T19:43:48.881Z,1703187828.881 [DATMMP](INFO): Received message type: remote_header
2023-12-21T19:43:48.881Z,1703187828.881 [DATMMP](INFO): Handled
2023-12-21T19:43:49.131Z,1703187829.131 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:49.131Z,1703187829.131 [DATMMP](INFO): nav_stat rx: 	 x0	 x1	 x1
2023-12-21T19:43:49.132Z,1703187829.132 [DATMMP](INFO): Received message type: nav_stat
2023-12-21T19:43:49.132Z,1703187829.132 [DATMMP](INFO): Handled
2023-12-21T19:43:49.383Z,1703187829.383 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:49.384Z,1703187829.384 [DATMMP](INFO): directional_debug rx: 	 xBF	 x26F	 x42	 x12	 x39B0	 x2E11	 x31F2	 x5F63
2023-12-21T19:43:49.385Z,1703187829.385 [DATMMP](INFO): Received message type: directional_debug
2023-12-21T19:43:49.385Z,1703187829.385 [DATMMP](INFO): Handled
2023-12-21T19:43:49.521Z,1703187829.521 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187840.00. Resetting abort timer.
2023-12-21T19:43:49.635Z,1703187829.635 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:49.636Z,1703187829.636 [DATMMP](INFO): directional rx: 	 xBB	 x23B	 x51D	 xFD91	 xC70	 xFD91	 x0	 x745	 xFFFB	 x5	 x27B5966	 x-43569E0
2023-12-21T19:43:49.638Z,1703187829.638 [DATMMP](INFO): Received message type: directional
2023-12-21T19:43:49.638Z,1703187829.638 [DATMMP](INFO): Handled
2023-12-21T19:43:49.890Z,1703187829.890 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:49.892Z,1703187829.892 [DATMMP](INFO): acstats rx: 	 xA	 x0	 xFFFF	 x17E	 x20	 x63	 x112	 xF8	 xD	 xFFFF	 xE6	 x42	 xD	 x0
2023-12-21T19:43:49.893Z,1703187829.893 [DATMMP](INFO): Received message type: acstats
2023-12-21T19:43:49.893Z,1703187829.893 [DATMMP](INFO): Handled
2023-12-21T19:43:49.950Z,1703187829.950 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703187840.00. Resetting abort timer.
2023-12-21T19:43:50.143Z,1703187830.143 [DATMMP](INFO): GSXN notify for xid: 0
2023-12-21T19:43:50.144Z,1703187830.144 [DATMMP](INFO): range_update rx: 	 xA	 x2	 xC	 x11
2023-12-21T19:43:50.144Z,1703187830.144 [DATMMP](INFO): Received message type: range_update
2023-12-21T19:43:50.144Z,1703187830.144 [DATMMP](INFO): Handled
2023-12-21T19:43:50.145Z,1703187830.145 [DATMMP](INFO): direction in FSK: [0.079953,0.091976,-0.992546]
2023-12-21T19:43:50.355Z,1703187830.355 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m
2023-12-21T19:43:50.395Z,1703187830.395 [DATMMP](INFO): GSXN notify for xid: 25
2023-12-21T19:43:50.396Z,1703187830.396 [DATMMP](INFO): cmd_result rx: 	 x2	 x1A	 x0	 x4
2023-12-21T19:43:50.396Z,1703187830.396 [DATMMP](DEBUG): Command complete rang
2023-12-21T19:43:50.396Z,1703187830.396 [DATMMP](ERROR): 4:COMPLETE
2023-12-21T19:44:00.415Z,1703187840.415 [senddata_direct_and_track_test:D.Wait](INFO): Done Waiting.
2023-12-21T19:44:00.415Z,1703187840.415 [senddata_direct_and_track_test:D.Wait] Stopped
2023-12-21T19:44:00.415Z,1703187840.415 [senddata_direct_and_track_test:D.Wait](DEBUG): Uninitialize Wait Component.
2023-12-21T19:44:00.416Z,1703187840.416 [senddata_direct_and_track_test](INFO): Completed senddata_direct_and_track_test
2023-12-21T19:44:00.416Z,1703187840.416 [MissionManager](INFO): senddata_direct_and_track_test is completed.
2023-12-21T19:44:00.416Z,1703187840.416 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test
2023-12-21T19:44:00.416Z,1703187840.416 [senddata_direct_and_track_test] Stopped
2023-12-21T19:44:00.416Z,1703187840.416 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test
2023-12-21T19:44:00.416Z,1703187840.416 [senddata_direct_and_track_test:AbortDrift] Stopped
2023-12-21T19:44:00.417Z,1703187840.417 [senddata_direct_and_track_test:AbortDrift](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:AbortDrift
2023-12-21T19:44:00.417Z,1703187840.417 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift] Stopped
2023-12-21T19:44:00.417Z,1703187840.417 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Uninitializing AbortDrift.
2023-12-21T19:44:00.417Z,1703187840.417 [senddata_direct_and_track_test:TrackAC.] Stopped
2023-12-21T19:44:00.417Z,1703187840.417 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact.
2023-12-21T19:44:00.820Z,1703187840.820 [MissionManager](IMPORTANT): Started mission Default
2023-12-21T19:44:00.820Z,1703187840.820 [Default] Running Loop=1
2023-12-21T19:44:00.820Z,1703187840.820 [Default](DEBUG): Aggregate::initialize Default
2023-12-21T19:44:00.820Z,1703187840.820 [Default:B.GoToSurface] Running Loop=1
2023-12-21T19:44:00.820Z,1703187840.820 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2023-12-21T19:44:00.821Z,1703187840.821 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2023-12-21T19:44:00.821Z,1703187840.821 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2023-12-21T19:44:00.821Z,1703187840.821 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2023-12-21T19:44:00.822Z,1703187840.822 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2023-12-21T19:44:00.822Z,1703187840.822 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2023-12-21T19:44:00.823Z,1703187840.823 [Default:A.Wait] Running Loop=1
2023-12-21T19:44:00.823Z,1703187840.823 [Default:A.Wait](DEBUG): Initialize Wait Component.
2023-12-21T19:44:14.187Z,1703187854.187 [Default:A.Wait](INFO): Done Waiting.
2023-12-21T19:44:14.187Z,1703187854.187 [Default:A.Wait] Stopped
2023-12-21T19:44:14.187Z,1703187854.187 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2023-12-21T19:44:14.583Z,1703187854.583 [Default:CheckIn] Running Loop=1
2023-12-21T19:44:14.584Z,1703187854.584 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2023-12-21T19:44:14.584Z,1703187854.584 [Default:CheckIn:Read_GPS] Running Loop=1
2023-12-21T19:46:37.169Z,1703187997.169 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2023-12-21T19:46:37.169Z,1703187997.169 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2023-12-21T19:46:37.180Z,1703187997.180 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2023-12-21T19:46:37.597Z,1703187997.597 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2023-12-21T19:46:37.597Z,1703187997.597 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6