2023-12-21T20:39:39.415Z,1703191179.415 [CommandExec](IMPORTANT): got command restart logs 2023-12-21T20:39:55.756Z,1703191195.756 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml 2023-12-21T20:39:55.757Z,1703191195.757 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml 2023-12-21T20:39:55.861Z,1703191195.861 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 10.000000 count 2023-12-21T20:39:55.864Z,1703191195.864 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m 2023-12-21T20:39:55.896Z,1703191195.896 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s 2023-12-21T20:39:55.907Z,1703191195.907 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count 2023-12-21T20:39:55.910Z,1703191195.910 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count 2023-12-21T20:39:55.912Z,1703191195.912 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count 2023-12-21T20:39:55.915Z,1703191195.915 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.BeingInterrogatedTimeout = 1.000000 h 2023-12-21T20:39:55.917Z,1703191195.917 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min 2023-12-21T20:39:55.929Z,1703191195.929 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum 2023-12-21T20:39:55.952Z,1703191195.952 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum 2023-12-21T20:39:55.966Z,1703191195.966 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum 2023-12-21T20:39:55.967Z,1703191195.967 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/AbortDrift.tl 2023-12-21T20:39:55.967Z,1703191195.967 [MissionManager](IMPORTANT): Loading Compiled TethysL script from file Missions/Insert/AbortDrift.tx 2023-12-21T20:39:56.074Z,1703191196.074 [MissionManager](INFO): DefineArg senddata_direct_and_track_test:AbortDrift.AcousticTimeout = 96.000000 h 2023-12-21T20:39:56.076Z,1703191196.076 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](DEBUG): Construct AbortDrift. 2023-12-21T20:39:56.082Z,1703191196.082 [senddata_direct_and_track_test:AbortDrift:C.Execute](DEBUG): Construct Execute. 2023-12-21T20:39:56.084Z,1703191196.084 [MissionManager](INFO): RedefineArg senddata_direct_and_track_test:AbortDrift.AcousticTimeout = reader:senddata_direct_and_track_test.BeingInterrogatedTimeout 2023-12-21T20:39:56.114Z,1703191196.114 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait. 2023-12-21T20:39:56.132Z,1703191196.132 [senddata_direct_and_track_test:D.Wait](DEBUG): Construct Wait. 2023-12-21T20:39:56.149Z,1703191196.149 [MissionManager](DEBUG): The acoustic address of the asset to be tracked. 21 is waveglider Tiny 10 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. 0 How long to wait between acoustic queries 15 Number of return pings to request with each acoustic query (more than 1 will activate oneway mode) 1 Number of fixes to average to produce smoothed lat/lon/dep output 2 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. 2 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. 1 1 Modem ID1. 9 Modem ID2. 5 Modem ID. Set to modemId1 or modemId2. Initialized to 1. 1 2023-12-21T20:39:56.151Z,1703191196.151 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml 2023-12-21T20:39:56.229Z,1703191196.229 [Default] Stopped 2023-12-21T20:39:56.229Z,1703191196.229 [Default](DEBUG): Aggregate::uninitialize Default 2023-12-21T20:39:56.229Z,1703191196.229 [Default:B.GoToSurface] Stopped 2023-12-21T20:39:56.229Z,1703191196.229 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-12-21T20:39:56.229Z,1703191196.229 [Default:CheckIn] Stopped 2023-12-21T20:39:56.229Z,1703191196.229 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-12-21T20:39:56.229Z,1703191196.229 [Default:CheckIn:Read_GPS] Stopped 2023-12-21T20:39:56.229Z,1703191196.229 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test 2023-12-21T20:39:56.230Z,1703191196.230 [senddata_direct_and_track_test] Running Loop=1 2023-12-21T20:39:56.230Z,1703191196.230 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test 2023-12-21T20:39:56.230Z,1703191196.230 [senddata_direct_and_track_test:AbortDrift] Running Loop=1 2023-12-21T20:39:56.230Z,1703191196.230 [senddata_direct_and_track_test:AbortDrift](DEBUG): Aggregate::initialize senddata_direct_and_track_test:AbortDrift 2023-12-21T20:39:56.230Z,1703191196.230 [senddata_direct_and_track_test:AbortDrift:A] Running Loop=1 2023-12-21T20:39:56.230Z,1703191196.230 [senddata_direct_and_track_test:TrackAC.] Running Loop=1 2023-12-21T20:39:56.230Z,1703191196.230 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact. 2023-12-21T20:39:56.231Z,1703191196.231 [senddata_direct_and_track_test:DirectData] Running Loop=1 2023-12-21T20:39:56.231Z,1703191196.231 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData 2023-12-21T20:39:56.231Z,1703191196.231 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1 2023-12-21T20:39:56.231Z,1703191196.231 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component. 2023-12-21T20:39:56.231Z,1703191196.231 [senddata_direct_and_track_test:TrackAC.] Running Loop=1 2023-12-21T20:39:56.232Z,1703191196.232 [senddata_direct_and_track_test:AbortDrift] Running Loop=1 2023-12-21T20:39:56.232Z,1703191196.232 [senddata_direct_and_track_test:AbortDrift:A](INFO): Insert acoustic timeout set to 1.000000 h . 2023-12-21T20:39:56.232Z,1703191196.232 [senddata_direct_and_track_test:AbortDrift:A] Stopped 2023-12-21T20:39:56.233Z,1703191196.233 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift] Running Loop=1 2023-12-21T20:39:56.233Z,1703191196.233 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Initializing AbortDrift. 2023-12-21T20:39:56.233Z,1703191196.233 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](IMPORTANT): Acoustic timeout set to: 1.00 hours. 2023-12-21T20:39:56.631Z,1703191196.631 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191168.00. Resetting abort timer. 2023-12-21T20:40:11.573Z,1703191211.573 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:40:11.818Z,1703191211.818 [DATMMP](INFO): ****** received valid address query ****** 2023-12-21T20:40:11.819Z,1703191211.819 [DATMMP](INFO): ****** received valid ping request ****** 2023-12-21T20:40:11.819Z,1703191211.819 [DATMMP](INFO): Querying Benthos address 10 2023-12-21T20:40:12.071Z,1703191212.071 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:12.072Z,1703191212.072 [DATMMP](INFO): timestamp rx: x0 x14 x28 x9 x1F34 2023-12-21T20:40:12.072Z,1703191212.072 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:40:12.072Z,1703191212.072 [DATMMP](INFO): Handled 2023-12-21T20:40:14.338Z,1703191214.338 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:14.339Z,1703191214.339 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:40:14.339Z,1703191214.339 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:40:14.339Z,1703191214.339 [DATMMP](INFO): Handled 2023-12-21T20:40:14.591Z,1703191214.591 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:14.592Z,1703191214.592 [DATMMP](INFO): timestamp rx: x1 x14 x28 xB x2068 2023-12-21T20:40:14.592Z,1703191214.592 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191228.016384 2023-12-21T20:40:14.592Z,1703191214.592 [DATMMP](INFO): Rx ping set to:1703191214.591699 2023-12-21T20:40:14.593Z,1703191214.593 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:40:14.593Z,1703191214.593 [DATMMP](INFO): Handled 2023-12-21T20:40:15.095Z,1703191215.095 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:15.096Z,1703191215.096 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-12-21T20:40:15.096Z,1703191215.096 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:40:15.096Z,1703191215.096 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:40:15.097Z,1703191215.097 [DATMMP](INFO): Handled 2023-12-21T20:40:15.347Z,1703191215.347 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:15.347Z,1703191215.347 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:40:15.348Z,1703191215.348 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:40:15.348Z,1703191215.348 [DATMMP](INFO): Handled 2023-12-21T20:40:15.599Z,1703191215.599 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:15.600Z,1703191215.600 [DATMMP](INFO): directional_debug rx: x219 x1D5 x43 x11 x3C30 x2D31 x2E32 x61F3 2023-12-21T20:40:15.601Z,1703191215.601 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:40:15.601Z,1703191215.601 [DATMMP](INFO): Handled 2023-12-21T20:40:15.629Z,1703191215.629 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191168.00. Resetting abort timer. 2023-12-21T20:40:15.851Z,1703191215.851 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:15.852Z,1703191215.852 [DATMMP](INFO): directional rx: x222 x17F x3C3 xFE2B xB25 xFE29 x0 x75D xFFFC x2 x27B5966 x-43569E0 2023-12-21T20:40:15.854Z,1703191215.854 [DATMMP](INFO): Received message type: directional 2023-12-21T20:40:15.854Z,1703191215.854 [DATMMP](INFO): Handled 2023-12-21T20:40:16.045Z,1703191216.045 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191168.00. Resetting abort timer. 2023-12-21T20:40:16.103Z,1703191216.103 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:16.105Z,1703191216.105 [DATMMP](INFO): acstats rx: xA x0 xFFFF x18A x2A x64 x116 xF7 xD xFFFF xD9 x42 xD x0 2023-12-21T20:40:16.105Z,1703191216.105 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:40:16.105Z,1703191216.105 [DATMMP](INFO): Handled 2023-12-21T20:40:16.355Z,1703191216.355 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:16.356Z,1703191216.356 [DATMMP](INFO): range_update rx: xA x2 xC x11 2023-12-21T20:40:16.356Z,1703191216.356 [DATMMP](INFO): Received message type: range_update 2023-12-21T20:40:16.356Z,1703191216.356 [DATMMP](INFO): Handled 2023-12-21T20:40:16.357Z,1703191216.357 [DATMMP](INFO): direction in FSK: [0.147805,0.290084,0.945518] 2023-12-21T20:40:16.512Z,1703191216.512 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m 2023-12-21T20:40:16.607Z,1703191216.607 [DATMMP](INFO): GSXN notify for xid: 55 2023-12-21T20:40:16.608Z,1703191216.608 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-12-21T20:40:16.608Z,1703191216.608 [DATMMP](DEBUG): Command complete rang 2023-12-21T20:40:16.608Z,1703191216.608 [DATMMP](ERROR): 4:COMPLETE 2023-12-21T20:40:26.928Z,1703191226.928 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:40:26.943Z,1703191226.943 [DATMMP](INFO): ****** received valid address query ****** 2023-12-21T20:40:26.943Z,1703191226.943 [DATMMP](INFO): ****** received valid ping request ****** 2023-12-21T20:40:26.943Z,1703191226.943 [DATMMP](INFO): Querying Benthos address 10 2023-12-21T20:40:27.195Z,1703191227.195 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:27.196Z,1703191227.196 [DATMMP](INFO): timestamp rx: x0 x14 x28 x18 x250F 2023-12-21T20:40:27.196Z,1703191227.196 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:40:27.196Z,1703191227.196 [DATMMP](INFO): Handled 2023-12-21T20:40:29.463Z,1703191229.463 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:29.463Z,1703191229.463 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:40:29.463Z,1703191229.463 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:40:29.464Z,1703191229.464 [DATMMP](INFO): Handled 2023-12-21T20:40:29.715Z,1703191229.715 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:29.716Z,1703191229.716 [DATMMP](INFO): timestamp rx: x1 x14 x28 x1A x2643 2023-12-21T20:40:29.716Z,1703191229.716 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191257.686080 2023-12-21T20:40:29.717Z,1703191229.717 [DATMMP](INFO): Rx ping set to:1703191229.715789 2023-12-21T20:40:29.717Z,1703191229.717 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:40:29.717Z,1703191229.717 [DATMMP](INFO): Handled 2023-12-21T20:40:30.219Z,1703191230.219 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:30.220Z,1703191230.220 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-12-21T20:40:30.220Z,1703191230.220 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:40:30.220Z,1703191230.220 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:40:30.220Z,1703191230.220 [DATMMP](INFO): Handled 2023-12-21T20:40:30.471Z,1703191230.471 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:30.471Z,1703191230.471 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:40:30.472Z,1703191230.472 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:40:30.472Z,1703191230.472 [DATMMP](INFO): Handled 2023-12-21T20:40:30.725Z,1703191230.725 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:30.726Z,1703191230.726 [DATMMP](INFO): directional_debug rx: x1A0 x25A x42 xE x3CB0 x2E61 x2FA2 x60C3 2023-12-21T20:40:30.727Z,1703191230.727 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:40:30.727Z,1703191230.727 [DATMMP](INFO): Handled 2023-12-21T20:40:30.975Z,1703191230.975 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:30.977Z,1703191230.977 [DATMMP](INFO): directional rx: x19E x21D x43C xFDA6 xB9D xFDA7 x0 x757 xFFFA x2 x27B5966 x-43569E0 2023-12-21T20:40:30.979Z,1703191230.979 [DATMMP](INFO): Received message type: directional 2023-12-21T20:40:30.979Z,1703191230.979 [DATMMP](INFO): Handled 2023-12-21T20:40:31.140Z,1703191231.140 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191168.00. Resetting abort timer. 2023-12-21T20:40:31.227Z,1703191231.227 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:31.228Z,1703191231.228 [DATMMP](INFO): acstats rx: xA x0 xFFFF x18D x20 x64 x113 xF6 xD xFFFF xD9 x42 xD x0 2023-12-21T20:40:31.229Z,1703191231.229 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:40:31.229Z,1703191231.229 [DATMMP](INFO): Handled 2023-12-21T20:40:31.479Z,1703191231.479 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:31.479Z,1703191231.479 [DATMMP](INFO): range_update rx: xA x2 xC x11 2023-12-21T20:40:31.480Z,1703191231.480 [DATMMP](INFO): Received message type: range_update 2023-12-21T20:40:31.480Z,1703191231.480 [DATMMP](INFO): Handled 2023-12-21T20:40:31.481Z,1703191231.481 [DATMMP](INFO): direction in FSK: [-0.468328,-0.032749,-0.882947] 2023-12-21T20:40:31.731Z,1703191231.731 [DATMMP](INFO): GSXN notify for xid: 56 2023-12-21T20:40:31.731Z,1703191231.731 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-12-21T20:40:31.732Z,1703191231.732 [DATMMP](DEBUG): Command complete rang 2023-12-21T20:40:31.732Z,1703191231.732 [DATMMP](ERROR): 4:COMPLETE 2023-12-21T20:40:31.835Z,1703191231.835 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m 2023-12-21T20:40:42.284Z,1703191242.284 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:40:42.314Z,1703191242.314 [DATMMP](INFO): ****** received valid address query ****** 2023-12-21T20:40:42.315Z,1703191242.315 [DATMMP](INFO): ****** received valid ping request ****** 2023-12-21T20:40:42.315Z,1703191242.315 [DATMMP](INFO): Querying Benthos address 10 2023-12-21T20:40:42.567Z,1703191242.567 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:42.568Z,1703191242.568 [DATMMP](INFO): timestamp rx: x0 x14 x28 x28 xBAB 2023-12-21T20:40:42.568Z,1703191242.568 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:40:42.568Z,1703191242.568 [DATMMP](INFO): Handled 2023-12-21T20:40:44.835Z,1703191244.835 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:44.835Z,1703191244.835 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:40:44.835Z,1703191244.835 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:40:44.836Z,1703191244.836 [DATMMP](INFO): Handled 2023-12-21T20:40:45.087Z,1703191245.087 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:45.088Z,1703191245.088 [DATMMP](INFO): timestamp rx: x1 x14 x28 x2A xCDF 2023-12-21T20:40:45.088Z,1703191245.088 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191274.186368 2023-12-21T20:40:45.089Z,1703191245.089 [DATMMP](INFO): Rx ping set to:1703191245.087857 2023-12-21T20:40:45.089Z,1703191245.089 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:40:45.089Z,1703191245.089 [DATMMP](INFO): Handled 2023-12-21T20:40:45.591Z,1703191245.591 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:45.592Z,1703191245.592 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-12-21T20:40:45.592Z,1703191245.592 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:40:45.592Z,1703191245.592 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:40:45.593Z,1703191245.593 [DATMMP](INFO): Handled 2023-12-21T20:40:45.843Z,1703191245.843 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:45.843Z,1703191245.843 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:40:45.844Z,1703191245.844 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:40:45.844Z,1703191245.844 [DATMMP](INFO): Handled 2023-12-21T20:40:46.095Z,1703191246.095 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:46.096Z,1703191246.096 [DATMMP](INFO): directional_debug rx: x106 x236 x41 x11 x35D0 x2B21 x2B32 x58F3 2023-12-21T20:40:46.097Z,1703191246.097 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:40:46.097Z,1703191246.097 [DATMMP](INFO): Handled 2023-12-21T20:40:46.309Z,1703191246.309 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:40:46.347Z,1703191246.347 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:46.348Z,1703191246.348 [DATMMP](INFO): directional rx: x102 x1F5 x4D6 xFDCA xC29 xFDC9 x0 x74C xFFFD x4 x27B5966 x-43569E0 2023-12-21T20:40:46.350Z,1703191246.350 [DATMMP](INFO): Received message type: directional 2023-12-21T20:40:46.350Z,1703191246.350 [DATMMP](INFO): Handled 2023-12-21T20:40:46.599Z,1703191246.599 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:46.601Z,1703191246.601 [DATMMP](INFO): acstats rx: xA x0 xFFFF x18C x18 x62 x110 xF6 xD xFFFF xDE x42 xD x0 2023-12-21T20:40:46.601Z,1703191246.601 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:40:46.601Z,1703191246.601 [DATMMP](INFO): Handled 2023-12-21T20:40:46.716Z,1703191246.716 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:40:46.851Z,1703191246.851 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:46.851Z,1703191246.851 [DATMMP](INFO): range_update rx: xA x2 xC x11 2023-12-21T20:40:46.852Z,1703191246.852 [DATMMP](INFO): Received message type: range_update 2023-12-21T20:40:46.852Z,1703191246.852 [DATMMP](INFO): Handled 2023-12-21T20:40:46.853Z,1703191246.853 [DATMMP](INFO): direction in FSK: [0.833347,-0.336694,-0.438371] 2023-12-21T20:40:47.103Z,1703191247.103 [DATMMP](INFO): GSXN notify for xid: 57 2023-12-21T20:40:47.104Z,1703191247.104 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-12-21T20:40:47.104Z,1703191247.104 [DATMMP](DEBUG): Command complete rang 2023-12-21T20:40:47.104Z,1703191247.104 [DATMMP](ERROR): 4:COMPLETE 2023-12-21T20:40:47.180Z,1703191247.180 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m 2023-12-21T20:40:55.204Z,1703191255.204 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24 2023-12-21T20:40:55.204Z,1703191255.204 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault 2023-12-21T20:40:55.214Z,1703191255.214 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources 2023-12-21T20:40:55.621Z,1703191255.621 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources 2023-12-21T20:40:55.621Z,1703191255.621 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24 2023-12-21T20:40:56.459Z,1703191256.459 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting. 2023-12-21T20:40:56.459Z,1703191256.459 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped 2023-12-21T20:40:56.460Z,1703191256.460 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component. 2023-12-21T20:40:56.460Z,1703191256.460 [senddata_direct_and_track_test:DirectData:B] Running Loop=1 2023-12-21T20:40:56.820Z,1703191256.820 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:10:_.pressure 2023-12-21T20:40:56.820Z,1703191256.820 [senddata_direct_and_track_test:DirectData:B] Stopped 2023-12-21T20:40:56.820Z,1703191256.820 [senddata_direct_and_track_test:DirectData:C] Running Loop=1 2023-12-21T20:40:56.930Z,1703191256.930 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-12-21T20:40:56.931Z,1703191256.931 [DATMMP](INFO): modem://10: set _.pressure 1.010992 atmosphere 2023-12-21T20:40:56.932Z,1703191256.932 [DATMMP](INFO): #Outgoing data=1 2023-12-21T20:40:56.932Z,1703191256.932 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-12-21T20:40:57.182Z,1703191257.182 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-12-21T20:40:57.182Z,1703191257.182 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-12-21T20:40:57.235Z,1703191257.235 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:10:_.temperature 2023-12-21T20:40:57.235Z,1703191257.235 [senddata_direct_and_track_test:DirectData:C] Stopped 2023-12-21T20:40:57.235Z,1703191257.235 [senddata_direct_and_track_test:DirectData:D] Running Loop=1 2023-12-21T20:40:57.434Z,1703191257.434 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-12-21T20:40:57.435Z,1703191257.435 [DATMMP](INFO): Tx to 10 len 34 xid 58 2023-12-21T20:40:57.435Z,1703191257.435 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-12-21T20:40:57.436Z,1703191257.436 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:40:57.687Z,1703191257.687 [DATMMP](INFO): GSXN notify for xid: 58 2023-12-21T20:40:57.687Z,1703191257.687 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-12-21T20:40:57.688Z,1703191257.688 [DATMMP](DEBUG): Command complete send 2023-12-21T20:40:57.688Z,1703191257.688 [DATMMP](ERROR): 1:COMPLETE 2023-12-21T20:40:57.688Z,1703191257.688 [DATMMP](INFO): Received message type: cmd_result 2023-12-21T20:40:57.688Z,1703191257.688 [DATMMP](INFO): Handled 2023-12-21T20:40:57.688Z,1703191257.688 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:40:57.690Z,1703191257.690 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:10:_.humidity 2023-12-21T20:40:57.690Z,1703191257.690 [senddata_direct_and_track_test:DirectData:D] Stopped 2023-12-21T20:40:57.690Z,1703191257.690 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData 2023-12-21T20:40:57.691Z,1703191257.691 [senddata_direct_and_track_test:DirectData] Stopped 2023-12-21T20:40:57.691Z,1703191257.691 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData 2023-12-21T20:40:57.691Z,1703191257.691 [senddata_direct_and_track_test:DirectData](INFO): Running loop #2 2023-12-21T20:40:57.691Z,1703191257.691 [senddata_direct_and_track_test:DirectData] Running Loop=2 2023-12-21T20:40:57.691Z,1703191257.691 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData 2023-12-21T20:40:57.691Z,1703191257.691 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1 2023-12-21T20:40:57.691Z,1703191257.691 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component. 2023-12-21T20:40:57.692Z,1703191257.692 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:40:57.939Z,1703191257.939 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:40:57.940Z,1703191257.940 [DATMMP](INFO): timestamp rx: x0 x14 x28 x37 x136E 2023-12-21T20:40:57.940Z,1703191257.940 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:40:57.940Z,1703191257.940 [DATMMP](INFO): Handled 2023-12-21T20:40:57.940Z,1703191257.940 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:40:58.190Z,1703191258.190 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:40:58.442Z,1703191258.442 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:40:58.694Z,1703191258.694 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:40:58.946Z,1703191258.946 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:40:59.198Z,1703191259.198 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:40:59.450Z,1703191259.450 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:40:59.702Z,1703191259.702 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:40:59.954Z,1703191259.954 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:00.207Z,1703191260.207 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:00.458Z,1703191260.458 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:00.710Z,1703191260.710 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:00.962Z,1703191260.962 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:01.214Z,1703191261.214 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:01.466Z,1703191261.466 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:01.718Z,1703191261.718 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:01.971Z,1703191261.971 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:02.223Z,1703191262.223 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:02.223Z,1703191262.223 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:41:02.224Z,1703191262.224 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:41:02.224Z,1703191262.224 [DATMMP](INFO): Handled 2023-12-21T20:41:02.224Z,1703191262.224 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:02.474Z,1703191262.474 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:02.475Z,1703191262.475 [DATMMP](INFO): timestamp rx: x1 x14 x28 x3B x182F 2023-12-21T20:41:02.476Z,1703191262.476 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191319.481280 2023-12-21T20:41:02.476Z,1703191262.476 [DATMMP](INFO): Rx ping set to:1703191262.475543 2023-12-21T20:41:02.477Z,1703191262.477 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:02.477Z,1703191262.477 [DATMMP](INFO): Handled 2023-12-21T20:41:02.477Z,1703191262.477 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:02.727Z,1703191262.727 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:02.728Z,1703191262.728 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-12-21T20:41:02.728Z,1703191262.728 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:41:02.728Z,1703191262.728 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:41:02.729Z,1703191262.729 [DATMMP](INFO): Handled 2023-12-21T20:41:02.729Z,1703191262.729 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:02.979Z,1703191262.979 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:02.979Z,1703191262.979 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:41:02.980Z,1703191262.980 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:41:02.980Z,1703191262.980 [DATMMP](INFO): Handled 2023-12-21T20:41:02.980Z,1703191262.980 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:03.231Z,1703191263.231 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:03.232Z,1703191263.232 [DATMMP](INFO): directional_debug rx: x202 x2C0 x3F x18 x3C60 x3921 x3552 x5773 2023-12-21T20:41:03.233Z,1703191263.233 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:41:03.233Z,1703191263.233 [DATMMP](INFO): Handled 2023-12-21T20:41:03.233Z,1703191263.233 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:03.292Z,1703191263.292 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:03.483Z,1703191263.483 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:03.484Z,1703191263.484 [DATMMP](INFO): directional rx: x205 x298 x3DA xFD40 xB3F xFD3E x0 x753 xFFFA x4 x27B5966 x-43569E0 2023-12-21T20:41:03.486Z,1703191263.486 [DATMMP](INFO): Received message type: directional 2023-12-21T20:41:03.486Z,1703191263.486 [DATMMP](INFO): Handled 2023-12-21T20:41:03.487Z,1703191263.487 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:03.711Z,1703191263.711 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:03.735Z,1703191263.735 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:03.736Z,1703191263.736 [DATMMP](INFO): acstats rx: xA x5 xFFFF x185 x29 x52 x10E x100 xE xFFFF xCB x43 xD x0 2023-12-21T20:41:03.737Z,1703191263.737 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:41:03.737Z,1703191263.737 [DATMMP](INFO): Handled 2023-12-21T20:41:03.737Z,1703191263.737 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:03.987Z,1703191263.987 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:03.988Z,1703191263.988 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-12-21T20:41:03.988Z,1703191263.988 [DATMMP](INFO): Check CRC 2023-12-21T20:41:03.988Z,1703191263.988 [DATMMP](INFO): data rx parseDataResponse 4 2023-12-21T20:41:03.988Z,1703191263.988 [DATMMP](INFO): Got DATA: len 4 2023-12-21T20:41:03.988Z,1703191263.988 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-12-21T20:41:03.988Z,1703191263.988 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-12-21T20:41:03.989Z,1703191263.989 [DATMMP](INFO): Received command: 2023-12-21T20:41:03.989Z,1703191263.989 [DATMMP](INFO): Received message type: data_rx 2023-12-21T20:41:03.989Z,1703191263.989 [DATMMP](INFO): Handled 2023-12-21T20:41:03.989Z,1703191263.989 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-12-21T20:41:03.989Z,1703191263.989 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-12-21T20:41:04.238Z,1703191264.238 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-12-21T20:41:04.239Z,1703191264.239 [DATMMP](INFO): modem://10: set _.temperature 24.340143 celsius 2023-12-21T20:41:04.240Z,1703191264.240 [DATMMP](INFO): #Outgoing data=1 2023-12-21T20:41:04.240Z,1703191264.240 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-12-21T20:41:04.491Z,1703191264.491 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-12-21T20:41:04.491Z,1703191264.491 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-12-21T20:41:04.742Z,1703191264.742 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-12-21T20:41:04.743Z,1703191264.743 [DATMMP](INFO): Tx to 10 len 35 xid 59 2023-12-21T20:41:04.743Z,1703191264.743 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-12-21T20:41:04.744Z,1703191264.744 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:41:04.995Z,1703191264.995 [DATMMP](INFO): GSXN notify for xid: 59 2023-12-21T20:41:04.995Z,1703191264.995 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-12-21T20:41:04.996Z,1703191264.996 [DATMMP](DEBUG): Command complete send 2023-12-21T20:41:04.996Z,1703191264.996 [DATMMP](ERROR): 1:COMPLETE 2023-12-21T20:41:04.996Z,1703191264.996 [DATMMP](INFO): Received message type: cmd_result 2023-12-21T20:41:04.996Z,1703191264.996 [DATMMP](INFO): Handled 2023-12-21T20:41:04.996Z,1703191264.996 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:05.246Z,1703191265.246 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:05.248Z,1703191265.248 [DATMMP](INFO): timestamp rx: x0 x14 x29 x2 x1F26 2023-12-21T20:41:05.248Z,1703191265.248 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:05.248Z,1703191265.248 [DATMMP](INFO): Handled 2023-12-21T20:41:05.248Z,1703191265.248 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:05.498Z,1703191265.498 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:05.750Z,1703191265.750 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:06.002Z,1703191266.002 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:06.254Z,1703191266.254 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:06.507Z,1703191266.507 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:06.758Z,1703191266.758 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:07.010Z,1703191267.010 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:07.262Z,1703191267.262 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:07.514Z,1703191267.514 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:07.766Z,1703191267.766 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:08.018Z,1703191268.018 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:08.270Z,1703191268.270 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:08.522Z,1703191268.522 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:08.774Z,1703191268.774 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:09.026Z,1703191269.026 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:09.278Z,1703191269.278 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:09.531Z,1703191269.531 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:09.531Z,1703191269.531 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:41:09.531Z,1703191269.531 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:41:09.532Z,1703191269.532 [DATMMP](INFO): Handled 2023-12-21T20:41:09.532Z,1703191269.532 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:09.783Z,1703191269.783 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:09.784Z,1703191269.784 [DATMMP](INFO): timestamp rx: x1 x14 x29 x6 x23E7 2023-12-21T20:41:09.784Z,1703191269.784 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191291.792576 2023-12-21T20:41:09.784Z,1703191269.784 [DATMMP](INFO): Rx ping set to:1703191269.783624 2023-12-21T20:41:09.785Z,1703191269.785 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:09.785Z,1703191269.785 [DATMMP](INFO): Handled 2023-12-21T20:41:09.785Z,1703191269.785 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:10.035Z,1703191270.035 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:10.036Z,1703191270.036 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-12-21T20:41:10.036Z,1703191270.036 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:41:10.036Z,1703191270.036 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:41:10.037Z,1703191270.037 [DATMMP](INFO): Handled 2023-12-21T20:41:10.037Z,1703191270.037 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:10.287Z,1703191270.287 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:10.287Z,1703191270.287 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:41:10.288Z,1703191270.288 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:41:10.288Z,1703191270.288 [DATMMP](INFO): Handled 2023-12-21T20:41:10.288Z,1703191270.288 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:10.539Z,1703191270.539 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:10.540Z,1703191270.540 [DATMMP](INFO): directional_debug rx: x7E x2AC x3F x9 x4550 x3FF1 x3A62 x6A23 2023-12-21T20:41:10.541Z,1703191270.541 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:41:10.541Z,1703191270.541 [DATMMP](INFO): Handled 2023-12-21T20:41:10.541Z,1703191270.541 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:10.601Z,1703191270.601 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:10.791Z,1703191270.791 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:10.792Z,1703191270.792 [DATMMP](INFO): directional rx: x7A x286 x55E xFD54 xCC0 xFD56 x0 x753 xFFFA x3 x27B5966 x-43569E0 2023-12-21T20:41:10.794Z,1703191270.794 [DATMMP](INFO): Received message type: directional 2023-12-21T20:41:10.794Z,1703191270.794 [DATMMP](INFO): Handled 2023-12-21T20:41:10.794Z,1703191270.794 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:11.022Z,1703191271.022 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:11.042Z,1703191271.042 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:11.044Z,1703191271.044 [DATMMP](INFO): acstats rx: xA x5 xFFFF x137 x29 x51 x103 x108 xE xFFFF xC5 x42 xD x0 2023-12-21T20:41:11.045Z,1703191271.045 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:41:11.045Z,1703191271.045 [DATMMP](INFO): Handled 2023-12-21T20:41:11.045Z,1703191271.045 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:11.295Z,1703191271.295 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:11.295Z,1703191271.295 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-12-21T20:41:11.296Z,1703191271.296 [DATMMP](INFO): Check CRC 2023-12-21T20:41:11.296Z,1703191271.296 [DATMMP](INFO): data rx parseDataResponse 4 2023-12-21T20:41:11.296Z,1703191271.296 [DATMMP](INFO): Got DATA: len 4 2023-12-21T20:41:11.296Z,1703191271.296 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-12-21T20:41:11.296Z,1703191271.296 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-12-21T20:41:11.296Z,1703191271.296 [DATMMP](INFO): Received command: 2023-12-21T20:41:11.297Z,1703191271.297 [DATMMP](INFO): Received message type: data_rx 2023-12-21T20:41:11.297Z,1703191271.297 [DATMMP](INFO): Handled 2023-12-21T20:41:11.297Z,1703191271.297 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-12-21T20:41:11.297Z,1703191271.297 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-12-21T20:41:11.546Z,1703191271.546 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-12-21T20:41:11.547Z,1703191271.547 [DATMMP](INFO): modem://10: set _.humidity 41.991211 percent 2023-12-21T20:41:11.548Z,1703191271.548 [DATMMP](INFO): #Outgoing data=1 2023-12-21T20:41:11.548Z,1703191271.548 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-12-21T20:41:11.798Z,1703191271.798 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-12-21T20:41:11.799Z,1703191271.799 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-12-21T20:41:12.050Z,1703191272.050 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-12-21T20:41:12.051Z,1703191272.051 [DATMMP](INFO): Tx to 10 len 32 xid 60 2023-12-21T20:41:12.051Z,1703191272.051 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-12-21T20:41:12.052Z,1703191272.052 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:41:12.303Z,1703191272.303 [DATMMP](INFO): GSXN notify for xid: 60 2023-12-21T20:41:12.303Z,1703191272.303 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-12-21T20:41:12.304Z,1703191272.304 [DATMMP](DEBUG): Command complete send 2023-12-21T20:41:12.304Z,1703191272.304 [DATMMP](ERROR): 1:COMPLETE 2023-12-21T20:41:12.304Z,1703191272.304 [DATMMP](INFO): Received message type: cmd_result 2023-12-21T20:41:12.304Z,1703191272.304 [DATMMP](INFO): Handled 2023-12-21T20:41:12.304Z,1703191272.304 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:12.557Z,1703191272.557 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:12.558Z,1703191272.558 [DATMMP](INFO): timestamp rx: x0 x14 x29 xA x3CE 2023-12-21T20:41:12.559Z,1703191272.559 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:12.559Z,1703191272.559 [DATMMP](INFO): Handled 2023-12-21T20:41:12.559Z,1703191272.559 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:12.806Z,1703191272.806 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:12.984Z,1703191272.984 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:41:13.058Z,1703191273.058 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:13.059Z,1703191273.059 [DATMMP](INFO): ****** received valid address query ****** 2023-12-21T20:41:13.059Z,1703191273.059 [DATMMP](INFO): ****** received valid ping request ****** 2023-12-21T20:41:13.059Z,1703191273.059 [DATMMP](INFO): Querying Benthos address 10 2023-12-21T20:41:13.311Z,1703191273.311 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:13.312Z,1703191273.312 [DATMMP](INFO): timestamp rx: x0 x14 x29 xB x1E6 2023-12-21T20:41:13.312Z,1703191273.312 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:13.312Z,1703191273.312 [DATMMP](INFO): Handled 2023-12-21T20:41:13.312Z,1703191273.312 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:13.562Z,1703191273.562 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:13.814Z,1703191273.814 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:14.066Z,1703191274.066 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:14.318Z,1703191274.318 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:14.570Z,1703191274.570 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:14.822Z,1703191274.822 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:15.074Z,1703191275.074 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:15.327Z,1703191275.327 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:15.579Z,1703191275.579 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:15.830Z,1703191275.830 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:16.082Z,1703191276.082 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:16.335Z,1703191276.335 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:16.335Z,1703191276.335 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:41:16.335Z,1703191276.335 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:41:16.336Z,1703191276.336 [DATMMP](INFO): Handled 2023-12-21T20:41:16.336Z,1703191276.336 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:16.587Z,1703191276.587 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:16.588Z,1703191276.588 [DATMMP](INFO): timestamp rx: x1 x14 x29 xD x1FDA 2023-12-21T20:41:16.588Z,1703191276.588 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191288.659456 2023-12-21T20:41:16.588Z,1703191276.588 [DATMMP](INFO): Rx ping set to:1703191276.587620 2023-12-21T20:41:16.589Z,1703191276.589 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:16.589Z,1703191276.589 [DATMMP](INFO): Handled 2023-12-21T20:41:16.589Z,1703191276.589 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:16.838Z,1703191276.838 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:17.091Z,1703191277.091 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:17.092Z,1703191277.092 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-12-21T20:41:17.092Z,1703191277.092 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:41:17.092Z,1703191277.092 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:41:17.092Z,1703191277.092 [DATMMP](INFO): Handled 2023-12-21T20:41:17.093Z,1703191277.093 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:17.343Z,1703191277.343 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:17.343Z,1703191277.343 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:41:17.344Z,1703191277.344 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:41:17.344Z,1703191277.344 [DATMMP](INFO): Handled 2023-12-21T20:41:17.344Z,1703191277.344 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:17.595Z,1703191277.595 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:17.596Z,1703191277.596 [DATMMP](INFO): directional_debug rx: x136 x280 x40 x10 x3E60 x37D1 x3652 x6363 2023-12-21T20:41:17.597Z,1703191277.597 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:41:17.597Z,1703191277.597 [DATMMP](INFO): Handled 2023-12-21T20:41:17.597Z,1703191277.597 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:17.831Z,1703191277.831 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:17.847Z,1703191277.847 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:17.848Z,1703191277.848 [DATMMP](INFO): directional rx: x133 x24C x4A6 xFD80 xC07 xFD80 x0 x753 xFFFA x4 x27B5966 x-43569E0 2023-12-21T20:41:17.850Z,1703191277.850 [DATMMP](INFO): Received message type: directional 2023-12-21T20:41:17.850Z,1703191277.850 [DATMMP](INFO): Handled 2023-12-21T20:41:17.850Z,1703191277.850 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:18.099Z,1703191278.099 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:18.101Z,1703191278.101 [DATMMP](INFO): acstats rx: xA x0 xFFFF x187 x29 x51 x10E xF4 xD xFFFF xEF x42 xD x0 2023-12-21T20:41:18.101Z,1703191278.101 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:41:18.101Z,1703191278.101 [DATMMP](INFO): Handled 2023-12-21T20:41:18.101Z,1703191278.101 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:18.236Z,1703191278.236 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:18.351Z,1703191278.351 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:18.352Z,1703191278.352 [DATMMP](INFO): range_update rx: xA x2 x159C x1CD0 2023-12-21T20:41:18.352Z,1703191278.352 [DATMMP](INFO): Received message type: range_update 2023-12-21T20:41:18.352Z,1703191278.352 [DATMMP](INFO): Handled 2023-12-21T20:41:18.352Z,1703191278.352 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:18.353Z,1703191278.353 [DATMMP](INFO): direction in FSK: [-0.059391,0.163176,-0.984808] 2023-12-21T20:41:18.603Z,1703191278.603 [DATMMP](INFO): GSXN notify for xid: 61 2023-12-21T20:41:18.604Z,1703191278.604 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-12-21T20:41:18.604Z,1703191278.604 [DATMMP](DEBUG): Command complete rang 2023-12-21T20:41:18.604Z,1703191278.604 [DATMMP](ERROR): 4:COMPLETE 2023-12-21T20:41:18.604Z,1703191278.604 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:18.694Z,1703191278.694 [Reporter](INFO): DATMMP.acoustic_contact_range 553.200012 m 2023-12-21T20:41:18.855Z,1703191278.855 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:18.855Z,1703191278.855 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:41:18.855Z,1703191278.855 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:41:18.856Z,1703191278.856 [DATMMP](INFO): Handled 2023-12-21T20:41:18.856Z,1703191278.856 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:19.107Z,1703191279.107 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:19.108Z,1703191279.108 [DATMMP](INFO): timestamp rx: x1 x14 x29 xF xACE 2023-12-21T20:41:19.108Z,1703191279.108 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191302.012288 2023-12-21T20:41:19.108Z,1703191279.108 [DATMMP](INFO): Rx ping set to:1703191279.107673 2023-12-21T20:41:19.109Z,1703191279.109 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:19.109Z,1703191279.109 [DATMMP](INFO): Handled 2023-12-21T20:41:19.109Z,1703191279.109 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:19.359Z,1703191279.359 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:19.360Z,1703191279.360 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-12-21T20:41:19.361Z,1703191279.361 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:41:19.361Z,1703191279.361 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:41:19.361Z,1703191279.361 [DATMMP](INFO): Handled 2023-12-21T20:41:19.361Z,1703191279.361 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:19.611Z,1703191279.611 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:19.611Z,1703191279.611 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:41:19.612Z,1703191279.612 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:41:19.612Z,1703191279.612 [DATMMP](INFO): Handled 2023-12-21T20:41:19.612Z,1703191279.612 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:19.863Z,1703191279.863 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:19.864Z,1703191279.864 [DATMMP](INFO): directional_debug rx: xF8 x1DC x3F xB x3630 x28A1 x2662 x55F3 2023-12-21T20:41:19.865Z,1703191279.865 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:41:19.865Z,1703191279.865 [DATMMP](INFO): Handled 2023-12-21T20:41:19.865Z,1703191279.865 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:20.115Z,1703191280.115 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:20.116Z,1703191280.116 [DATMMP](INFO): directional rx: xF2 x18B x4E4 xFE24 xC40 xFE23 x0 x753 xFFFA x5 x27B5966 x-43569E0 2023-12-21T20:41:20.118Z,1703191280.118 [DATMMP](INFO): Received message type: directional 2023-12-21T20:41:20.118Z,1703191280.118 [DATMMP](INFO): Handled 2023-12-21T20:41:20.118Z,1703191280.118 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:20.244Z,1703191280.244 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:20.367Z,1703191280.367 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:20.369Z,1703191280.369 [DATMMP](INFO): acstats rx: xA x5 xFFFF x2D0 x2A x56 xF8 x105 xD xFFFF xD6 x42 xD x0 2023-12-21T20:41:20.369Z,1703191280.369 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:41:20.369Z,1703191280.369 [DATMMP](INFO): Handled 2023-12-21T20:41:20.369Z,1703191280.369 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:20.623Z,1703191280.623 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:20.624Z,1703191280.624 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-12-21T20:41:20.624Z,1703191280.624 [DATMMP](INFO): Check CRC 2023-12-21T20:41:20.624Z,1703191280.624 [DATMMP](INFO): data rx parseDataResponse 4 2023-12-21T20:41:20.624Z,1703191280.624 [DATMMP](INFO): Got DATA: len 4 2023-12-21T20:41:20.624Z,1703191280.624 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-12-21T20:41:20.625Z,1703191280.625 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-12-21T20:41:20.625Z,1703191280.625 [DATMMP](INFO): Received command: 2023-12-21T20:41:20.625Z,1703191280.625 [DATMMP](INFO): Received message type: data_rx 2023-12-21T20:41:20.625Z,1703191280.625 [DATMMP](INFO): Handled 2023-12-21T20:41:20.625Z,1703191280.625 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-12-21T20:41:20.625Z,1703191280.625 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-12-21T20:41:22.644Z,1703191282.644 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-12-21T20:41:28.334Z,1703191288.334 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:41:28.443Z,1703191288.443 [DATMMP](INFO): ****** received valid address query ****** 2023-12-21T20:41:28.443Z,1703191288.443 [DATMMP](INFO): ****** received valid ping request ****** 2023-12-21T20:41:28.443Z,1703191288.443 [DATMMP](INFO): Querying Benthos address 10 2023-12-21T20:41:28.695Z,1703191288.695 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:28.696Z,1703191288.696 [DATMMP](INFO): timestamp rx: x0 x14 x29 x1A x1185 2023-12-21T20:41:28.696Z,1703191288.696 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:28.696Z,1703191288.696 [DATMMP](INFO): Handled 2023-12-21T20:41:29.511Z,1703191289.511 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-12-21T20:41:30.967Z,1703191290.967 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:30.967Z,1703191290.967 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:41:30.968Z,1703191290.968 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:41:30.968Z,1703191290.968 [DATMMP](INFO): Handled 2023-12-21T20:41:31.219Z,1703191291.219 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:31.220Z,1703191291.220 [DATMMP](INFO): timestamp rx: x1 x14 x29 x1C x12B9 2023-12-21T20:41:31.220Z,1703191291.220 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191334.845824 2023-12-21T20:41:31.221Z,1703191291.221 [DATMMP](INFO): Rx ping set to:1703191291.219907 2023-12-21T20:41:31.221Z,1703191291.221 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:31.221Z,1703191291.221 [DATMMP](INFO): Handled 2023-12-21T20:41:31.723Z,1703191291.723 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:31.724Z,1703191291.724 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-12-21T20:41:31.724Z,1703191291.724 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:41:31.725Z,1703191291.725 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:41:31.725Z,1703191291.725 [DATMMP](INFO): Handled 2023-12-21T20:41:31.983Z,1703191291.983 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:31.983Z,1703191291.983 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:41:31.984Z,1703191291.984 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:41:31.984Z,1703191291.984 [DATMMP](INFO): Handled 2023-12-21T20:41:32.235Z,1703191292.235 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:32.236Z,1703191292.236 [DATMMP](INFO): directional_debug rx: x3F0 x322 x3F x12 x42F0 x3FD1 x3B22 x6BF3 2023-12-21T20:41:32.237Z,1703191292.237 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:41:32.237Z,1703191292.237 [DATMMP](INFO): Handled 2023-12-21T20:41:32.373Z,1703191292.373 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:32.487Z,1703191292.487 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:32.488Z,1703191292.488 [DATMMP](INFO): directional rx: x3F2 x30C x1EC xFCDE x941 xFCD7 x0 x754 xFFFB x5 x27B5966 x-43569E0 2023-12-21T20:41:32.490Z,1703191292.490 [DATMMP](INFO): Received message type: directional 2023-12-21T20:41:32.490Z,1703191292.490 [DATMMP](INFO): Handled 2023-12-21T20:41:32.740Z,1703191292.740 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:32.742Z,1703191292.742 [DATMMP](INFO): acstats rx: xA x0 xFFFF x156 x29 x54 x10D xF6 xD xFFFF xE7 x42 xD x0 2023-12-21T20:41:32.742Z,1703191292.742 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:41:32.742Z,1703191292.742 [DATMMP](INFO): Handled 2023-12-21T20:41:32.804Z,1703191292.804 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:32.991Z,1703191292.991 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:32.992Z,1703191292.992 [DATMMP](INFO): range_update rx: xA x2 xC x11 2023-12-21T20:41:32.992Z,1703191292.992 [DATMMP](INFO): Received message type: range_update 2023-12-21T20:41:32.992Z,1703191292.992 [DATMMP](INFO): Handled 2023-12-21T20:41:32.993Z,1703191292.993 [DATMMP](INFO): direction in FSK: [-0.093125,0.103426,0.990268] 2023-12-21T20:41:33.208Z,1703191293.208 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m 2023-12-21T20:41:33.243Z,1703191293.243 [DATMMP](INFO): GSXN notify for xid: 62 2023-12-21T20:41:33.244Z,1703191293.244 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-12-21T20:41:33.244Z,1703191293.244 [DATMMP](DEBUG): Command complete rang 2023-12-21T20:41:33.244Z,1703191293.244 [DATMMP](ERROR): 4:COMPLETE 2023-12-21T20:41:43.705Z,1703191303.705 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:41:43.835Z,1703191303.835 [DATMMP](INFO): ****** received valid address query ****** 2023-12-21T20:41:43.835Z,1703191303.835 [DATMMP](INFO): ****** received valid ping request ****** 2023-12-21T20:41:43.835Z,1703191303.835 [DATMMP](INFO): Querying Benthos address 10 2023-12-21T20:41:44.087Z,1703191304.087 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:44.088Z,1703191304.088 [DATMMP](INFO): timestamp rx: x0 x14 x29 x29 x2125 2023-12-21T20:41:44.088Z,1703191304.088 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:44.088Z,1703191304.088 [DATMMP](INFO): Handled 2023-12-21T20:41:44.863Z,1703191304.863 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-12-21T20:41:46.355Z,1703191306.355 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:46.356Z,1703191306.356 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:41:46.356Z,1703191306.356 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:41:46.356Z,1703191306.356 [DATMMP](INFO): Handled 2023-12-21T20:41:46.607Z,1703191306.607 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:46.608Z,1703191306.608 [DATMMP](INFO): timestamp rx: x1 x14 x29 x2B x2257 2023-12-21T20:41:46.608Z,1703191306.608 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191324.890880 2023-12-21T20:41:46.609Z,1703191306.609 [DATMMP](INFO): Rx ping set to:1703191306.607935 2023-12-21T20:41:46.609Z,1703191306.609 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:46.609Z,1703191306.609 [DATMMP](INFO): Handled 2023-12-21T20:41:47.111Z,1703191307.111 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:47.112Z,1703191307.112 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-12-21T20:41:47.113Z,1703191307.113 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:41:47.113Z,1703191307.113 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:41:47.113Z,1703191307.113 [DATMMP](INFO): Handled 2023-12-21T20:41:47.363Z,1703191307.363 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:47.364Z,1703191307.364 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:41:47.364Z,1703191307.364 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:41:47.364Z,1703191307.364 [DATMMP](INFO): Handled 2023-12-21T20:41:47.618Z,1703191307.618 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:47.622Z,1703191307.622 [DATMMP](INFO): directional_debug rx: x23F x270 x40 x18 x2FC0 x2671 x27B2 x4C73 2023-12-21T20:41:47.623Z,1703191307.623 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:41:47.623Z,1703191307.623 [DATMMP](INFO): Handled 2023-12-21T20:41:47.733Z,1703191307.733 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:47.867Z,1703191307.867 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:47.920Z,1703191307.920 [DATMMP](INFO): directional rx: x248 x239 x39D xFD90 xAF9 xFD8B x0 x753 xFFFC x5 x27B5966 x-43569E0 2023-12-21T20:41:47.927Z,1703191307.927 [DATMMP](INFO): Received message type: directional 2023-12-21T20:41:47.927Z,1703191307.927 [DATMMP](INFO): Handled 2023-12-21T20:41:48.119Z,1703191308.119 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:48.121Z,1703191308.121 [DATMMP](INFO): acstats rx: xA x0 xFFFF x16D x2A x5D x110 xF9 xD xFFFF xE6 x42 xD x0 2023-12-21T20:41:48.121Z,1703191308.121 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:41:48.121Z,1703191308.121 [DATMMP](INFO): Handled 2023-12-21T20:41:48.137Z,1703191308.137 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:41:48.371Z,1703191308.371 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:48.372Z,1703191308.372 [DATMMP](INFO): range_update rx: xA x2 xC x10 2023-12-21T20:41:48.372Z,1703191308.372 [DATMMP](INFO): Received message type: range_update 2023-12-21T20:41:48.372Z,1703191308.372 [DATMMP](INFO): Handled 2023-12-21T20:41:48.373Z,1703191308.373 [DATMMP](INFO): direction in FSK: [0.094735,0.044175,-0.994522] 2023-12-21T20:41:48.578Z,1703191308.578 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m 2023-12-21T20:41:48.623Z,1703191308.623 [DATMMP](INFO): GSXN notify for xid: 63 2023-12-21T20:41:48.623Z,1703191308.623 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-12-21T20:41:48.624Z,1703191308.624 [DATMMP](DEBUG): Command complete rang 2023-12-21T20:41:48.624Z,1703191308.624 [DATMMP](ERROR): 4:COMPLETE 2023-12-21T20:41:58.237Z,1703191318.237 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting. 2023-12-21T20:41:58.237Z,1703191318.237 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped 2023-12-21T20:41:58.237Z,1703191318.237 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component. 2023-12-21T20:41:58.237Z,1703191318.237 [senddata_direct_and_track_test:DirectData:B] Running Loop=1 2023-12-21T20:41:58.620Z,1703191318.620 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:10:_.pressure 2023-12-21T20:41:58.620Z,1703191318.620 [senddata_direct_and_track_test:DirectData:B] Stopped 2023-12-21T20:41:58.621Z,1703191318.621 [senddata_direct_and_track_test:DirectData:C] Running Loop=1 2023-12-21T20:41:58.706Z,1703191318.706 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-12-21T20:41:58.707Z,1703191318.707 [DATMMP](INFO): modem://10: set _.pressure 1.012360 atmosphere 2023-12-21T20:41:58.708Z,1703191318.708 [DATMMP](INFO): #Outgoing data=1 2023-12-21T20:41:58.708Z,1703191318.708 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-12-21T20:41:58.958Z,1703191318.958 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-12-21T20:41:58.958Z,1703191318.958 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-12-21T20:41:59.052Z,1703191319.052 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:10:_.temperature 2023-12-21T20:41:59.052Z,1703191319.052 [senddata_direct_and_track_test:DirectData:C] Stopped 2023-12-21T20:41:59.052Z,1703191319.052 [senddata_direct_and_track_test:DirectData:D] Running Loop=1 2023-12-21T20:41:59.052Z,1703191319.052 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:41:59.210Z,1703191319.210 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-12-21T20:41:59.211Z,1703191319.211 [DATMMP](INFO): Tx to 10 len 34 xid 64 2023-12-21T20:41:59.213Z,1703191319.213 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-12-21T20:41:59.214Z,1703191319.214 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:41:59.214Z,1703191319.214 [DATMMP](INFO): ****** received valid address query ****** 2023-12-21T20:41:59.214Z,1703191319.214 [DATMMP](INFO): ****** received valid ping request ****** 2023-12-21T20:41:59.215Z,1703191319.215 [DATMMP](INFO): Querying Benthos address 10 2023-12-21T20:41:59.453Z,1703191319.453 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:10:_.humidity 2023-12-21T20:41:59.453Z,1703191319.453 [senddata_direct_and_track_test:DirectData:D] Stopped 2023-12-21T20:41:59.454Z,1703191319.454 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData 2023-12-21T20:41:59.454Z,1703191319.454 [senddata_direct_and_track_test:DirectData] Stopped 2023-12-21T20:41:59.454Z,1703191319.454 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData 2023-12-21T20:41:59.454Z,1703191319.454 [senddata_direct_and_track_test:D.Wait] Running Loop=1 2023-12-21T20:41:59.454Z,1703191319.454 [senddata_direct_and_track_test:D.Wait](DEBUG): Initialize Wait Component. 2023-12-21T20:41:59.463Z,1703191319.463 [DATMMP](INFO): GSXN notify for xid: 64 2023-12-21T20:41:59.464Z,1703191319.464 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-12-21T20:41:59.464Z,1703191319.464 [DATMMP](DEBUG): Command complete send 2023-12-21T20:41:59.464Z,1703191319.464 [DATMMP](ERROR): 1:COMPLETE 2023-12-21T20:41:59.464Z,1703191319.464 [DATMMP](INFO): Received message type: cmd_result 2023-12-21T20:41:59.464Z,1703191319.464 [DATMMP](INFO): Handled 2023-12-21T20:41:59.465Z,1703191319.465 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:59.715Z,1703191319.715 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:59.716Z,1703191319.716 [DATMMP](INFO): timestamp rx: x0 x14 x29 x39 x7C0 2023-12-21T20:41:59.716Z,1703191319.716 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:59.716Z,1703191319.716 [DATMMP](INFO): Handled 2023-12-21T20:41:59.716Z,1703191319.716 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:41:59.968Z,1703191319.968 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:41:59.969Z,1703191319.969 [DATMMP](INFO): timestamp rx: x0 x14 x29 x39 xB9A 2023-12-21T20:41:59.970Z,1703191319.970 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:41:59.970Z,1703191319.970 [DATMMP](INFO): Handled 2023-12-21T20:41:59.970Z,1703191319.970 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:00.218Z,1703191320.218 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:00.470Z,1703191320.470 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:00.619Z,1703191320.619 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-12-21T20:42:00.722Z,1703191320.722 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:00.974Z,1703191320.974 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:01.226Z,1703191321.226 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:01.478Z,1703191321.478 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:01.730Z,1703191321.730 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:01.982Z,1703191321.982 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:02.239Z,1703191322.239 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:02.487Z,1703191322.487 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:02.739Z,1703191322.739 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:02.990Z,1703191322.990 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:03.242Z,1703191323.242 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:03.494Z,1703191323.494 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:03.746Z,1703191323.746 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:03.998Z,1703191323.998 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:04.258Z,1703191324.258 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:04.510Z,1703191324.510 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:04.762Z,1703191324.762 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:05.014Z,1703191325.014 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:05.266Z,1703191325.266 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:05.526Z,1703191325.526 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:05.779Z,1703191325.779 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:06.030Z,1703191326.030 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:06.282Z,1703191326.282 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:06.534Z,1703191326.534 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:06.786Z,1703191326.786 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:07.039Z,1703191327.039 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:07.291Z,1703191327.291 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:07.542Z,1703191327.542 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:07.794Z,1703191327.794 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:08.047Z,1703191328.047 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:08.298Z,1703191328.298 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:08.550Z,1703191328.550 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:08.803Z,1703191328.803 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:09.054Z,1703191329.054 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:09.306Z,1703191329.306 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:09.307Z,1703191329.307 [DATMMP](DEBUG): In sendingAckWaiting, timeout so set commsState_ = SENDING_FILL_BUFFER 2023-12-21T20:42:09.558Z,1703191329.558 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-12-21T20:42:09.559Z,1703191329.559 [DATMMP](INFO): modem://10: set _.temperature 23.856684 celsius 2023-12-21T20:42:09.560Z,1703191329.560 [DATMMP](INFO): #Outgoing data=1 2023-12-21T20:42:09.560Z,1703191329.560 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-12-21T20:42:09.811Z,1703191329.811 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-12-21T20:42:09.811Z,1703191329.811 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-12-21T20:42:10.063Z,1703191330.063 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-12-21T20:42:10.063Z,1703191330.063 [DATMMP](INFO): Tx to 10 len 34 xid 66 2023-12-21T20:42:10.064Z,1703191330.064 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-12-21T20:42:10.064Z,1703191330.064 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:10.064Z,1703191330.064 [DATMMP](ERROR): Timeout waiting for range request10.094332 2023-12-21T20:42:10.315Z,1703191330.315 [DATMMP](INFO): GSXN notify for xid: 66 2023-12-21T20:42:10.315Z,1703191330.315 [DATMMP](INFO): iface_err rx: x1 x7 xA 2023-12-21T20:42:10.316Z,1703191330.316 [DATMMP](ERROR): 10:Error talking to DAT device_busy 2023-12-21T20:42:10.316Z,1703191330.316 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:10.316Z,1703191330.316 [DATMMP](ERROR): Timeout waiting for range request10.346426 2023-12-21T20:42:10.566Z,1703191330.566 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:10.567Z,1703191330.567 [DATMMP](ERROR): Timeout waiting for range request10.596966 2023-12-21T20:42:10.818Z,1703191330.818 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:10.819Z,1703191330.819 [DATMMP](ERROR): Timeout waiting for range request10.848936 2023-12-21T20:42:11.070Z,1703191331.070 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:11.071Z,1703191331.071 [DATMMP](ERROR): Timeout waiting for range request11.101020 2023-12-21T20:42:11.322Z,1703191331.322 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:11.323Z,1703191331.323 [DATMMP](ERROR): Timeout waiting for range request11.352919 2023-12-21T20:42:11.575Z,1703191331.575 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:11.575Z,1703191331.575 [DATMMP](ERROR): Timeout waiting for range request11.605048 2023-12-21T20:42:11.827Z,1703191331.827 [DATMMP](INFO): GSXN notify for xid: 65 2023-12-21T20:42:11.828Z,1703191331.828 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x5 2023-12-21T20:42:11.828Z,1703191331.828 [DATMMP](ERROR): 5:Command error: timeout 2023-12-21T20:42:11.828Z,1703191331.828 [DATMMP](DEBUG): Command timeout rangerec 2023-12-21T20:42:11.829Z,1703191331.829 [DATMMP](ERROR): 5:COMPLETE 2023-12-21T20:42:11.829Z,1703191331.829 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:11.829Z,1703191331.829 [DATMMP](ERROR): Timeout waiting for range request11.859386 2023-12-21T20:42:12.079Z,1703191332.079 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:12.079Z,1703191332.079 [DATMMP](ERROR): Timeout waiting for range request12.109188 2023-12-21T20:42:12.330Z,1703191332.330 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:12.331Z,1703191332.331 [DATMMP](ERROR): Timeout waiting for range request12.361026 2023-12-21T20:42:12.582Z,1703191332.582 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:12.583Z,1703191332.583 [DATMMP](ERROR): Timeout waiting for range request12.612957 2023-12-21T20:42:12.834Z,1703191332.834 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:12.835Z,1703191332.835 [DATMMP](ERROR): Timeout waiting for range request12.864926 2023-12-21T20:42:13.086Z,1703191333.086 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:13.087Z,1703191333.087 [DATMMP](ERROR): Timeout waiting for range request13.116974 2023-12-21T20:42:13.339Z,1703191333.339 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:13.339Z,1703191333.339 [DATMMP](ERROR): Timeout waiting for range request13.369048 2023-12-21T20:42:13.590Z,1703191333.590 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:13.591Z,1703191333.591 [DATMMP](ERROR): Timeout waiting for range request13.620917 2023-12-21T20:42:13.842Z,1703191333.842 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:13.843Z,1703191333.843 [DATMMP](ERROR): Timeout waiting for range request13.872945 2023-12-21T20:42:14.095Z,1703191334.095 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:14.095Z,1703191334.095 [DATMMP](ERROR): Timeout waiting for range request14.125052 2023-12-21T20:42:14.347Z,1703191334.347 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:14.347Z,1703191334.347 [DATMMP](ERROR): Timeout waiting for range request14.377062 2023-12-21T20:42:14.473Z,1703191334.473 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:42:14.599Z,1703191334.599 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:14.599Z,1703191334.599 [DATMMP](ERROR): Timeout waiting for range request14.629074 2023-12-21T20:42:14.599Z,1703191334.599 [DATMMP](INFO): ****** received valid address query ****** 2023-12-21T20:42:14.599Z,1703191334.599 [DATMMP](INFO): ****** received valid ping request ****** 2023-12-21T20:42:14.600Z,1703191334.600 [DATMMP](INFO): Querying Benthos address 10 2023-12-21T20:42:14.851Z,1703191334.851 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:14.852Z,1703191334.852 [DATMMP](INFO): timestamp rx: x0 x14 x2A xC x175F 2023-12-21T20:42:14.852Z,1703191334.852 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:14.852Z,1703191334.852 [DATMMP](INFO): Handled 2023-12-21T20:42:14.852Z,1703191334.852 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:15.103Z,1703191335.103 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:15.354Z,1703191335.354 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:15.611Z,1703191335.611 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:15.863Z,1703191335.863 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:16.115Z,1703191336.115 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:16.366Z,1703191336.366 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:16.618Z,1703191336.618 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:16.784Z,1703191336.784 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-12-21T20:42:16.870Z,1703191336.870 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:17.123Z,1703191337.123 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:17.123Z,1703191337.123 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:42:17.124Z,1703191337.124 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:42:17.124Z,1703191337.124 [DATMMP](INFO): Handled 2023-12-21T20:42:17.124Z,1703191337.124 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:17.376Z,1703191337.376 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:17.377Z,1703191337.377 [DATMMP](INFO): timestamp rx: x1 x14 x2A xE x1893 2023-12-21T20:42:17.378Z,1703191337.378 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191395.456704 2023-12-21T20:42:17.378Z,1703191337.378 [DATMMP](INFO): Rx ping set to:1703191337.377121 2023-12-21T20:42:17.378Z,1703191337.378 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:17.378Z,1703191337.378 [DATMMP](INFO): Handled 2023-12-21T20:42:17.379Z,1703191337.379 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:17.626Z,1703191337.626 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:17.879Z,1703191337.879 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:17.880Z,1703191337.880 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-12-21T20:42:17.880Z,1703191337.880 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:42:17.881Z,1703191337.881 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:42:17.881Z,1703191337.881 [DATMMP](INFO): Handled 2023-12-21T20:42:17.881Z,1703191337.881 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:18.131Z,1703191338.131 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:18.132Z,1703191338.132 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:42:18.132Z,1703191338.132 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:42:18.132Z,1703191338.132 [DATMMP](INFO): Handled 2023-12-21T20:42:18.132Z,1703191338.132 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:18.383Z,1703191338.383 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:18.384Z,1703191338.384 [DATMMP](INFO): directional_debug rx: x25B x307 x40 x16 x3DB0 x3901 x35D2 x58B3 2023-12-21T20:42:18.385Z,1703191338.385 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:42:18.385Z,1703191338.385 [DATMMP](INFO): Handled 2023-12-21T20:42:18.385Z,1703191338.385 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:18.512Z,1703191338.512 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:42:18.635Z,1703191338.635 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:18.637Z,1703191338.637 [DATMMP](INFO): directional rx: x261 x2EE x381 xFCF9 xAF3 xFCF3 x0 x757 xFFFA x6 x27B5966 x-43569E0 2023-12-21T20:42:18.639Z,1703191338.639 [DATMMP](INFO): Received message type: directional 2023-12-21T20:42:18.639Z,1703191338.639 [DATMMP](INFO): Handled 2023-12-21T20:42:18.639Z,1703191338.639 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:18.860Z,1703191338.860 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:42:18.887Z,1703191338.887 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:18.889Z,1703191338.889 [DATMMP](INFO): acstats rx: xA x0 xFFFF x15C x2A x54 x10B xF6 xD xFFFF xE8 x42 xD x0 2023-12-21T20:42:18.889Z,1703191338.889 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:42:18.889Z,1703191338.889 [DATMMP](INFO): Handled 2023-12-21T20:42:18.889Z,1703191338.889 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:19.139Z,1703191339.139 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:19.140Z,1703191339.140 [DATMMP](INFO): range_update rx: xA x2 xC x11 2023-12-21T20:42:19.140Z,1703191339.140 [DATMMP](INFO): Received message type: range_update 2023-12-21T20:42:19.140Z,1703191339.140 [DATMMP](INFO): Handled 2023-12-21T20:42:19.140Z,1703191339.140 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:19.141Z,1703191339.141 [DATMMP](INFO): direction in FSK: [-0.572791,0.030019,0.819152] 2023-12-21T20:42:19.287Z,1703191339.287 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m 2023-12-21T20:42:19.391Z,1703191339.391 [DATMMP](INFO): GSXN notify for xid: 67 2023-12-21T20:42:19.392Z,1703191339.392 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-12-21T20:42:19.392Z,1703191339.392 [DATMMP](DEBUG): Command complete rang 2023-12-21T20:42:19.392Z,1703191339.392 [DATMMP](ERROR): 4:COMPLETE 2023-12-21T20:42:19.392Z,1703191339.392 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:19.642Z,1703191339.642 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:19.894Z,1703191339.894 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:20.146Z,1703191340.146 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:20.146Z,1703191340.146 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-12-21T20:42:20.147Z,1703191340.147 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-12-21T20:42:20.398Z,1703191340.398 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-12-21T20:42:20.399Z,1703191340.399 [DATMMP](INFO): modem://10: set _.humidity 42.052254 percent 2023-12-21T20:42:20.400Z,1703191340.400 [DATMMP](INFO): #Outgoing data=2 2023-12-21T20:42:20.400Z,1703191340.400 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-12-21T20:42:20.651Z,1703191340.651 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-12-21T20:42:20.651Z,1703191340.651 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-12-21T20:42:20.902Z,1703191340.902 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-12-21T20:42:20.903Z,1703191340.903 [DATMMP](INFO): Tx to 10 len 34 xid 68 2023-12-21T20:42:20.903Z,1703191340.903 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-12-21T20:42:20.904Z,1703191340.904 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:21.155Z,1703191341.155 [DATMMP](INFO): GSXN notify for xid: 68 2023-12-21T20:42:21.156Z,1703191341.156 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-12-21T20:42:21.156Z,1703191341.156 [DATMMP](DEBUG): Command complete send 2023-12-21T20:42:21.156Z,1703191341.156 [DATMMP](ERROR): 1:COMPLETE 2023-12-21T20:42:21.156Z,1703191341.156 [DATMMP](INFO): Received message type: cmd_result 2023-12-21T20:42:21.156Z,1703191341.156 [DATMMP](INFO): Handled 2023-12-21T20:42:21.156Z,1703191341.156 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:21.407Z,1703191341.407 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:21.408Z,1703191341.408 [DATMMP](INFO): timestamp rx: x0 x14 x2A x12 x24FF 2023-12-21T20:42:21.408Z,1703191341.408 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:21.408Z,1703191341.408 [DATMMP](INFO): Handled 2023-12-21T20:42:21.408Z,1703191341.408 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:21.658Z,1703191341.658 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:21.910Z,1703191341.910 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:22.162Z,1703191342.162 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:22.414Z,1703191342.414 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:22.667Z,1703191342.667 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:22.918Z,1703191342.918 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:23.170Z,1703191343.170 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:23.422Z,1703191343.422 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:23.675Z,1703191343.675 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:23.926Z,1703191343.926 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:24.178Z,1703191344.178 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:24.430Z,1703191344.430 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:24.682Z,1703191344.682 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:24.934Z,1703191344.934 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:25.186Z,1703191345.186 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:25.438Z,1703191345.438 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:25.691Z,1703191345.691 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:25.691Z,1703191345.691 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:42:25.691Z,1703191345.691 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:42:25.692Z,1703191345.692 [DATMMP](INFO): Handled 2023-12-21T20:42:25.692Z,1703191345.692 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:25.942Z,1703191345.942 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:25.944Z,1703191345.944 [DATMMP](INFO): timestamp rx: x1 x14 x2A x17 x2AF 2023-12-21T20:42:25.944Z,1703191345.944 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191349.743424 2023-12-21T20:42:25.944Z,1703191345.944 [DATMMP](INFO): Rx ping set to:1703191345.943595 2023-12-21T20:42:25.945Z,1703191345.945 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:25.945Z,1703191345.945 [DATMMP](INFO): Handled 2023-12-21T20:42:25.945Z,1703191345.945 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:26.195Z,1703191346.195 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:26.196Z,1703191346.196 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-12-21T20:42:26.196Z,1703191346.196 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:42:26.197Z,1703191346.197 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:42:26.197Z,1703191346.197 [DATMMP](INFO): Handled 2023-12-21T20:42:26.197Z,1703191346.197 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:26.447Z,1703191346.447 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:26.447Z,1703191346.447 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:42:26.448Z,1703191346.448 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:42:26.448Z,1703191346.448 [DATMMP](INFO): Handled 2023-12-21T20:42:26.448Z,1703191346.448 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:26.699Z,1703191346.699 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:26.700Z,1703191346.700 [DATMMP](INFO): directional_debug rx: x61 x270 x3F x17 x3C90 x3961 x3472 x6B43 2023-12-21T20:42:26.701Z,1703191346.701 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:42:26.701Z,1703191346.701 [DATMMP](INFO): Handled 2023-12-21T20:42:26.701Z,1703191346.701 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:26.929Z,1703191346.929 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:42:26.951Z,1703191346.951 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:26.952Z,1703191346.952 [DATMMP](INFO): directional rx: x5D x240 x57B xFD90 xCE2 xFD93 x0 x75A xFFF9 x4 x27B5966 x-43569E0 2023-12-21T20:42:26.954Z,1703191346.954 [DATMMP](INFO): Received message type: directional 2023-12-21T20:42:26.954Z,1703191346.954 [DATMMP](INFO): Handled 2023-12-21T20:42:26.955Z,1703191346.955 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:27.202Z,1703191347.202 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:27.205Z,1703191347.205 [DATMMP](INFO): acstats rx: xA x5 xFFFF x166 x2A x52 x103 xFF xD xFFFF xB5 x43 xD x0 2023-12-21T20:42:27.205Z,1703191347.205 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:42:27.205Z,1703191347.205 [DATMMP](INFO): Handled 2023-12-21T20:42:27.205Z,1703191347.205 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:27.309Z,1703191347.309 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:42:27.457Z,1703191347.457 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:27.459Z,1703191347.459 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-12-21T20:42:27.460Z,1703191347.460 [DATMMP](INFO): Check CRC 2023-12-21T20:42:27.460Z,1703191347.460 [DATMMP](INFO): data rx parseDataResponse 4 2023-12-21T20:42:27.460Z,1703191347.460 [DATMMP](INFO): Got DATA: len 4 2023-12-21T20:42:27.460Z,1703191347.460 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-12-21T20:42:27.460Z,1703191347.460 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-12-21T20:42:27.460Z,1703191347.460 [DATMMP](INFO): Received command: 2023-12-21T20:42:27.461Z,1703191347.461 [DATMMP](INFO): Received message type: data_rx 2023-12-21T20:42:27.461Z,1703191347.461 [DATMMP](INFO): Handled 2023-12-21T20:42:27.461Z,1703191347.461 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-12-21T20:42:27.461Z,1703191347.461 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-12-21T20:42:27.706Z,1703191347.706 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-12-21T20:42:27.707Z,1703191347.707 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-12-21T20:42:27.958Z,1703191347.958 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-12-21T20:42:27.958Z,1703191347.958 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-12-21T20:42:28.210Z,1703191348.210 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-12-21T20:42:28.211Z,1703191348.211 [DATMMP](INFO): Tx to 10 len 35 xid 69 2023-12-21T20:42:28.212Z,1703191348.212 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-12-21T20:42:28.212Z,1703191348.212 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:28.463Z,1703191348.463 [DATMMP](INFO): GSXN notify for xid: 69 2023-12-21T20:42:28.463Z,1703191348.463 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-12-21T20:42:28.464Z,1703191348.464 [DATMMP](DEBUG): Command complete send 2023-12-21T20:42:28.464Z,1703191348.464 [DATMMP](ERROR): 1:COMPLETE 2023-12-21T20:42:28.464Z,1703191348.464 [DATMMP](INFO): Received message type: cmd_result 2023-12-21T20:42:28.464Z,1703191348.464 [DATMMP](INFO): Handled 2023-12-21T20:42:28.464Z,1703191348.464 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:28.715Z,1703191348.715 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:28.716Z,1703191348.716 [DATMMP](INFO): timestamp rx: x0 x14 x2A x1A x9A7 2023-12-21T20:42:28.716Z,1703191348.716 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:28.716Z,1703191348.716 [DATMMP](INFO): Handled 2023-12-21T20:42:28.716Z,1703191348.716 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:28.977Z,1703191348.977 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:29.230Z,1703191349.230 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:29.482Z,1703191349.482 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:29.738Z,1703191349.738 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:29.746Z,1703191349.746 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:42:29.990Z,1703191349.990 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:29.991Z,1703191349.991 [DATMMP](INFO): ****** received valid address query ****** 2023-12-21T20:42:29.991Z,1703191349.991 [DATMMP](INFO): ****** received valid ping request ****** 2023-12-21T20:42:29.991Z,1703191349.991 [DATMMP](INFO): Querying Benthos address 10 2023-12-21T20:42:30.245Z,1703191350.245 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:30.248Z,1703191350.248 [DATMMP](INFO): timestamp rx: x0 x14 x2A x1B x26FF 2023-12-21T20:42:30.248Z,1703191350.248 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:30.248Z,1703191350.248 [DATMMP](INFO): Handled 2023-12-21T20:42:30.249Z,1703191350.249 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:30.494Z,1703191350.494 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:30.746Z,1703191350.746 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:30.999Z,1703191350.999 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:31.250Z,1703191351.250 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:31.502Z,1703191351.502 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:31.746Z,1703191351.746 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-12-21T20:42:31.754Z,1703191351.754 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:32.006Z,1703191352.006 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:32.258Z,1703191352.258 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:32.511Z,1703191352.511 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:32.511Z,1703191352.511 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:42:32.511Z,1703191352.511 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:42:32.512Z,1703191352.512 [DATMMP](INFO): Handled 2023-12-21T20:42:32.512Z,1703191352.512 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:32.763Z,1703191352.763 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:32.764Z,1703191352.764 [DATMMP](INFO): timestamp rx: x1 x14 x2A x1E x123 2023-12-21T20:42:32.764Z,1703191352.764 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191352.882688 2023-12-21T20:42:32.764Z,1703191352.764 [DATMMP](INFO): Rx ping set to:1703191352.763663 2023-12-21T20:42:32.765Z,1703191352.765 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:32.765Z,1703191352.765 [DATMMP](INFO): Handled 2023-12-21T20:42:32.765Z,1703191352.765 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:33.014Z,1703191353.014 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:33.267Z,1703191353.267 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:33.268Z,1703191353.268 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-12-21T20:42:33.268Z,1703191353.268 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:42:33.268Z,1703191353.268 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:42:33.268Z,1703191353.268 [DATMMP](INFO): Handled 2023-12-21T20:42:33.269Z,1703191353.269 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:33.519Z,1703191353.519 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:33.519Z,1703191353.519 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:42:33.520Z,1703191353.520 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:42:33.520Z,1703191353.520 [DATMMP](INFO): Handled 2023-12-21T20:42:33.520Z,1703191353.520 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:33.771Z,1703191353.771 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:33.772Z,1703191353.772 [DATMMP](INFO): directional_debug rx: x1C7 x293 x41 x18 x31B0 x24C1 x2682 x4DF3 2023-12-21T20:42:33.773Z,1703191353.773 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:42:33.773Z,1703191353.773 [DATMMP](INFO): Handled 2023-12-21T20:42:33.773Z,1703191353.773 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:33.777Z,1703191353.777 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:42:34.023Z,1703191354.023 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:34.024Z,1703191354.024 [DATMMP](INFO): directional rx: x1C7 x262 x415 xFD6D xB80 xFD6B x0 x75C xFFFA x3 x27B5966 x-43569E0 2023-12-21T20:42:34.026Z,1703191354.026 [DATMMP](INFO): Received message type: directional 2023-12-21T20:42:34.026Z,1703191354.026 [DATMMP](INFO): Handled 2023-12-21T20:42:34.027Z,1703191354.027 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:34.188Z,1703191354.188 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:42:34.275Z,1703191354.275 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:34.277Z,1703191354.277 [DATMMP](INFO): acstats rx: xA x0 xFFFF x185 x2A x5E x107 xF6 xD xFFFF xE4 x42 xD x0 2023-12-21T20:42:34.277Z,1703191354.277 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:42:34.277Z,1703191354.277 [DATMMP](INFO): Handled 2023-12-21T20:42:34.277Z,1703191354.277 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:34.527Z,1703191354.527 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:34.527Z,1703191354.527 [DATMMP](INFO): range_update rx: xA x2 xC x11 2023-12-21T20:42:34.528Z,1703191354.528 [DATMMP](INFO): Received message type: range_update 2023-12-21T20:42:34.528Z,1703191354.528 [DATMMP](INFO): Handled 2023-12-21T20:42:34.528Z,1703191354.528 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:34.529Z,1703191354.529 [DATMMP](INFO): direction in FSK: [0.397133,-0.278075,-0.874620] 2023-12-21T20:42:34.632Z,1703191354.632 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m 2023-12-21T20:42:34.779Z,1703191354.779 [DATMMP](INFO): GSXN notify for xid: 70 2023-12-21T20:42:34.780Z,1703191354.780 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-12-21T20:42:34.780Z,1703191354.780 [DATMMP](DEBUG): Command complete rang 2023-12-21T20:42:34.780Z,1703191354.780 [DATMMP](ERROR): 4:COMPLETE 2023-12-21T20:42:34.780Z,1703191354.780 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:35.031Z,1703191355.031 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:35.031Z,1703191355.031 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:42:35.032Z,1703191355.032 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:42:35.032Z,1703191355.032 [DATMMP](INFO): Handled 2023-12-21T20:42:35.032Z,1703191355.032 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:35.283Z,1703191355.283 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:35.284Z,1703191355.284 [DATMMP](INFO): timestamp rx: x1 x14 x2A x1F x1328 2023-12-21T20:42:35.284Z,1703191355.284 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191398.933888 2023-12-21T20:42:35.284Z,1703191355.284 [DATMMP](INFO): Rx ping set to:1703191355.283642 2023-12-21T20:42:35.285Z,1703191355.285 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:35.285Z,1703191355.285 [DATMMP](INFO): Handled 2023-12-21T20:42:35.285Z,1703191355.285 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:35.535Z,1703191355.535 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:35.536Z,1703191355.536 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-12-21T20:42:35.536Z,1703191355.536 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:42:35.536Z,1703191355.536 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:42:35.537Z,1703191355.537 [DATMMP](INFO): Handled 2023-12-21T20:42:35.537Z,1703191355.537 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:35.787Z,1703191355.787 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:35.787Z,1703191355.787 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:42:35.788Z,1703191355.788 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:42:35.788Z,1703191355.788 [DATMMP](INFO): Handled 2023-12-21T20:42:35.788Z,1703191355.788 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:36.039Z,1703191356.039 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:36.040Z,1703191356.040 [DATMMP](INFO): directional_debug rx: x43 x2B1 x40 x11 x3750 x2A31 x2AD2 x5733 2023-12-21T20:42:36.041Z,1703191356.041 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:42:36.041Z,1703191356.041 [DATMMP](INFO): Handled 2023-12-21T20:42:36.041Z,1703191356.041 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:36.205Z,1703191356.205 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:42:36.291Z,1703191356.291 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:36.292Z,1703191356.292 [DATMMP](INFO): directional rx: x40 x28D x599 xFD4F xD05 xFD52 x0 x75E xFFFA x3 x27B5966 x-43569E0 2023-12-21T20:42:36.294Z,1703191356.294 [DATMMP](INFO): Received message type: directional 2023-12-21T20:42:36.294Z,1703191356.294 [DATMMP](INFO): Handled 2023-12-21T20:42:36.295Z,1703191356.295 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:36.543Z,1703191356.543 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:36.545Z,1703191356.545 [DATMMP](INFO): acstats rx: xA x5 xFFFF x2D0 x2A x55 xF2 x103 xE xFFFF xDD x41 xD x0 2023-12-21T20:42:36.545Z,1703191356.545 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:42:36.545Z,1703191356.545 [DATMMP](INFO): Handled 2023-12-21T20:42:36.545Z,1703191356.545 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:36.644Z,1703191356.644 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191296.00. Resetting abort timer. 2023-12-21T20:42:36.795Z,1703191356.795 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:36.795Z,1703191356.795 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-12-21T20:42:36.796Z,1703191356.796 [DATMMP](INFO): Check CRC 2023-12-21T20:42:36.796Z,1703191356.796 [DATMMP](INFO): data rx parseDataResponse 4 2023-12-21T20:42:36.796Z,1703191356.796 [DATMMP](INFO): Got DATA: len 4 2023-12-21T20:42:36.796Z,1703191356.796 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-12-21T20:42:36.796Z,1703191356.796 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-12-21T20:42:36.796Z,1703191356.796 [DATMMP](INFO): Received command: 2023-12-21T20:42:36.797Z,1703191356.797 [DATMMP](INFO): Received message type: data_rx 2023-12-21T20:42:36.797Z,1703191356.797 [DATMMP](INFO): Handled 2023-12-21T20:42:36.797Z,1703191356.797 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-12-21T20:42:36.797Z,1703191356.797 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-12-21T20:42:37.054Z,1703191357.054 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-12-21T20:42:37.055Z,1703191357.055 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-12-21T20:42:37.307Z,1703191357.307 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-12-21T20:42:37.307Z,1703191357.307 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-12-21T20:42:37.558Z,1703191357.558 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-12-21T20:42:37.559Z,1703191357.559 [DATMMP](INFO): Tx to 10 len 32 xid 71 2023-12-21T20:42:37.559Z,1703191357.559 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-12-21T20:42:37.560Z,1703191357.560 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-12-21T20:42:37.811Z,1703191357.811 [DATMMP](INFO): GSXN notify for xid: 71 2023-12-21T20:42:37.812Z,1703191357.812 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-12-21T20:42:37.812Z,1703191357.812 [DATMMP](DEBUG): Command complete send 2023-12-21T20:42:37.813Z,1703191357.813 [DATMMP](ERROR): 1:COMPLETE 2023-12-21T20:42:37.814Z,1703191357.814 [DATMMP](INFO): Received message type: cmd_result 2023-12-21T20:42:37.814Z,1703191357.814 [DATMMP](INFO): Handled 2023-12-21T20:42:37.815Z,1703191357.815 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:38.062Z,1703191358.062 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:38.064Z,1703191358.064 [DATMMP](INFO): timestamp rx: x0 x14 x2A x23 x1752 2023-12-21T20:42:38.064Z,1703191358.064 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:38.064Z,1703191358.064 [DATMMP](INFO): Handled 2023-12-21T20:42:38.064Z,1703191358.064 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:38.314Z,1703191358.314 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:38.567Z,1703191358.567 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:38.819Z,1703191358.819 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:39.070Z,1703191359.070 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:39.322Z,1703191359.322 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:39.574Z,1703191359.574 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:39.826Z,1703191359.826 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:40.079Z,1703191360.079 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:40.330Z,1703191360.330 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:40.582Z,1703191360.582 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:40.834Z,1703191360.834 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:41.086Z,1703191361.086 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:41.338Z,1703191361.338 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:41.590Z,1703191361.590 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:41.842Z,1703191361.842 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:42.094Z,1703191362.094 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:42.347Z,1703191362.347 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:42.347Z,1703191362.347 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:42:42.347Z,1703191362.347 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:42:42.348Z,1703191362.348 [DATMMP](INFO): Handled 2023-12-21T20:42:42.348Z,1703191362.348 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:42.599Z,1703191362.599 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:42.600Z,1703191362.600 [DATMMP](INFO): timestamp rx: x1 x14 x2A x27 x1C12 2023-12-21T20:42:42.601Z,1703191362.601 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191365.184320 2023-12-21T20:42:42.601Z,1703191362.601 [DATMMP](INFO): Rx ping set to:1703191362.600356 2023-12-21T20:42:42.601Z,1703191362.601 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:42.601Z,1703191362.601 [DATMMP](INFO): Handled 2023-12-21T20:42:42.602Z,1703191362.602 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:42.851Z,1703191362.851 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:42.852Z,1703191362.852 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-12-21T20:42:42.852Z,1703191362.852 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:42:42.852Z,1703191362.852 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:42:42.853Z,1703191362.853 [DATMMP](INFO): Handled 2023-12-21T20:42:42.853Z,1703191362.853 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:43.103Z,1703191363.103 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:43.103Z,1703191363.103 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:42:43.104Z,1703191363.104 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:42:43.104Z,1703191363.104 [DATMMP](INFO): Handled 2023-12-21T20:42:43.104Z,1703191363.104 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:43.355Z,1703191363.355 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:43.356Z,1703191363.356 [DATMMP](INFO): directional_debug rx: x11A x2BA x3F x16 x3E60 x38E1 x35A2 x6B93 2023-12-21T20:42:43.357Z,1703191363.357 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:42:43.357Z,1703191363.357 [DATMMP](INFO): Handled 2023-12-21T20:42:43.358Z,1703191363.358 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:43.489Z,1703191363.489 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191424.00. Resetting abort timer. 2023-12-21T20:42:43.607Z,1703191363.607 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:43.608Z,1703191363.608 [DATMMP](INFO): directional rx: x118 x292 x4C2 xFD46 xC35 xFD47 x0 x761 xFFFA x3 x27B5966 x-43569E0 2023-12-21T20:42:43.610Z,1703191363.610 [DATMMP](INFO): Received message type: directional 2023-12-21T20:42:43.610Z,1703191363.610 [DATMMP](INFO): Handled 2023-12-21T20:42:43.611Z,1703191363.611 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:43.858Z,1703191363.858 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:43.860Z,1703191363.860 [DATMMP](INFO): acstats rx: xA x5 xFFFF x15B xF x53 xFE xF6 xE xFFFF xD9 x42 xD x0 2023-12-21T20:42:43.861Z,1703191363.861 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:42:43.861Z,1703191363.861 [DATMMP](INFO): Handled 2023-12-21T20:42:43.861Z,1703191363.861 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-12-21T20:42:44.044Z,1703191364.044 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191424.00. Resetting abort timer. 2023-12-21T20:42:44.110Z,1703191364.110 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:44.111Z,1703191364.111 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-12-21T20:42:44.112Z,1703191364.112 [DATMMP](INFO): Check CRC 2023-12-21T20:42:44.112Z,1703191364.112 [DATMMP](INFO): data rx parseDataResponse 4 2023-12-21T20:42:44.112Z,1703191364.112 [DATMMP](INFO): Got DATA: len 4 2023-12-21T20:42:44.112Z,1703191364.112 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-12-21T20:42:44.112Z,1703191364.112 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-12-21T20:42:44.112Z,1703191364.112 [DATMMP](INFO): Received command: 2023-12-21T20:42:44.113Z,1703191364.113 [DATMMP](INFO): Received message type: data_rx 2023-12-21T20:42:44.113Z,1703191364.113 [DATMMP](INFO): Handled 2023-12-21T20:42:44.113Z,1703191364.113 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-12-21T20:42:44.113Z,1703191364.113 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-12-21T20:42:45.113Z,1703191365.113 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-12-21T20:42:45.119Z,1703191365.119 [DATMMP](INFO): ****** received valid address query ****** 2023-12-21T20:42:45.119Z,1703191365.119 [DATMMP](INFO): ****** received valid ping request ****** 2023-12-21T20:42:45.119Z,1703191365.119 [DATMMP](INFO): Querying Benthos address 10 2023-12-21T20:42:45.370Z,1703191365.370 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:45.372Z,1703191365.372 [DATMMP](INFO): timestamp rx: x0 x14 x2A x2B x3D6 2023-12-21T20:42:45.372Z,1703191365.372 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:45.372Z,1703191365.372 [DATMMP](INFO): Handled 2023-12-21T20:42:47.496Z,1703191367.496 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7). 2023-12-21T20:42:47.639Z,1703191367.639 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:47.639Z,1703191367.639 [DATMMP](INFO): doppler rx: xFFFF 2023-12-21T20:42:47.640Z,1703191367.640 [DATMMP](INFO): Received message type: doppler 2023-12-21T20:42:47.640Z,1703191367.640 [DATMMP](INFO): Handled 2023-12-21T20:42:47.895Z,1703191367.895 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:47.896Z,1703191367.896 [DATMMP](INFO): timestamp rx: x1 x14 x2A x2D x50B 2023-12-21T20:42:47.896Z,1703191367.896 [DATMMP](INFO): Rx dataTimestamp_ set to:1703191377.636928 2023-12-21T20:42:47.897Z,1703191367.897 [DATMMP](INFO): Rx ping set to:1703191367.895735 2023-12-21T20:42:47.897Z,1703191367.897 [DATMMP](INFO): Received message type: timestamp 2023-12-21T20:42:47.897Z,1703191367.897 [DATMMP](INFO): Handled 2023-12-21T20:42:48.399Z,1703191368.399 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:48.400Z,1703191368.400 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-12-21T20:42:48.400Z,1703191368.400 [DATMMP](INFO): DATA Src=10, Dst=12 2023-12-21T20:42:48.401Z,1703191368.401 [DATMMP](INFO): Received message type: remote_header 2023-12-21T20:42:48.401Z,1703191368.401 [DATMMP](INFO): Handled 2023-12-21T20:42:48.651Z,1703191368.651 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:48.652Z,1703191368.652 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-12-21T20:42:48.652Z,1703191368.652 [DATMMP](INFO): Received message type: nav_stat 2023-12-21T20:42:48.652Z,1703191368.652 [DATMMP](INFO): Handled 2023-12-21T20:42:48.903Z,1703191368.903 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:48.904Z,1703191368.904 [DATMMP](INFO): directional_debug rx: x136 x281 x42 x19 x33F0 x2A11 x2C52 x5853 2023-12-21T20:42:48.905Z,1703191368.905 [DATMMP](INFO): Received message type: directional_debug 2023-12-21T20:42:48.905Z,1703191368.905 [DATMMP](INFO): Handled 2023-12-21T20:42:49.141Z,1703191369.141 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191424.00. Resetting abort timer. 2023-12-21T20:42:49.155Z,1703191369.155 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:49.156Z,1703191369.156 [DATMMP](INFO): directional rx: x133 x24E x4A6 xFD7F xC14 xFD7E x0 x761 xFFFB x4 x27B5966 x-43569E0 2023-12-21T20:42:49.158Z,1703191369.158 [DATMMP](INFO): Received message type: directional 2023-12-21T20:42:49.158Z,1703191369.158 [DATMMP](INFO): Handled 2023-12-21T20:42:49.407Z,1703191369.407 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:49.409Z,1703191369.409 [DATMMP](INFO): acstats rx: xA x0 xFFFF x186 x29 x5D x10C xF5 xD xFFFF xEF x42 xD x0 2023-12-21T20:42:49.409Z,1703191369.409 [DATMMP](INFO): Received message type: acstats 2023-12-21T20:42:49.409Z,1703191369.409 [DATMMP](INFO): Handled 2023-12-21T20:42:49.549Z,1703191369.549 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1703191424.00. Resetting abort timer. 2023-12-21T20:42:49.659Z,1703191369.659 [DATMMP](INFO): GSXN notify for xid: 0 2023-12-21T20:42:49.660Z,1703191369.660 [DATMMP](INFO): range_update rx: xA x2 xC x11 2023-12-21T20:42:49.660Z,1703191369.660 [DATMMP](INFO): Received message type: range_update 2023-12-21T20:42:49.660Z,1703191369.660 [DATMMP](INFO): Handled 2023-12-21T20:42:49.661Z,1703191369.661 [DATMMP](INFO): direction in FSK: [-0.065260,0.179301,-0.981627] 2023-12-21T20:42:49.911Z,1703191369.911 [DATMMP](INFO): GSXN notify for xid: 72 2023-12-21T20:42:49.911Z,1703191369.911 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-12-21T20:42:49.912Z,1703191369.912 [DATMMP](DEBUG): Command complete rang 2023-12-21T20:42:49.912Z,1703191369.912 [DATMMP](ERROR): 4:COMPLETE 2023-12-21T20:42:50.018Z,1703191370.018 [Reporter](INFO): DATMMP.acoustic_contact_range 1.200000 m 2023-12-21T20:43:00.060Z,1703191380.060 [senddata_direct_and_track_test:D.Wait](INFO): Done Waiting. 2023-12-21T20:43:00.060Z,1703191380.060 [senddata_direct_and_track_test:D.Wait] Stopped 2023-12-21T20:43:00.060Z,1703191380.060 [senddata_direct_and_track_test:D.Wait](DEBUG): Uninitialize Wait Component. 2023-12-21T20:43:00.061Z,1703191380.061 [senddata_direct_and_track_test](INFO): Completed senddata_direct_and_track_test 2023-12-21T20:43:00.061Z,1703191380.061 [MissionManager](INFO): senddata_direct_and_track_test is completed. 2023-12-21T20:43:00.062Z,1703191380.062 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test 2023-12-21T20:43:00.062Z,1703191380.062 [senddata_direct_and_track_test] Stopped 2023-12-21T20:43:00.062Z,1703191380.062 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test 2023-12-21T20:43:00.062Z,1703191380.062 [senddata_direct_and_track_test:AbortDrift] Stopped 2023-12-21T20:43:00.062Z,1703191380.062 [senddata_direct_and_track_test:AbortDrift](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:AbortDrift 2023-12-21T20:43:00.062Z,1703191380.062 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift] Stopped 2023-12-21T20:43:00.062Z,1703191380.062 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Uninitializing AbortDrift. 2023-12-21T20:43:00.062Z,1703191380.062 [senddata_direct_and_track_test:TrackAC.] Stopped 2023-12-21T20:43:00.063Z,1703191380.063 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact. 2023-12-21T20:43:00.456Z,1703191380.456 [MissionManager](IMPORTANT): Started mission Default 2023-12-21T20:43:00.456Z,1703191380.456 [Default] Running Loop=1 2023-12-21T20:43:00.456Z,1703191380.456 [Default](DEBUG): Aggregate::initialize Default 2023-12-21T20:43:00.456Z,1703191380.456 [Default:B.GoToSurface] Running Loop=1 2023-12-21T20:43:00.456Z,1703191380.456 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-12-21T20:43:00.457Z,1703191380.457 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-12-21T20:43:00.457Z,1703191380.457 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-12-21T20:43:00.457Z,1703191380.457 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-12-21T20:43:00.486Z,1703191380.486 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-12-21T20:43:00.486Z,1703191380.486 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-12-21T20:43:00.487Z,1703191380.487 [Default:A.Wait] Running Loop=1 2023-12-21T20:43:00.487Z,1703191380.487 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-12-21T20:43:02.438Z,1703191382.438 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).