2023-05-12T17:26:09.179Z,1683912369.179 [CommandExec](IMPORTANT): got command restart logs 2023-05-12T17:26:09.827Z,1683912369.827 [NAL9602](INFO): Powering up NAL9602 2023-05-12T17:26:20.799Z,1683912380.799 [NAL9602](INFO): NAL9602 initialized 2023-05-12T17:26:28.622Z,1683912388.622 [CommandExec](IMPORTANT): got command failComponent 2023-05-12T17:26:28.623Z,1683912388.623 [CommandExec](IMPORTANT): Failed components: 2023-05-12T17:26:28.623Z,1683912388.623 [CommandExec](IMPORTANT): No failed Components. 2023-05-12T17:26:39.881Z,1683912399.881 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml 2023-05-12T17:26:39.881Z,1683912399.881 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml 2023-05-12T17:26:39.953Z,1683912399.953 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 10.000000 count 2023-05-12T17:26:39.967Z,1683912399.967 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m 2023-05-12T17:26:39.969Z,1683912399.969 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s 2023-05-12T17:26:39.973Z,1683912399.973 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count 2023-05-12T17:26:39.976Z,1683912399.976 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count 2023-05-12T17:26:39.978Z,1683912399.978 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count 2023-05-12T17:26:39.980Z,1683912399.980 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.BeingInterrogatedTimeout = 1.000000 h 2023-05-12T17:26:39.982Z,1683912399.982 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min 2023-05-12T17:26:39.984Z,1683912399.984 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum 2023-05-12T17:26:39.986Z,1683912399.986 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum 2023-05-12T17:26:39.989Z,1683912399.989 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum 2023-05-12T17:26:39.989Z,1683912399.989 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/AbortDrift.xml 2023-05-12T17:26:40.004Z,1683912400.004 [MissionManager](INFO): DefineArg senddata_direct_and_track_test:AbortDrift.AcousticTimeout = 96.000000 h 2023-05-12T17:26:40.032Z,1683912400.032 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](DEBUG): Construct AbortDrift. 2023-05-12T17:26:40.034Z,1683912400.034 [senddata_direct_and_track_test:AbortDrift:C.Execute](DEBUG): Construct Execute. 2023-05-12T17:26:40.036Z,1683912400.036 [MissionManager](INFO): RedefineArg senddata_direct_and_track_test:AbortDrift.AcousticTimeout = reader:senddata_direct_and_track_test.BeingInterrogatedTimeout 2023-05-12T17:26:40.169Z,1683912400.169 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait. 2023-05-12T17:26:40.216Z,1683912400.216 [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-05-12T17:26:40.223Z,1683912400.223 [Default] Stopped 2023-05-12T17:26:40.223Z,1683912400.223 [Default](DEBUG): Aggregate::uninitialize Default 2023-05-12T17:26:40.223Z,1683912400.223 [Default:B.GoToSurface] Stopped 2023-05-12T17:26:40.223Z,1683912400.223 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-05-12T17:26:40.223Z,1683912400.223 [Default:CheckIn] Stopped 2023-05-12T17:26:40.223Z,1683912400.223 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-12T17:26:40.223Z,1683912400.223 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T17:26:40.223Z,1683912400.223 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test 2023-05-12T17:26:40.224Z,1683912400.224 [senddata_direct_and_track_test] Running Loop=1 2023-05-12T17:26:40.224Z,1683912400.224 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test 2023-05-12T17:26:40.224Z,1683912400.224 [senddata_direct_and_track_test:AbortDrift] Running Loop=1 2023-05-12T17:26:40.224Z,1683912400.224 [senddata_direct_and_track_test:AbortDrift](DEBUG): Aggregate::initialize senddata_direct_and_track_test:AbortDrift 2023-05-12T17:26:40.224Z,1683912400.224 [senddata_direct_and_track_test:AbortDrift:A] Running Loop=1 2023-05-12T17:26:40.224Z,1683912400.224 [senddata_direct_and_track_test:TrackAC.] Running Loop=1 2023-05-12T17:26:40.224Z,1683912400.224 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact. 2023-05-12T17:26:40.225Z,1683912400.225 [senddata_direct_and_track_test:DirectData] Running Loop=1 2023-05-12T17:26:40.225Z,1683912400.225 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData 2023-05-12T17:26:40.225Z,1683912400.225 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1 2023-05-12T17:26:40.225Z,1683912400.225 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component. 2023-05-12T17:26:40.225Z,1683912400.225 [senddata_direct_and_track_test:TrackAC.] Running Loop=1 2023-05-12T17:26:40.226Z,1683912400.226 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml 2023-05-12T17:26:40.230Z,1683912400.230 [senddata_direct_and_track_test:AbortDrift] Running Loop=1 2023-05-12T17:26:40.231Z,1683912400.231 [senddata_direct_and_track_test:AbortDrift:A](INFO): Insert acoustic timeout set to 1.000000 h . 2023-05-12T17:26:40.231Z,1683912400.231 [senddata_direct_and_track_test:AbortDrift:A] Stopped 2023-05-12T17:26:40.231Z,1683912400.231 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift] Running Loop=1 2023-05-12T17:26:40.231Z,1683912400.231 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Initializing AbortDrift. 2023-05-12T17:26:40.232Z,1683912400.232 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](IMPORTANT): Acoustic timeout set to: 1.00 hours. 2023-05-12T17:26:40.613Z,1683912400.613 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid gps time fix: 1683911680.00. Resetting abort timer. 2023-05-12T17:26:40.614Z,1683912400.614 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912320.00. Resetting abort timer. 2023-05-12T17:26:55.561Z,1683912415.561 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T17:26:55.782Z,1683912415.782 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T17:26:55.782Z,1683912415.782 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T17:26:55.783Z,1683912415.783 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T17:26:56.034Z,1683912416.034 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:26:56.035Z,1683912416.035 [DATMMP](INFO): timestamp rx: x0 x11 x1A x36 x24D8 2023-05-12T17:26:56.035Z,1683912416.035 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:26:56.035Z,1683912416.035 [DATMMP](INFO): Handled 2023-05-12T17:26:56.036Z,1683912416.036 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:56.286Z,1683912416.286 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:56.538Z,1683912416.538 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:56.790Z,1683912416.790 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:57.042Z,1683912417.042 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:57.294Z,1683912417.294 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:57.546Z,1683912417.546 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:57.798Z,1683912417.798 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:58.050Z,1683912418.050 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:58.302Z,1683912418.302 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:26:58.303Z,1683912418.303 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T17:26:58.303Z,1683912418.303 [DATMMP](INFO): Received message type: doppler 2023-05-12T17:26:58.303Z,1683912418.303 [DATMMP](INFO): Handled 2023-05-12T17:26:58.303Z,1683912418.303 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:58.554Z,1683912418.554 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:26:58.555Z,1683912418.555 [DATMMP](INFO): timestamp rx: x1 x11 x1A x38 x2609 2023-05-12T17:26:58.556Z,1683912418.556 [DATMMP](INFO): Rx dataTimestamp_ set to:1683912447.092160 2023-05-12T17:26:58.556Z,1683912418.556 [DATMMP](INFO): Rx ping set to:1683912418.555305 2023-05-12T17:26:58.556Z,1683912418.556 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:26:58.556Z,1683912418.556 [DATMMP](INFO): Handled 2023-05-12T17:26:58.557Z,1683912418.557 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:58.806Z,1683912418.806 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:59.058Z,1683912419.058 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:26:59.059Z,1683912419.059 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T17:26:59.060Z,1683912419.060 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T17:26:59.060Z,1683912419.060 [DATMMP](INFO): Received message type: remote_header 2023-05-12T17:26:59.060Z,1683912419.060 [DATMMP](INFO): Handled 2023-05-12T17:26:59.060Z,1683912419.060 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:59.311Z,1683912419.311 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:26:59.311Z,1683912419.311 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T17:26:59.312Z,1683912419.312 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T17:26:59.312Z,1683912419.312 [DATMMP](INFO): Handled 2023-05-12T17:26:59.312Z,1683912419.312 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:59.562Z,1683912419.562 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:26:59.563Z,1683912419.563 [DATMMP](INFO): directional_debug rx: x39 x1EE x24 xB3 x10E0 x13B1 x1282 x1733 2023-05-12T17:26:59.564Z,1683912419.564 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T17:26:59.564Z,1683912419.564 [DATMMP](INFO): Handled 2023-05-12T17:26:59.565Z,1683912419.565 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:26:59.593Z,1683912419.593 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:26:59.814Z,1683912419.814 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:26:59.816Z,1683912419.816 [DATMMP](INFO): directional rx: x32 x1A8 x5A3 xFE12 x6B6 xFE19 x0 x128 x6 xFFEE x27B5966 x-43569E0 2023-05-12T17:26:59.818Z,1683912419.818 [DATMMP](INFO): Received message type: directional 2023-05-12T17:26:59.818Z,1683912419.818 [DATMMP](INFO): Handled 2023-05-12T17:26:59.818Z,1683912419.818 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:00.003Z,1683912420.003 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:27:00.066Z,1683912420.066 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:00.068Z,1683912420.068 [DATMMP](INFO): acstats rx: xA x0 xFFFF x28E x22 x90 xB4 xAB xD xFFFF xB3 x1E xC x0 2023-05-12T17:27:00.068Z,1683912420.068 [DATMMP](INFO): Received message type: acstats 2023-05-12T17:27:00.068Z,1683912420.068 [DATMMP](INFO): Handled 2023-05-12T17:27:00.068Z,1683912420.068 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:00.318Z,1683912420.318 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:00.319Z,1683912420.319 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T17:27:00.320Z,1683912420.320 [DATMMP](INFO): Received message type: range_update 2023-05-12T17:27:00.320Z,1683912420.320 [DATMMP](INFO): Handled 2023-05-12T17:27:00.321Z,1683912420.321 [DATMMP](INFO): direction in FSK: [-0.693706,-0.036355,0.719340] 2023-05-12T17:27:00.421Z,1683912420.421 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T17:27:00.421Z,1683912420.421 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T17:27:00.570Z,1683912420.570 [DATMMP](INFO): GSXN notify for xid: 48 2023-05-12T17:27:00.571Z,1683912420.571 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T17:27:00.572Z,1683912420.572 [DATMMP](ERROR): 4:Command error: data 2023-05-12T17:27:00.572Z,1683912420.572 [DATMMP](DEBUG): Command complete rang 2023-05-12T17:27:00.572Z,1683912420.572 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T17:27:10.905Z,1683912430.905 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T17:27:11.154Z,1683912431.154 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T17:27:11.154Z,1683912431.154 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T17:27:11.155Z,1683912431.155 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T17:27:11.406Z,1683912431.406 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:11.407Z,1683912431.407 [DATMMP](INFO): timestamp rx: x0 x11 x1B xA xB73 2023-05-12T17:27:11.408Z,1683912431.408 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:11.408Z,1683912431.408 [DATMMP](INFO): Handled 2023-05-12T17:27:11.408Z,1683912431.408 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:11.658Z,1683912431.658 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:11.702Z,1683912431.702 [NAL9602](INFO): Not Powering down - fast GPS 2023-05-12T17:27:11.910Z,1683912431.910 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:12.162Z,1683912432.162 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:12.414Z,1683912432.414 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:12.666Z,1683912432.666 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:12.918Z,1683912432.918 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:13.170Z,1683912433.170 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:13.424Z,1683912433.424 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:13.674Z,1683912433.674 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:13.675Z,1683912433.675 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T17:27:13.675Z,1683912433.675 [DATMMP](INFO): Received message type: doppler 2023-05-12T17:27:13.675Z,1683912433.675 [DATMMP](INFO): Handled 2023-05-12T17:27:13.675Z,1683912433.675 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:13.926Z,1683912433.926 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:13.927Z,1683912433.927 [DATMMP](INFO): timestamp rx: x1 x11 x1B xC xCA4 2023-05-12T17:27:13.928Z,1683912433.928 [DATMMP](INFO): Rx dataTimestamp_ set to:1683912463.630784 2023-05-12T17:27:13.928Z,1683912433.928 [DATMMP](INFO): Rx ping set to:1683912433.927391 2023-05-12T17:27:13.928Z,1683912433.928 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:13.928Z,1683912433.928 [DATMMP](INFO): Handled 2023-05-12T17:27:13.929Z,1683912433.929 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:14.192Z,1683912434.192 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:14.446Z,1683912434.446 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:14.448Z,1683912434.448 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T17:27:14.448Z,1683912434.448 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T17:27:14.448Z,1683912434.448 [DATMMP](INFO): Received message type: remote_header 2023-05-12T17:27:14.448Z,1683912434.448 [DATMMP](INFO): Handled 2023-05-12T17:27:14.448Z,1683912434.448 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:14.698Z,1683912434.698 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:14.699Z,1683912434.699 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T17:27:14.699Z,1683912434.699 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T17:27:14.699Z,1683912434.699 [DATMMP](INFO): Handled 2023-05-12T17:27:14.700Z,1683912434.700 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:14.950Z,1683912434.950 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:14.952Z,1683912434.952 [DATMMP](INFO): directional_debug rx: xE2 x18A x24 xA0 x1080 x13B1 x12C2 x16F3 2023-05-12T17:27:14.953Z,1683912434.953 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T17:27:14.953Z,1683912434.953 [DATMMP](INFO): Handled 2023-05-12T17:27:14.953Z,1683912434.953 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:15.202Z,1683912435.202 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:15.204Z,1683912435.204 [DATMMP](INFO): directional rx: xDC x12C x4FA xFE76 x5F4 xFE82 x0 x107 x5 xFFED x27B5966 x-43569E0 2023-05-12T17:27:15.206Z,1683912435.206 [DATMMP](INFO): Received message type: directional 2023-05-12T17:27:15.206Z,1683912435.206 [DATMMP](INFO): Handled 2023-05-12T17:27:15.206Z,1683912435.206 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:15.357Z,1683912435.357 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:27:15.454Z,1683912435.454 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:15.456Z,1683912435.456 [DATMMP](INFO): acstats rx: xA x0 xFFFF x2C7 x23 x9C xCA xB3 xD xFFFF xB2 x1D xA x0 2023-05-12T17:27:15.456Z,1683912435.456 [DATMMP](INFO): Received message type: acstats 2023-05-12T17:27:15.456Z,1683912435.456 [DATMMP](INFO): Handled 2023-05-12T17:27:15.457Z,1683912435.457 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:15.706Z,1683912435.706 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:15.707Z,1683912435.707 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T17:27:15.707Z,1683912435.707 [DATMMP](INFO): Received message type: range_update 2023-05-12T17:27:15.708Z,1683912435.708 [DATMMP](INFO): Handled 2023-05-12T17:27:15.709Z,1683912435.709 [DATMMP](INFO): direction in FSK: [-0.804412,-0.200562,0.559193] 2023-05-12T17:27:15.807Z,1683912435.807 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T17:27:15.807Z,1683912435.807 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T17:27:15.958Z,1683912435.958 [DATMMP](INFO): GSXN notify for xid: 49 2023-05-12T17:27:15.959Z,1683912435.959 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T17:27:15.959Z,1683912435.959 [DATMMP](ERROR): 4:Command error: data 2023-05-12T17:27:15.960Z,1683912435.960 [DATMMP](DEBUG): Command complete rang 2023-05-12T17:27:15.960Z,1683912435.960 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T17:27:26.284Z,1683912446.284 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T17:27:26.294Z,1683912446.294 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T17:27:26.295Z,1683912446.295 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T17:27:26.295Z,1683912446.295 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T17:27:26.546Z,1683912446.546 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:26.547Z,1683912446.547 [DATMMP](INFO): timestamp rx: x0 x11 x1B x19 x114E 2023-05-12T17:27:26.547Z,1683912446.547 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:26.548Z,1683912446.548 [DATMMP](INFO): Handled 2023-05-12T17:27:26.548Z,1683912446.548 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:26.798Z,1683912446.798 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:27.050Z,1683912447.050 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:27.302Z,1683912447.302 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:27.554Z,1683912447.554 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:27.806Z,1683912447.806 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:28.058Z,1683912448.058 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:28.310Z,1683912448.310 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:28.564Z,1683912448.564 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:28.814Z,1683912448.814 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:28.815Z,1683912448.815 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T17:27:28.815Z,1683912448.815 [DATMMP](INFO): Received message type: doppler 2023-05-12T17:27:28.815Z,1683912448.815 [DATMMP](INFO): Handled 2023-05-12T17:27:28.815Z,1683912448.815 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:29.066Z,1683912449.066 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:29.067Z,1683912449.067 [DATMMP](INFO): timestamp rx: x1 x11 x1B x1B x127F 2023-05-12T17:27:29.068Z,1683912449.068 [DATMMP](INFO): Rx dataTimestamp_ set to:1683912493.251904 2023-05-12T17:27:29.068Z,1683912449.068 [DATMMP](INFO): Rx ping set to:1683912449.067333 2023-05-12T17:27:29.068Z,1683912449.068 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:29.068Z,1683912449.068 [DATMMP](INFO): Handled 2023-05-12T17:27:29.069Z,1683912449.069 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:29.318Z,1683912449.318 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:29.570Z,1683912449.570 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:29.572Z,1683912449.572 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T17:27:29.572Z,1683912449.572 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T17:27:29.572Z,1683912449.572 [DATMMP](INFO): Received message type: remote_header 2023-05-12T17:27:29.572Z,1683912449.572 [DATMMP](INFO): Handled 2023-05-12T17:27:29.572Z,1683912449.572 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:29.822Z,1683912449.822 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:29.823Z,1683912449.823 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T17:27:29.823Z,1683912449.823 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T17:27:29.823Z,1683912449.823 [DATMMP](INFO): Handled 2023-05-12T17:27:29.823Z,1683912449.823 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:30.074Z,1683912450.074 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:30.076Z,1683912450.076 [DATMMP](INFO): directional_debug rx: x20 x1F3 x24 xBB x1060 x1361 x1222 x1673 2023-05-12T17:27:30.077Z,1683912450.077 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T17:27:30.077Z,1683912450.077 [DATMMP](INFO): Handled 2023-05-12T17:27:30.077Z,1683912450.077 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:30.324Z,1683912450.324 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:27:30.326Z,1683912450.326 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:30.328Z,1683912450.328 [DATMMP](INFO): directional rx: x19 x1AF x5BC xFE0D x692 xFE11 x0 xE9 x5 xFFF0 x27B5966 x-43569E0 2023-05-12T17:27:30.330Z,1683912450.330 [DATMMP](INFO): Received message type: directional 2023-05-12T17:27:30.330Z,1683912450.330 [DATMMP](INFO): Handled 2023-05-12T17:27:30.330Z,1683912450.330 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:30.578Z,1683912450.578 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:30.580Z,1683912450.580 [DATMMP](INFO): acstats rx: xA x0 xFFFF x293 x16 x9B xB4 xAF xD xFFFF xBD x20 xC x0 2023-05-12T17:27:30.580Z,1683912450.580 [DATMMP](INFO): Received message type: acstats 2023-05-12T17:27:30.580Z,1683912450.580 [DATMMP](INFO): Handled 2023-05-12T17:27:30.581Z,1683912450.581 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:30.731Z,1683912450.731 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:27:30.830Z,1683912450.830 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:30.831Z,1683912450.831 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T17:27:30.832Z,1683912450.832 [DATMMP](INFO): Received message type: range_update 2023-05-12T17:27:30.832Z,1683912450.832 [DATMMP](INFO): Handled 2023-05-12T17:27:30.833Z,1683912450.833 [DATMMP](INFO): direction in FSK: [-0.666369,-0.354315,0.656059] 2023-05-12T17:27:31.082Z,1683912451.082 [DATMMP](INFO): GSXN notify for xid: 50 2023-05-12T17:27:31.083Z,1683912451.083 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T17:27:31.083Z,1683912451.083 [DATMMP](ERROR): 4:Command error: data 2023-05-12T17:27:31.084Z,1683912451.084 [DATMMP](DEBUG): Command complete rang 2023-05-12T17:27:31.084Z,1683912451.084 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T17:27:31.174Z,1683912451.174 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T17:27:31.174Z,1683912451.174 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T17:27:40.421Z,1683912460.421 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting. 2023-05-12T17:27:40.421Z,1683912460.421 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped 2023-05-12T17:27:40.421Z,1683912460.421 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T17:27:40.421Z,1683912460.421 [senddata_direct_and_track_test:DirectData:B] Running Loop=1 2023-05-12T17:27:40.900Z,1683912460.900 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:10:_.pressure 2023-05-12T17:27:40.900Z,1683912460.900 [senddata_direct_and_track_test:DirectData:B] Stopped 2023-05-12T17:27:40.900Z,1683912460.900 [senddata_direct_and_track_test:DirectData:C] Running Loop=1 2023-05-12T17:27:40.910Z,1683912460.910 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:27:40.915Z,1683912460.915 [DATMMP](INFO): modem://10: set _.pressure 0.743017 atmosphere 2023-05-12T17:27:40.916Z,1683912460.916 [DATMMP](INFO): #Outgoing data=1 2023-05-12T17:27:40.916Z,1683912460.916 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:27:41.162Z,1683912461.162 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:27:41.162Z,1683912461.162 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:27:41.233Z,1683912461.233 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:10:_.temperature 2023-05-12T17:27:41.233Z,1683912461.233 [senddata_direct_and_track_test:DirectData:C] Stopped 2023-05-12T17:27:41.234Z,1683912461.234 [senddata_direct_and_track_test:DirectData:D] Running Loop=1 2023-05-12T17:27:41.414Z,1683912461.414 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:27:41.415Z,1683912461.415 [DATMMP](INFO): Tx to 10 len 34 xid 51 2023-05-12T17:27:41.415Z,1683912461.415 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T17:27:41.415Z,1683912461.415 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:27:41.632Z,1683912461.632 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:10:_.humidity 2023-05-12T17:27:41.632Z,1683912461.632 [senddata_direct_and_track_test:DirectData:D] Stopped 2023-05-12T17:27:41.633Z,1683912461.633 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData 2023-05-12T17:27:41.633Z,1683912461.633 [senddata_direct_and_track_test:DirectData] Stopped 2023-05-12T17:27:41.633Z,1683912461.633 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData 2023-05-12T17:27:41.633Z,1683912461.633 [senddata_direct_and_track_test:DirectData](INFO): Running loop #2 2023-05-12T17:27:41.633Z,1683912461.633 [senddata_direct_and_track_test:DirectData] Running Loop=2 2023-05-12T17:27:41.633Z,1683912461.633 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData 2023-05-12T17:27:41.633Z,1683912461.633 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1 2023-05-12T17:27:41.633Z,1683912461.633 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component. 2023-05-12T17:27:41.634Z,1683912461.634 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T17:27:41.666Z,1683912461.666 [DATMMP](INFO): GSXN notify for xid: 51 2023-05-12T17:27:41.667Z,1683912461.667 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-05-12T17:27:41.667Z,1683912461.667 [DATMMP](DEBUG): Command complete send 2023-05-12T17:27:41.668Z,1683912461.668 [DATMMP](ERROR): 1:COMPLETE 2023-05-12T17:27:41.668Z,1683912461.668 [DATMMP](INFO): Received message type: cmd_result 2023-05-12T17:27:41.668Z,1683912461.668 [DATMMP](INFO): Handled 2023-05-12T17:27:41.668Z,1683912461.668 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:41.668Z,1683912461.668 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T17:27:41.668Z,1683912461.668 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T17:27:41.669Z,1683912461.669 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T17:27:41.918Z,1683912461.918 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:41.919Z,1683912461.919 [DATMMP](INFO): timestamp rx: x0 x11 x1B x28 x1911 2023-05-12T17:27:41.919Z,1683912461.919 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:41.920Z,1683912461.920 [DATMMP](INFO): Handled 2023-05-12T17:27:41.920Z,1683912461.920 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:41.920Z,1683912461.920 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:42.170Z,1683912462.170 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:42.171Z,1683912462.171 [DATMMP](INFO): timestamp rx: x0 x11 x1B x28 x1EF9 2023-05-12T17:27:42.172Z,1683912462.172 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:42.172Z,1683912462.172 [DATMMP](INFO): Handled 2023-05-12T17:27:42.172Z,1683912462.172 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:42.172Z,1683912462.172 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:42.422Z,1683912462.422 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:42.422Z,1683912462.422 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:42.674Z,1683912462.674 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:42.674Z,1683912462.674 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:42.926Z,1683912462.926 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:42.926Z,1683912462.926 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:43.178Z,1683912463.178 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:43.178Z,1683912463.178 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:43.430Z,1683912463.430 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:43.430Z,1683912463.430 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:43.682Z,1683912463.682 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:43.682Z,1683912463.682 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:43.934Z,1683912463.934 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:43.934Z,1683912463.934 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:44.186Z,1683912464.186 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:44.186Z,1683912464.186 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:44.438Z,1683912464.438 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:44.438Z,1683912464.438 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:44.690Z,1683912464.690 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:44.690Z,1683912464.690 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:44.942Z,1683912464.942 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:44.943Z,1683912464.943 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:45.194Z,1683912465.194 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:45.194Z,1683912465.194 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:45.446Z,1683912465.446 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:45.446Z,1683912465.446 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:45.698Z,1683912465.698 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:45.699Z,1683912465.699 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T17:27:45.699Z,1683912465.699 [DATMMP](INFO): Received message type: doppler 2023-05-12T17:27:45.699Z,1683912465.699 [DATMMP](INFO): Handled 2023-05-12T17:27:45.699Z,1683912465.699 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:45.700Z,1683912465.700 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:45.950Z,1683912465.950 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:45.951Z,1683912465.951 [DATMMP](INFO): timestamp rx: x1 x11 x1B x2C xE08 2023-05-12T17:27:45.952Z,1683912465.952 [DATMMP](INFO): Rx dataTimestamp_ set to:1683912499.081920 2023-05-12T17:27:45.952Z,1683912465.952 [DATMMP](INFO): Rx ping set to:1683912465.951346 2023-05-12T17:27:45.952Z,1683912465.952 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:45.952Z,1683912465.952 [DATMMP](INFO): Handled 2023-05-12T17:27:45.953Z,1683912465.953 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:45.953Z,1683912465.953 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:46.202Z,1683912466.202 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:46.202Z,1683912466.202 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:46.455Z,1683912466.455 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:46.456Z,1683912466.456 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T17:27:46.456Z,1683912466.456 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T17:27:46.456Z,1683912466.456 [DATMMP](INFO): Received message type: remote_header 2023-05-12T17:27:46.456Z,1683912466.456 [DATMMP](INFO): Handled 2023-05-12T17:27:46.457Z,1683912466.457 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:46.457Z,1683912466.457 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:46.706Z,1683912466.706 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:46.707Z,1683912466.707 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T17:27:46.707Z,1683912466.707 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T17:27:46.707Z,1683912466.707 [DATMMP](INFO): Handled 2023-05-12T17:27:46.708Z,1683912466.708 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:46.708Z,1683912466.708 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:46.958Z,1683912466.958 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:46.959Z,1683912466.959 [DATMMP](INFO): directional_debug rx: x20A x1F1 x24 x1CA x10B0 x13B1 x1272 x16C3 2023-05-12T17:27:46.960Z,1683912466.960 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T17:27:46.960Z,1683912466.960 [DATMMP](INFO): Handled 2023-05-12T17:27:46.961Z,1683912466.961 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:46.961Z,1683912466.961 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:47.210Z,1683912467.210 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:47.212Z,1683912467.212 [DATMMP](INFO): directional rx: x20F x19F x3D2 xFE0F x498 xFE1F x0 xCE x5 xFFF0 x27B5966 x-43569E0 2023-05-12T17:27:47.214Z,1683912467.214 [DATMMP](INFO): Received message type: directional 2023-05-12T17:27:47.214Z,1683912467.214 [DATMMP](INFO): Handled 2023-05-12T17:27:47.214Z,1683912467.214 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:47.214Z,1683912467.214 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:47.324Z,1683912467.324 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:27:47.462Z,1683912467.462 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:47.464Z,1683912467.464 [DATMMP](INFO): acstats rx: xA x0 xFFFF x2A3 x17 x9C xCA xB3 xD xFFFF xB0 x1E xC x0 2023-05-12T17:27:47.464Z,1683912467.464 [DATMMP](INFO): Received message type: acstats 2023-05-12T17:27:47.464Z,1683912467.464 [DATMMP](INFO): Handled 2023-05-12T17:27:47.465Z,1683912467.465 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:47.465Z,1683912467.465 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:47.714Z,1683912467.714 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:47.715Z,1683912467.715 [DATMMP](INFO): range_update rx: xA x2 x2D09 x3C0D 2023-05-12T17:27:47.716Z,1683912467.716 [DATMMP](INFO): Received message type: range_update 2023-05-12T17:27:47.716Z,1683912467.716 [DATMMP](INFO): Handled 2023-05-12T17:27:47.716Z,1683912467.716 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:47.717Z,1683912467.717 [DATMMP](INFO): direction in FSK: [0.152057,0.715372,0.681998] 2023-05-12T17:27:47.720Z,1683912467.720 [Reporter](INFO): DATMMP.acoustic_contact_range 1152.900024 m 2023-05-12T17:27:47.720Z,1683912467.720 [Reporter](INFO): acoustic_contact_range 1152.900024 m 2023-05-12T17:27:47.966Z,1683912467.966 [DATMMP](INFO): GSXN notify for xid: 52 2023-05-12T17:27:47.967Z,1683912467.967 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T17:27:47.967Z,1683912467.967 [DATMMP](ERROR): 4:Command error: data 2023-05-12T17:27:47.968Z,1683912467.968 [DATMMP](DEBUG): Command complete rang 2023-05-12T17:27:47.968Z,1683912467.968 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T17:27:47.968Z,1683912467.968 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:48.218Z,1683912468.218 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:48.219Z,1683912468.219 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T17:27:48.219Z,1683912468.219 [DATMMP](INFO): Received message type: doppler 2023-05-12T17:27:48.219Z,1683912468.219 [DATMMP](INFO): Handled 2023-05-12T17:27:48.219Z,1683912468.219 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:48.470Z,1683912468.470 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:48.471Z,1683912468.471 [DATMMP](INFO): timestamp rx: x1 x11 x1B x2D x2014 2023-05-12T17:27:48.472Z,1683912468.472 [DATMMP](INFO): Rx dataTimestamp_ set to:1683912481.204800 2023-05-12T17:27:48.472Z,1683912468.472 [DATMMP](INFO): Rx ping set to:1683912468.471212 2023-05-12T17:27:48.472Z,1683912468.472 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:48.472Z,1683912468.472 [DATMMP](INFO): Handled 2023-05-12T17:27:48.472Z,1683912468.472 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:48.722Z,1683912468.722 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:48.724Z,1683912468.724 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-05-12T17:27:48.724Z,1683912468.724 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T17:27:48.724Z,1683912468.724 [DATMMP](INFO): Received message type: remote_header 2023-05-12T17:27:48.724Z,1683912468.724 [DATMMP](INFO): Handled 2023-05-12T17:27:48.724Z,1683912468.724 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:48.974Z,1683912468.974 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:48.975Z,1683912468.975 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T17:27:48.975Z,1683912468.975 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T17:27:48.975Z,1683912468.975 [DATMMP](INFO): Handled 2023-05-12T17:27:48.975Z,1683912468.975 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:49.226Z,1683912469.226 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:49.227Z,1683912469.227 [DATMMP](INFO): directional_debug rx: xCC x19D x24 xCA x1070 x1361 x1262 x1673 2023-05-12T17:27:49.228Z,1683912469.228 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T17:27:49.228Z,1683912469.228 [DATMMP](INFO): Handled 2023-05-12T17:27:49.229Z,1683912469.229 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:49.360Z,1683912469.360 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:27:49.479Z,1683912469.479 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:49.480Z,1683912469.480 [DATMMP](INFO): directional rx: xC5 x142 x510 xFE63 x5CE xFE6C x0 xCB x6 xFFF0 x27B5966 x-43569E0 2023-05-12T17:27:49.482Z,1683912469.482 [DATMMP](INFO): Received message type: directional 2023-05-12T17:27:49.482Z,1683912469.482 [DATMMP](INFO): Handled 2023-05-12T17:27:49.482Z,1683912469.482 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:49.720Z,1683912469.720 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:27:49.730Z,1683912469.730 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:49.732Z,1683912469.732 [DATMMP](INFO): acstats rx: xA x5 xFFFF x2D0 x23 x8C xBD xBD xD xFFFF xAF x24 xD x0 2023-05-12T17:27:49.732Z,1683912469.732 [DATMMP](INFO): Received message type: acstats 2023-05-12T17:27:49.732Z,1683912469.732 [DATMMP](INFO): Handled 2023-05-12T17:27:49.733Z,1683912469.733 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:49.982Z,1683912469.982 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:49.983Z,1683912469.983 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-05-12T17:27:49.983Z,1683912469.983 [DATMMP](INFO): Check CRC 2023-05-12T17:27:49.983Z,1683912469.983 [DATMMP](INFO): data rx parseDataResponse 4 2023-05-12T17:27:49.983Z,1683912469.983 [DATMMP](INFO): Got DATA: len 4 2023-05-12T17:27:49.984Z,1683912469.984 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-05-12T17:27:49.984Z,1683912469.984 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-05-12T17:27:49.984Z,1683912469.984 [DATMMP](INFO): Received command: 2023-05-12T17:27:49.984Z,1683912469.984 [DATMMP](INFO): Received message type: data_rx 2023-05-12T17:27:49.984Z,1683912469.984 [DATMMP](INFO): Handled 2023-05-12T17:27:49.984Z,1683912469.984 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-05-12T17:27:49.985Z,1683912469.985 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:27:50.234Z,1683912470.234 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:27:50.235Z,1683912470.235 [DATMMP](INFO): modem://10: set _.temperature 24.380426 celsius 2023-05-12T17:27:50.235Z,1683912470.235 [DATMMP](INFO): #Outgoing data=1 2023-05-12T17:27:50.235Z,1683912470.235 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:27:50.486Z,1683912470.486 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:27:50.486Z,1683912470.486 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:27:50.738Z,1683912470.738 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:27:50.739Z,1683912470.739 [DATMMP](INFO): Tx to 10 len 35 xid 53 2023-05-12T17:27:50.739Z,1683912470.739 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T17:27:50.739Z,1683912470.739 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:27:50.990Z,1683912470.990 [DATMMP](INFO): GSXN notify for xid: 53 2023-05-12T17:27:50.991Z,1683912470.991 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-05-12T17:27:50.991Z,1683912470.991 [DATMMP](DEBUG): Command complete send 2023-05-12T17:27:50.992Z,1683912470.992 [DATMMP](ERROR): 1:COMPLETE 2023-05-12T17:27:50.992Z,1683912470.992 [DATMMP](INFO): Received message type: cmd_result 2023-05-12T17:27:50.992Z,1683912470.992 [DATMMP](INFO): Handled 2023-05-12T17:27:50.992Z,1683912470.992 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:51.242Z,1683912471.242 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:51.243Z,1683912471.243 [DATMMP](INFO): timestamp rx: x0 x11 x1B x31 x24C8 2023-05-12T17:27:51.243Z,1683912471.243 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:51.243Z,1683912471.243 [DATMMP](INFO): Handled 2023-05-12T17:27:51.244Z,1683912471.244 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:51.494Z,1683912471.494 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:51.750Z,1683912471.750 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:52.002Z,1683912472.002 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:52.254Z,1683912472.254 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:52.506Z,1683912472.506 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:52.758Z,1683912472.758 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:53.010Z,1683912473.010 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:53.263Z,1683912473.263 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:53.514Z,1683912473.514 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:53.766Z,1683912473.766 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:54.018Z,1683912474.018 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:54.270Z,1683912474.270 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:54.522Z,1683912474.522 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:54.774Z,1683912474.774 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:55.026Z,1683912475.026 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:55.278Z,1683912475.278 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:55.530Z,1683912475.530 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:55.531Z,1683912475.531 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T17:27:55.531Z,1683912475.531 [DATMMP](INFO): Received message type: doppler 2023-05-12T17:27:55.531Z,1683912475.531 [DATMMP](INFO): Handled 2023-05-12T17:27:55.531Z,1683912475.531 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:55.782Z,1683912475.782 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:55.783Z,1683912475.783 [DATMMP](INFO): timestamp rx: x1 x11 x1B x36 x79E 2023-05-12T17:27:55.784Z,1683912475.784 [DATMMP](INFO): Rx dataTimestamp_ set to:1683912493.045056 2023-05-12T17:27:55.784Z,1683912475.784 [DATMMP](INFO): Rx ping set to:1683912475.783420 2023-05-12T17:27:55.784Z,1683912475.784 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:55.784Z,1683912475.784 [DATMMP](INFO): Handled 2023-05-12T17:27:55.785Z,1683912475.785 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:56.034Z,1683912476.034 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:56.286Z,1683912476.286 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:56.288Z,1683912476.288 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-05-12T17:27:56.288Z,1683912476.288 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T17:27:56.288Z,1683912476.288 [DATMMP](INFO): Received message type: remote_header 2023-05-12T17:27:56.288Z,1683912476.288 [DATMMP](INFO): Handled 2023-05-12T17:27:56.288Z,1683912476.288 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:56.538Z,1683912476.538 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:56.539Z,1683912476.539 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T17:27:56.539Z,1683912476.539 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T17:27:56.539Z,1683912476.539 [DATMMP](INFO): Handled 2023-05-12T17:27:56.539Z,1683912476.539 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:56.791Z,1683912476.791 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:56.792Z,1683912476.792 [DATMMP](INFO): directional_debug rx: x75 x1E1 x24 xC4 x10A0 x1361 x1222 x1693 2023-05-12T17:27:56.793Z,1683912476.793 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T17:27:56.793Z,1683912476.793 [DATMMP](INFO): Handled 2023-05-12T17:27:56.793Z,1683912476.793 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:56.991Z,1683912476.991 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T17:27:56.992Z,1683912476.992 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:27:57.042Z,1683912477.042 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:57.044Z,1683912477.044 [DATMMP](INFO): directional rx: x6E x196 x567 xFE1F x607 xFE29 x0 xB3 x5 xFFED x27B5966 x-43569E0 2023-05-12T17:27:57.046Z,1683912477.046 [DATMMP](INFO): Received message type: directional 2023-05-12T17:27:57.046Z,1683912477.046 [DATMMP](INFO): Handled 2023-05-12T17:27:57.046Z,1683912477.046 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:57.046Z,1683912477.046 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T17:27:57.046Z,1683912477.046 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T17:27:57.047Z,1683912477.047 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T17:27:57.294Z,1683912477.294 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:57.296Z,1683912477.296 [DATMMP](INFO): acstats rx: xA x5 xFFFF x2C7 x22 x91 xCB xC6 xD xFFFF xAF x25 xD x0 2023-05-12T17:27:57.296Z,1683912477.296 [DATMMP](INFO): Received message type: acstats 2023-05-12T17:27:57.296Z,1683912477.296 [DATMMP](INFO): Handled 2023-05-12T17:27:57.296Z,1683912477.296 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T17:27:57.297Z,1683912477.297 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:57.395Z,1683912477.395 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:27:57.546Z,1683912477.546 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:57.547Z,1683912477.547 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-05-12T17:27:57.547Z,1683912477.547 [DATMMP](INFO): Check CRC 2023-05-12T17:27:57.547Z,1683912477.547 [DATMMP](INFO): data rx parseDataResponse 4 2023-05-12T17:27:57.548Z,1683912477.548 [DATMMP](INFO): Got DATA: len 4 2023-05-12T17:27:57.548Z,1683912477.548 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-05-12T17:27:57.548Z,1683912477.548 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-05-12T17:27:57.548Z,1683912477.548 [DATMMP](INFO): Received command: 2023-05-12T17:27:57.548Z,1683912477.548 [DATMMP](INFO): Received message type: data_rx 2023-05-12T17:27:57.548Z,1683912477.548 [DATMMP](INFO): Handled 2023-05-12T17:27:57.549Z,1683912477.549 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-05-12T17:27:57.549Z,1683912477.549 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:27:57.549Z,1683912477.549 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:57.798Z,1683912477.798 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:57.799Z,1683912477.799 [DATMMP](INFO): timestamp rx: x0 x11 x1B x38 x788 2023-05-12T17:27:57.799Z,1683912477.799 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:57.800Z,1683912477.800 [DATMMP](INFO): Handled 2023-05-12T17:27:57.800Z,1683912477.800 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:27:57.801Z,1683912477.801 [DATMMP](INFO): modem://10: set _.humidity 12.879990 percent 2023-05-12T17:27:57.801Z,1683912477.801 [DATMMP](INFO): #Outgoing data=1 2023-05-12T17:27:57.801Z,1683912477.801 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:27:57.801Z,1683912477.801 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:58.050Z,1683912478.050 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:27:58.050Z,1683912478.050 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:27:58.051Z,1683912478.051 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:58.302Z,1683912478.302 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:27:58.303Z,1683912478.303 [DATMMP](INFO): Tx to 10 len 32 xid 55 2023-05-12T17:27:58.303Z,1683912478.303 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T17:27:58.303Z,1683912478.303 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:27:58.303Z,1683912478.303 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:58.554Z,1683912478.554 [DATMMP](INFO): GSXN notify for xid: 55 2023-05-12T17:27:58.555Z,1683912478.555 [DATMMP](INFO): iface_err rx: x1 x7 xA 2023-05-12T17:27:58.555Z,1683912478.555 [DATMMP](ERROR): 10:Error talking to DAT device_busy 2023-05-12T17:27:58.556Z,1683912478.556 [DATMMP](INFO): Received message type: iface_err 2023-05-12T17:27:58.556Z,1683912478.556 [DATMMP](INFO): Handled 2023-05-12T17:27:58.556Z,1683912478.556 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:27:58.556Z,1683912478.556 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:58.806Z,1683912478.806 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:27:58.807Z,1683912478.807 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:59.058Z,1683912479.058 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:27:59.058Z,1683912479.058 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:59.310Z,1683912479.310 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:27:59.310Z,1683912479.310 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:59.562Z,1683912479.562 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:59.563Z,1683912479.563 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T17:27:59.563Z,1683912479.563 [DATMMP](INFO): Received message type: doppler 2023-05-12T17:27:59.563Z,1683912479.563 [DATMMP](INFO): Handled 2023-05-12T17:27:59.563Z,1683912479.563 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:27:59.564Z,1683912479.564 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:27:59.814Z,1683912479.814 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:27:59.815Z,1683912479.815 [DATMMP](INFO): timestamp rx: x1 x11 x1B x3A x8B8 2023-05-12T17:27:59.816Z,1683912479.816 [DATMMP](INFO): Rx dataTimestamp_ set to:1683912499.835584 2023-05-12T17:27:59.816Z,1683912479.816 [DATMMP](INFO): Rx ping set to:1683912479.815393 2023-05-12T17:27:59.816Z,1683912479.816 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:27:59.816Z,1683912479.816 [DATMMP](INFO): Handled 2023-05-12T17:27:59.817Z,1683912479.817 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:27:59.817Z,1683912479.817 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:00.066Z,1683912480.066 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:00.066Z,1683912480.066 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:00.318Z,1683912480.318 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:00.320Z,1683912480.320 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T17:28:00.320Z,1683912480.320 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T17:28:00.320Z,1683912480.320 [DATMMP](INFO): Received message type: remote_header 2023-05-12T17:28:00.320Z,1683912480.320 [DATMMP](INFO): Handled 2023-05-12T17:28:00.320Z,1683912480.320 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:00.320Z,1683912480.320 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:00.570Z,1683912480.570 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:00.571Z,1683912480.571 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T17:28:00.571Z,1683912480.571 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T17:28:00.571Z,1683912480.571 [DATMMP](INFO): Handled 2023-05-12T17:28:00.571Z,1683912480.571 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:00.572Z,1683912480.572 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:00.822Z,1683912480.822 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:00.823Z,1683912480.823 [DATMMP](INFO): directional_debug rx: x5C x1CB x24 xB3 x1090 x13C1 x1272 x1693 2023-05-12T17:28:00.824Z,1683912480.824 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T17:28:00.824Z,1683912480.824 [DATMMP](INFO): Handled 2023-05-12T17:28:00.825Z,1683912480.825 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:00.825Z,1683912480.825 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:01.033Z,1683912481.033 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:28:01.074Z,1683912481.074 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:01.076Z,1683912481.076 [DATMMP](INFO): directional rx: x55 x17E x580 xFE35 x615 xFE3E x0 xA7 x5 xFFED x27B5966 x-43569E0 2023-05-12T17:28:01.078Z,1683912481.078 [DATMMP](INFO): Received message type: directional 2023-05-12T17:28:01.078Z,1683912481.078 [DATMMP](INFO): Handled 2023-05-12T17:28:01.078Z,1683912481.078 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:01.078Z,1683912481.078 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:01.326Z,1683912481.326 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:01.328Z,1683912481.328 [DATMMP](INFO): acstats rx: xA x0 xFFFF x2C2 x22 x9B xB4 xB0 xD xFFFF x90 x1D xA x0 2023-05-12T17:28:01.328Z,1683912481.328 [DATMMP](INFO): Received message type: acstats 2023-05-12T17:28:01.328Z,1683912481.328 [DATMMP](INFO): Handled 2023-05-12T17:28:01.329Z,1683912481.329 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:01.329Z,1683912481.329 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:01.432Z,1683912481.432 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:28:01.578Z,1683912481.578 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:01.579Z,1683912481.579 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T17:28:01.579Z,1683912481.579 [DATMMP](INFO): Received message type: range_update 2023-05-12T17:28:01.580Z,1683912481.580 [DATMMP](INFO): Handled 2023-05-12T17:28:01.580Z,1683912481.580 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:01.581Z,1683912481.581 [DATMMP](INFO): direction in FSK: [-0.132664,0.082898,0.987688] 2023-05-12T17:28:01.830Z,1683912481.830 [DATMMP](INFO): GSXN notify for xid: 54 2023-05-12T17:28:01.831Z,1683912481.831 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T17:28:01.831Z,1683912481.831 [DATMMP](ERROR): 4:Command error: data 2023-05-12T17:28:01.832Z,1683912481.832 [DATMMP](DEBUG): Command complete rang 2023-05-12T17:28:01.832Z,1683912481.832 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T17:28:01.896Z,1683912481.896 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T17:28:01.897Z,1683912481.897 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T17:28:02.082Z,1683912482.082 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:02.334Z,1683912482.334 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:02.586Z,1683912482.586 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:02.838Z,1683912482.838 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:03.090Z,1683912483.090 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:03.342Z,1683912483.342 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:03.594Z,1683912483.594 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:03.847Z,1683912483.847 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:04.098Z,1683912484.098 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:04.350Z,1683912484.350 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:04.602Z,1683912484.602 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:04.854Z,1683912484.854 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:05.106Z,1683912485.106 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:05.358Z,1683912485.358 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:05.612Z,1683912485.612 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:06.114Z,1683912486.114 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:06.366Z,1683912486.366 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:06.618Z,1683912486.618 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:06.870Z,1683912486.870 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:07.122Z,1683912487.122 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:07.374Z,1683912487.374 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:07.626Z,1683912487.626 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:07.878Z,1683912487.878 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:08.130Z,1683912488.130 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:08.382Z,1683912488.382 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:08.382Z,1683912488.382 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:08.382Z,1683912488.382 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:08.634Z,1683912488.634 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:08.634Z,1683912488.634 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:08.886Z,1683912488.886 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:08.886Z,1683912488.886 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:09.138Z,1683912489.138 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:09.138Z,1683912489.138 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:09.138Z,1683912489.138 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:09.138Z,1683912489.138 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:09.139Z,1683912489.139 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:09.390Z,1683912489.390 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:09.390Z,1683912489.390 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:09.642Z,1683912489.642 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:09.642Z,1683912489.642 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:09.894Z,1683912489.894 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:09.894Z,1683912489.894 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:09.894Z,1683912489.894 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:09.894Z,1683912489.894 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:09.895Z,1683912489.895 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:10.146Z,1683912490.146 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:10.146Z,1683912490.146 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:10.398Z,1683912490.398 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:10.398Z,1683912490.398 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:10.650Z,1683912490.650 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:10.650Z,1683912490.650 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:10.650Z,1683912490.650 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:10.650Z,1683912490.650 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:10.650Z,1683912490.650 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:10.902Z,1683912490.902 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:10.902Z,1683912490.902 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:11.154Z,1683912491.154 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:11.154Z,1683912491.154 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:11.406Z,1683912491.406 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:11.406Z,1683912491.406 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:11.406Z,1683912491.406 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:11.406Z,1683912491.406 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:11.406Z,1683912491.406 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:11.658Z,1683912491.658 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:11.658Z,1683912491.658 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:11.910Z,1683912491.910 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:11.910Z,1683912491.910 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:12.162Z,1683912492.162 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:12.162Z,1683912492.162 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:12.162Z,1683912492.162 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:12.162Z,1683912492.162 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:12.162Z,1683912492.162 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:12.354Z,1683912492.354 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T17:28:12.414Z,1683912492.414 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:12.414Z,1683912492.414 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:12.414Z,1683912492.414 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T17:28:12.415Z,1683912492.415 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T17:28:12.415Z,1683912492.415 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T17:28:12.666Z,1683912492.666 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:12.667Z,1683912492.667 [DATMMP](INFO): timestamp rx: x0 x11 x1C xB x1726 2023-05-12T17:28:12.667Z,1683912492.667 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:28:12.667Z,1683912492.667 [DATMMP](INFO): Handled 2023-05-12T17:28:12.668Z,1683912492.668 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:12.668Z,1683912492.668 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:12.668Z,1683912492.668 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:12.918Z,1683912492.918 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:12.918Z,1683912492.918 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:12.918Z,1683912492.918 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:12.918Z,1683912492.918 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:12.918Z,1683912492.918 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:12.919Z,1683912492.919 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:13.170Z,1683912493.170 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:13.171Z,1683912493.171 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:13.171Z,1683912493.171 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:13.422Z,1683912493.422 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:13.422Z,1683912493.422 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:13.422Z,1683912493.422 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:13.674Z,1683912493.674 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:13.674Z,1683912493.674 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:13.674Z,1683912493.674 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:13.674Z,1683912493.674 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:13.675Z,1683912493.675 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:13.675Z,1683912493.675 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:13.926Z,1683912493.926 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:13.926Z,1683912493.926 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:13.926Z,1683912493.926 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:14.178Z,1683912494.178 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:14.178Z,1683912494.178 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:14.178Z,1683912494.178 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:14.430Z,1683912494.430 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:14.430Z,1683912494.430 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:14.430Z,1683912494.430 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:14.430Z,1683912494.430 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:14.431Z,1683912494.431 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:14.431Z,1683912494.431 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:14.682Z,1683912494.682 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:14.682Z,1683912494.682 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:14.682Z,1683912494.682 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:14.934Z,1683912494.934 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:14.935Z,1683912494.935 [DATMMP](INFO): doppler rx: x0 2023-05-12T17:28:14.935Z,1683912494.935 [DATMMP](INFO): Received message type: doppler 2023-05-12T17:28:14.935Z,1683912494.935 [DATMMP](INFO): Handled 2023-05-12T17:28:14.936Z,1683912494.936 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:14.936Z,1683912494.936 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:14.936Z,1683912494.936 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:15.186Z,1683912495.186 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:15.187Z,1683912495.187 [DATMMP](INFO): timestamp rx: x1 x11 x1C xD x1857 2023-05-12T17:28:15.188Z,1683912495.188 [DATMMP](INFO): Rx dataTimestamp_ set to:1683912553.890880 2023-05-12T17:28:15.188Z,1683912495.188 [DATMMP](INFO): Rx ping set to:1683912495.187446 2023-05-12T17:28:15.188Z,1683912495.188 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:28:15.189Z,1683912495.189 [DATMMP](INFO): Handled 2023-05-12T17:28:15.189Z,1683912495.189 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:15.189Z,1683912495.189 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:15.189Z,1683912495.189 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:15.189Z,1683912495.189 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:15.189Z,1683912495.189 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:15.189Z,1683912495.189 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:15.438Z,1683912495.438 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:15.438Z,1683912495.438 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:15.438Z,1683912495.438 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:15.690Z,1683912495.690 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:15.692Z,1683912495.692 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T17:28:15.692Z,1683912495.692 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T17:28:15.692Z,1683912495.692 [DATMMP](INFO): Received message type: remote_header 2023-05-12T17:28:15.692Z,1683912495.692 [DATMMP](INFO): Handled 2023-05-12T17:28:15.692Z,1683912495.692 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:15.692Z,1683912495.692 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:15.692Z,1683912495.692 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:15.942Z,1683912495.942 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:15.943Z,1683912495.943 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T17:28:15.943Z,1683912495.943 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T17:28:15.943Z,1683912495.943 [DATMMP](INFO): Handled 2023-05-12T17:28:15.943Z,1683912495.943 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:15.944Z,1683912495.944 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:15.944Z,1683912495.944 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:15.944Z,1683912495.944 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:15.944Z,1683912495.944 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:15.944Z,1683912495.944 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:16.195Z,1683912496.195 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:16.196Z,1683912496.196 [DATMMP](INFO): directional_debug rx: xBA x19D x24 xB6 x10A0 x1371 x1242 x1673 2023-05-12T17:28:16.197Z,1683912496.197 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T17:28:16.197Z,1683912496.197 [DATMMP](INFO): Handled 2023-05-12T17:28:16.197Z,1683912496.197 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:16.197Z,1683912496.197 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:16.197Z,1683912496.197 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:16.381Z,1683912496.381 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:28:16.446Z,1683912496.446 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:16.448Z,1683912496.448 [DATMMP](INFO): directional rx: xB3 x143 x522 xFE63 x59F xFE6E x0 x88 x3 xFFEF x27B5966 x-43569E0 2023-05-12T17:28:16.450Z,1683912496.450 [DATMMP](INFO): Received message type: directional 2023-05-12T17:28:16.450Z,1683912496.450 [DATMMP](INFO): Handled 2023-05-12T17:28:16.450Z,1683912496.450 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:16.450Z,1683912496.450 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:16.450Z,1683912496.450 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:16.698Z,1683912496.698 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:16.700Z,1683912496.700 [DATMMP](INFO): acstats rx: xA x0 x0 x2C8 x17 x9B xCA xB8 xD xFFFF xAB x1D xC x0 2023-05-12T17:28:16.700Z,1683912496.700 [DATMMP](INFO): Received message type: acstats 2023-05-12T17:28:16.700Z,1683912496.700 [DATMMP](INFO): Handled 2023-05-12T17:28:16.700Z,1683912496.700 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:16.701Z,1683912496.701 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:16.701Z,1683912496.701 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:16.701Z,1683912496.701 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:16.701Z,1683912496.701 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:16.701Z,1683912496.701 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:16.815Z,1683912496.815 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:28:16.950Z,1683912496.950 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:16.951Z,1683912496.951 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T17:28:16.952Z,1683912496.952 [DATMMP](INFO): Received message type: range_update 2023-05-12T17:28:16.952Z,1683912496.952 [DATMMP](INFO): Handled 2023-05-12T17:28:16.952Z,1683912496.952 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:16.952Z,1683912496.952 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:16.953Z,1683912496.953 [DATMMP](INFO): direction in FSK: [-0.353738,-0.486878,0.798636] 2023-05-12T17:28:17.202Z,1683912497.202 [DATMMP](INFO): GSXN notify for xid: 56 2023-05-12T17:28:17.203Z,1683912497.203 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T17:28:17.203Z,1683912497.203 [DATMMP](ERROR): 4:Command error: data 2023-05-12T17:28:17.204Z,1683912497.204 [DATMMP](DEBUG): Command complete rang 2023-05-12T17:28:17.204Z,1683912497.204 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T17:28:17.204Z,1683912497.204 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:17.204Z,1683912497.204 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:17.214Z,1683912497.214 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T17:28:17.215Z,1683912497.215 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T17:28:17.454Z,1683912497.454 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:17.454Z,1683912497.454 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:17.454Z,1683912497.454 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:17.455Z,1683912497.455 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:17.455Z,1683912497.455 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:17.706Z,1683912497.706 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:17.706Z,1683912497.706 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:17.958Z,1683912497.958 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:17.958Z,1683912497.958 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:18.210Z,1683912498.210 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:18.210Z,1683912498.210 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:18.210Z,1683912498.210 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:18.210Z,1683912498.210 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:18.210Z,1683912498.210 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:18.462Z,1683912498.462 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:18.462Z,1683912498.462 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:18.714Z,1683912498.714 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:18.714Z,1683912498.714 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:18.966Z,1683912498.966 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:18.966Z,1683912498.966 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:18.966Z,1683912498.966 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:18.966Z,1683912498.966 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:18.967Z,1683912498.967 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:19.218Z,1683912499.218 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:19.218Z,1683912499.218 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:19.470Z,1683912499.470 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:19.470Z,1683912499.470 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:19.722Z,1683912499.722 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:19.722Z,1683912499.722 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:19.722Z,1683912499.722 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:19.722Z,1683912499.722 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:19.722Z,1683912499.722 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:19.974Z,1683912499.974 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:19.974Z,1683912499.974 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:20.226Z,1683912500.226 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:20.226Z,1683912500.226 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:20.478Z,1683912500.478 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:20.478Z,1683912500.478 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:20.478Z,1683912500.478 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:20.479Z,1683912500.479 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:20.479Z,1683912500.479 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:20.730Z,1683912500.730 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:20.730Z,1683912500.730 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:20.982Z,1683912500.982 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:20.982Z,1683912500.982 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:21.234Z,1683912501.234 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:21.234Z,1683912501.234 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:21.234Z,1683912501.234 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:21.235Z,1683912501.235 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:21.235Z,1683912501.235 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:21.486Z,1683912501.486 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:21.486Z,1683912501.486 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:21.739Z,1683912501.739 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:21.739Z,1683912501.739 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:21.990Z,1683912501.990 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:21.990Z,1683912501.990 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:21.990Z,1683912501.990 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:21.990Z,1683912501.990 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:21.990Z,1683912501.990 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:22.242Z,1683912502.242 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:22.242Z,1683912502.242 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:22.494Z,1683912502.494 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:22.494Z,1683912502.494 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:22.747Z,1683912502.747 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:22.747Z,1683912502.747 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:22.747Z,1683912502.747 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:22.747Z,1683912502.747 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:22.747Z,1683912502.747 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:22.998Z,1683912502.998 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:22.998Z,1683912502.998 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:23.250Z,1683912503.250 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:23.250Z,1683912503.250 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:23.502Z,1683912503.502 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:23.502Z,1683912503.502 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:23.502Z,1683912503.502 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:23.502Z,1683912503.502 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:23.502Z,1683912503.502 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:23.754Z,1683912503.754 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:23.755Z,1683912503.755 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:24.006Z,1683912504.006 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:24.006Z,1683912504.006 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:24.258Z,1683912504.258 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:24.258Z,1683912504.258 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:24.258Z,1683912504.258 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:24.258Z,1683912504.258 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:24.258Z,1683912504.258 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:24.519Z,1683912504.519 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:24.519Z,1683912504.519 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:24.771Z,1683912504.771 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:24.771Z,1683912504.771 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:25.022Z,1683912505.022 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:25.022Z,1683912505.022 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:25.022Z,1683912505.022 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:25.022Z,1683912505.022 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:25.023Z,1683912505.023 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:25.274Z,1683912505.274 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:25.274Z,1683912505.274 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:25.526Z,1683912505.526 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:25.526Z,1683912505.526 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:25.778Z,1683912505.778 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:25.778Z,1683912505.778 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:25.778Z,1683912505.778 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:25.778Z,1683912505.778 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:25.779Z,1683912505.779 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:26.030Z,1683912506.030 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:26.030Z,1683912506.030 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:26.282Z,1683912506.282 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:26.282Z,1683912506.282 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:26.534Z,1683912506.534 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:26.534Z,1683912506.534 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:26.534Z,1683912506.534 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:26.534Z,1683912506.534 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:26.535Z,1683912506.535 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:26.786Z,1683912506.786 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:26.786Z,1683912506.786 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:27.038Z,1683912507.038 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:27.038Z,1683912507.038 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:27.290Z,1683912507.290 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:27.290Z,1683912507.290 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:27.290Z,1683912507.290 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:27.291Z,1683912507.291 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:27.291Z,1683912507.291 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:27.542Z,1683912507.542 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:27.542Z,1683912507.542 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:27.715Z,1683912507.715 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T17:28:27.794Z,1683912507.794 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:27.794Z,1683912507.794 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:27.794Z,1683912507.794 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T17:28:27.795Z,1683912507.795 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T17:28:27.795Z,1683912507.795 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T17:28:28.047Z,1683912508.047 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:28.048Z,1683912508.048 [DATMMP](INFO): timestamp rx: x0 x11 x1C x1A x24D1 2023-05-12T17:28:28.048Z,1683912508.048 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:28:28.048Z,1683912508.048 [DATMMP](INFO): Handled 2023-05-12T17:28:28.048Z,1683912508.048 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:28.048Z,1683912508.048 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:28.048Z,1683912508.048 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:28.048Z,1683912508.048 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:28.048Z,1683912508.048 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:28.049Z,1683912508.049 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:28.298Z,1683912508.298 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:28.299Z,1683912508.299 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:28.299Z,1683912508.299 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:28.550Z,1683912508.550 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:28.550Z,1683912508.550 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:28.550Z,1683912508.550 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:28.802Z,1683912508.802 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:28.802Z,1683912508.802 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:28.802Z,1683912508.802 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:28.802Z,1683912508.802 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:28.802Z,1683912508.802 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:28.803Z,1683912508.803 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:29.054Z,1683912509.054 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:29.054Z,1683912509.054 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:29.055Z,1683912509.055 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:29.306Z,1683912509.306 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:29.558Z,1683912509.558 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:29.558Z,1683912509.558 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:29.558Z,1683912509.558 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:29.810Z,1683912509.810 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:29.810Z,1683912509.810 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:29.810Z,1683912509.810 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:29.810Z,1683912509.810 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:29.811Z,1683912509.811 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:29.811Z,1683912509.811 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:30.062Z,1683912510.062 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:30.062Z,1683912510.062 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:30.062Z,1683912510.062 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:30.316Z,1683912510.316 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:30.317Z,1683912510.317 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T17:28:30.317Z,1683912510.317 [DATMMP](INFO): Received message type: doppler 2023-05-12T17:28:30.317Z,1683912510.317 [DATMMP](INFO): Handled 2023-05-12T17:28:30.318Z,1683912510.318 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:30.318Z,1683912510.318 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:30.318Z,1683912510.318 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:30.566Z,1683912510.566 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:30.567Z,1683912510.567 [DATMMP](INFO): timestamp rx: x1 x11 x1C x1C x2601 2023-05-12T17:28:30.568Z,1683912510.568 [DATMMP](INFO): Rx dataTimestamp_ set to:1683912539.010240 2023-05-12T17:28:30.568Z,1683912510.568 [DATMMP](INFO): Rx ping set to:1683912510.567312 2023-05-12T17:28:30.568Z,1683912510.568 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:28:30.568Z,1683912510.568 [DATMMP](INFO): Handled 2023-05-12T17:28:30.568Z,1683912510.568 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:30.569Z,1683912510.569 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:30.569Z,1683912510.569 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:30.569Z,1683912510.569 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:30.569Z,1683912510.569 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:30.569Z,1683912510.569 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:30.818Z,1683912510.818 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:30.818Z,1683912510.818 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:30.818Z,1683912510.818 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:31.070Z,1683912511.070 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:31.072Z,1683912511.072 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T17:28:31.072Z,1683912511.072 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T17:28:31.072Z,1683912511.072 [DATMMP](INFO): Received message type: remote_header 2023-05-12T17:28:31.072Z,1683912511.072 [DATMMP](INFO): Handled 2023-05-12T17:28:31.072Z,1683912511.072 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:31.072Z,1683912511.072 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:31.073Z,1683912511.073 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:31.322Z,1683912511.322 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:31.323Z,1683912511.323 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T17:28:31.323Z,1683912511.323 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T17:28:31.324Z,1683912511.324 [DATMMP](INFO): Handled 2023-05-12T17:28:31.324Z,1683912511.324 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:31.324Z,1683912511.324 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:31.324Z,1683912511.324 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:31.324Z,1683912511.324 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:31.324Z,1683912511.324 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:31.324Z,1683912511.324 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:31.574Z,1683912511.574 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:31.576Z,1683912511.576 [DATMMP](INFO): directional_debug rx: x210 x1EB x24 x1AF x1050 x13A1 x1242 x16A3 2023-05-12T17:28:31.577Z,1683912511.577 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T17:28:31.577Z,1683912511.577 [DATMMP](INFO): Handled 2023-05-12T17:28:31.577Z,1683912511.577 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:31.577Z,1683912511.577 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:31.577Z,1683912511.577 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:31.736Z,1683912511.736 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:28:31.826Z,1683912511.826 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:31.828Z,1683912511.828 [DATMMP](INFO): directional rx: x217 x198 x3CC xFE15 x425 xFE28 x0 x5F x3 xFFED x27B5966 x-43569E0 2023-05-12T17:28:31.830Z,1683912511.830 [DATMMP](INFO): Received message type: directional 2023-05-12T17:28:31.830Z,1683912511.830 [DATMMP](INFO): Handled 2023-05-12T17:28:31.830Z,1683912511.830 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:31.830Z,1683912511.830 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:31.830Z,1683912511.830 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:32.078Z,1683912512.078 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:32.080Z,1683912512.080 [DATMMP](INFO): acstats rx: xA x0 xFFFF x28C xE x9E xCA xB9 xD xFFFF xA9 x1D xB x0 2023-05-12T17:28:32.080Z,1683912512.080 [DATMMP](INFO): Received message type: acstats 2023-05-12T17:28:32.080Z,1683912512.080 [DATMMP](INFO): Handled 2023-05-12T17:28:32.080Z,1683912512.080 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:32.081Z,1683912512.081 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:32.081Z,1683912512.081 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:32.081Z,1683912512.081 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:32.081Z,1683912512.081 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:32.081Z,1683912512.081 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:32.152Z,1683912512.152 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683912448.00. Resetting abort timer. 2023-05-12T17:28:32.331Z,1683912512.331 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:32.332Z,1683912512.332 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T17:28:32.332Z,1683912512.332 [DATMMP](INFO): Received message type: range_update 2023-05-12T17:28:32.332Z,1683912512.332 [DATMMP](INFO): Handled 2023-05-12T17:28:32.332Z,1683912512.332 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:32.333Z,1683912512.333 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:32.334Z,1683912512.334 [DATMMP](INFO): direction in FSK: [0.202734,0.623949,0.754710] 2023-05-12T17:28:32.551Z,1683912512.551 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T17:28:32.552Z,1683912512.552 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T17:28:32.582Z,1683912512.582 [DATMMP](INFO): GSXN notify for xid: 57 2023-05-12T17:28:32.583Z,1683912512.583 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T17:28:32.583Z,1683912512.583 [DATMMP](ERROR): 4:Command error: data 2023-05-12T17:28:32.584Z,1683912512.584 [DATMMP](DEBUG): Command complete rang 2023-05-12T17:28:32.584Z,1683912512.584 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T17:28:32.584Z,1683912512.584 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:32.584Z,1683912512.584 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:32.834Z,1683912512.834 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:32.834Z,1683912512.834 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:32.834Z,1683912512.834 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:32.834Z,1683912512.834 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:32.834Z,1683912512.834 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:33.086Z,1683912513.086 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:33.086Z,1683912513.086 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:33.338Z,1683912513.338 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:33.338Z,1683912513.338 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:33.590Z,1683912513.590 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:33.590Z,1683912513.590 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:33.590Z,1683912513.590 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:33.590Z,1683912513.590 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:33.590Z,1683912513.590 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:33.842Z,1683912513.842 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:33.842Z,1683912513.842 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:34.094Z,1683912514.094 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:34.094Z,1683912514.094 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:34.346Z,1683912514.346 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:34.347Z,1683912514.347 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:34.347Z,1683912514.347 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:34.347Z,1683912514.347 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:34.347Z,1683912514.347 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:34.598Z,1683912514.598 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:34.599Z,1683912514.599 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:34.850Z,1683912514.850 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:34.850Z,1683912514.850 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:35.102Z,1683912515.102 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:35.102Z,1683912515.102 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:35.102Z,1683912515.102 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:35.102Z,1683912515.102 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:35.103Z,1683912515.103 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:35.354Z,1683912515.354 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:35.354Z,1683912515.354 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:35.606Z,1683912515.606 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:35.606Z,1683912515.606 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:35.858Z,1683912515.858 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:35.858Z,1683912515.858 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:35.858Z,1683912515.858 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:35.859Z,1683912515.859 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:35.859Z,1683912515.859 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:36.110Z,1683912516.110 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:36.110Z,1683912516.110 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:36.362Z,1683912516.362 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:36.362Z,1683912516.362 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:36.614Z,1683912516.614 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:36.614Z,1683912516.614 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:36.614Z,1683912516.614 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:36.614Z,1683912516.614 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:36.614Z,1683912516.614 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:36.866Z,1683912516.866 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:36.866Z,1683912516.866 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:37.118Z,1683912517.118 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:37.118Z,1683912517.118 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:37.370Z,1683912517.370 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:37.370Z,1683912517.370 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:37.370Z,1683912517.370 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:37.370Z,1683912517.370 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:37.370Z,1683912517.370 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:37.622Z,1683912517.622 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:37.622Z,1683912517.622 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:37.874Z,1683912517.874 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:37.874Z,1683912517.874 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:38.126Z,1683912518.126 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:38.126Z,1683912518.126 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:38.126Z,1683912518.126 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:38.126Z,1683912518.126 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:38.126Z,1683912518.126 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:38.378Z,1683912518.378 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:38.378Z,1683912518.378 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:38.630Z,1683912518.630 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:38.630Z,1683912518.630 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:38.882Z,1683912518.882 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:38.882Z,1683912518.882 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:38.882Z,1683912518.882 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:38.882Z,1683912518.882 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:38.883Z,1683912518.883 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:39.134Z,1683912519.134 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:39.134Z,1683912519.134 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:39.390Z,1683912519.390 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:39.390Z,1683912519.390 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:39.642Z,1683912519.642 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:39.642Z,1683912519.642 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:39.642Z,1683912519.642 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:39.642Z,1683912519.642 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:39.642Z,1683912519.642 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:39.894Z,1683912519.894 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:39.895Z,1683912519.895 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:40.146Z,1683912520.146 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:40.146Z,1683912520.146 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:40.398Z,1683912520.398 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:40.398Z,1683912520.398 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:40.398Z,1683912520.398 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:40.399Z,1683912520.399 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:40.399Z,1683912520.399 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:40.650Z,1683912520.650 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:40.650Z,1683912520.650 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:40.902Z,1683912520.902 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:40.902Z,1683912520.902 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:41.154Z,1683912521.154 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:41.154Z,1683912521.154 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:41.154Z,1683912521.154 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:41.154Z,1683912521.154 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:41.155Z,1683912521.155 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:41.406Z,1683912521.406 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:41.407Z,1683912521.407 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:41.658Z,1683912521.658 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:41.658Z,1683912521.658 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:41.910Z,1683912521.910 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:41.910Z,1683912521.910 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:41.910Z,1683912521.910 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:41.911Z,1683912521.911 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:41.911Z,1683912521.911 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:42.162Z,1683912522.162 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:42.162Z,1683912522.162 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:42.246Z,1683912522.246 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting. 2023-05-12T17:28:42.246Z,1683912522.246 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped 2023-05-12T17:28:42.246Z,1683912522.246 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T17:28:42.246Z,1683912522.246 [senddata_direct_and_track_test:DirectData:B] Running Loop=1 2023-05-12T17:28:42.414Z,1683912522.414 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:42.414Z,1683912522.414 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:42.637Z,1683912522.637 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:10:_.pressure 2023-05-12T17:28:42.637Z,1683912522.637 [senddata_direct_and_track_test:DirectData:B] Stopped 2023-05-12T17:28:42.637Z,1683912522.637 [senddata_direct_and_track_test:DirectData:C] Running Loop=1 2023-05-12T17:28:42.667Z,1683912522.667 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:42.667Z,1683912522.667 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:42.667Z,1683912522.667 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:42.667Z,1683912522.667 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:42.667Z,1683912522.667 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:42.918Z,1683912522.918 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:42.919Z,1683912522.919 [DATMMP](INFO): modem://10: set _.pressure 0.743541 atmosphere 2023-05-12T17:28:42.919Z,1683912522.919 [DATMMP](INFO): #Outgoing data=1 2023-05-12T17:28:42.919Z,1683912522.919 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:43.041Z,1683912523.041 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:10:_.temperature 2023-05-12T17:28:43.041Z,1683912523.041 [senddata_direct_and_track_test:DirectData:C] Stopped 2023-05-12T17:28:43.041Z,1683912523.041 [senddata_direct_and_track_test:DirectData:D] Running Loop=1 2023-05-12T17:28:43.042Z,1683912523.042 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T17:28:43.170Z,1683912523.170 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:43.170Z,1683912523.170 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:43.171Z,1683912523.171 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T17:28:43.171Z,1683912523.171 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T17:28:43.171Z,1683912523.171 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T17:28:43.430Z,1683912523.430 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:43.431Z,1683912523.431 [DATMMP](INFO): timestamp rx: x0 x11 x1C x2A xD5F 2023-05-12T17:28:43.431Z,1683912523.431 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:28:43.431Z,1683912523.431 [DATMMP](INFO): Handled 2023-05-12T17:28:43.432Z,1683912523.432 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:43.432Z,1683912523.432 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:43.432Z,1683912523.432 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:43.432Z,1683912523.432 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:43.432Z,1683912523.432 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:43.432Z,1683912523.432 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:43.479Z,1683912523.479 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:10:_.humidity 2023-05-12T17:28:43.479Z,1683912523.479 [senddata_direct_and_track_test:DirectData:D] Stopped 2023-05-12T17:28:43.479Z,1683912523.479 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData 2023-05-12T17:28:43.480Z,1683912523.480 [senddata_direct_and_track_test:DirectData] Stopped 2023-05-12T17:28:43.480Z,1683912523.480 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData 2023-05-12T17:28:43.480Z,1683912523.480 [senddata_direct_and_track_test](INFO): Completed senddata_direct_and_track_test 2023-05-12T17:28:43.480Z,1683912523.480 [MissionManager](INFO): senddata_direct_and_track_test is completed. 2023-05-12T17:28:43.481Z,1683912523.481 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test 2023-05-12T17:28:43.481Z,1683912523.481 [senddata_direct_and_track_test] Stopped 2023-05-12T17:28:43.481Z,1683912523.481 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test 2023-05-12T17:28:43.481Z,1683912523.481 [senddata_direct_and_track_test:AbortDrift] Stopped 2023-05-12T17:28:43.481Z,1683912523.481 [senddata_direct_and_track_test:AbortDrift](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:AbortDrift 2023-05-12T17:28:43.481Z,1683912523.481 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift] Stopped 2023-05-12T17:28:43.481Z,1683912523.481 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Uninitializing AbortDrift. 2023-05-12T17:28:43.481Z,1683912523.481 [senddata_direct_and_track_test:TrackAC.] Stopped 2023-05-12T17:28:43.481Z,1683912523.481 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact. 2023-05-12T17:28:43.674Z,1683912523.674 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:43.675Z,1683912523.675 [DATMMP](INFO): modem://10: set _.temperature 24.380426 celsius 2023-05-12T17:28:43.675Z,1683912523.675 [DATMMP](INFO): #Outgoing data=2 2023-05-12T17:28:43.675Z,1683912523.675 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:43.676Z,1683912523.676 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:43.850Z,1683912523.850 [MissionManager](IMPORTANT): Started mission Default 2023-05-12T17:28:43.850Z,1683912523.850 [Default] Running Loop=1 2023-05-12T17:28:43.851Z,1683912523.851 [Default](DEBUG): Aggregate::initialize Default 2023-05-12T17:28:43.851Z,1683912523.851 [Default:B.GoToSurface] Running Loop=1 2023-05-12T17:28:43.851Z,1683912523.851 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-05-12T17:28:43.851Z,1683912523.851 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-05-12T17:28:43.851Z,1683912523.851 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-05-12T17:28:43.852Z,1683912523.852 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-05-12T17:28:43.852Z,1683912523.852 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-05-12T17:28:43.852Z,1683912523.852 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-05-12T17:28:43.852Z,1683912523.852 [Default:A.Wait] Running Loop=1 2023-05-12T17:28:43.853Z,1683912523.853 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-05-12T17:28:43.926Z,1683912523.926 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:43.926Z,1683912523.926 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:43.926Z,1683912523.926 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:44.178Z,1683912524.178 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:44.179Z,1683912524.179 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:44.179Z,1683912524.179 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:44.179Z,1683912524.179 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:44.179Z,1683912524.179 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:44.179Z,1683912524.179 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:44.430Z,1683912524.430 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:44.431Z,1683912524.431 [DATMMP](INFO): modem://10: set _.humidity 12.879990 percent 2023-05-12T17:28:44.431Z,1683912524.431 [DATMMP](INFO): #Outgoing data=3 2023-05-12T17:28:44.431Z,1683912524.431 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:44.431Z,1683912524.431 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:44.682Z,1683912524.682 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:44.682Z,1683912524.682 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:44.682Z,1683912524.682 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:44.934Z,1683912524.934 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:44.934Z,1683912524.934 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:44.934Z,1683912524.934 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:44.934Z,1683912524.934 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:44.934Z,1683912524.934 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:44.935Z,1683912524.935 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:45.186Z,1683912525.186 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:45.187Z,1683912525.187 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:45.187Z,1683912525.187 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:45.438Z,1683912525.438 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:45.438Z,1683912525.438 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:45.438Z,1683912525.438 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:45.690Z,1683912525.690 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:45.691Z,1683912525.691 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T17:28:45.691Z,1683912525.691 [DATMMP](INFO): Received message type: doppler 2023-05-12T17:28:45.691Z,1683912525.691 [DATMMP](INFO): Handled 2023-05-12T17:28:45.691Z,1683912525.691 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:45.691Z,1683912525.691 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:45.691Z,1683912525.691 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:45.692Z,1683912525.692 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:45.692Z,1683912525.692 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:45.692Z,1683912525.692 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:45.942Z,1683912525.942 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:45.943Z,1683912525.943 [DATMMP](INFO): timestamp rx: x1 x11 x1C x2C xE90 2023-05-12T17:28:45.944Z,1683912525.944 [DATMMP](INFO): Rx dataTimestamp_ set to:1683912560.425984 2023-05-12T17:28:45.944Z,1683912525.944 [DATMMP](INFO): Rx ping set to:1683912525.943310 2023-05-12T17:28:45.944Z,1683912525.944 [DATMMP](INFO): Received message type: timestamp 2023-05-12T17:28:45.944Z,1683912525.944 [DATMMP](INFO): Handled 2023-05-12T17:28:45.944Z,1683912525.944 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:45.945Z,1683912525.945 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:45.945Z,1683912525.945 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:46.194Z,1683912526.194 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:46.194Z,1683912526.194 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:46.194Z,1683912526.194 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:46.446Z,1683912526.446 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:46.448Z,1683912526.448 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T17:28:46.448Z,1683912526.448 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T17:28:46.448Z,1683912526.448 [DATMMP](INFO): Received message type: remote_header 2023-05-12T17:28:46.448Z,1683912526.448 [DATMMP](INFO): Handled 2023-05-12T17:28:46.448Z,1683912526.448 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:46.448Z,1683912526.448 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:46.448Z,1683912526.448 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:46.449Z,1683912526.449 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:46.449Z,1683912526.449 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:46.449Z,1683912526.449 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:46.698Z,1683912526.698 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:46.699Z,1683912526.699 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T17:28:46.699Z,1683912526.699 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T17:28:46.699Z,1683912526.699 [DATMMP](INFO): Handled 2023-05-12T17:28:46.700Z,1683912526.700 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:46.700Z,1683912526.700 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:46.700Z,1683912526.700 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:46.950Z,1683912526.950 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:46.951Z,1683912526.951 [DATMMP](INFO): directional_debug rx: x213 x1E7 x24 x1A4 x1050 x13C1 x1282 x16B3 2023-05-12T17:28:46.952Z,1683912526.952 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T17:28:46.952Z,1683912526.952 [DATMMP](INFO): Handled 2023-05-12T17:28:46.953Z,1683912526.953 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:46.953Z,1683912526.953 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:46.953Z,1683912526.953 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:47.203Z,1683912527.203 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:47.204Z,1683912527.204 [DATMMP](INFO): directional rx: x21A x194 x3C9 xFE19 x404 xFE2A x0 x40 x4 xFFEE x27B5966 x-43569E0 2023-05-12T17:28:47.206Z,1683912527.206 [DATMMP](INFO): Received message type: directional 2023-05-12T17:28:47.206Z,1683912527.206 [DATMMP](INFO): Handled 2023-05-12T17:28:47.206Z,1683912527.206 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:47.206Z,1683912527.206 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:47.206Z,1683912527.206 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:47.206Z,1683912527.206 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:47.206Z,1683912527.206 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:47.207Z,1683912527.207 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:47.454Z,1683912527.454 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:47.456Z,1683912527.456 [DATMMP](INFO): acstats rx: xA x0 xFFFF x29A x15 x9E xCB xB6 xD xFFFF xA9 x1D xB x0 2023-05-12T17:28:47.456Z,1683912527.456 [DATMMP](INFO): Received message type: acstats 2023-05-12T17:28:47.457Z,1683912527.457 [DATMMP](INFO): Handled 2023-05-12T17:28:47.457Z,1683912527.457 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:47.457Z,1683912527.457 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:47.457Z,1683912527.457 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T17:28:47.706Z,1683912527.706 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T17:28:47.707Z,1683912527.707 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T17:28:47.707Z,1683912527.707 [DATMMP](INFO): Received message type: range_update 2023-05-12T17:28:47.708Z,1683912527.708 [DATMMP](INFO): Handled 2023-05-12T17:28:47.708Z,1683912527.708 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:47.708Z,1683912527.708 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:47.709Z,1683912527.709 [DATMMP](INFO): direction in FSK: [0.215671,0.561842,0.798636] 2023-05-12T17:28:47.939Z,1683912527.939 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T17:28:47.939Z,1683912527.939 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T17:28:47.958Z,1683912527.958 [DATMMP](INFO): GSXN notify for xid: 58 2023-05-12T17:28:47.959Z,1683912527.959 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T17:28:47.959Z,1683912527.959 [DATMMP](ERROR): 4:Command error: data 2023-05-12T17:28:47.960Z,1683912527.960 [DATMMP](DEBUG): Command complete rang 2023-05-12T17:28:47.960Z,1683912527.960 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T17:28:47.960Z,1683912527.960 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:47.960Z,1683912527.960 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:47.960Z,1683912527.960 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:47.960Z,1683912527.960 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:47.960Z,1683912527.960 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:48.210Z,1683912528.210 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:48.210Z,1683912528.210 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:48.462Z,1683912528.462 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:48.462Z,1683912528.462 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:48.714Z,1683912528.714 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:48.714Z,1683912528.714 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:48.714Z,1683912528.714 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:48.714Z,1683912528.714 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:48.715Z,1683912528.715 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:48.966Z,1683912528.966 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:48.966Z,1683912528.966 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:49.218Z,1683912529.218 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:49.218Z,1683912529.218 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:49.470Z,1683912529.470 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:49.470Z,1683912529.470 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:49.470Z,1683912529.470 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:49.470Z,1683912529.470 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:49.470Z,1683912529.470 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:49.722Z,1683912529.722 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:49.722Z,1683912529.722 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:49.974Z,1683912529.974 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:49.974Z,1683912529.974 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:50.226Z,1683912530.226 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:50.226Z,1683912530.226 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:50.226Z,1683912530.226 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:50.226Z,1683912530.226 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:50.226Z,1683912530.226 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:50.478Z,1683912530.478 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:50.478Z,1683912530.478 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:50.730Z,1683912530.730 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:50.730Z,1683912530.730 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:50.982Z,1683912530.982 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:50.982Z,1683912530.982 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:50.982Z,1683912530.982 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:50.982Z,1683912530.982 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:50.982Z,1683912530.982 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:51.234Z,1683912531.234 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:51.234Z,1683912531.234 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:51.486Z,1683912531.486 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:51.486Z,1683912531.486 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:51.738Z,1683912531.738 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:51.738Z,1683912531.738 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:51.738Z,1683912531.738 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:51.738Z,1683912531.738 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:51.738Z,1683912531.738 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:51.990Z,1683912531.990 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:51.990Z,1683912531.990 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:52.242Z,1683912532.242 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:52.242Z,1683912532.242 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:52.494Z,1683912532.494 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:52.494Z,1683912532.494 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:52.495Z,1683912532.495 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:52.495Z,1683912532.495 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:52.495Z,1683912532.495 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:52.746Z,1683912532.746 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:52.746Z,1683912532.746 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:52.998Z,1683912532.998 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:52.998Z,1683912532.998 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:53.250Z,1683912533.250 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:53.250Z,1683912533.250 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:53.250Z,1683912533.250 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:53.250Z,1683912533.250 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:53.250Z,1683912533.250 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:53.502Z,1683912533.502 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:53.502Z,1683912533.502 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:53.755Z,1683912533.755 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:53.755Z,1683912533.755 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:54.006Z,1683912534.006 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:54.006Z,1683912534.006 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:54.006Z,1683912534.006 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:54.006Z,1683912534.006 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:54.007Z,1683912534.007 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:54.258Z,1683912534.258 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:54.258Z,1683912534.258 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:54.510Z,1683912534.510 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:54.510Z,1683912534.510 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:54.762Z,1683912534.762 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:54.762Z,1683912534.762 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:54.762Z,1683912534.762 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:54.762Z,1683912534.762 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:54.762Z,1683912534.762 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:55.017Z,1683912535.017 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:55.017Z,1683912535.017 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:55.266Z,1683912535.266 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:55.266Z,1683912535.266 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:55.518Z,1683912535.518 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:55.518Z,1683912535.518 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:55.518Z,1683912535.518 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:55.518Z,1683912535.518 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:55.518Z,1683912535.518 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:55.770Z,1683912535.770 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:55.771Z,1683912535.771 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:56.022Z,1683912536.022 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:56.022Z,1683912536.022 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:56.274Z,1683912536.274 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:56.274Z,1683912536.274 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:56.274Z,1683912536.274 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:56.274Z,1683912536.274 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:56.274Z,1683912536.274 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:56.526Z,1683912536.526 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:56.527Z,1683912536.527 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:56.778Z,1683912536.778 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:56.778Z,1683912536.778 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:57.030Z,1683912537.030 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:57.030Z,1683912537.030 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:57.030Z,1683912537.030 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:57.030Z,1683912537.030 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:57.030Z,1683912537.030 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:57.182Z,1683912537.182 [Default:A.Wait](INFO): Done Waiting. 2023-05-12T17:28:57.182Z,1683912537.182 [Default:A.Wait] Stopped 2023-05-12T17:28:57.182Z,1683912537.182 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T17:28:57.282Z,1683912537.282 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:57.282Z,1683912537.282 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:57.534Z,1683912537.534 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:57.534Z,1683912537.534 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:57.596Z,1683912537.596 [Default:CheckIn] Running Loop=1 2023-05-12T17:28:57.597Z,1683912537.597 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-12T17:28:57.597Z,1683912537.597 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-12T17:28:57.786Z,1683912537.786 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:57.786Z,1683912537.786 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:57.787Z,1683912537.787 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:57.787Z,1683912537.787 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:57.787Z,1683912537.787 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:58.038Z,1683912538.038 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:58.039Z,1683912538.039 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:58.290Z,1683912538.290 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:58.290Z,1683912538.290 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:58.542Z,1683912538.542 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:58.542Z,1683912538.542 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:58.542Z,1683912538.542 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:58.542Z,1683912538.542 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:58.542Z,1683912538.542 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:58.794Z,1683912538.794 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:58.794Z,1683912538.794 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:59.046Z,1683912539.046 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:59.046Z,1683912539.046 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:28:59.299Z,1683912539.299 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:28:59.299Z,1683912539.299 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:28:59.299Z,1683912539.299 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:28:59.299Z,1683912539.299 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:28:59.299Z,1683912539.299 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:28:59.550Z,1683912539.550 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:28:59.550Z,1683912539.550 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:28:59.802Z,1683912539.802 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:28:59.802Z,1683912539.802 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:00.054Z,1683912540.054 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:00.054Z,1683912540.054 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:00.054Z,1683912540.054 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:00.054Z,1683912540.054 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:00.055Z,1683912540.055 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:00.306Z,1683912540.306 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:00.306Z,1683912540.306 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:00.558Z,1683912540.558 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:00.558Z,1683912540.558 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:00.810Z,1683912540.810 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:00.810Z,1683912540.810 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:00.810Z,1683912540.810 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:00.810Z,1683912540.810 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:00.810Z,1683912540.810 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:01.062Z,1683912541.062 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:01.062Z,1683912541.062 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:01.314Z,1683912541.314 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:01.314Z,1683912541.314 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:01.566Z,1683912541.566 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:01.566Z,1683912541.566 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:01.566Z,1683912541.566 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:01.566Z,1683912541.566 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:01.566Z,1683912541.566 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:01.818Z,1683912541.818 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:01.818Z,1683912541.818 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:02.070Z,1683912542.070 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:02.070Z,1683912542.070 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:02.322Z,1683912542.322 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:02.322Z,1683912542.322 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:02.322Z,1683912542.322 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:02.322Z,1683912542.322 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:02.322Z,1683912542.322 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:02.574Z,1683912542.574 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:02.574Z,1683912542.574 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:03.078Z,1683912543.078 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:03.078Z,1683912543.078 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:03.330Z,1683912543.330 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:03.330Z,1683912543.330 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:03.330Z,1683912543.330 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:03.330Z,1683912543.330 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:03.330Z,1683912543.330 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:03.582Z,1683912543.582 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:03.582Z,1683912543.582 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:03.834Z,1683912543.834 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:03.834Z,1683912543.834 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:04.086Z,1683912544.086 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:04.086Z,1683912544.086 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:04.086Z,1683912544.086 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:04.086Z,1683912544.086 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:04.087Z,1683912544.087 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:04.338Z,1683912544.338 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:04.339Z,1683912544.339 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:04.590Z,1683912544.590 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:04.590Z,1683912544.590 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:04.842Z,1683912544.842 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:04.842Z,1683912544.842 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:04.842Z,1683912544.842 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:04.842Z,1683912544.842 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:04.842Z,1683912544.842 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:05.094Z,1683912545.094 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:05.094Z,1683912545.094 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:05.346Z,1683912545.346 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:05.346Z,1683912545.346 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:05.598Z,1683912545.598 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:05.598Z,1683912545.598 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:05.598Z,1683912545.598 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:05.598Z,1683912545.598 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:05.599Z,1683912545.599 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:05.850Z,1683912545.850 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:05.850Z,1683912545.850 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:06.102Z,1683912546.102 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:06.102Z,1683912546.102 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:06.354Z,1683912546.354 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:06.354Z,1683912546.354 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:06.354Z,1683912546.354 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:06.354Z,1683912546.354 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:06.354Z,1683912546.354 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:06.606Z,1683912546.606 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:06.606Z,1683912546.606 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:06.858Z,1683912546.858 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:06.858Z,1683912546.858 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:07.110Z,1683912547.110 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:07.110Z,1683912547.110 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:07.110Z,1683912547.110 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:07.110Z,1683912547.110 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:07.110Z,1683912547.110 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:07.364Z,1683912547.364 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:07.365Z,1683912547.365 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:07.614Z,1683912547.614 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:07.614Z,1683912547.614 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:07.866Z,1683912547.866 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:07.866Z,1683912547.866 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:07.866Z,1683912547.866 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:07.866Z,1683912547.866 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:07.867Z,1683912547.867 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:08.118Z,1683912548.118 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:08.118Z,1683912548.118 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:08.370Z,1683912548.370 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:08.370Z,1683912548.370 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:08.622Z,1683912548.622 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:08.622Z,1683912548.622 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:08.622Z,1683912548.622 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:08.623Z,1683912548.623 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:08.623Z,1683912548.623 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:08.882Z,1683912548.882 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:08.882Z,1683912548.882 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:09.134Z,1683912549.134 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:09.134Z,1683912549.134 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:09.386Z,1683912549.386 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:09.386Z,1683912549.386 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:09.386Z,1683912549.386 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:09.386Z,1683912549.386 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:09.386Z,1683912549.386 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:09.638Z,1683912549.638 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:09.639Z,1683912549.639 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:09.890Z,1683912549.890 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:09.890Z,1683912549.890 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:10.142Z,1683912550.142 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:10.142Z,1683912550.142 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:10.142Z,1683912550.142 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:10.143Z,1683912550.143 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:10.143Z,1683912550.143 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:10.394Z,1683912550.394 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:10.394Z,1683912550.394 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:10.646Z,1683912550.646 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:10.646Z,1683912550.646 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:10.898Z,1683912550.898 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:10.898Z,1683912550.898 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:10.898Z,1683912550.898 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:10.899Z,1683912550.899 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:10.899Z,1683912550.899 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:11.150Z,1683912551.150 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:11.150Z,1683912551.150 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:11.402Z,1683912551.402 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:11.402Z,1683912551.402 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:11.654Z,1683912551.654 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:11.654Z,1683912551.654 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:11.654Z,1683912551.654 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:11.654Z,1683912551.654 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:11.655Z,1683912551.655 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:11.907Z,1683912551.907 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:11.907Z,1683912551.907 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:12.158Z,1683912552.158 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:12.158Z,1683912552.158 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:12.410Z,1683912552.410 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:12.410Z,1683912552.410 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:12.410Z,1683912552.410 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:12.410Z,1683912552.410 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:12.410Z,1683912552.410 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:12.662Z,1683912552.662 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:12.662Z,1683912552.662 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:12.922Z,1683912552.922 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:12.922Z,1683912552.922 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:13.174Z,1683912553.174 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:13.174Z,1683912553.174 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:13.174Z,1683912553.174 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:13.174Z,1683912553.174 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:13.175Z,1683912553.175 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:13.426Z,1683912553.426 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:13.426Z,1683912553.426 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:13.678Z,1683912553.678 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:13.678Z,1683912553.678 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:13.930Z,1683912553.930 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:13.930Z,1683912553.930 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:13.930Z,1683912553.930 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:13.930Z,1683912553.930 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:13.931Z,1683912553.931 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:14.182Z,1683912554.182 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:14.182Z,1683912554.182 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:14.434Z,1683912554.434 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:14.434Z,1683912554.434 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:14.686Z,1683912554.686 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:14.686Z,1683912554.686 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:14.686Z,1683912554.686 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:14.686Z,1683912554.686 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:14.686Z,1683912554.686 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:14.938Z,1683912554.938 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:14.938Z,1683912554.938 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:15.190Z,1683912555.190 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:15.190Z,1683912555.190 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:15.442Z,1683912555.442 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:15.442Z,1683912555.442 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:15.442Z,1683912555.442 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:15.442Z,1683912555.442 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:15.442Z,1683912555.442 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:15.694Z,1683912555.694 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:15.694Z,1683912555.694 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:15.946Z,1683912555.946 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:15.946Z,1683912555.946 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:16.198Z,1683912556.198 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:16.198Z,1683912556.198 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:16.198Z,1683912556.198 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:16.199Z,1683912556.199 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:16.199Z,1683912556.199 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:16.450Z,1683912556.450 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:16.450Z,1683912556.450 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:16.702Z,1683912556.702 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:16.702Z,1683912556.702 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:16.955Z,1683912556.955 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:16.955Z,1683912556.955 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:16.955Z,1683912556.955 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:16.955Z,1683912556.955 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:16.955Z,1683912556.955 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:17.206Z,1683912557.206 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:17.206Z,1683912557.206 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:17.458Z,1683912557.458 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:17.458Z,1683912557.458 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:17.711Z,1683912557.711 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:17.711Z,1683912557.711 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:17.711Z,1683912557.711 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:17.711Z,1683912557.711 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:17.711Z,1683912557.711 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:17.962Z,1683912557.962 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:17.962Z,1683912557.962 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:18.214Z,1683912558.214 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:18.214Z,1683912558.214 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:18.466Z,1683912558.466 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:18.466Z,1683912558.466 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:18.466Z,1683912558.466 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:18.466Z,1683912558.466 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:18.466Z,1683912558.466 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:18.718Z,1683912558.718 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:18.718Z,1683912558.718 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:18.970Z,1683912558.970 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:18.970Z,1683912558.970 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:19.222Z,1683912559.222 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:19.222Z,1683912559.222 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:19.222Z,1683912559.222 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:19.223Z,1683912559.223 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:19.223Z,1683912559.223 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:19.474Z,1683912559.474 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:19.474Z,1683912559.474 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:19.726Z,1683912559.726 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:19.726Z,1683912559.726 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:19.978Z,1683912559.978 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:19.978Z,1683912559.978 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:19.978Z,1683912559.978 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:19.978Z,1683912559.978 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:19.979Z,1683912559.979 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:20.230Z,1683912560.230 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:20.230Z,1683912560.230 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:20.482Z,1683912560.482 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:20.482Z,1683912560.482 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:20.735Z,1683912560.735 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:20.735Z,1683912560.735 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:20.735Z,1683912560.735 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:20.735Z,1683912560.735 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:20.735Z,1683912560.735 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:20.986Z,1683912560.986 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:20.986Z,1683912560.986 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:21.238Z,1683912561.238 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:21.238Z,1683912561.238 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:21.490Z,1683912561.490 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:21.490Z,1683912561.490 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:21.490Z,1683912561.490 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:21.490Z,1683912561.490 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:21.490Z,1683912561.490 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:21.742Z,1683912561.742 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:21.742Z,1683912561.742 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:21.994Z,1683912561.994 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:21.994Z,1683912561.994 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:22.246Z,1683912562.246 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:22.246Z,1683912562.246 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:22.246Z,1683912562.246 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:22.247Z,1683912562.247 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:22.247Z,1683912562.247 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:22.498Z,1683912562.498 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:22.499Z,1683912562.499 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:22.750Z,1683912562.750 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:22.750Z,1683912562.750 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:23.002Z,1683912563.002 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:23.002Z,1683912563.002 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:23.002Z,1683912563.002 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:23.002Z,1683912563.002 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:23.002Z,1683912563.002 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:23.254Z,1683912563.254 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:23.254Z,1683912563.254 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:23.506Z,1683912563.506 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:23.506Z,1683912563.506 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:23.758Z,1683912563.758 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:23.758Z,1683912563.758 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:23.758Z,1683912563.758 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:23.759Z,1683912563.759 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:23.759Z,1683912563.759 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:24.010Z,1683912564.010 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:24.010Z,1683912564.010 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:24.082Z,1683912564.082 [CommandExec](IMPORTANT): got command quit 2023-05-12T17:29:24.262Z,1683912564.262 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:24.262Z,1683912564.262 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:24.514Z,1683912564.514 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:24.514Z,1683912564.514 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:24.514Z,1683912564.514 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:24.514Z,1683912564.514 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:24.514Z,1683912564.514 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:24.766Z,1683912564.766 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:24.767Z,1683912564.767 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:25.018Z,1683912565.018 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:25.018Z,1683912565.018 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:25.086Z,1683912565.086 [Supervisor](INFO): Stop Mission called by Supervisor::terminate 2023-05-12T17:29:25.086Z,1683912565.086 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:25.086Z,1683912565.086 [CommandExec](INFO): Uninitializing the command executive. 2023-05-12T17:29:25.086Z,1683912565.086 [CommandExec](INFO): Uninitializing the command scheduler. 2023-05-12T17:29:25.087Z,1683912565.087 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:25.106Z,1683912565.106 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2023-05-12T17:29:25.106Z,1683912565.106 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2023-05-12T17:29:25.106Z,1683912565.106 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:25.107Z,1683912565.107 [NavChartDb](INFO): Join timeout helper Thread ID is 6908 2023-05-12T17:29:25.222Z,1683912565.222 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:25.222Z,1683912565.222 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:25.234Z,1683912565.234 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2023-05-12T17:29:25.234Z,1683912565.234 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:25.234Z,1683912565.234 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 6909 2023-05-12T17:29:25.270Z,1683912565.270 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:25.270Z,1683912565.270 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:25.271Z,1683912565.271 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:25.271Z,1683912565.271 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:25.271Z,1683912565.271 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:25.490Z,1683912565.490 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:25.490Z,1683912565.490 [WetLabsBB2FL](INFO): Powering down 2023-05-12T17:29:25.491Z,1683912565.491 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:25.498Z,1683912565.498 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2023-05-12T17:29:25.498Z,1683912565.498 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:25.498Z,1683912565.498 [CTD_Seabird](INFO): Join timeout helper Thread ID is 6910 2023-05-12T17:29:25.522Z,1683912565.522 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:25.522Z,1683912565.522 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:25.774Z,1683912565.774 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:25.774Z,1683912565.774 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:25.782Z,1683912565.782 [CTD_Seabird](INFO): Powering down 2023-05-12T17:29:25.794Z,1683912565.794 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:25.794Z,1683912565.794 [CTD_Seabird](INFO): Powering down 2023-05-12T17:29:25.806Z,1683912565.806 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:25.854Z,1683912565.854 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2023-05-12T17:29:25.854Z,1683912565.854 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:25.854Z,1683912565.854 [Radio_Surface](INFO): Join timeout helper Thread ID is 6911 2023-05-12T17:29:25.974Z,1683912565.974 [Radio_Surface](INFO): Powering down 2023-05-12T17:29:25.975Z,1683912565.975 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:25.975Z,1683912565.975 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:25.986Z,1683912565.986 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2023-05-12T17:29:25.989Z,1683912565.989 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:26.002Z,1683912566.002 [Onboard](INFO): Join timeout helper Thread ID is 6912 2023-05-12T17:29:26.026Z,1683912566.026 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:26.026Z,1683912566.026 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:26.027Z,1683912566.027 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:26.027Z,1683912566.027 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:26.027Z,1683912566.027 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:26.278Z,1683912566.278 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:26.278Z,1683912566.278 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:26.450Z,1683912566.450 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2023-05-12T17:29:26.530Z,1683912566.530 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:26.530Z,1683912566.530 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:26.782Z,1683912566.782 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:26.782Z,1683912566.782 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:26.782Z,1683912566.782 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:26.782Z,1683912566.782 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:26.783Z,1683912566.783 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:27.034Z,1683912567.034 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:27.034Z,1683912567.034 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:27.287Z,1683912567.287 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:27.287Z,1683912567.287 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:27.538Z,1683912567.538 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T17:29:27.538Z,1683912567.538 [DATMMP](INFO): In sendingTransmit, dataTxMessage not ack'd 2023-05-12T17:29:27.538Z,1683912567.538 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T17:29:27.538Z,1683912567.538 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T17:29:27.538Z,1683912567.538 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T17:29:27.790Z,1683912567.790 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T17:29:27.790Z,1683912567.790 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T17:29:27.886Z,1683912567.886 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:27.887Z,1683912567.887 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:27.891Z,1683912567.891 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2023-05-12T17:29:27.891Z,1683912567.891 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:27.891Z,1683912567.891 [DataOverHttps](INFO): Join timeout helper Thread ID is 6913 2023-05-12T17:29:28.042Z,1683912568.042 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T17:29:28.042Z,1683912568.042 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T17:29:28.470Z,1683912568.470 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:28.470Z,1683912568.470 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.482Z,1683912568.482 [ComponentRegistry](INFO): Shutting down DATMMP ThreadHandler 2023-05-12T17:29:28.482Z,1683912568.482 [DATMMP ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.483Z,1683912568.483 [DATMMP](INFO): Join timeout helper Thread ID is 6914 2023-05-12T17:29:28.546Z,1683912568.546 [DATMMP](INFO): Stop 2023-05-12T17:29:28.546Z,1683912568.546 [DATMMP](INFO): uninitialize 2023-05-12T17:29:28.546Z,1683912568.546 [DATMMP](INFO): Powering down 2023-05-12T17:29:28.619Z,1683912568.619 [DATMMP ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:28.619Z,1683912568.619 [DATMMP](INFO): uninitialize 2023-05-12T17:29:28.619Z,1683912568.619 [DATMMP](INFO): Powering down 2023-05-12T17:29:28.620Z,1683912568.620 [DATMMP ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.622Z,1683912568.622 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2023-05-12T17:29:28.623Z,1683912568.623 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.623Z,1683912568.623 [BackseatComponent](INFO): Join timeout helper Thread ID is 6915 2023-05-12T17:29:28.726Z,1683912568.726 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:28.726Z,1683912568.726 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.742Z,1683912568.742 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2023-05-12T17:29:28.743Z,1683912568.743 [logger ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.743Z,1683912568.743 [logger](INFO): Join timeout helper Thread ID is 6916 2023-05-12T17:29:28.754Z,1683912568.754 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:28.754Z,1683912568.754 [logger ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.762Z,1683912568.762 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2023-05-12T17:29:28.762Z,1683912568.762 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.763Z,1683912568.763 [CommandLine](INFO): Join timeout helper Thread ID is 6917 2023-05-12T17:29:28.858Z,1683912568.858 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:28.858Z,1683912568.858 [CommandLine ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.866Z,1683912568.866 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2023-05-12T17:29:28.867Z,1683912568.867 [CommandExec ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.867Z,1683912568.867 [CommandExec](INFO): Join timeout helper Thread ID is 6918 2023-05-12T17:29:28.868Z,1683912568.868 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2023-05-12T17:29:28.868Z,1683912568.868 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:28.869Z,1683912568.869 [controlThread](INFO): Join timeout helper Thread ID is 6919 2023-05-12T17:29:29.070Z,1683912569.070 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2023-05-12T17:29:29.070Z,1683912569.070 [controlThread](DEBUG): Uninitializing ControlThread 2023-05-12T17:29:29.071Z,1683912569.071 [AHRS_M2](INFO): Powering down 2023-05-12T17:29:29.142Z,1683912569.142 [NAL9602](INFO): Powering down 2023-05-12T17:29:29.145Z,1683912569.145 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2023-05-12T17:29:29.146Z,1683912569.146 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2023-05-12T17:29:29.146Z,1683912569.146 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2023-05-12T17:29:29.147Z,1683912569.147 [MissionManager](INFO): Uninitializing Mission Default 2023-05-12T17:29:29.147Z,1683912569.147 [Default] Stopped 2023-05-12T17:29:29.147Z,1683912569.147 [Default](DEBUG): Aggregate::uninitialize Default 2023-05-12T17:29:29.147Z,1683912569.147 [Default:B.GoToSurface] Stopped 2023-05-12T17:29:29.147Z,1683912569.147 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-05-12T17:29:29.147Z,1683912569.147 [Default:CheckIn] Stopped 2023-05-12T17:29:29.147Z,1683912569.147 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-12T17:29:29.147Z,1683912569.147 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T17:29:29.150Z,1683912569.150 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2023-05-12T17:29:29.150Z,1683912569.150 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2023-05-12T17:29:29.151Z,1683912569.151 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2023-05-12T17:29:29.151Z,1683912569.151 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2023-05-12T17:29:29.151Z,1683912569.151 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2023-05-12T17:29:29.151Z,1683912569.151 [BuoyancyServo](INFO): Powering down 2023-05-12T17:29:29.166Z,1683912569.166 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2023-05-12T17:29:29.166Z,1683912569.166 [ElevatorServo](INFO): Powering down 2023-05-12T17:29:29.167Z,1683912569.167 [MassServo](DEBUG): Uninitialize Mass Servo. 2023-05-12T17:29:29.167Z,1683912569.167 [MassServo](INFO): Powering down 2023-05-12T17:29:29.168Z,1683912569.168 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2023-05-12T17:29:29.168Z,1683912569.168 [RudderServo](INFO): Powering down 2023-05-12T17:29:29.169Z,1683912569.169 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2023-05-12T17:29:29.169Z,1683912569.169 [ThrusterHE](INFO): Powering down 2023-05-12T17:29:29.170Z,1683912569.170 [SBIT](DEBUG): Uninitialize SBIT Component. 2023-05-12T17:29:29.170Z,1683912569.170 [IBIT](DEBUG): Uninitialize IBIT Component. 2023-05-12T17:29:29.170Z,1683912569.170 [CBIT](DEBUG): Uninitialize CBIT Component. 2023-05-12T17:29:29.170Z,1683912569.170 [CBIT](DEBUG): Powering off loads. 2023-05-12T17:29:29.182Z,1683912569.182 [CBIT](DEBUG): Disabling WDT. 2023-05-12T17:29:29.194Z,1683912569.194 [CBIT](DEBUG): Opening all GF detection circuits. 2023-05-12T17:29:29.195Z,1683912569.195 [controlThread ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:29.245Z,1683912569.245 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:29.248Z,1683912569.248 [Onboard ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:29.253Z,1683912569.253 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:29.259Z,1683912569.259 [DATMMP ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:29.301Z,1683912569.301 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:29.339Z,1683912569.339 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:29.344Z,1683912569.344 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:29.376Z,1683912569.376 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2023-05-12T17:29:29.437Z,1683912569.437 [logger ThreadHandler](INFO): Thread cancelled.