2023-05-12T19:24:17.257Z,1683919457.257 [CommandExec](IMPORTANT): got command restart logs 2023-05-12T19:24:29.707Z,1683919469.707 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2023-05-12T19:24:29.710Z,1683919469.710 [BPC1](INFO): Received data from all battery sticks. 2023-05-12T19:25:19.162Z,1683919519.162 [CommandExec](IMPORTANT): got command run ./Missions/Demo/senddata_direct_and_track_test.xml 2023-05-12T19:25:19.165Z,1683919519.165 [MissionManager](INFO): Loading Mission from file: ./Missions/Demo/senddata_direct_and_track_test.xml 2023-05-12T19:25:19.227Z,1683919519.227 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetContactLabel = 10.000000 count 2023-05-12T19:25:19.229Z,1683919519.229 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcousticTargetDepth = 0.000000 m 2023-05-12T19:25:19.231Z,1683919519.231 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.TrackingUpdatePeriod = 15.000000 s 2023-05-12T19:25:19.233Z,1683919519.233 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfPings = 1.000000 count 2023-05-12T19:25:19.235Z,1683919519.235 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfFixesLowPass = 2.000000 count 2023-05-12T19:25:19.238Z,1683919519.238 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.NumberOfStartingFixesToIgnore = 2.000000 count 2023-05-12T19:25:19.240Z,1683919519.240 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.BeingInterrogatedTimeout = 1.000000 h 2023-05-12T19:25:19.242Z,1683919519.242 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.AcommsInterval = 1.000000 min 2023-05-12T19:25:19.276Z,1683919519.276 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId1 = 9.000000 enum 2023-05-12T19:25:19.278Z,1683919519.278 [MissionManager](INFO): DefineArg senddata_direct_and_track_test.modemId2 = 5.000000 enum 2023-05-12T19:25:19.285Z,1683919519.285 [MissionManager](INFO): DefineOutput senddata_direct_and_track_test.ModemID = 1.000000 enum 2023-05-12T19:25:19.285Z,1683919519.285 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/AbortDrift.xml 2023-05-12T19:25:19.312Z,1683919519.312 [MissionManager](INFO): DefineArg senddata_direct_and_track_test:AbortDrift.AcousticTimeout = 96.000000 h 2023-05-12T19:25:19.314Z,1683919519.314 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](DEBUG): Construct AbortDrift. 2023-05-12T19:25:19.316Z,1683919519.316 [senddata_direct_and_track_test:AbortDrift:C.Execute](DEBUG): Construct Execute. 2023-05-12T19:25:19.319Z,1683919519.319 [MissionManager](INFO): RedefineArg senddata_direct_and_track_test:AbortDrift.AcousticTimeout = reader:senddata_direct_and_track_test.BeingInterrogatedTimeout 2023-05-12T19:25:19.362Z,1683919519.362 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Construct Wait. 2023-05-12T19:25:19.417Z,1683919519.417 [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-12T19:25:19.419Z,1683919519.419 [CommandExec](IMPORTANT): Running ./Missions/Demo/senddata_direct_and_track_test.xml 2023-05-12T19:25:19.427Z,1683919519.427 [Default] Stopped 2023-05-12T19:25:19.427Z,1683919519.427 [Default](DEBUG): Aggregate::uninitialize Default 2023-05-12T19:25:19.427Z,1683919519.427 [Default:B.GoToSurface] Stopped 2023-05-12T19:25:19.427Z,1683919519.427 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2023-05-12T19:25:19.427Z,1683919519.427 [Default:CheckIn] Stopped 2023-05-12T19:25:19.427Z,1683919519.427 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2023-05-12T19:25:19.428Z,1683919519.428 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T19:25:19.428Z,1683919519.428 [MissionManager](IMPORTANT): Started mission senddata_direct_and_track_test 2023-05-12T19:25:19.432Z,1683919519.432 [senddata_direct_and_track_test] Running Loop=1 2023-05-12T19:25:19.432Z,1683919519.432 [senddata_direct_and_track_test](DEBUG): Aggregate::initialize senddata_direct_and_track_test 2023-05-12T19:25:19.432Z,1683919519.432 [senddata_direct_and_track_test:AbortDrift] Running Loop=1 2023-05-12T19:25:19.432Z,1683919519.432 [senddata_direct_and_track_test:AbortDrift](DEBUG): Aggregate::initialize senddata_direct_and_track_test:AbortDrift 2023-05-12T19:25:19.433Z,1683919519.433 [senddata_direct_and_track_test:AbortDrift:A] Running Loop=1 2023-05-12T19:25:19.433Z,1683919519.433 [senddata_direct_and_track_test:TrackAC.] Running Loop=1 2023-05-12T19:25:19.433Z,1683919519.433 [senddata_direct_and_track_test:TrackAC.](INFO): Initializing TrackAcousticContact. 2023-05-12T19:25:19.433Z,1683919519.433 [senddata_direct_and_track_test:DirectData] Running Loop=1 2023-05-12T19:25:19.433Z,1683919519.433 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData 2023-05-12T19:25:19.433Z,1683919519.433 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1 2023-05-12T19:25:19.433Z,1683919519.433 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component. 2023-05-12T19:25:19.433Z,1683919519.433 [senddata_direct_and_track_test:TrackAC.] Running Loop=1 2023-05-12T19:25:19.441Z,1683919519.441 [senddata_direct_and_track_test:AbortDrift] Running Loop=1 2023-05-12T19:25:19.442Z,1683919519.442 [senddata_direct_and_track_test:AbortDrift:A](INFO): Insert acoustic timeout set to 1.000000 h . 2023-05-12T19:25:19.442Z,1683919519.442 [senddata_direct_and_track_test:AbortDrift:A] Stopped 2023-05-12T19:25:19.442Z,1683919519.442 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift] Running Loop=1 2023-05-12T19:25:19.442Z,1683919519.442 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Initializing AbortDrift. 2023-05-12T19:25:19.442Z,1683919519.442 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](IMPORTANT): Acoustic timeout set to: 1.00 hours. 2023-05-12T19:25:19.810Z,1683919519.810 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid gps time fix: 1683919104.00. Resetting abort timer. 2023-05-12T19:25:19.810Z,1683919519.810 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919360.00. Resetting abort timer. 2023-05-12T19:25:34.758Z,1683919534.758 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T19:25:34.884Z,1683919534.884 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T19:25:34.885Z,1683919534.885 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T19:25:34.885Z,1683919534.885 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T19:25:35.145Z,1683919535.145 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:35.146Z,1683919535.146 [DATMMP](INFO): timestamp rx: x0 x13 x19 x21 x1211 2023-05-12T19:25:35.146Z,1683919535.146 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:25:35.146Z,1683919535.146 [DATMMP](INFO): Handled 2023-05-12T19:25:35.146Z,1683919535.146 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:35.396Z,1683919535.396 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:35.648Z,1683919535.648 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:35.900Z,1683919535.900 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:36.153Z,1683919536.153 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:36.404Z,1683919536.404 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:36.656Z,1683919536.656 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:36.908Z,1683919536.908 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:37.160Z,1683919537.160 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:37.412Z,1683919537.412 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:37.413Z,1683919537.413 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:25:37.413Z,1683919537.413 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:25:37.413Z,1683919537.413 [DATMMP](INFO): Handled 2023-05-12T19:25:37.414Z,1683919537.414 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:37.665Z,1683919537.665 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:37.666Z,1683919537.666 [DATMMP](INFO): timestamp rx: x1 x13 x19 x23 x1340 2023-05-12T19:25:37.666Z,1683919537.666 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919583.131072 2023-05-12T19:25:37.666Z,1683919537.666 [DATMMP](INFO): Rx ping set to:1683919537.665568 2023-05-12T19:25:37.666Z,1683919537.666 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:25:37.667Z,1683919537.667 [DATMMP](INFO): Handled 2023-05-12T19:25:37.667Z,1683919537.667 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:37.916Z,1683919537.916 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:38.169Z,1683919538.169 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:38.170Z,1683919538.170 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T19:25:38.170Z,1683919538.170 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:25:38.170Z,1683919538.170 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:25:38.170Z,1683919538.170 [DATMMP](INFO): Handled 2023-05-12T19:25:38.171Z,1683919538.171 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:38.421Z,1683919538.421 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:38.421Z,1683919538.421 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:25:38.422Z,1683919538.422 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:25:38.422Z,1683919538.422 [DATMMP](INFO): Handled 2023-05-12T19:25:38.422Z,1683919538.422 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:38.673Z,1683919538.673 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:38.674Z,1683919538.674 [DATMMP](INFO): directional_debug rx: xD6 x166 x24 xB6 xFF0 x1371 x1222 x1623 2023-05-12T19:25:38.675Z,1683919538.675 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:25:38.675Z,1683919538.675 [DATMMP](INFO): Handled 2023-05-12T19:25:38.675Z,1683919538.675 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:38.818Z,1683919538.818 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919488.00. Resetting abort timer. 2023-05-12T19:25:38.925Z,1683919538.925 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:38.926Z,1683919538.926 [DATMMP](INFO): directional rx: xD3 x112 x506 xFE9A x5D6 xFEA3 x0 xD9 x5 xFFF0 x27B5966 x-43569E0 2023-05-12T19:25:38.928Z,1683919538.928 [DATMMP](INFO): Received message type: directional 2023-05-12T19:25:38.928Z,1683919538.928 [DATMMP](INFO): Handled 2023-05-12T19:25:38.928Z,1683919538.928 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:39.177Z,1683919539.177 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:39.179Z,1683919539.179 [DATMMP](INFO): acstats rx: xA x0 xFFFF x283 x23 x96 xB4 xAD xD xFFFF xBD x1E xC x0 2023-05-12T19:25:39.179Z,1683919539.179 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:25:39.179Z,1683919539.179 [DATMMP](INFO): Handled 2023-05-12T19:25:39.180Z,1683919539.180 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:39.210Z,1683919539.210 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919488.00. Resetting abort timer. 2023-05-12T19:25:39.429Z,1683919539.429 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:39.429Z,1683919539.429 [DATMMP](INFO): range_update rx: xA x2 x9 xC 2023-05-12T19:25:39.430Z,1683919539.430 [DATMMP](INFO): Received message type: range_update 2023-05-12T19:25:39.430Z,1683919539.430 [DATMMP](INFO): Handled 2023-05-12T19:25:39.431Z,1683919539.431 [DATMMP](INFO): direction in FSK: [-0.898246,-0.438105,-0.034900] 2023-05-12T19:25:39.619Z,1683919539.619 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T19:25:39.619Z,1683919539.619 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T19:25:39.681Z,1683919539.681 [DATMMP](INFO): GSXN notify for xid: 31 2023-05-12T19:25:39.682Z,1683919539.682 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T19:25:39.682Z,1683919539.682 [DATMMP](ERROR): 4:Command error: data 2023-05-12T19:25:39.682Z,1683919539.682 [DATMMP](DEBUG): Command complete rang 2023-05-12T19:25:39.682Z,1683919539.682 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T19:25:49.885Z,1683919549.885 [CommandExec](IMPORTANT): got command report touch TrackAcousticContact.contact_latitude 2023-05-12T19:25:49.886Z,1683919549.886 [CommandExec](IMPORTANT): got command report touch TrackAcousticContact.contact_longitude 2023-05-12T19:25:50.114Z,1683919550.114 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T19:25:50.272Z,1683919550.272 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T19:25:50.273Z,1683919550.273 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T19:25:50.273Z,1683919550.273 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T19:25:50.525Z,1683919550.525 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:50.525Z,1683919550.525 [DATMMP](INFO): timestamp rx: x0 x13 x19 x30 x21AF 2023-05-12T19:25:50.526Z,1683919550.526 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:25:50.526Z,1683919550.526 [DATMMP](INFO): Handled 2023-05-12T19:25:50.526Z,1683919550.526 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:50.777Z,1683919550.777 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:51.028Z,1683919551.028 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:51.281Z,1683919551.281 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:51.532Z,1683919551.532 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:51.784Z,1683919551.784 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:52.036Z,1683919552.036 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:52.288Z,1683919552.288 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:52.541Z,1683919552.541 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:52.793Z,1683919552.793 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:52.793Z,1683919552.793 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:25:52.793Z,1683919552.793 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:25:52.793Z,1683919552.793 [DATMMP](INFO): Handled 2023-05-12T19:25:52.794Z,1683919552.794 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:53.045Z,1683919553.045 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:53.046Z,1683919553.046 [DATMMP](INFO): timestamp rx: x1 x13 x19 x32 x22DF 2023-05-12T19:25:53.046Z,1683919553.046 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919573.186368 2023-05-12T19:25:53.047Z,1683919553.047 [DATMMP](INFO): Rx ping set to:1683919553.045749 2023-05-12T19:25:53.047Z,1683919553.047 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:25:53.047Z,1683919553.047 [DATMMP](INFO): Handled 2023-05-12T19:25:53.047Z,1683919553.047 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:53.297Z,1683919553.297 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:53.549Z,1683919553.549 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:53.550Z,1683919553.550 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T19:25:53.550Z,1683919553.550 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:25:53.550Z,1683919553.550 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:25:53.550Z,1683919553.550 [DATMMP](INFO): Handled 2023-05-12T19:25:53.550Z,1683919553.550 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:53.801Z,1683919553.801 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:53.801Z,1683919553.801 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:25:53.802Z,1683919553.802 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:25:53.802Z,1683919553.802 [DATMMP](INFO): Handled 2023-05-12T19:25:53.802Z,1683919553.802 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:54.053Z,1683919554.053 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:54.054Z,1683919554.054 [DATMMP](INFO): directional_debug rx: x2C x1F8 x24 xB6 x1040 x13A1 x1232 x1693 2023-05-12T19:25:54.055Z,1683919554.055 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:25:54.055Z,1683919554.055 [DATMMP](INFO): Handled 2023-05-12T19:25:54.055Z,1683919554.055 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:54.162Z,1683919554.162 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:25:54.305Z,1683919554.305 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:54.306Z,1683919554.306 [DATMMP](INFO): directional rx: x25 x1B5 x5B0 xFE08 x61E xFE0D x0 x84 x6 xFFEE x27B5966 x-43569E0 2023-05-12T19:25:54.308Z,1683919554.308 [DATMMP](INFO): Received message type: directional 2023-05-12T19:25:54.308Z,1683919554.308 [DATMMP](INFO): Handled 2023-05-12T19:25:54.308Z,1683919554.308 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:54.557Z,1683919554.557 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:54.558Z,1683919554.558 [DATMMP](INFO): acstats rx: xA x0 xFFFF x2CB x22 x9B xA6 xA7 xD xFFFF xA6 x1E xB x0 2023-05-12T19:25:54.559Z,1683919554.559 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:25:54.559Z,1683919554.559 [DATMMP](INFO): Handled 2023-05-12T19:25:54.559Z,1683919554.559 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:25:54.562Z,1683919554.562 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:25:54.809Z,1683919554.809 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:25:54.810Z,1683919554.810 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T19:25:54.810Z,1683919554.810 [DATMMP](INFO): Received message type: range_update 2023-05-12T19:25:54.810Z,1683919554.810 [DATMMP](INFO): Handled 2023-05-12T19:25:54.811Z,1683919554.811 [DATMMP](INFO): direction in FSK: [-0.777677,-0.222995,0.587785] 2023-05-12T19:25:54.974Z,1683919554.974 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T19:25:54.974Z,1683919554.974 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T19:25:54.975Z,1683919554.975 [Reporter](INFO): TrackAcousticContact.contact_latitude 0.642281 rad 2023-05-12T19:25:54.975Z,1683919554.975 [Reporter](INFO): TrackAcousticContact.contact_longitude -2.127556 rad 2023-05-12T19:25:55.061Z,1683919555.061 [DATMMP](INFO): GSXN notify for xid: 32 2023-05-12T19:25:55.061Z,1683919555.061 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T19:25:55.062Z,1683919555.062 [DATMMP](ERROR): 4:Command error: data 2023-05-12T19:25:55.062Z,1683919555.062 [DATMMP](DEBUG): Command complete rang 2023-05-12T19:25:55.062Z,1683919555.062 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T19:26:05.459Z,1683919565.459 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T19:26:05.645Z,1683919565.645 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T19:26:05.645Z,1683919565.645 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T19:26:05.645Z,1683919565.645 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T19:26:05.897Z,1683919565.897 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:05.898Z,1683919565.898 [DATMMP](INFO): timestamp rx: x0 x13 x1A x4 xA3E 2023-05-12T19:26:05.898Z,1683919565.898 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:05.898Z,1683919565.898 [DATMMP](INFO): Handled 2023-05-12T19:26:05.898Z,1683919565.898 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:06.148Z,1683919566.148 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:06.400Z,1683919566.400 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:06.653Z,1683919566.653 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:06.904Z,1683919566.904 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:07.156Z,1683919567.156 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:07.408Z,1683919567.408 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:07.661Z,1683919567.661 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:07.912Z,1683919567.912 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:08.167Z,1683919568.167 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:08.170Z,1683919568.170 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:26:08.170Z,1683919568.170 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:26:08.170Z,1683919568.170 [DATMMP](INFO): Handled 2023-05-12T19:26:08.170Z,1683919568.170 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:08.417Z,1683919568.417 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:08.417Z,1683919568.417 [DATMMP](INFO): timestamp rx: x1 x13 x1A x6 xB6E 2023-05-12T19:26:08.418Z,1683919568.418 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919594.602112 2023-05-12T19:26:08.418Z,1683919568.418 [DATMMP](INFO): Rx ping set to:1683919568.417509 2023-05-12T19:26:08.418Z,1683919568.418 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:08.419Z,1683919568.419 [DATMMP](INFO): Handled 2023-05-12T19:26:08.419Z,1683919568.419 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:08.668Z,1683919568.668 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:08.921Z,1683919568.921 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:08.922Z,1683919568.922 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T19:26:08.922Z,1683919568.922 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:26:08.922Z,1683919568.922 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:26:08.922Z,1683919568.922 [DATMMP](INFO): Handled 2023-05-12T19:26:08.922Z,1683919568.922 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:09.173Z,1683919569.173 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:09.173Z,1683919569.173 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:26:09.174Z,1683919569.174 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:26:09.174Z,1683919569.174 [DATMMP](INFO): Handled 2023-05-12T19:26:09.174Z,1683919569.174 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:09.425Z,1683919569.425 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:09.426Z,1683919569.426 [DATMMP](INFO): directional_debug rx: x218 x1E7 x24 x1B4 x1070 x1391 x1262 x16B3 2023-05-12T19:26:09.427Z,1683919569.427 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:26:09.427Z,1683919569.427 [DATMMP](INFO): Handled 2023-05-12T19:26:09.427Z,1683919569.427 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:09.513Z,1683919569.513 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:09.677Z,1683919569.677 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:09.678Z,1683919569.678 [DATMMP](INFO): directional rx: x220 x194 x3C4 xFE19 x3E3 xFE2B x0 x26 x4 xFFED x27B5966 x-43569E0 2023-05-12T19:26:09.680Z,1683919569.680 [DATMMP](INFO): Received message type: directional 2023-05-12T19:26:09.680Z,1683919569.680 [DATMMP](INFO): Handled 2023-05-12T19:26:09.680Z,1683919569.680 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:09.920Z,1683919569.920 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:09.929Z,1683919569.929 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:09.930Z,1683919569.930 [DATMMP](INFO): acstats rx: xA x0 xFFFF x277 x16 x9A xC9 xB9 xD xFFFF x96 x1D xA x0 2023-05-12T19:26:09.930Z,1683919569.930 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:26:09.931Z,1683919569.931 [DATMMP](INFO): Handled 2023-05-12T19:26:09.931Z,1683919569.931 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:10.184Z,1683919570.184 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:10.191Z,1683919570.191 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T19:26:10.199Z,1683919570.199 [DATMMP](INFO): Received message type: range_update 2023-05-12T19:26:10.200Z,1683919570.200 [DATMMP](INFO): Handled 2023-05-12T19:26:10.207Z,1683919570.207 [DATMMP](INFO): direction in FSK: [0.263818,0.540907,0.798636] 2023-05-12T19:26:10.345Z,1683919570.345 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T19:26:10.346Z,1683919570.346 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T19:26:10.346Z,1683919570.346 [Reporter](INFO): TrackAcousticContact.contact_latitude 0.642281 rad 2023-05-12T19:26:10.347Z,1683919570.347 [Reporter](INFO): TrackAcousticContact.contact_longitude -2.127556 rad 2023-05-12T19:26:10.433Z,1683919570.433 [DATMMP](INFO): GSXN notify for xid: 33 2023-05-12T19:26:10.433Z,1683919570.433 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T19:26:10.434Z,1683919570.434 [DATMMP](ERROR): 4:Command error: data 2023-05-12T19:26:10.434Z,1683919570.434 [DATMMP](DEBUG): Command complete rang 2023-05-12T19:26:10.434Z,1683919570.434 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T19:26:19.648Z,1683919579.648 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting. 2023-05-12T19:26:19.648Z,1683919579.648 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped 2023-05-12T19:26:19.648Z,1683919579.648 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T19:26:19.649Z,1683919579.649 [senddata_direct_and_track_test:DirectData:B] Running Loop=1 2023-05-12T19:26:20.018Z,1683919580.018 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:10:_.pressure 2023-05-12T19:26:20.018Z,1683919580.018 [senddata_direct_and_track_test:DirectData:B] Stopped 2023-05-12T19:26:20.018Z,1683919580.018 [senddata_direct_and_track_test:DirectData:C] Running Loop=1 2023-05-12T19:26:20.260Z,1683919580.260 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T19:26:20.261Z,1683919580.261 [DATMMP](INFO): modem://10: set _.pressure 0.742417 atmosphere 2023-05-12T19:26:20.261Z,1683919580.261 [DATMMP](INFO): #Outgoing data=1 2023-05-12T19:26:20.262Z,1683919580.262 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T19:26:20.418Z,1683919580.418 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:10:_.temperature 2023-05-12T19:26:20.418Z,1683919580.418 [senddata_direct_and_track_test:DirectData:C] Stopped 2023-05-12T19:26:20.418Z,1683919580.418 [senddata_direct_and_track_test:DirectData:D] Running Loop=1 2023-05-12T19:26:20.513Z,1683919580.513 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T19:26:20.513Z,1683919580.513 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T19:26:20.764Z,1683919580.764 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T19:26:20.765Z,1683919580.765 [DATMMP](INFO): Tx to 10 len 34 xid 34 2023-05-12T19:26:20.766Z,1683919580.766 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T19:26:20.766Z,1683919580.766 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:20.854Z,1683919580.854 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:10:_.humidity 2023-05-12T19:26:20.854Z,1683919580.854 [senddata_direct_and_track_test:DirectData:D] Stopped 2023-05-12T19:26:20.855Z,1683919580.855 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData 2023-05-12T19:26:20.855Z,1683919580.855 [senddata_direct_and_track_test:DirectData] Stopped 2023-05-12T19:26:20.855Z,1683919580.855 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData 2023-05-12T19:26:20.855Z,1683919580.855 [senddata_direct_and_track_test:DirectData](INFO): Running loop #2 2023-05-12T19:26:20.855Z,1683919580.855 [senddata_direct_and_track_test:DirectData] Running Loop=2 2023-05-12T19:26:20.855Z,1683919580.855 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::initialize senddata_direct_and_track_test:DirectData 2023-05-12T19:26:20.855Z,1683919580.855 [senddata_direct_and_track_test:DirectData:A.Wait] Running Loop=1 2023-05-12T19:26:20.855Z,1683919580.855 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Initialize Wait Component. 2023-05-12T19:26:20.856Z,1683919580.856 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T19:26:21.017Z,1683919581.017 [DATMMP](INFO): GSXN notify for xid: 34 2023-05-12T19:26:21.018Z,1683919581.018 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-05-12T19:26:21.018Z,1683919581.018 [DATMMP](DEBUG): Command complete send 2023-05-12T19:26:21.018Z,1683919581.018 [DATMMP](ERROR): 1:COMPLETE 2023-05-12T19:26:21.018Z,1683919581.018 [DATMMP](INFO): Received message type: cmd_result 2023-05-12T19:26:21.018Z,1683919581.018 [DATMMP](INFO): Handled 2023-05-12T19:26:21.018Z,1683919581.018 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:21.019Z,1683919581.019 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T19:26:21.019Z,1683919581.019 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T19:26:21.024Z,1683919581.024 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T19:26:21.269Z,1683919581.269 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:21.270Z,1683919581.270 [DATMMP](INFO): timestamp rx: x0 x13 x1A x13 x100D 2023-05-12T19:26:21.270Z,1683919581.270 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:21.270Z,1683919581.270 [DATMMP](INFO): Handled 2023-05-12T19:26:21.270Z,1683919581.270 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:21.270Z,1683919581.270 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:21.521Z,1683919581.521 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:21.522Z,1683919581.522 [DATMMP](INFO): timestamp rx: x0 x13 x1A x13 x17E9 2023-05-12T19:26:21.522Z,1683919581.522 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:21.522Z,1683919581.522 [DATMMP](INFO): Handled 2023-05-12T19:26:21.522Z,1683919581.522 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:21.522Z,1683919581.522 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:21.773Z,1683919581.773 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:21.773Z,1683919581.773 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:22.024Z,1683919582.024 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:22.276Z,1683919582.276 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:22.276Z,1683919582.276 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:22.528Z,1683919582.528 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:22.529Z,1683919582.529 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:22.781Z,1683919582.781 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:22.781Z,1683919582.781 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:23.032Z,1683919583.032 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:23.033Z,1683919583.033 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:23.284Z,1683919583.284 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:23.285Z,1683919583.285 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:23.536Z,1683919583.536 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:23.536Z,1683919583.536 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:23.789Z,1683919583.789 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:23.789Z,1683919583.789 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:24.040Z,1683919584.040 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:24.292Z,1683919584.292 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:24.292Z,1683919584.292 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:24.544Z,1683919584.544 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:24.544Z,1683919584.544 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:24.796Z,1683919584.796 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:24.797Z,1683919584.797 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:25.049Z,1683919585.049 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:25.049Z,1683919585.049 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:26:25.049Z,1683919585.049 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:26:25.050Z,1683919585.050 [DATMMP](INFO): Handled 2023-05-12T19:26:25.050Z,1683919585.050 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:25.050Z,1683919585.050 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:25.302Z,1683919585.302 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:25.303Z,1683919585.303 [DATMMP](INFO): timestamp rx: x1 x13 x1A x17 x505 2023-05-12T19:26:25.303Z,1683919585.303 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919595.575488 2023-05-12T19:26:25.303Z,1683919585.303 [DATMMP](INFO): Rx ping set to:1683919585.302663 2023-05-12T19:26:25.304Z,1683919585.304 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:25.312Z,1683919585.312 [DATMMP](INFO): Handled 2023-05-12T19:26:25.312Z,1683919585.312 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:25.313Z,1683919585.313 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:25.552Z,1683919585.552 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:25.552Z,1683919585.552 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:25.805Z,1683919585.805 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:25.806Z,1683919585.806 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T19:26:25.806Z,1683919585.806 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:26:25.806Z,1683919585.806 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:26:25.806Z,1683919585.806 [DATMMP](INFO): Handled 2023-05-12T19:26:25.806Z,1683919585.806 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:25.807Z,1683919585.807 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:26.057Z,1683919586.057 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:26.057Z,1683919586.057 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:26:26.058Z,1683919586.058 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:26:26.058Z,1683919586.058 [DATMMP](INFO): Handled 2023-05-12T19:26:26.058Z,1683919586.058 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:26.309Z,1683919586.309 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:26.310Z,1683919586.310 [DATMMP](INFO): directional_debug rx: x9E x1B3 x24 xBC x1030 x13A1 x11E2 x16A3 2023-05-12T19:26:26.311Z,1683919586.311 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:26:26.311Z,1683919586.311 [DATMMP](INFO): Handled 2023-05-12T19:26:26.311Z,1683919586.311 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:26.311Z,1683919586.311 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:26.496Z,1683919586.496 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:26.561Z,1683919586.561 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:26.562Z,1683919586.562 [DATMMP](INFO): directional rx: x97 x15E x53E xFE4D x518 xFE56 x0 xDF8 x5 xFFEF x27B5966 x-43569E0 2023-05-12T19:26:26.564Z,1683919586.564 [DATMMP](INFO): Received message type: directional 2023-05-12T19:26:26.564Z,1683919586.564 [DATMMP](INFO): Handled 2023-05-12T19:26:26.564Z,1683919586.564 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:26.564Z,1683919586.564 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:26.813Z,1683919586.813 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:26.814Z,1683919586.814 [DATMMP](INFO): acstats rx: xA x0 xFFFF x2CD x22 x98 xB5 xB1 xD xFFFF xB0 x20 xC x0 2023-05-12T19:26:26.814Z,1683919586.814 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:26:26.815Z,1683919586.815 [DATMMP](INFO): Handled 2023-05-12T19:26:26.815Z,1683919586.815 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:26.815Z,1683919586.815 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:26.905Z,1683919586.905 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:27.065Z,1683919587.065 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:27.066Z,1683919587.066 [DATMMP](INFO): range_update rx: xA x2 x2B92 x3A19 2023-05-12T19:26:27.066Z,1683919587.066 [DATMMP](INFO): Received message type: range_update 2023-05-12T19:26:27.066Z,1683919587.066 [DATMMP](INFO): Handled 2023-05-12T19:26:27.066Z,1683919587.066 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:27.067Z,1683919587.067 [DATMMP](INFO): direction in FSK: [-0.036020,-0.256300,0.965926] 2023-05-12T19:26:27.325Z,1683919587.325 [DATMMP](INFO): GSXN notify for xid: 35 2023-05-12T19:26:27.326Z,1683919587.326 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T19:26:27.326Z,1683919587.326 [DATMMP](ERROR): 4:Command error: data 2023-05-12T19:26:27.326Z,1683919587.326 [DATMMP](DEBUG): Command complete rang 2023-05-12T19:26:27.326Z,1683919587.326 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T19:26:27.336Z,1683919587.336 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:27.340Z,1683919587.340 [Reporter](INFO): DATMMP.acoustic_contact_range 1115.400024 m 2023-05-12T19:26:27.341Z,1683919587.341 [Reporter](INFO): acoustic_contact_range 1115.400024 m 2023-05-12T19:26:27.341Z,1683919587.341 [Reporter](INFO): TrackAcousticContact.contact_latitude 0.642274 rad 2023-05-12T19:26:27.342Z,1683919587.342 [Reporter](INFO): TrackAcousticContact.contact_longitude -2.127507 rad 2023-05-12T19:26:27.577Z,1683919587.577 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:27.577Z,1683919587.577 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:26:27.577Z,1683919587.577 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:26:27.577Z,1683919587.577 [DATMMP](INFO): Handled 2023-05-12T19:26:27.578Z,1683919587.578 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:27.829Z,1683919587.829 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:27.829Z,1683919587.829 [DATMMP](INFO): timestamp rx: x1 x13 x1A x18 x1716 2023-05-12T19:26:27.830Z,1683919587.830 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919641.749568 2023-05-12T19:26:27.830Z,1683919587.830 [DATMMP](INFO): Rx ping set to:1683919587.829551 2023-05-12T19:26:27.830Z,1683919587.830 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:27.831Z,1683919587.831 [DATMMP](INFO): Handled 2023-05-12T19:26:27.831Z,1683919587.831 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:28.080Z,1683919588.080 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:28.082Z,1683919588.082 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-05-12T19:26:28.082Z,1683919588.082 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:26:28.082Z,1683919588.082 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:26:28.082Z,1683919588.082 [DATMMP](INFO): Handled 2023-05-12T19:26:28.333Z,1683919588.333 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:28.333Z,1683919588.333 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:26:28.334Z,1683919588.334 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:26:28.334Z,1683919588.334 [DATMMP](INFO): Handled 2023-05-12T19:26:28.334Z,1683919588.334 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:28.585Z,1683919588.585 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:28.586Z,1683919588.586 [DATMMP](INFO): directional_debug rx: x6F x1D4 x23 xB4 x1010 x1341 x11F2 x15D3 2023-05-12T19:26:28.587Z,1683919588.587 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:26:28.587Z,1683919588.587 [DATMMP](INFO): Handled 2023-05-12T19:26:28.587Z,1683919588.587 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:28.837Z,1683919588.837 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:28.838Z,1683919588.838 [DATMMP](INFO): directional rx: x68 x188 x56D xFE2C x53F xFE34 x0 xDF4 x5 xFFEF x27B5966 x-43569E0 2023-05-12T19:26:28.840Z,1683919588.840 [DATMMP](INFO): Received message type: directional 2023-05-12T19:26:28.840Z,1683919588.840 [DATMMP](INFO): Handled 2023-05-12T19:26:28.840Z,1683919588.840 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:28.925Z,1683919588.925 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:29.089Z,1683919589.089 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:29.091Z,1683919589.091 [DATMMP](INFO): acstats rx: xA x5 xFFFF x2D0 x22 x8B xB3 xC3 xD xFFFF xAC x26 xD x0 2023-05-12T19:26:29.091Z,1683919589.091 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:26:29.091Z,1683919589.091 [DATMMP](INFO): Handled 2023-05-12T19:26:29.091Z,1683919589.091 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:29.341Z,1683919589.341 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:29.341Z,1683919589.341 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-05-12T19:26:29.341Z,1683919589.341 [DATMMP](INFO): Check CRC 2023-05-12T19:26:29.342Z,1683919589.342 [DATMMP](INFO): data rx parseDataResponse 4 2023-05-12T19:26:29.342Z,1683919589.342 [DATMMP](INFO): Got DATA: len 4 2023-05-12T19:26:29.342Z,1683919589.342 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-05-12T19:26:29.342Z,1683919589.342 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-05-12T19:26:29.342Z,1683919589.342 [DATMMP](INFO): Received command: 2023-05-12T19:26:29.343Z,1683919589.343 [DATMMP](INFO): Received message type: data_rx 2023-05-12T19:26:29.343Z,1683919589.343 [DATMMP](INFO): Handled 2023-05-12T19:26:29.343Z,1683919589.343 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-05-12T19:26:29.343Z,1683919589.343 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-05-12T19:26:29.593Z,1683919589.593 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T19:26:29.594Z,1683919589.594 [DATMMP](INFO): modem://10: set _.temperature 24.219263 celsius 2023-05-12T19:26:29.594Z,1683919589.594 [DATMMP](INFO): #Outgoing data=1 2023-05-12T19:26:29.594Z,1683919589.594 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T19:26:29.844Z,1683919589.844 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T19:26:29.844Z,1683919589.844 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T19:26:30.348Z,1683919590.348 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T19:26:30.349Z,1683919590.349 [DATMMP](INFO): Tx to 10 len 35 xid 36 2023-05-12T19:26:30.349Z,1683919590.349 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T19:26:30.349Z,1683919590.349 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:30.601Z,1683919590.601 [DATMMP](INFO): GSXN notify for xid: 36 2023-05-12T19:26:30.602Z,1683919590.602 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-05-12T19:26:30.602Z,1683919590.602 [DATMMP](DEBUG): Command complete send 2023-05-12T19:26:30.602Z,1683919590.602 [DATMMP](ERROR): 1:COMPLETE 2023-05-12T19:26:30.602Z,1683919590.602 [DATMMP](INFO): Received message type: cmd_result 2023-05-12T19:26:30.602Z,1683919590.602 [DATMMP](INFO): Handled 2023-05-12T19:26:30.602Z,1683919590.602 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:30.853Z,1683919590.853 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:30.853Z,1683919590.853 [DATMMP](INFO): timestamp rx: x0 x13 x1A x1D x6C 2023-05-12T19:26:30.854Z,1683919590.854 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:30.854Z,1683919590.854 [DATMMP](INFO): Handled 2023-05-12T19:26:30.854Z,1683919590.854 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:31.105Z,1683919591.105 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:31.356Z,1683919591.356 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:31.608Z,1683919591.608 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:31.860Z,1683919591.860 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:32.113Z,1683919592.113 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:32.364Z,1683919592.364 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:32.616Z,1683919592.616 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:32.870Z,1683919592.870 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:33.120Z,1683919593.120 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:33.372Z,1683919593.372 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:33.625Z,1683919593.625 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:33.876Z,1683919593.876 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:34.128Z,1683919594.128 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:34.380Z,1683919594.380 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:34.632Z,1683919594.632 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:34.885Z,1683919594.885 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:34.885Z,1683919594.885 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:26:34.885Z,1683919594.885 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:26:34.885Z,1683919594.885 [DATMMP](INFO): Handled 2023-05-12T19:26:34.886Z,1683919594.886 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:35.137Z,1683919595.137 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:35.138Z,1683919595.138 [DATMMP](INFO): timestamp rx: x1 x13 x1A x20 x25EC 2023-05-12T19:26:35.138Z,1683919595.138 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919622.843776 2023-05-12T19:26:35.138Z,1683919595.138 [DATMMP](INFO): Rx ping set to:1683919595.137621 2023-05-12T19:26:35.139Z,1683919595.139 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:35.139Z,1683919595.139 [DATMMP](INFO): Handled 2023-05-12T19:26:35.139Z,1683919595.139 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:35.388Z,1683919595.388 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:35.641Z,1683919595.641 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:35.642Z,1683919595.642 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-05-12T19:26:35.642Z,1683919595.642 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:26:35.642Z,1683919595.642 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:26:35.642Z,1683919595.642 [DATMMP](INFO): Handled 2023-05-12T19:26:35.642Z,1683919595.642 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:35.893Z,1683919595.893 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:35.894Z,1683919595.894 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:26:35.894Z,1683919595.894 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:26:35.894Z,1683919595.894 [DATMMP](INFO): Handled 2023-05-12T19:26:35.894Z,1683919595.894 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:36.149Z,1683919596.149 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:36.150Z,1683919596.150 [DATMMP](INFO): directional_debug rx: x43 x1E6 x23 xC2 xFF0 x1351 x11F2 x1623 2023-05-12T19:26:36.151Z,1683919596.151 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:26:36.151Z,1683919596.151 [DATMMP](INFO): Handled 2023-05-12T19:26:36.151Z,1683919596.151 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:36.211Z,1683919596.211 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T19:26:36.212Z,1683919596.212 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:36.400Z,1683919596.400 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:36.402Z,1683919596.402 [DATMMP](INFO): directional rx: x3C x19F x599 xFE1A x54D xFE1F x0 xDD8 x6 xFFEE x27B5966 x-43569E0 2023-05-12T19:26:36.404Z,1683919596.404 [DATMMP](INFO): Received message type: directional 2023-05-12T19:26:36.404Z,1683919596.404 [DATMMP](INFO): Handled 2023-05-12T19:26:36.404Z,1683919596.404 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:36.404Z,1683919596.404 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T19:26:36.404Z,1683919596.404 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T19:26:36.405Z,1683919596.405 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T19:26:36.591Z,1683919596.591 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:36.653Z,1683919596.653 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:36.654Z,1683919596.654 [DATMMP](INFO): acstats rx: xA x5 xFFFF x2AB x22 x89 xCD xC8 xD xFFFF xA9 x27 xC x0 2023-05-12T19:26:36.654Z,1683919596.654 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:26:36.655Z,1683919596.655 [DATMMP](INFO): Handled 2023-05-12T19:26:36.655Z,1683919596.655 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:36.655Z,1683919596.655 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:36.905Z,1683919596.905 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:36.906Z,1683919596.906 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-05-12T19:26:36.906Z,1683919596.906 [DATMMP](INFO): Check CRC 2023-05-12T19:26:36.906Z,1683919596.906 [DATMMP](INFO): data rx parseDataResponse 4 2023-05-12T19:26:36.906Z,1683919596.906 [DATMMP](INFO): Got DATA: len 4 2023-05-12T19:26:36.906Z,1683919596.906 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-05-12T19:26:36.906Z,1683919596.906 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-05-12T19:26:36.907Z,1683919596.907 [DATMMP](INFO): Received command: 2023-05-12T19:26:36.907Z,1683919596.907 [DATMMP](INFO): Received message type: data_rx 2023-05-12T19:26:36.907Z,1683919596.907 [DATMMP](INFO): Handled 2023-05-12T19:26:36.907Z,1683919596.907 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-05-12T19:26:36.907Z,1683919596.907 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-05-12T19:26:36.908Z,1683919596.908 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:37.157Z,1683919597.157 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:37.158Z,1683919597.158 [DATMMP](INFO): timestamp rx: x0 x13 x1A x23 x78 2023-05-12T19:26:37.158Z,1683919597.158 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:37.158Z,1683919597.158 [DATMMP](INFO): Handled 2023-05-12T19:26:37.158Z,1683919597.158 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T19:26:37.159Z,1683919597.159 [DATMMP](INFO): modem://10: set _.humidity 12.892199 percent 2023-05-12T19:26:37.159Z,1683919597.159 [DATMMP](INFO): #Outgoing data=1 2023-05-12T19:26:37.159Z,1683919597.159 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T19:26:37.160Z,1683919597.160 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:37.408Z,1683919597.408 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T19:26:37.408Z,1683919597.408 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T19:26:37.409Z,1683919597.409 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:37.660Z,1683919597.660 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T19:26:37.661Z,1683919597.661 [DATMMP](INFO): Tx to 10 len 32 xid 38 2023-05-12T19:26:37.661Z,1683919597.661 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T19:26:37.661Z,1683919597.661 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:37.662Z,1683919597.662 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:37.913Z,1683919597.913 [DATMMP](INFO): GSXN notify for xid: 38 2023-05-12T19:26:37.913Z,1683919597.913 [DATMMP](INFO): iface_err rx: x1 x7 xA 2023-05-12T19:26:37.914Z,1683919597.914 [DATMMP](ERROR): 10:Error talking to DAT device_busy 2023-05-12T19:26:37.914Z,1683919597.914 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:37.914Z,1683919597.914 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:38.164Z,1683919598.164 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:38.165Z,1683919598.165 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:38.416Z,1683919598.416 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:38.417Z,1683919598.417 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:38.668Z,1683919598.668 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:38.669Z,1683919598.669 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:38.921Z,1683919598.921 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:38.921Z,1683919598.921 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:26:38.921Z,1683919598.921 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:26:38.921Z,1683919598.921 [DATMMP](INFO): Handled 2023-05-12T19:26:38.922Z,1683919598.922 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:38.922Z,1683919598.922 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:39.173Z,1683919599.173 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:39.173Z,1683919599.173 [DATMMP](INFO): timestamp rx: x1 x13 x1A x25 x1A7 2023-05-12T19:26:39.174Z,1683919599.174 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919601.137216 2023-05-12T19:26:39.174Z,1683919599.174 [DATMMP](INFO): Rx ping set to:1683919599.173556 2023-05-12T19:26:39.174Z,1683919599.174 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:39.175Z,1683919599.175 [DATMMP](INFO): Handled 2023-05-12T19:26:39.175Z,1683919599.175 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:39.175Z,1683919599.175 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:39.424Z,1683919599.424 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:39.425Z,1683919599.425 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:39.677Z,1683919599.677 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:39.678Z,1683919599.678 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T19:26:39.678Z,1683919599.678 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:26:39.678Z,1683919599.678 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:26:39.678Z,1683919599.678 [DATMMP](INFO): Handled 2023-05-12T19:26:39.678Z,1683919599.678 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:39.679Z,1683919599.679 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:39.929Z,1683919599.929 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:39.929Z,1683919599.929 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:26:39.930Z,1683919599.930 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:26:39.930Z,1683919599.930 [DATMMP](INFO): Handled 2023-05-12T19:26:39.930Z,1683919599.930 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:39.930Z,1683919599.930 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:40.181Z,1683919600.181 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:40.183Z,1683919600.183 [DATMMP](INFO): directional_debug rx: x68 x1E7 x25 xB4 x1050 x1371 x1232 x15F3 2023-05-12T19:26:40.183Z,1683919600.183 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:26:40.184Z,1683919600.184 [DATMMP](INFO): Handled 2023-05-12T19:26:40.184Z,1683919600.184 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:40.184Z,1683919600.184 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:40.282Z,1683919600.282 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:40.433Z,1683919600.433 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:40.434Z,1683919600.434 [DATMMP](INFO): directional rx: x62 x19F x574 xFE19 x51D xFE21 x0 xDCE x6 xFFED x27B5966 x-43569E0 2023-05-12T19:26:40.441Z,1683919600.441 [DATMMP](INFO): Received message type: directional 2023-05-12T19:26:40.441Z,1683919600.441 [DATMMP](INFO): Handled 2023-05-12T19:26:40.441Z,1683919600.441 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:40.441Z,1683919600.441 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:40.631Z,1683919600.631 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:40.685Z,1683919600.685 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:40.686Z,1683919600.686 [DATMMP](INFO): acstats rx: xA x0 xFFFF x29F x22 x9C xB5 xB1 xD xFFFF xB4 x1D xB x0 2023-05-12T19:26:40.687Z,1683919600.687 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:26:40.687Z,1683919600.687 [DATMMP](INFO): Handled 2023-05-12T19:26:40.687Z,1683919600.687 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:40.687Z,1683919600.687 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:40.937Z,1683919600.937 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:40.937Z,1683919600.937 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T19:26:40.938Z,1683919600.938 [DATMMP](INFO): Received message type: range_update 2023-05-12T19:26:40.938Z,1683919600.938 [DATMMP](INFO): Handled 2023-05-12T19:26:40.938Z,1683919600.938 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:40.939Z,1683919600.939 [DATMMP](INFO): direction in FSK: [-0.432909,0.418056,0.798636] 2023-05-12T19:26:41.056Z,1683919601.056 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T19:26:41.057Z,1683919601.057 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T19:26:41.057Z,1683919601.057 [Reporter](INFO): TrackAcousticContact.contact_latitude 0.642281 rad 2023-05-12T19:26:41.058Z,1683919601.058 [Reporter](INFO): TrackAcousticContact.contact_longitude -2.127556 rad 2023-05-12T19:26:41.189Z,1683919601.189 [DATMMP](INFO): GSXN notify for xid: 37 2023-05-12T19:26:41.190Z,1683919601.190 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T19:26:41.190Z,1683919601.190 [DATMMP](ERROR): 4:Command error: data 2023-05-12T19:26:41.190Z,1683919601.190 [DATMMP](DEBUG): Command complete rang 2023-05-12T19:26:41.190Z,1683919601.190 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T19:26:41.190Z,1683919601.190 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:41.440Z,1683919601.440 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:41.692Z,1683919601.692 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:41.944Z,1683919601.944 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:42.196Z,1683919602.196 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:42.448Z,1683919602.448 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:42.700Z,1683919602.700 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:42.952Z,1683919602.952 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:43.205Z,1683919603.205 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:43.456Z,1683919603.456 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:43.708Z,1683919603.708 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:43.960Z,1683919603.960 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:44.213Z,1683919604.213 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:44.464Z,1683919604.464 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:44.716Z,1683919604.716 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:44.969Z,1683919604.969 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:45.222Z,1683919605.222 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:45.473Z,1683919605.473 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:45.724Z,1683919605.724 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:45.976Z,1683919605.976 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:46.228Z,1683919606.228 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:46.480Z,1683919606.480 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:46.732Z,1683919606.732 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:46.984Z,1683919606.984 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:47.236Z,1683919607.236 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:47.488Z,1683919607.488 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:47.740Z,1683919607.740 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:47.740Z,1683919607.740 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T19:26:47.741Z,1683919607.741 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T19:26:47.992Z,1683919607.992 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T19:26:47.993Z,1683919607.993 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T19:26:48.244Z,1683919608.244 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T19:26:48.244Z,1683919608.244 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T19:26:48.496Z,1683919608.496 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T19:26:48.497Z,1683919608.497 [DATMMP](INFO): Tx to 10 len 32 xid 39 2023-05-12T19:26:48.497Z,1683919608.497 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T19:26:48.498Z,1683919608.498 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:26:48.749Z,1683919608.749 [DATMMP](INFO): GSXN notify for xid: 39 2023-05-12T19:26:48.750Z,1683919608.750 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-05-12T19:26:48.750Z,1683919608.750 [DATMMP](DEBUG): Command complete send 2023-05-12T19:26:48.750Z,1683919608.750 [DATMMP](ERROR): 1:COMPLETE 2023-05-12T19:26:48.750Z,1683919608.750 [DATMMP](INFO): Received message type: cmd_result 2023-05-12T19:26:48.750Z,1683919608.750 [DATMMP](INFO): Handled 2023-05-12T19:26:48.750Z,1683919608.750 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:49.001Z,1683919609.001 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:49.001Z,1683919609.001 [DATMMP](INFO): timestamp rx: x0 x13 x1A x2F x647 2023-05-12T19:26:49.002Z,1683919609.002 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:49.002Z,1683919609.002 [DATMMP](INFO): Handled 2023-05-12T19:26:49.002Z,1683919609.002 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:49.252Z,1683919609.252 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:49.756Z,1683919609.756 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:50.008Z,1683919610.008 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:50.260Z,1683919610.260 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:50.512Z,1683919610.512 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:50.765Z,1683919610.765 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:51.016Z,1683919611.016 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:51.268Z,1683919611.268 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:51.515Z,1683919611.515 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T19:26:51.520Z,1683919611.520 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:51.521Z,1683919611.521 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T19:26:51.521Z,1683919611.521 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T19:26:51.521Z,1683919611.521 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T19:26:51.773Z,1683919611.773 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:51.774Z,1683919611.774 [DATMMP](INFO): timestamp rx: x0 x13 x1A x32 x45F 2023-05-12T19:26:51.774Z,1683919611.774 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:51.774Z,1683919611.774 [DATMMP](INFO): Handled 2023-05-12T19:26:51.774Z,1683919611.774 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:51.774Z,1683919611.774 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:52.024Z,1683919612.024 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:52.025Z,1683919612.025 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:52.276Z,1683919612.276 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:52.276Z,1683919612.276 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:52.528Z,1683919612.528 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:52.528Z,1683919612.528 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:52.781Z,1683919612.781 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:52.781Z,1683919612.781 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:53.032Z,1683919613.032 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:53.033Z,1683919613.033 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:53.284Z,1683919613.284 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:53.285Z,1683919613.285 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:53.536Z,1683919613.536 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:53.537Z,1683919613.537 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:53.789Z,1683919613.789 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:53.789Z,1683919613.789 [DATMMP](INFO): doppler rx: x0 2023-05-12T19:26:53.790Z,1683919613.790 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:26:53.790Z,1683919613.790 [DATMMP](INFO): Handled 2023-05-12T19:26:53.790Z,1683919613.790 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:53.790Z,1683919613.790 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:54.041Z,1683919614.041 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:54.042Z,1683919614.042 [DATMMP](INFO): timestamp rx: x1 x13 x1A x33 x2357 2023-05-12T19:26:54.043Z,1683919614.043 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919635.366592 2023-05-12T19:26:54.043Z,1683919614.043 [DATMMP](INFO): Rx ping set to:1683919614.042224 2023-05-12T19:26:54.043Z,1683919614.043 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:54.043Z,1683919614.043 [DATMMP](INFO): Handled 2023-05-12T19:26:54.043Z,1683919614.043 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:54.044Z,1683919614.044 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:54.292Z,1683919614.292 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:54.293Z,1683919614.293 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:54.545Z,1683919614.545 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:54.547Z,1683919614.547 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-05-12T19:26:54.549Z,1683919614.549 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:26:54.549Z,1683919614.549 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:26:54.549Z,1683919614.549 [DATMMP](INFO): Handled 2023-05-12T19:26:54.550Z,1683919614.550 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:54.550Z,1683919614.550 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:54.797Z,1683919614.797 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:54.797Z,1683919614.797 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:26:54.797Z,1683919614.797 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:26:54.798Z,1683919614.798 [DATMMP](INFO): Handled 2023-05-12T19:26:54.798Z,1683919614.798 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:54.798Z,1683919614.798 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:55.049Z,1683919615.049 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:55.050Z,1683919615.050 [DATMMP](INFO): directional_debug rx: xE4 x152 x24 xBE x1040 x1361 x11F2 x1663 2023-05-12T19:26:55.051Z,1683919615.051 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:26:55.051Z,1683919615.051 [DATMMP](INFO): Handled 2023-05-12T19:26:55.051Z,1683919615.051 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:55.051Z,1683919615.051 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:55.170Z,1683919615.170 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:55.301Z,1683919615.301 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:55.302Z,1683919615.302 [DATMMP](INFO): directional rx: xE4 x101 x4F8 xFEAE x484 xFEBA x0 xDA5 x4 xFFEE x27B5966 x-43569E0 2023-05-12T19:26:55.304Z,1683919615.304 [DATMMP](INFO): Received message type: directional 2023-05-12T19:26:55.304Z,1683919615.304 [DATMMP](INFO): Handled 2023-05-12T19:26:55.304Z,1683919615.304 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:26:55.304Z,1683919615.304 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:55.552Z,1683919615.552 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:55.554Z,1683919615.554 [DATMMP](INFO): acstats rx: xA x5 x0 x1DF x16 x93 xBE xC4 xD xFFFF xB0 x26 xD x0 2023-05-12T19:26:55.554Z,1683919615.554 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:26:55.554Z,1683919615.554 [DATMMP](INFO): Handled 2023-05-12T19:26:55.555Z,1683919615.555 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:55.643Z,1683919615.643 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:55.805Z,1683919615.805 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:55.806Z,1683919615.806 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-05-12T19:26:55.806Z,1683919615.806 [DATMMP](INFO): Check CRC 2023-05-12T19:26:55.806Z,1683919615.806 [DATMMP](INFO): data rx parseDataResponse 4 2023-05-12T19:26:55.806Z,1683919615.806 [DATMMP](INFO): Got DATA: len 4 2023-05-12T19:26:55.806Z,1683919615.806 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-05-12T19:26:55.806Z,1683919615.806 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-05-12T19:26:55.807Z,1683919615.807 [DATMMP](INFO): Received command: 2023-05-12T19:26:55.807Z,1683919615.807 [DATMMP](INFO): Received message type: data_rx 2023-05-12T19:26:55.807Z,1683919615.807 [DATMMP](INFO): Handled 2023-05-12T19:26:55.807Z,1683919615.807 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-05-12T19:26:55.807Z,1683919615.807 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-05-12T19:26:55.808Z,1683919615.808 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:56.057Z,1683919616.057 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:56.057Z,1683919616.057 [DATMMP](INFO): doppler rx: x0 2023-05-12T19:26:56.058Z,1683919616.058 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:26:56.058Z,1683919616.058 [DATMMP](INFO): Handled 2023-05-12T19:26:56.058Z,1683919616.058 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:56.309Z,1683919616.309 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:56.310Z,1683919616.310 [DATMMP](INFO): timestamp rx: x1 x13 x1A x34 x23D4 2023-05-12T19:26:56.310Z,1683919616.310 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919637.598016 2023-05-12T19:26:56.310Z,1683919616.310 [DATMMP](INFO): Rx ping set to:1683919616.309622 2023-05-12T19:26:56.311Z,1683919616.311 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:26:56.311Z,1683919616.311 [DATMMP](INFO): Handled 2023-05-12T19:26:56.311Z,1683919616.311 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:56.561Z,1683919616.561 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:56.562Z,1683919616.562 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T19:26:56.562Z,1683919616.562 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:26:56.562Z,1683919616.562 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:26:56.562Z,1683919616.562 [DATMMP](INFO): Handled 2023-05-12T19:26:56.563Z,1683919616.563 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:56.821Z,1683919616.821 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:56.821Z,1683919616.821 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:26:56.822Z,1683919616.822 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:26:56.822Z,1683919616.822 [DATMMP](INFO): Handled 2023-05-12T19:26:56.822Z,1683919616.822 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:57.074Z,1683919617.074 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:57.075Z,1683919617.075 [DATMMP](INFO): directional_debug rx: xCB x13C x22 xB0 xFF0 x1361 x11F2 x1623 2023-05-12T19:26:57.076Z,1683919617.076 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:26:57.077Z,1683919617.077 [DATMMP](INFO): Handled 2023-05-12T19:26:57.077Z,1683919617.077 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:57.191Z,1683919617.191 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:57.325Z,1683919617.325 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:57.326Z,1683919617.326 [DATMMP](INFO): directional rx: xCD xF1 x511 xFEC4 x49B xFED0 x0 xDA2 x4 xFFEE x27B5966 x-43569E0 2023-05-12T19:26:57.328Z,1683919617.328 [DATMMP](INFO): Received message type: directional 2023-05-12T19:26:57.328Z,1683919617.328 [DATMMP](INFO): Handled 2023-05-12T19:26:57.328Z,1683919617.328 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:57.577Z,1683919617.577 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:57.578Z,1683919617.578 [DATMMP](INFO): acstats rx: xA x0 x0 x1E0 x23 x8A xC9 xB9 xD xFFFF xB2 x1F xB x0 2023-05-12T19:26:57.579Z,1683919617.579 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:26:57.579Z,1683919617.579 [DATMMP](INFO): Handled 2023-05-12T19:26:57.579Z,1683919617.579 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:26:57.589Z,1683919617.589 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:26:57.828Z,1683919617.828 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:26:57.829Z,1683919617.829 [DATMMP](INFO): range_update rx: xA x2 x16BE x1E53 2023-05-12T19:26:57.830Z,1683919617.830 [DATMMP](INFO): Received message type: range_update 2023-05-12T19:26:57.830Z,1683919617.830 [DATMMP](INFO): Handled 2023-05-12T19:26:57.831Z,1683919617.831 [DATMMP](INFO): direction in FSK: [-0.574490,-0.432910,-0.694658] 2023-05-12T19:26:58.035Z,1683919618.035 [Reporter](INFO): DATMMP.acoustic_contact_range 582.200012 m 2023-05-12T19:26:58.036Z,1683919618.036 [Reporter](INFO): acoustic_contact_range 582.200012 m 2023-05-12T19:26:58.037Z,1683919618.037 [Reporter](INFO): TrackAcousticContact.contact_latitude 0.642308 rad 2023-05-12T19:26:58.037Z,1683919618.037 [Reporter](INFO): TrackAcousticContact.contact_longitude -2.127481 rad 2023-05-12T19:26:58.081Z,1683919618.081 [DATMMP](INFO): GSXN notify for xid: 40 2023-05-12T19:26:58.082Z,1683919618.082 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T19:26:58.082Z,1683919618.082 [DATMMP](ERROR): 4:Command error: data 2023-05-12T19:26:58.082Z,1683919618.082 [DATMMP](DEBUG): Command complete rang 2023-05-12T19:26:58.082Z,1683919618.082 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T19:27:06.883Z,1683919626.883 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T19:27:06.908Z,1683919626.908 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T19:27:06.909Z,1683919626.909 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T19:27:06.909Z,1683919626.909 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T19:27:07.161Z,1683919627.161 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:07.161Z,1683919627.161 [DATMMP](INFO): timestamp rx: x0 x13 x1B x5 x13FD 2023-05-12T19:27:07.162Z,1683919627.162 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:27:07.162Z,1683919627.162 [DATMMP](INFO): Handled 2023-05-12T19:27:07.162Z,1683919627.162 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:07.412Z,1683919627.412 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:07.664Z,1683919627.664 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:07.916Z,1683919627.916 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:08.168Z,1683919628.168 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:08.420Z,1683919628.420 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:08.673Z,1683919628.673 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:08.924Z,1683919628.924 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:09.177Z,1683919629.177 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:09.429Z,1683919629.429 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:09.429Z,1683919629.429 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:27:09.429Z,1683919629.429 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:27:09.430Z,1683919629.430 [DATMMP](INFO): Handled 2023-05-12T19:27:09.430Z,1683919629.430 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:09.681Z,1683919629.681 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:09.682Z,1683919629.682 [DATMMP](INFO): timestamp rx: x1 x13 x1B x7 x152D 2023-05-12T19:27:09.682Z,1683919629.682 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919679.985088 2023-05-12T19:27:09.683Z,1683919629.683 [DATMMP](INFO): Rx ping set to:1683919629.681900 2023-05-12T19:27:09.683Z,1683919629.683 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:27:09.683Z,1683919629.683 [DATMMP](INFO): Handled 2023-05-12T19:27:09.683Z,1683919629.683 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:09.932Z,1683919629.932 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:10.185Z,1683919630.185 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:10.186Z,1683919630.186 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T19:27:10.186Z,1683919630.186 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:27:10.186Z,1683919630.186 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:27:10.186Z,1683919630.186 [DATMMP](INFO): Handled 2023-05-12T19:27:10.187Z,1683919630.187 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:10.437Z,1683919630.437 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:10.437Z,1683919630.437 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:27:10.438Z,1683919630.438 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:27:10.438Z,1683919630.438 [DATMMP](INFO): Handled 2023-05-12T19:27:10.438Z,1683919630.438 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:10.688Z,1683919630.688 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:10.690Z,1683919630.690 [DATMMP](INFO): directional_debug rx: xB9 x233 x23 x597 x1040 x1381 x1242 x15F3 2023-05-12T19:27:10.691Z,1683919630.691 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:27:10.691Z,1683919630.691 [DATMMP](INFO): Handled 2023-05-12T19:27:10.691Z,1683919630.691 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:10.914Z,1683919630.914 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:27:10.941Z,1683919630.941 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:10.942Z,1683919630.942 [DATMMP](INFO): directional rx: xB4 x1F5 x523 xFDCD x478 xFDD9 x0 xD7D x5 xFFEC x27B5966 x-43569E0 2023-05-12T19:27:10.944Z,1683919630.944 [DATMMP](INFO): Received message type: directional 2023-05-12T19:27:10.948Z,1683919630.948 [DATMMP](INFO): Handled 2023-05-12T19:27:10.948Z,1683919630.948 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:11.193Z,1683919631.193 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:11.195Z,1683919631.195 [DATMMP](INFO): acstats rx: xA x0 xFFFF x2C6 x22 x88 xB4 xB2 xD xFFFF xAF x1F xA x0 2023-05-12T19:27:11.195Z,1683919631.195 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:27:11.195Z,1683919631.195 [DATMMP](INFO): Handled 2023-05-12T19:27:11.195Z,1683919631.195 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:11.339Z,1683919631.339 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Received valid acoustic ping at time: 1683919616.00. Resetting abort timer. 2023-05-12T19:27:11.445Z,1683919631.445 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:11.445Z,1683919631.445 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T19:27:11.446Z,1683919631.446 [DATMMP](INFO): Received message type: range_update 2023-05-12T19:27:11.446Z,1683919631.446 [DATMMP](INFO): Handled 2023-05-12T19:27:11.447Z,1683919631.447 [DATMMP](INFO): direction in FSK: [0.527979,0.754034,-0.390731] 2023-05-12T19:27:11.701Z,1683919631.701 [DATMMP](INFO): GSXN notify for xid: 41 2023-05-12T19:27:11.701Z,1683919631.701 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T19:27:11.702Z,1683919631.702 [DATMMP](ERROR): 4:Command error: data 2023-05-12T19:27:11.702Z,1683919631.702 [DATMMP](DEBUG): Command complete rang 2023-05-12T19:27:11.702Z,1683919631.702 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T19:27:11.792Z,1683919631.792 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T19:27:11.792Z,1683919631.792 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T19:27:11.793Z,1683919631.793 [Reporter](INFO): TrackAcousticContact.contact_latitude 0.642281 rad 2023-05-12T19:27:11.793Z,1683919631.793 [Reporter](INFO): TrackAcousticContact.contact_longitude -2.127557 rad 2023-05-12T19:27:12.513Z,1683919632.513 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2023-05-12T19:27:21.415Z,1683919641.415 [senddata_direct_and_track_test:DirectData:A.Wait](INFO): Done Waiting. 2023-05-12T19:27:21.415Z,1683919641.415 [senddata_direct_and_track_test:DirectData:A.Wait] Stopped 2023-05-12T19:27:21.415Z,1683919641.415 [senddata_direct_and_track_test:DirectData:A.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T19:27:21.416Z,1683919641.416 [senddata_direct_and_track_test:DirectData:B] Running Loop=1 2023-05-12T19:27:21.815Z,1683919641.815 [senddata_direct_and_track_test:DirectData:B](INFO): Queuing up send data for Onboard.Pressure with destination: modem:10:_.pressure 2023-05-12T19:27:21.815Z,1683919641.815 [senddata_direct_and_track_test:DirectData:B] Stopped 2023-05-12T19:27:21.815Z,1683919641.815 [senddata_direct_and_track_test:DirectData:C] Running Loop=1 2023-05-12T19:27:22.032Z,1683919642.032 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T19:27:22.033Z,1683919642.033 [DATMMP](INFO): modem://10: set _.pressure 0.744443 atmosphere 2023-05-12T19:27:22.033Z,1683919642.033 [DATMMP](INFO): #Outgoing data=1 2023-05-12T19:27:22.034Z,1683919642.034 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T19:27:22.225Z,1683919642.225 [senddata_direct_and_track_test:DirectData:C](INFO): Queuing up send data for Onboard.Temperature with destination: modem:10:_.temperature 2023-05-12T19:27:22.225Z,1683919642.225 [senddata_direct_and_track_test:DirectData:C] Stopped 2023-05-12T19:27:22.225Z,1683919642.225 [senddata_direct_and_track_test:DirectData:D] Running Loop=1 2023-05-12T19:27:22.225Z,1683919642.225 [senddata_direct_and_track_test:TrackAC.](INFO): *** querying acoustic contact *** 2023-05-12T19:27:22.284Z,1683919642.284 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T19:27:22.285Z,1683919642.285 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T19:27:22.285Z,1683919642.285 [DATMMP](INFO): ****** received valid address query ****** 2023-05-12T19:27:22.285Z,1683919642.285 [DATMMP](INFO): ****** received valid ping request ****** 2023-05-12T19:27:22.285Z,1683919642.285 [DATMMP](INFO): Querying Benthos address 10 2023-05-12T19:27:22.537Z,1683919642.537 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:22.538Z,1683919642.538 [DATMMP](INFO): timestamp rx: x0 x13 x1B x14 x21A8 2023-05-12T19:27:22.538Z,1683919642.538 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:27:22.538Z,1683919642.538 [DATMMP](INFO): Handled 2023-05-12T19:27:22.538Z,1683919642.538 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T19:27:22.538Z,1683919642.538 [DATMMP](INFO): Tx to 10 len 34 xid 43 2023-05-12T19:27:22.539Z,1683919642.539 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T19:27:22.539Z,1683919642.539 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:22.539Z,1683919642.539 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:22.638Z,1683919642.638 [senddata_direct_and_track_test:DirectData:D](INFO): Queuing up send data for Onboard.Humidity with destination: modem:10:_.humidity 2023-05-12T19:27:22.638Z,1683919642.638 [senddata_direct_and_track_test:DirectData:D] Stopped 2023-05-12T19:27:22.638Z,1683919642.638 [senddata_direct_and_track_test:DirectData](INFO): Completed senddata_direct_and_track_test:DirectData 2023-05-12T19:27:22.638Z,1683919642.638 [senddata_direct_and_track_test:DirectData] Stopped 2023-05-12T19:27:22.638Z,1683919642.638 [senddata_direct_and_track_test:DirectData](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:DirectData 2023-05-12T19:27:22.639Z,1683919642.639 [senddata_direct_and_track_test](INFO): Completed senddata_direct_and_track_test 2023-05-12T19:27:22.639Z,1683919642.639 [MissionManager](INFO): senddata_direct_and_track_test is completed. 2023-05-12T19:27:22.639Z,1683919642.639 [MissionManager](INFO): Uninitializing Mission senddata_direct_and_track_test 2023-05-12T19:27:22.640Z,1683919642.640 [senddata_direct_and_track_test] Stopped 2023-05-12T19:27:22.640Z,1683919642.640 [senddata_direct_and_track_test](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test 2023-05-12T19:27:22.640Z,1683919642.640 [senddata_direct_and_track_test:AbortDrift] Stopped 2023-05-12T19:27:22.640Z,1683919642.640 [senddata_direct_and_track_test:AbortDrift](DEBUG): Aggregate::uninitialize senddata_direct_and_track_test:AbortDrift 2023-05-12T19:27:22.640Z,1683919642.640 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift] Stopped 2023-05-12T19:27:22.640Z,1683919642.640 [senddata_direct_and_track_test:AbortDrift:B.AbortDrift](INFO): Uninitializing AbortDrift. 2023-05-12T19:27:22.640Z,1683919642.640 [senddata_direct_and_track_test:TrackAC.] Stopped 2023-05-12T19:27:22.640Z,1683919642.640 [senddata_direct_and_track_test:TrackAC.](DEBUG): Uninitializing TrackAcousticContact. 2023-05-12T19:27:22.789Z,1683919642.789 [DATMMP](INFO): GSXN notify for xid: 43 2023-05-12T19:27:22.789Z,1683919642.789 [DATMMP](INFO): iface_err rx: x1 x7 xA 2023-05-12T19:27:22.790Z,1683919642.790 [DATMMP](ERROR): 10:Error talking to DAT device_busy 2023-05-12T19:27:22.790Z,1683919642.790 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:22.790Z,1683919642.790 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:23.039Z,1683919643.039 [MissionManager](IMPORTANT): Started mission Default 2023-05-12T19:27:23.039Z,1683919643.039 [Default] Running Loop=1 2023-05-12T19:27:23.039Z,1683919643.039 [Default](DEBUG): Aggregate::initialize Default 2023-05-12T19:27:23.039Z,1683919643.039 [Default:B.GoToSurface] Running Loop=1 2023-05-12T19:27:23.039Z,1683919643.039 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2023-05-12T19:27:23.040Z,1683919643.040 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2023-05-12T19:27:23.040Z,1683919643.040 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:23.041Z,1683919643.041 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:23.041Z,1683919643.041 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2023-05-12T19:27:23.041Z,1683919643.041 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2023-05-12T19:27:23.042Z,1683919643.042 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2023-05-12T19:27:23.042Z,1683919643.042 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2023-05-12T19:27:23.042Z,1683919643.042 [Default:A.Wait] Running Loop=1 2023-05-12T19:27:23.042Z,1683919643.042 [Default:A.Wait](DEBUG): Initialize Wait Component. 2023-05-12T19:27:23.292Z,1683919643.292 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:23.292Z,1683919643.292 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:23.545Z,1683919643.545 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:23.545Z,1683919643.545 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:23.796Z,1683919643.796 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:23.797Z,1683919643.797 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:24.048Z,1683919644.048 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:24.048Z,1683919644.048 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:24.300Z,1683919644.300 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:24.301Z,1683919644.301 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:24.552Z,1683919644.552 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:24.552Z,1683919644.552 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:24.805Z,1683919644.805 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:24.805Z,1683919644.805 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:27:24.806Z,1683919644.806 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:27:24.806Z,1683919644.806 [DATMMP](INFO): Handled 2023-05-12T19:27:24.806Z,1683919644.806 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:24.806Z,1683919644.806 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:25.059Z,1683919645.059 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:25.061Z,1683919645.061 [DATMMP](INFO): timestamp rx: x1 x13 x1B x16 x22D8 2023-05-12T19:27:25.062Z,1683919645.062 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919665.114688 2023-05-12T19:27:25.062Z,1683919645.062 [DATMMP](INFO): Rx ping set to:1683919645.061176 2023-05-12T19:27:25.062Z,1683919645.062 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:27:25.062Z,1683919645.062 [DATMMP](INFO): Handled 2023-05-12T19:27:25.062Z,1683919645.062 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:25.062Z,1683919645.062 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:25.308Z,1683919645.308 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:25.309Z,1683919645.309 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:25.561Z,1683919645.561 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:25.562Z,1683919645.562 [DATMMP](INFO): remote_header rx: x4 x0 x5 x20 x0 xC xA x0 2023-05-12T19:27:25.562Z,1683919645.562 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:27:25.562Z,1683919645.562 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:27:25.562Z,1683919645.562 [DATMMP](INFO): Handled 2023-05-12T19:27:25.562Z,1683919645.562 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:25.563Z,1683919645.563 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:25.813Z,1683919645.813 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:25.813Z,1683919645.813 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:27:25.814Z,1683919645.814 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:27:25.814Z,1683919645.814 [DATMMP](INFO): Handled 2023-05-12T19:27:25.814Z,1683919645.814 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:25.814Z,1683919645.814 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:26.065Z,1683919646.065 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:26.066Z,1683919646.066 [DATMMP](INFO): directional_debug rx: x27 x1EE x24 xB0 x1040 x1381 x1232 x1673 2023-05-12T19:27:26.067Z,1683919646.067 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:27:26.067Z,1683919646.067 [DATMMP](INFO): Handled 2023-05-12T19:27:26.067Z,1683919646.067 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:26.067Z,1683919646.067 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:26.316Z,1683919646.316 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:26.318Z,1683919646.318 [DATMMP](INFO): directional rx: x20 x1A9 x5B5 xFE12 x4E8 xFE19 x0 xD57 x5 xFFEE x27B5966 x-43569E0 2023-05-12T19:27:26.319Z,1683919646.319 [DATMMP](INFO): Received message type: directional 2023-05-12T19:27:26.320Z,1683919646.320 [DATMMP](INFO): Handled 2023-05-12T19:27:26.320Z,1683919646.320 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:26.320Z,1683919646.320 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:26.569Z,1683919646.569 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:26.570Z,1683919646.570 [DATMMP](INFO): acstats rx: xA x0 xFFFF x2CB x22 x9C xCA xB7 xD xFFFF xAD x1D xC x0 2023-05-12T19:27:26.571Z,1683919646.571 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:27:26.571Z,1683919646.571 [DATMMP](INFO): Handled 2023-05-12T19:27:26.571Z,1683919646.571 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:26.571Z,1683919646.571 [DATMMP](INFO): Range requested while waiting for previous to complete. 2023-05-12T19:27:26.821Z,1683919646.821 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:26.821Z,1683919646.821 [DATMMP](INFO): range_update rx: xA x2 x9 xD 2023-05-12T19:27:26.822Z,1683919646.822 [DATMMP](INFO): Received message type: range_update 2023-05-12T19:27:26.822Z,1683919646.822 [DATMMP](INFO): Handled 2023-05-12T19:27:26.822Z,1683919646.822 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:26.823Z,1683919646.823 [DATMMP](INFO): direction in FSK: [-0.648519,-0.248943,0.719340] 2023-05-12T19:27:27.073Z,1683919647.073 [DATMMP](INFO): GSXN notify for xid: 42 2023-05-12T19:27:27.074Z,1683919647.074 [DATMMP](INFO): cmd_result rx: x2 x1A x0 x4 2023-05-12T19:27:27.074Z,1683919647.074 [DATMMP](ERROR): 4:Command error: data 2023-05-12T19:27:27.074Z,1683919647.074 [DATMMP](DEBUG): Command complete rang 2023-05-12T19:27:27.074Z,1683919647.074 [DATMMP](ERROR): 4:COMPLETE 2023-05-12T19:27:27.097Z,1683919647.097 [Reporter](INFO): DATMMP.acoustic_contact_range 0.900000 m 2023-05-12T19:27:27.097Z,1683919647.097 [Reporter](INFO): acoustic_contact_range 0.900000 m 2023-05-12T19:27:27.539Z,1683919647.539 [DATMMP](INFO): GSXN type: 255 2023-05-12T19:27:27.539Z,1683919647.539 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:27.576Z,1683919647.576 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:27.828Z,1683919647.828 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:28.081Z,1683919648.081 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:28.332Z,1683919648.332 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:28.584Z,1683919648.584 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:28.836Z,1683919648.836 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:29.340Z,1683919649.340 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:29.592Z,1683919649.592 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:29.844Z,1683919649.844 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:30.096Z,1683919650.096 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:30.348Z,1683919650.348 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:30.600Z,1683919650.600 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:30.852Z,1683919650.852 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:31.356Z,1683919651.356 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:31.608Z,1683919651.608 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:31.860Z,1683919651.860 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:32.112Z,1683919652.112 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:32.364Z,1683919652.364 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:32.616Z,1683919652.616 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:32.616Z,1683919652.616 [DATMMP](FAULT): Buffer send receipt timeout failure. 2023-05-12T19:27:32.617Z,1683919652.617 [DATMMP](DEBUG): In sendingTransmitVerify, timeout set commsState_ = SENDING_FILL_BUFFER 2023-05-12T19:27:32.868Z,1683919652.868 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T19:27:32.869Z,1683919652.869 [DATMMP](INFO): modem://10: set _.temperature 24.219263 celsius 2023-05-12T19:27:32.869Z,1683919652.869 [DATMMP](INFO): #Outgoing data=1 2023-05-12T19:27:32.870Z,1683919652.870 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T19:27:33.120Z,1683919653.120 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T19:27:33.120Z,1683919653.120 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T19:27:33.372Z,1683919653.372 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T19:27:33.373Z,1683919653.373 [DATMMP](INFO): Tx to 10 len 34 xid 44 2023-05-12T19:27:33.373Z,1683919653.373 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T19:27:33.373Z,1683919653.373 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:33.625Z,1683919653.625 [DATMMP](INFO): GSXN notify for xid: 44 2023-05-12T19:27:33.625Z,1683919653.625 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-05-12T19:27:33.626Z,1683919653.626 [DATMMP](DEBUG): Command complete send 2023-05-12T19:27:33.626Z,1683919653.626 [DATMMP](ERROR): 1:COMPLETE 2023-05-12T19:27:33.626Z,1683919653.626 [DATMMP](INFO): Received message type: cmd_result 2023-05-12T19:27:33.626Z,1683919653.626 [DATMMP](INFO): Handled 2023-05-12T19:27:33.626Z,1683919653.626 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:33.877Z,1683919653.877 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:33.878Z,1683919653.878 [DATMMP](INFO): timestamp rx: x0 x13 x1B x20 x67 2023-05-12T19:27:33.878Z,1683919653.878 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:27:33.878Z,1683919653.878 [DATMMP](INFO): Handled 2023-05-12T19:27:33.878Z,1683919653.878 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:34.129Z,1683919654.129 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:34.380Z,1683919654.380 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:34.632Z,1683919654.632 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:34.884Z,1683919654.884 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:35.136Z,1683919655.136 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:35.388Z,1683919655.388 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:35.640Z,1683919655.640 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:35.892Z,1683919655.892 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:36.144Z,1683919656.144 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:36.359Z,1683919656.359 [Default:A.Wait](INFO): Done Waiting. 2023-05-12T19:27:36.359Z,1683919656.359 [Default:A.Wait] Stopped 2023-05-12T19:27:36.359Z,1683919656.359 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2023-05-12T19:27:36.397Z,1683919656.397 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:36.648Z,1683919656.648 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:36.768Z,1683919656.768 [Default:CheckIn] Running Loop=1 2023-05-12T19:27:36.768Z,1683919656.768 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2023-05-12T19:27:36.768Z,1683919656.768 [Default:CheckIn:Read_GPS] Running Loop=1 2023-05-12T19:27:36.900Z,1683919656.900 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:37.153Z,1683919657.153 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:37.404Z,1683919657.404 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:37.657Z,1683919657.657 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:37.909Z,1683919657.909 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:37.909Z,1683919657.909 [DATMMP](INFO): doppler rx: x0 2023-05-12T19:27:37.909Z,1683919657.909 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:27:37.909Z,1683919657.909 [DATMMP](INFO): Handled 2023-05-12T19:27:37.910Z,1683919657.910 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:38.161Z,1683919658.161 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:38.162Z,1683919658.162 [DATMMP](INFO): timestamp rx: x1 x13 x1B x24 xCC 2023-05-12T19:27:38.162Z,1683919658.162 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919658.040384 2023-05-12T19:27:38.162Z,1683919658.162 [DATMMP](INFO): Rx ping set to:1683919658.161744 2023-05-12T19:27:38.163Z,1683919658.163 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:27:38.163Z,1683919658.163 [DATMMP](INFO): Handled 2023-05-12T19:27:38.163Z,1683919658.163 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:38.412Z,1683919658.412 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:38.666Z,1683919658.666 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:38.667Z,1683919658.667 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-05-12T19:27:38.667Z,1683919658.667 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:27:38.667Z,1683919658.667 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:27:38.667Z,1683919658.667 [DATMMP](INFO): Handled 2023-05-12T19:27:38.667Z,1683919658.667 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:38.917Z,1683919658.917 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:38.918Z,1683919658.918 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:27:38.918Z,1683919658.918 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:27:38.918Z,1683919658.918 [DATMMP](INFO): Handled 2023-05-12T19:27:38.918Z,1683919658.918 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:39.172Z,1683919659.172 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:39.174Z,1683919659.174 [DATMMP](INFO): directional_debug rx: xEC x16C x23 xB8 xFF0 x1311 x11E2 x1653 2023-05-12T19:27:39.175Z,1683919659.175 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:27:39.175Z,1683919659.175 [DATMMP](INFO): Handled 2023-05-12T19:27:39.175Z,1683919659.175 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:39.425Z,1683919659.425 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:39.426Z,1683919659.426 [DATMMP](INFO): directional rx: xEA x115 x4F0 xFE94 x3FC xFE9F x0 xD25 x5 xFFEF x27B5966 x-43569E0 2023-05-12T19:27:39.428Z,1683919659.428 [DATMMP](INFO): Received message type: directional 2023-05-12T19:27:39.428Z,1683919659.428 [DATMMP](INFO): Handled 2023-05-12T19:27:39.428Z,1683919659.428 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:39.676Z,1683919659.676 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:39.678Z,1683919659.678 [DATMMP](INFO): acstats rx: xA x5 x0 x29E x23 x85 xC4 xCD xD xFFFF xAD x24 xC x0 2023-05-12T19:27:39.678Z,1683919659.678 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:27:39.678Z,1683919659.678 [DATMMP](INFO): Handled 2023-05-12T19:27:39.679Z,1683919659.679 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:39.929Z,1683919659.929 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:39.930Z,1683919659.930 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-05-12T19:27:39.930Z,1683919659.930 [DATMMP](INFO): Check CRC 2023-05-12T19:27:39.930Z,1683919659.930 [DATMMP](INFO): data rx parseDataResponse 4 2023-05-12T19:27:39.930Z,1683919659.930 [DATMMP](INFO): Got DATA: len 4 2023-05-12T19:27:39.930Z,1683919659.930 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-05-12T19:27:39.930Z,1683919659.930 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-05-12T19:27:39.930Z,1683919659.930 [DATMMP](INFO): Received command: 2023-05-12T19:27:39.931Z,1683919659.931 [DATMMP](INFO): Received message type: data_rx 2023-05-12T19:27:39.931Z,1683919659.931 [DATMMP](INFO): Handled 2023-05-12T19:27:39.931Z,1683919659.931 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-05-12T19:27:39.931Z,1683919659.931 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-05-12T19:27:40.181Z,1683919660.181 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T19:27:40.181Z,1683919660.181 [DATMMP](INFO): modem://10: set _.humidity 12.892199 percent 2023-05-12T19:27:40.182Z,1683919660.182 [DATMMP](INFO): #Outgoing data=2 2023-05-12T19:27:40.182Z,1683919660.182 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T19:27:40.444Z,1683919660.444 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T19:27:40.445Z,1683919660.445 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T19:27:40.696Z,1683919660.696 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T19:27:40.697Z,1683919660.697 [DATMMP](INFO): Tx to 10 len 35 xid 45 2023-05-12T19:27:40.697Z,1683919660.697 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T19:27:40.698Z,1683919660.698 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:40.949Z,1683919660.949 [DATMMP](INFO): GSXN notify for xid: 45 2023-05-12T19:27:40.949Z,1683919660.949 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-05-12T19:27:40.950Z,1683919660.950 [DATMMP](DEBUG): Command complete send 2023-05-12T19:27:40.950Z,1683919660.950 [DATMMP](ERROR): 1:COMPLETE 2023-05-12T19:27:40.950Z,1683919660.950 [DATMMP](INFO): Received message type: cmd_result 2023-05-12T19:27:40.950Z,1683919660.950 [DATMMP](INFO): Handled 2023-05-12T19:27:40.950Z,1683919660.950 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:41.201Z,1683919661.201 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:41.202Z,1683919661.202 [DATMMP](INFO): timestamp rx: x0 x13 x1B x27 xE13 2023-05-12T19:27:41.202Z,1683919661.202 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:27:41.202Z,1683919661.202 [DATMMP](INFO): Handled 2023-05-12T19:27:41.452Z,1683919661.452 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:41.704Z,1683919661.704 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:41.956Z,1683919661.956 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:42.208Z,1683919662.208 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:42.460Z,1683919662.460 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:42.712Z,1683919662.712 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:42.964Z,1683919662.964 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:43.216Z,1683919663.216 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:43.468Z,1683919663.468 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:43.720Z,1683919663.720 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:43.972Z,1683919663.972 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:44.224Z,1683919664.224 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:44.476Z,1683919664.476 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:44.728Z,1683919664.728 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:44.981Z,1683919664.981 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:45.234Z,1683919665.234 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:45.235Z,1683919665.235 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:27:45.235Z,1683919665.235 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:27:45.235Z,1683919665.235 [DATMMP](INFO): Handled 2023-05-12T19:27:45.235Z,1683919665.235 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:45.485Z,1683919665.485 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:45.485Z,1683919665.485 [DATMMP](INFO): timestamp rx: x1 x13 x1B x2B xC84 2023-05-12T19:27:45.486Z,1683919665.486 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919694.303104 2023-05-12T19:27:45.486Z,1683919665.486 [DATMMP](INFO): Rx ping set to:1683919665.485560 2023-05-12T19:27:45.486Z,1683919665.486 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:27:45.487Z,1683919665.487 [DATMMP](INFO): Handled 2023-05-12T19:27:45.487Z,1683919665.487 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:45.736Z,1683919665.736 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:45.988Z,1683919665.988 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:45.990Z,1683919665.990 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-05-12T19:27:45.990Z,1683919665.990 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:27:45.990Z,1683919665.990 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:27:45.990Z,1683919665.990 [DATMMP](INFO): Handled 2023-05-12T19:27:45.990Z,1683919665.990 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:46.241Z,1683919666.241 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:46.241Z,1683919666.241 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:27:46.242Z,1683919666.242 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:27:46.242Z,1683919666.242 [DATMMP](INFO): Handled 2023-05-12T19:27:46.242Z,1683919666.242 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:46.493Z,1683919666.493 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:46.494Z,1683919666.494 [DATMMP](INFO): directional_debug rx: x8B x1C4 x22 xBC xFF0 x1351 x1222 x1653 2023-05-12T19:27:46.495Z,1683919666.495 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:27:46.495Z,1683919666.495 [DATMMP](INFO): Handled 2023-05-12T19:27:46.495Z,1683919666.495 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:46.745Z,1683919666.745 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:46.747Z,1683919666.747 [DATMMP](INFO): directional rx: x84 x173 x551 xFE3C x435 xFE44 x0 xD03 x6 xFFF0 x27B5966 x-43569E0 2023-05-12T19:27:46.748Z,1683919666.748 [DATMMP](INFO): Received message type: directional 2023-05-12T19:27:46.748Z,1683919666.748 [DATMMP](INFO): Handled 2023-05-12T19:27:46.748Z,1683919666.748 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:46.996Z,1683919666.996 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:46.998Z,1683919666.998 [DATMMP](INFO): acstats rx: xA x5 xFFFF x2CC x22 x85 xB4 xC1 xD xFFFF xAF x23 xD x0 2023-05-12T19:27:46.998Z,1683919666.998 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:27:46.998Z,1683919666.998 [DATMMP](INFO): Handled 2023-05-12T19:27:46.999Z,1683919666.999 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:47.249Z,1683919667.249 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:47.249Z,1683919667.249 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-05-12T19:27:47.250Z,1683919667.250 [DATMMP](INFO): Check CRC 2023-05-12T19:27:47.250Z,1683919667.250 [DATMMP](INFO): data rx parseDataResponse 4 2023-05-12T19:27:47.250Z,1683919667.250 [DATMMP](INFO): Got DATA: len 4 2023-05-12T19:27:47.250Z,1683919667.250 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-05-12T19:27:47.250Z,1683919667.250 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-05-12T19:27:47.250Z,1683919667.250 [DATMMP](INFO): Received command: 2023-05-12T19:27:47.251Z,1683919667.251 [DATMMP](INFO): Received message type: data_rx 2023-05-12T19:27:47.251Z,1683919667.251 [DATMMP](INFO): Handled 2023-05-12T19:27:47.251Z,1683919667.251 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-05-12T19:27:47.251Z,1683919667.251 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-05-12T19:27:47.500Z,1683919667.500 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T19:27:47.501Z,1683919667.501 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T19:27:47.752Z,1683919667.752 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T19:27:47.753Z,1683919667.753 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T19:27:48.005Z,1683919668.005 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T19:27:48.005Z,1683919668.005 [DATMMP](INFO): Tx to 10 len 32 xid 46 2023-05-12T19:27:48.006Z,1683919668.006 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T19:27:48.006Z,1683919668.006 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:27:48.257Z,1683919668.257 [DATMMP](INFO): GSXN notify for xid: 46 2023-05-12T19:27:48.258Z,1683919668.258 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-05-12T19:27:48.258Z,1683919668.258 [DATMMP](DEBUG): Command complete send 2023-05-12T19:27:48.258Z,1683919668.258 [DATMMP](ERROR): 1:COMPLETE 2023-05-12T19:27:48.258Z,1683919668.258 [DATMMP](INFO): Received message type: cmd_result 2023-05-12T19:27:48.258Z,1683919668.258 [DATMMP](INFO): Handled 2023-05-12T19:27:48.258Z,1683919668.258 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:48.509Z,1683919668.509 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:48.510Z,1683919668.510 [DATMMP](INFO): timestamp rx: x0 x13 x1B x2E x19CA 2023-05-12T19:27:48.510Z,1683919668.510 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:27:48.510Z,1683919668.510 [DATMMP](INFO): Handled 2023-05-12T19:27:48.510Z,1683919668.510 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:48.760Z,1683919668.760 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:49.012Z,1683919669.012 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:49.273Z,1683919669.273 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:49.524Z,1683919669.524 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:49.776Z,1683919669.776 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:50.028Z,1683919670.028 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:50.281Z,1683919670.281 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:50.532Z,1683919670.532 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:50.784Z,1683919670.784 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:51.036Z,1683919671.036 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:51.292Z,1683919671.292 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:51.544Z,1683919671.544 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:51.796Z,1683919671.796 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:52.048Z,1683919672.048 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:52.300Z,1683919672.300 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:52.553Z,1683919672.553 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:52.553Z,1683919672.553 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:27:52.554Z,1683919672.554 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:27:52.554Z,1683919672.554 [DATMMP](INFO): Handled 2023-05-12T19:27:52.554Z,1683919672.554 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:52.805Z,1683919672.805 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:52.806Z,1683919672.806 [DATMMP](INFO): timestamp rx: x1 x13 x1B x32 x183B 2023-05-12T19:27:52.806Z,1683919672.806 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919730.604160 2023-05-12T19:27:52.806Z,1683919672.806 [DATMMP](INFO): Rx ping set to:1683919672.805647 2023-05-12T19:27:52.807Z,1683919672.807 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:27:52.807Z,1683919672.807 [DATMMP](INFO): Handled 2023-05-12T19:27:52.807Z,1683919672.807 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:53.056Z,1683919673.056 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:53.309Z,1683919673.309 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:53.310Z,1683919673.310 [DATMMP](INFO): remote_header rx: xF x4 x5 x4 x0 xC xA x0 2023-05-12T19:27:53.311Z,1683919673.311 [DATMMP](INFO): DATA Src=10, Dst=12 2023-05-12T19:27:53.311Z,1683919673.311 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:27:53.311Z,1683919673.311 [DATMMP](INFO): Handled 2023-05-12T19:27:53.311Z,1683919673.311 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:53.561Z,1683919673.561 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:53.561Z,1683919673.561 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:27:53.562Z,1683919673.562 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:27:53.562Z,1683919673.562 [DATMMP](INFO): Handled 2023-05-12T19:27:53.562Z,1683919673.562 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:53.813Z,1683919673.813 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:53.814Z,1683919673.814 [DATMMP](INFO): directional_debug rx: x23 x1E7 x24 xC2 x1030 x1381 x1222 x1663 2023-05-12T19:27:53.815Z,1683919673.815 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:27:53.815Z,1683919673.815 [DATMMP](INFO): Handled 2023-05-12T19:27:53.815Z,1683919673.815 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:54.065Z,1683919674.065 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:54.066Z,1683919674.066 [DATMMP](INFO): directional rx: x1C x1A2 x5B9 xFE19 x46C xFE1D x0 xCD7 x6 xFFEF x27B5966 x-43569E0 2023-05-12T19:27:54.068Z,1683919674.068 [DATMMP](INFO): Received message type: directional 2023-05-12T19:27:54.068Z,1683919674.068 [DATMMP](INFO): Handled 2023-05-12T19:27:54.068Z,1683919674.068 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:54.317Z,1683919674.317 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:54.318Z,1683919674.318 [DATMMP](INFO): acstats rx: xA x5 xFFFF x2BE x22 x8F xBD xC8 xD xFFFF xA9 x24 xC x0 2023-05-12T19:27:54.318Z,1683919674.318 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:27:54.319Z,1683919674.319 [DATMMP](INFO): Handled 2023-05-12T19:27:54.319Z,1683919674.319 [DATMMP](INFO): *** SENDING_ACK_WAITING *** 2023-05-12T19:27:54.569Z,1683919674.569 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:27:54.569Z,1683919674.569 [DATMMP](INFO): data_rx rx: xA x0 x0 x4 2023-05-12T19:27:54.570Z,1683919674.570 [DATMMP](INFO): Check CRC 2023-05-12T19:27:54.570Z,1683919674.570 [DATMMP](INFO): data rx parseDataResponse 4 2023-05-12T19:27:54.570Z,1683919674.570 [DATMMP](INFO): Got DATA: len 4 2023-05-12T19:27:54.570Z,1683919674.570 [DATMMP](DEBUG): In parseResponses, got ack so set commsState_ = SENDING_VERIFIED 2023-05-12T19:27:54.570Z,1683919674.570 [DATMMP](INFO): Got ~~ ack, bytes left 2 2023-05-12T19:27:54.570Z,1683919674.570 [DATMMP](INFO): Received command: 2023-05-12T19:27:54.571Z,1683919674.571 [DATMMP](INFO): Received message type: data_rx 2023-05-12T19:27:54.571Z,1683919674.571 [DATMMP](INFO): Handled 2023-05-12T19:27:54.571Z,1683919674.571 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-05-12T19:27:54.571Z,1683919674.571 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-05-12T19:32:03.048Z,1683919923.048 [CommandExec](IMPORTANT): got command get Vehicle.id 2023-05-12T19:32:03.049Z,1683919923.049 [CommandExec](IMPORTANT): Vehicle.id 12 enum 2023-05-12T19:32:10.664Z,1683919930.664 [NAL9602](FAULT): GPS failed to acquire within timeout. 2023-05-12T19:32:10.664Z,1683919930.664 [NAL9602] Data Fault, FailCount= 1 2023-05-12T19:32:10.664Z,1683919930.664 [NAL9602](ERROR): Data Fault 2023-05-12T19:32:10.723Z,1683919930.723 [CBIT](ERROR): Data Fault in component: NAL9602 2023-05-12T19:32:11.073Z,1683919931.073 [NAL9602](INFO): Powering down 2023-05-12T19:32:11.902Z,1683919931.902 [CBIT](INFO): Clearing failed state for component NAL9602 2023-05-12T19:32:11.902Z,1683919931.902 [NAL9602] No Fault, FailCount= 1 2023-05-12T19:32:16.625Z,1683919936.625 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:16.625Z,1683919936.625 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:32:16.625Z,1683919936.625 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:32:16.625Z,1683919936.625 [DATMMP](INFO): Handled 2023-05-12T19:32:16.877Z,1683919936.877 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:16.877Z,1683919936.878 [DATMMP](INFO): timestamp rx: x1 x13 x20 xE x1893 2023-05-12T19:32:16.878Z,1683919936.878 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919995.456704 2023-05-12T19:32:16.878Z,1683919936.878 [DATMMP](INFO): Rx ping set to:1683919936.877561 2023-05-12T19:32:16.879Z,1683919936.879 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:32:16.879Z,1683919936.879 [DATMMP](INFO): Handled 2023-05-12T19:32:17.381Z,1683919937.381 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:17.381Z,1683919937.381 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:32:17.382Z,1683919937.382 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:32:17.382Z,1683919937.382 [DATMMP](INFO): Handled 2023-05-12T19:32:17.633Z,1683919937.633 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:17.634Z,1683919937.634 [DATMMP](INFO): directional_debug rx: x7D x1C5 x22 xB5 xFF0 x12F1 x11C2 x1673 2023-05-12T19:32:17.635Z,1683919937.635 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:32:17.635Z,1683919937.635 [DATMMP](INFO): Handled 2023-05-12T19:32:17.885Z,1683919937.885 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:17.886Z,1683919937.886 [DATMMP](INFO): directional rx: x76 x176 x55F xFE3B x83 xFE42 x0 x945 x6 xFFEE x27B5966 x-43569E0 2023-05-12T19:32:17.888Z,1683919937.888 [DATMMP](INFO): Received message type: directional 2023-05-12T19:32:17.888Z,1683919937.888 [DATMMP](INFO): Handled 2023-05-12T19:32:18.137Z,1683919938.137 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:18.138Z,1683919938.138 [DATMMP](INFO): remote_header rx: x0 x50 x5 x0 x0 xC x9 x0 2023-05-12T19:32:18.138Z,1683919938.138 [DATMMP](INFO): DATA Src=9, Dst=12 2023-05-12T19:32:18.138Z,1683919938.138 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:32:18.138Z,1683919938.138 [DATMMP](INFO): Handled 2023-05-12T19:32:18.389Z,1683919938.389 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:18.391Z,1683919938.391 [DATMMP](INFO): acstats rx: x9 x0 xFFFF x2CD x22 x84 xAF xB3 xD xFFFF x0 x23 x0 x0 2023-05-12T19:32:18.391Z,1683919938.391 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:32:18.391Z,1683919938.391 [DATMMP](INFO): Handled 2023-05-12T19:32:18.641Z,1683919938.641 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:18.641Z,1683919938.641 [DATMMP](INFO): timestamp rx: x0 x13 x20 xF x1BAB 2023-05-12T19:32:18.642Z,1683919938.642 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:32:18.642Z,1683919938.642 [DATMMP](INFO): Handled 2023-05-12T19:32:26.201Z,1683919946.201 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:26.201Z,1683919946.201 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:32:26.201Z,1683919946.201 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:32:26.202Z,1683919946.202 [DATMMP](INFO): Handled 2023-05-12T19:32:26.453Z,1683919946.453 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:26.454Z,1683919946.454 [DATMMP](INFO): timestamp rx: x1 x13 x20 x18 x6FD 2023-05-12T19:32:26.454Z,1683919946.454 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919961.493568 2023-05-12T19:32:26.454Z,1683919946.454 [DATMMP](INFO): Rx ping set to:1683919946.453599 2023-05-12T19:32:26.455Z,1683919946.455 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:32:26.455Z,1683919946.455 [DATMMP](INFO): Handled 2023-05-12T19:32:26.705Z,1683919946.705 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:26.706Z,1683919946.706 [DATMMP](INFO): remote_header rx: xF x4 x5 x6 x0 xC x9 x0 2023-05-12T19:32:26.706Z,1683919946.706 [DATMMP](INFO): DATA Src=9, Dst=12 2023-05-12T19:32:26.706Z,1683919946.706 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:32:26.706Z,1683919946.706 [DATMMP](INFO): Handled 2023-05-12T19:32:26.956Z,1683919946.956 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:26.957Z,1683919946.957 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:32:26.957Z,1683919946.957 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:32:26.958Z,1683919946.958 [DATMMP](INFO): Handled 2023-05-12T19:32:27.209Z,1683919947.209 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:27.210Z,1683919947.210 [DATMMP](INFO): directional_debug rx: x3F x1FD x24 xC4 x1040 x1371 x1212 x1643 2023-05-12T19:32:27.211Z,1683919947.211 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:32:27.211Z,1683919947.211 [DATMMP](INFO): Handled 2023-05-12T19:32:27.461Z,1683919947.461 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:27.462Z,1683919947.462 [DATMMP](INFO): directional rx: x39 x1BA x59D xFE03 x9C xFE0B x0 x923 x4 xFFEE x27B5966 x-43569E0 2023-05-12T19:32:27.464Z,1683919947.464 [DATMMP](INFO): Received message type: directional 2023-05-12T19:32:27.464Z,1683919947.464 [DATMMP](INFO): Handled 2023-05-12T19:32:27.713Z,1683919947.713 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:27.714Z,1683919947.714 [DATMMP](INFO): acstats rx: x9 x5 xFFFF x2D0 x22 x9A xBD xC3 xD xFFFF xB5 x23 xC x0 2023-05-12T19:32:27.715Z,1683919947.715 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:32:27.715Z,1683919947.715 [DATMMP](INFO): Handled 2023-05-12T19:32:27.965Z,1683919947.965 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:27.966Z,1683919947.966 [DATMMP](INFO): data_rx rx: x9 x0 x0 x6 2023-05-12T19:32:27.966Z,1683919947.966 [DATMMP](INFO): Check CRC 2023-05-12T19:32:27.966Z,1683919947.966 [DATMMP](INFO): data rx parseDataResponse 6 2023-05-12T19:32:27.966Z,1683919947.966 [DATMMP](INFO): Got DATA: len 6 2023-05-12T19:32:27.966Z,1683919947.966 [DATMMP](INFO): Received command: failc 2023-05-12T19:32:27.966Z,1683919947.966 [DATMMP](INFO): #Outgoing data=1 2023-05-12T19:32:27.967Z,1683919947.967 [DATMMP](INFO): Sending ack 2023-05-12T19:32:27.967Z,1683919947.967 [DATMMP](INFO): Received message type: data_rx 2023-05-12T19:32:27.967Z,1683919947.967 [DATMMP](INFO): Handled 2023-05-12T19:32:27.967Z,1683919947.967 [DATMMP](INFO): *** SENDING_FILL_BUFFER *** 2023-05-12T19:32:27.967Z,1683919947.967 [DATMMP](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_NAV_DATA 2023-05-12T19:32:28.057Z,1683919948.057 [CommandExec](IMPORTANT): got command failComponent 2023-05-12T19:32:28.057Z,1683919948.057 [CommandExec](IMPORTANT): Failed components: 2023-05-12T19:32:28.057Z,1683919948.057 [CommandExec](IMPORTANT): No failed Components. 2023-05-12T19:32:28.216Z,1683919948.216 [DATMMP](INFO): *** SENDING_NAV_DATA *** 2023-05-12T19:32:28.216Z,1683919948.216 [DATMMP](DEBUG): In sendingNavData, set commsState_ = SENDING_TRANSMIT 2023-05-12T19:32:28.476Z,1683919948.476 [DATMMP](INFO): *** SENDING_TRANSMIT *** 2023-05-12T19:32:28.477Z,1683919948.477 [DATMMP](INFO): Tx to 9 len 4 xid 47 2023-05-12T19:32:28.477Z,1683919948.477 [DATMMP](INFO): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2023-05-12T19:32:28.478Z,1683919948.478 [DATMMP](INFO): *** SENDING_TRANSMIT_VERIFY *** 2023-05-12T19:32:28.721Z,1683919948.721 [DATMMP](INFO): GSXN notify for xid: 47 2023-05-12T19:32:28.721Z,1683919948.721 [DATMMP](INFO): cmd_result rx: x1 x7 x0 x1 2023-05-12T19:32:28.722Z,1683919948.722 [DATMMP](DEBUG): In rxCmdResult, sent ack so set commsState_ = SENDING_VERIFIED 2023-05-12T19:32:28.722Z,1683919948.722 [DATMMP](DEBUG): Command complete send 2023-05-12T19:32:28.722Z,1683919948.722 [DATMMP](ERROR): 1:COMPLETE 2023-05-12T19:32:28.722Z,1683919948.722 [DATMMP](INFO): Received message type: cmd_result 2023-05-12T19:32:28.722Z,1683919948.722 [DATMMP](INFO): Handled 2023-05-12T19:32:28.722Z,1683919948.722 [DATMMP](INFO): *** SENDING_VERIFIED *** 2023-05-12T19:32:28.722Z,1683919948.722 [DATMMP](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2023-05-12T19:32:28.973Z,1683919948.973 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:28.974Z,1683919948.974 [DATMMP](INFO): timestamp rx: x0 x13 x20 x1B x439 2023-05-12T19:32:28.974Z,1683919948.974 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:32:28.974Z,1683919948.974 [DATMMP](INFO): Handled 2023-05-12T19:32:36.941Z,1683919956.941 [Default:CheckIn:Read_GPS](INFO): Timed out from 2023-05-12T19:27:36.8Z 2023-05-12T19:32:36.941Z,1683919956.941 [Default:CheckIn:Read_GPS] Stopped 2023-05-12T19:32:36.942Z,1683919956.942 [Default:CheckIn:Read_Iridium] Running Loop=1 2023-05-12T19:32:37.355Z,1683919957.355 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications 2023-05-12T19:32:41.369Z,1683919961.369 [NAL9602](INFO): Powering up NAL9602 2023-05-12T19:32:44.188Z,1683919964.188 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20230512T191652/Courier0000.lzma 2023-05-12T19:32:45.190Z,1683919965.190 [DataOverHttps](INFO): Moved sent file to Logs/20230512T191652/Courier0000.lzma.bak 2023-05-12T19:32:45.190Z,1683919965.190 [DataOverHttps](INFO): SBD MOMSN=18300632 2023-05-12T19:32:51.148Z,1683919971.148 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:51.149Z,1683919971.149 [DATMMP](INFO): doppler rx: xFFFF 2023-05-12T19:32:51.149Z,1683919971.149 [DATMMP](INFO): Received message type: doppler 2023-05-12T19:32:51.149Z,1683919971.149 [DATMMP](INFO): Handled 2023-05-12T19:32:51.401Z,1683919971.401 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:51.402Z,1683919971.402 [DATMMP](INFO): timestamp rx: x1 x13 x20 x31 x8EF 2023-05-12T19:32:51.403Z,1683919971.403 [DATMMP](INFO): Rx dataTimestamp_ set to:1683919991.350208 2023-05-12T19:32:51.403Z,1683919971.403 [DATMMP](INFO): Rx ping set to:1683919971.402403 2023-05-12T19:32:51.403Z,1683919971.403 [DATMMP](INFO): Received message type: timestamp 2023-05-12T19:32:51.404Z,1683919971.404 [DATMMP](INFO): Handled 2023-05-12T19:32:51.905Z,1683919971.905 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:51.906Z,1683919971.906 [DATMMP](INFO): remote_header rx: xF x4 x5 xD x0 xC x9 x0 2023-05-12T19:32:51.906Z,1683919971.906 [DATMMP](INFO): DATA Src=9, Dst=12 2023-05-12T19:32:51.906Z,1683919971.906 [DATMMP](INFO): Received message type: remote_header 2023-05-12T19:32:51.906Z,1683919971.906 [DATMMP](INFO): Handled 2023-05-12T19:32:52.157Z,1683919972.157 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:52.157Z,1683919972.157 [DATMMP](INFO): nav_stat rx: x0 x1 x1 2023-05-12T19:32:52.157Z,1683919972.157 [DATMMP](INFO): Received message type: nav_stat 2023-05-12T19:32:52.158Z,1683919972.158 [DATMMP](INFO): Handled 2023-05-12T19:32:52.306Z,1683919972.306 [NAL9602](INFO): NAL9602 initialized 2023-05-12T19:32:52.409Z,1683919972.409 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:52.410Z,1683919972.410 [DATMMP](INFO): directional_debug rx: x22C x1ED x25 x19D x13F0 x1831 x1672 x1B83 2023-05-12T19:32:52.411Z,1683919972.411 [DATMMP](INFO): Received message type: directional_debug 2023-05-12T19:32:52.411Z,1683919972.411 [DATMMP](INFO): Handled 2023-05-12T19:32:52.661Z,1683919972.661 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:52.662Z,1683919972.662 [DATMMP](INFO): directional rx: x236 x19B x3B0 xFE13 xC79 xFE27 x0 x8CD x2 xFFEC x27B5966 x-43569E0 2023-05-12T19:32:52.664Z,1683919972.664 [DATMMP](INFO): Received message type: directional 2023-05-12T19:32:52.664Z,1683919972.664 [DATMMP](INFO): Handled 2023-05-12T19:32:52.913Z,1683919972.913 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:52.914Z,1683919972.914 [DATMMP](INFO): acstats rx: x9 x5 xFFFF x2CE x23 x85 xD0 xC4 xD xFFFF xA9 x23 xB x0 2023-05-12T19:32:52.914Z,1683919972.914 [DATMMP](INFO): Received message type: acstats 2023-05-12T19:32:52.915Z,1683919972.915 [DATMMP](INFO): Handled 2023-05-12T19:32:53.165Z,1683919973.165 [DATMMP](INFO): GSXN notify for xid: 0 2023-05-12T19:32:53.165Z,1683919973.165 [DATMMP](INFO): data_rx rx: x9 x0 x0 xD 2023-05-12T19:32:53.166Z,1683919973.166 [DATMMP](INFO): Check CRC 2023-05-12T19:32:53.166Z,1683919973.166 [DATMMP](INFO): data rx parseDataResponse 13 2023-05-12T19:32:53.166Z,1683919973.166 [DATMMP](INFO): Got DATA: len 13 2023-05-12T19:32:53.166Z,1683919973.166 [DATMMP](INFO): Received command: restart logs 2023-05-12T19:32:53.166Z,1683919973.166 [DATMMP](INFO): #Outgoing data=1 2023-05-12T19:32:53.166Z,1683919973.166 [DATMMP](INFO): Sending ack 2023-05-12T19:32:53.167Z,1683919973.167 [DATMMP](INFO): Received message type: data_rx 2023-05-12T19:32:53.167Z,1683919973.167 [DATMMP](INFO): Handled