2021-05-18T16:04:19.465Z,1621353859.465 [CommandLine](IMPORTANT): got command restart logs 2021-05-18T16:04:26.852Z,1621353866.852 [NAL9602](INFO): NAL9602 initialized 2021-05-18T16:05:25.845Z,1621353925.845 [CommandLine](IMPORTANT): got command run ./Missions/lab_range_test.xml 2021-05-18T16:05:25.845Z,1621353925.845 [MissionManager](INFO): Loading Mission: ./Missions/lab_range_test.xml 2021-05-18T16:05:25.921Z,1621353925.921 [MissionManager](INFO): DefineArg lab_range_test.MissionTimeout = 2.000000 min 2021-05-18T16:05:25.923Z,1621353925.923 [MissionManager](INFO): DefineArg lab_range_test.ContactLabel = 50.000000 count 2021-05-18T16:05:25.948Z,1621353925.948 [MissionManager](INFO): DefineArg lab_range_test.TrackingUpdatePeriod = 5.000000 s 2021-05-18T16:05:25.950Z,1621353925.950 [MissionManager](INFO): DefineArg lab_range_test.NumberOfPings = 10.000000 count 2021-05-18T16:05:25.952Z,1621353925.952 [MissionManager](INFO): DefineArg lab_range_test.ContactDepth = nan m 2021-05-18T16:05:26.025Z,1621353926.025 [lab_range_test:B.Wait](DEBUG): Construct Wait. 2021-05-18T16:05:26.042Z,1621353926.042 [MissionManager](DEBUG): LAB TEST MISSION - ping remote xponder Maximum duration of mission 2 The acoustic address of the asset to be tracked 50 How long to wait between acoustic queries 5 Number of return pings to request with each acoustic query (more than 1 will activate oneway mode) 10 The acoustic address of the asset to be tracked NaN 2021-05-18T16:05:26.048Z,1621353926.048 [CommandLine](IMPORTANT): Running ./Missions/lab_range_test.xml 2021-05-18T16:05:26.253Z,1621353926.253 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:26.253Z,1621353926.253 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:26.253Z,1621353926.253 [DAT](INFO): Querying Benthos address 50 with 5 pings in terminal homing one-way mode. 2021-05-18T16:05:26.254Z,1621353926.254 [DAT](INFO): ****** ping requested ****** 2021-05-18T16:05:26.329Z,1621353926.329 [Default] Stopped 2021-05-18T16:05:26.329Z,1621353926.329 [Default](DEBUG): Aggregate::uninitialize Default 2021-05-18T16:05:26.329Z,1621353926.329 [Default:B.GoToSurface] Stopped 2021-05-18T16:05:26.330Z,1621353926.330 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2021-05-18T16:05:26.330Z,1621353926.330 [Default:CheckIn] Stopped 2021-05-18T16:05:26.330Z,1621353926.330 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn 2021-05-18T16:05:26.330Z,1621353926.330 [Default:CheckIn:Read_GPS] Stopped 2021-05-18T16:05:26.330Z,1621353926.330 [MissionManager](IMPORTANT): Started mission lab_range_test 2021-05-18T16:05:26.330Z,1621353926.330 [lab_range_test] Running Loop=1 2021-05-18T16:05:26.330Z,1621353926.330 [lab_range_test](DEBUG): Aggregate::initialize lab_range_test 2021-05-18T16:05:26.330Z,1621353926.330 [lab_range_test:A.] Running Loop=1 2021-05-18T16:05:26.331Z,1621353926.331 [lab_range_test:A.](INFO): Initializing Tracking. 2021-05-18T16:05:26.331Z,1621353926.331 [lab_range_test:B.Wait] Running Loop=1 2021-05-18T16:05:26.331Z,1621353926.331 [lab_range_test:B.Wait](DEBUG): Initialize Wait Component. 2021-05-18T16:05:26.331Z,1621353926.331 [lab_range_test:A.] Running Loop=1 2021-05-18T16:05:26.331Z,1621353926.331 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:26.332Z,1621353926.332 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.118404 forward, 0.992965 starboard, 0.000000 keelward ] 2021-05-18T16:05:26.333Z,1621353926.333 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:05:26.335Z,1621353926.335 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998921,-0.046374,-0.002706;0.046427,0.998610,0.024958;0.001545,-0.025057,0.999685 ] 2021-05-18T16:05:26.359Z,1621353926.359 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:05:26.360Z,1621353926.360 [lab_range_test:A.](INFO): direction in world frame: [ 0.164376 north, 0.986094 east, 0.024462 down ] 2021-05-18T16:05:26.361Z,1621353926.361 [lab_range_test:A.](INFO): relPosInFSK: [ 0.035521 forward, 0.297890 starboard, 0.000000 keelward ] 2021-05-18T16:05:26.361Z,1621353926.361 [lab_range_test:A.](INFO): relPosInNED: [ 0.049313 north, 0.295828 east, 0.007339 down ] 2021-05-18T16:05:26.362Z,1621353926.362 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:05:26.362Z,1621353926.362 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:05:26.677Z,1621353926.677 [DAT](INFO): DAT read: UART Wakeup 2021-05-18T16:05:26.678Z,1621353926.678 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2021-05-18T16:05:26.679Z,1621353926.679 [DAT](INFO): commRate: 800 2021-05-18T16:05:26.679Z,1621353926.679 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:26.679Z,1621353926.679 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:26.693Z,1621353926.693 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:27.096Z,1621353927.096 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:27.097Z,1621353927.096 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:27.116Z,1621353927.116 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:27.454Z,1621353927.454 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:27.454Z,1621353927.454 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:27.483Z,1621353927.483 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:27.858Z,1621353927.858 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:27.858Z,1621353927.858 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:27.901Z,1621353927.901 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:28.261Z,1621353928.261 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:28.262Z,1621353928.262 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:28.311Z,1621353928.311 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:28.667Z,1621353928.667 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:28.668Z,1621353928.668 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:28.688Z,1621353928.688 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:29.070Z,1621353929.070 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:29.070Z,1621353929.070 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:29.109Z,1621353929.109 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:29.498Z,1621353929.498 [DAT](INFO): DAT read: Forwarding Delay UpTx time:16:05:03.1387 2021-05-18T16:05:29.498Z,1621353929.498 [DAT](INFO): unknown deviceResponse_: Forwarding Delay UpTx time:16:05:03.1387 2021-05-18T16:05:29.498Z,1621353929.498 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:29.499Z,1621353929.499 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:29.513Z,1621353929.513 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:29.900Z,1621353929.900 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:29.900Z,1621353929.900 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:29.915Z,1621353929.915 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:30.296Z,1621353930.296 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:30.297Z,1621353930.297 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:30.357Z,1621353930.357 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:30.692Z,1621353930.692 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:30.692Z,1621353930.692 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:30.698Z,1621353930.698 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:31.090Z,1621353931.090 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:31.090Z,1621353931.090 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:31.130Z,1621353931.130 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:31.500Z,1621353931.500 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:31.500Z,1621353931.500 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:31.506Z,1621353931.506 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:31.507Z,1621353931.507 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:05:31.508Z,1621353931.508 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:05:31.902Z,1621353931.902 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:31.902Z,1621353931.902 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:31.913Z,1621353931.913 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:32.313Z,1621353932.313 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:32.313Z,1621353932.313 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:32.349Z,1621353932.349 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:32.727Z,1621353932.727 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:32.728Z,1621353932.728 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:32.741Z,1621353932.741 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:33.124Z,1621353933.124 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:33.124Z,1621353933.124 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:33.169Z,1621353933.169 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:33.519Z,1621353933.519 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:33.519Z,1621353933.519 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:33.532Z,1621353933.532 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:33.922Z,1621353933.922 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:33.923Z,1621353933.923 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:33.957Z,1621353933.957 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:34.322Z,1621353934.322 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:34.322Z,1621353934.322 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:34.361Z,1621353934.361 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:34.727Z,1621353934.727 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:34.728Z,1621353934.728 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:34.734Z,1621353934.734 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:35.130Z,1621353935.130 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:35.130Z,1621353935.130 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:35.141Z,1621353935.141 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:35.549Z,1621353935.549 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:35.549Z,1621353935.549 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:35.561Z,1621353935.561 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:35.957Z,1621353935.957 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:35.957Z,1621353935.957 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:35.968Z,1621353935.968 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:36.356Z,1621353936.356 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:36.357Z,1621353936.357 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:36.396Z,1621353936.396 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:36.755Z,1621353936.755 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:36.755Z,1621353936.755 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:36.762Z,1621353936.762 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:36.762Z,1621353936.762 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:05:36.762Z,1621353936.762 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:05:37.150Z,1621353937.150 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:37.150Z,1621353937.150 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:37.193Z,1621353937.193 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:37.559Z,1621353937.559 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:37.559Z,1621353937.559 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:37.565Z,1621353937.565 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:37.958Z,1621353937.958 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:37.958Z,1621353937.958 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:37.968Z,1621353937.968 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:38.373Z,1621353938.373 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:38.373Z,1621353938.373 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:38.385Z,1621353938.385 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:38.781Z,1621353938.781 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:38.781Z,1621353938.781 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:38.793Z,1621353938.793 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:39.188Z,1621353939.188 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:39.189Z,1621353939.189 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:39.225Z,1621353939.225 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:39.575Z,1621353939.575 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:39.575Z,1621353939.575 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:39.588Z,1621353939.588 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:39.978Z,1621353939.978 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:39.978Z,1621353939.978 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:39.989Z,1621353939.989 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:40.390Z,1621353940.390 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:40.390Z,1621353940.390 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:40.413Z,1621353940.413 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:40.788Z,1621353940.788 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:40.788Z,1621353940.788 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:40.829Z,1621353940.829 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:41.190Z,1621353941.190 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:41.190Z,1621353941.190 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:41.197Z,1621353941.197 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:41.605Z,1621353941.605 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:05:41.605Z,1621353941.605 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:05:41.605Z,1621353941.605 [DAT](FAULT): Timeout requesting ping 2021-05-18T16:05:41.605Z,1621353941.605 [DAT] Communications Fault, FailCount= 1 2021-05-18T16:05:41.605Z,1621353941.605 [DAT](ERROR): Communications Fault 2021-05-18T16:05:41.617Z,1621353941.617 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:41.625Z,1621353941.625 [CBIT](ERROR): Communications Fault in component: DAT 2021-05-18T16:05:42.020Z,1621353942.020 [DAT](INFO): Powering down 2021-05-18T16:05:42.100Z,1621353942.100 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:42.101Z,1621353942.101 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:05:42.101Z,1621353942.101 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:05:42.440Z,1621353942.440 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:42.816Z,1621353942.816 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:42.825Z,1621353942.825 [CBIT](INFO): Clearing failed state for component DAT 2021-05-18T16:05:42.825Z,1621353942.825 [DAT] No Fault, FailCount= 1 2021-05-18T16:05:43.220Z,1621353943.220 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:43.630Z,1621353943.630 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:44.027Z,1621353944.027 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:44.442Z,1621353944.442 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:44.857Z,1621353944.857 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:45.252Z,1621353945.252 [DAT](INFO): Powering up 2021-05-18T16:05:45.252Z,1621353945.252 [DAT](DEBUG): Initializing DAT. 2021-05-18T16:05:45.281Z,1621353945.281 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:45.644Z,1621353945.644 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:46.048Z,1621353946.048 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:46.449Z,1621353946.449 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:46.865Z,1621353946.865 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:47.281Z,1621353947.281 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:47.281Z,1621353947.281 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:05:47.281Z,1621353947.281 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:05:47.692Z,1621353947.692 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:48.078Z,1621353948.078 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:48.476Z,1621353948.476 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:48.883Z,1621353948.883 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:49.280Z,1621353949.280 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:49.685Z,1621353949.685 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:50.089Z,1621353950.089 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:50.512Z,1621353950.512 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:50.924Z,1621353950.924 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:51.328Z,1621353951.328 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:51.704Z,1621353951.704 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:52.110Z,1621353952.110 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:52.525Z,1621353952.525 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:52.525Z,1621353952.525 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:05:52.526Z,1621353952.526 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:05:52.916Z,1621353952.916 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:53.337Z,1621353953.337 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:53.745Z,1621353953.745 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:54.142Z,1621353954.142 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:54.533Z,1621353954.533 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:54.937Z,1621353954.937 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:55.356Z,1621353955.356 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:55.756Z,1621353955.756 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:56.175Z,1621353956.175 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:56.555Z,1621353956.555 [DAT](INFO): DAT read: 2021-05-18T16:05:56.556Z,1621353956.556 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2021-05-18T16:05:56.622Z,1621353956.622 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:56.972Z,1621353956.972 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:57.376Z,1621353957.376 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:57.804Z,1621353957.804 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:57.805Z,1621353957.805 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:05:57.805Z,1621353957.805 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:05:58.166Z,1621353958.166 [DAT](INFO): DAT read: MF Frequency Band 2021-05-18T16:05:58.168Z,1621353958.168 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.14.2 2021-05-18T16:05:58.168Z,1621353958.168 [DAT](INFO): DAT read: May 18 2021 16:05:28 2021-05-18T16:05:58.192Z,1621353958.192 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:58.593Z,1621353958.593 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:58.992Z,1621353958.992 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:59.381Z,1621353959.381 [DAT](INFO): DAT read: Features enabled [Bearing] 2021-05-18T16:05:59.382Z,1621353959.382 [DAT](INFO): DAT read: CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP 2021-05-18T16:05:59.383Z,1621353959.383 [DAT](INFO): commRate: 800 2021-05-18T16:05:59.451Z,1621353959.451 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:05:59.805Z,1621353959.805 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:00.206Z,1621353960.206 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:00.604Z,1621353960.604 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:00.996Z,1621353960.996 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:01.390Z,1621353961.390 [DAT](INFO): entering command mode 2021-05-18T16:06:01.401Z,1621353961.401 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:01.799Z,1621353961.799 [DAT](INFO): DAT read: 2021-05-18T16:06:01.800Z,1621353961.800 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:01.849Z,1621353961.849 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:02.202Z,1621353962.202 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:02.222Z,1621353962.222 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:02.617Z,1621353962.617 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:02.638Z,1621353962.638 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:03.024Z,1621353963.024 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:03.037Z,1621353963.037 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:03.037Z,1621353963.037 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:06:03.037Z,1621353963.037 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:06:03.428Z,1621353963.428 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:03.440Z,1621353963.440 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:03.818Z,1621353963.818 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:03.839Z,1621353963.839 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:04.222Z,1621353964.222 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:04.228Z,1621353964.228 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:04.623Z,1621353964.623 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:04.637Z,1621353964.636 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:05.032Z,1621353965.032 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:05.044Z,1621353965.044 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:05.447Z,1621353965.447 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:05.461Z,1621353965.461 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:05.853Z,1621353965.853 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:05.876Z,1621353965.876 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:06.252Z,1621353966.252 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:06.258Z,1621353966.258 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:06.650Z,1621353966.650 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:06.661Z,1621353966.661 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:07.050Z,1621353967.050 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:07.070Z,1621353967.070 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:07.451Z,1621353967.451 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:07.457Z,1621353967.457 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:07.858Z,1621353967.858 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:07.865Z,1621353967.865 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:08.272Z,1621353968.272 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:08.285Z,1621353968.285 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:08.285Z,1621353968.285 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:06:08.285Z,1621353968.285 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:06:08.677Z,1621353968.677 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:08.695Z,1621353968.695 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:09.080Z,1621353969.080 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:09.101Z,1621353969.101 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:09.474Z,1621353969.474 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:09.480Z,1621353969.480 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:09.880Z,1621353969.880 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:09.892Z,1621353969.892 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:10.282Z,1621353970.282 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:10.302Z,1621353970.302 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:10.687Z,1621353970.687 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:10.693Z,1621353970.693 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:11.086Z,1621353971.086 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:11.096Z,1621353971.096 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:11.513Z,1621353971.513 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:11.525Z,1621353971.525 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:11.910Z,1621353971.910 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:11.924Z,1621353971.924 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:12.312Z,1621353972.312 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:12.318Z,1621353972.318 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:12.706Z,1621353972.706 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:12.713Z,1621353972.713 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:13.110Z,1621353973.110 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:13.121Z,1621353973.121 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:13.515Z,1621353973.515 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:13.534Z,1621353973.534 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:13.535Z,1621353973.535 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:06:13.535Z,1621353973.535 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:06:13.918Z,1621353973.918 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:13.924Z,1621353973.924 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:14.328Z,1621353974.328 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:14.341Z,1621353974.341 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:14.741Z,1621353974.741 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:14.747Z,1621353974.747 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:15.143Z,1621353975.143 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:15.162Z,1621353975.162 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:15.534Z,1621353975.534 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:15.541Z,1621353975.541 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:15.934Z,1621353975.934 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:15.944Z,1621353975.944 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:16.346Z,1621353976.346 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:16.353Z,1621353976.353 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:16.743Z,1621353976.743 [DAT](DEBUG): checking for command mode acknowledgment 2021-05-18T16:06:16.743Z,1621353976.743 [DAT](FAULT): failed to enter command mode 2021-05-18T16:06:16.781Z,1621353976.781 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:17.147Z,1621353977.147 [DAT](INFO): entering command mode 2021-05-18T16:06:17.153Z,1621353977.153 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:17.566Z,1621353977.566 [DAT](INFO): DAT read: user:1> 2021-05-18T16:06:17.567Z,1621353977.567 [DAT](INFO): DAT read: Command '+++' not found 2021-05-18T16:06:17.568Z,1621353977.568 [DAT](INFO): DAT read: Error 2021-05-18T16:06:17.568Z,1621353977.568 [DAT](INFO): setting verbose to 3 2021-05-18T16:06:17.581Z,1621353977.581 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:17.968Z,1621353977.968 [DAT](INFO): DAT read: user:2> 2021-05-18T16:06:17.969Z,1621353977.969 [DAT](INFO): DAT read: Verbose | 3 2021-05-18T16:06:17.970Z,1621353977.970 [DAT](INFO): set verbose to 3 2021-05-18T16:06:17.970Z,1621353977.970 [DAT](INFO): setting DatVerbose to 27440 2021-05-18T16:06:17.978Z,1621353977.978 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:18.369Z,1621353978.369 [DAT](INFO): DAT read: user:3> 2021-05-18T16:06:18.370Z,1621353978.370 [DAT](INFO): DAT read: DatVerbose | 27440 2021-05-18T16:06:18.370Z,1621353978.370 [DAT](INFO): set DatVerbose to 27440 2021-05-18T16:06:18.370Z,1621353978.370 [DAT](INFO): setting transmit power to 8 2021-05-18T16:06:18.435Z,1621353978.435 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:18.770Z,1621353978.770 [DAT](INFO): DAT read: user:4> 2021-05-18T16:06:18.771Z,1621353978.771 [DAT](INFO): DAT read: TxPower | 8 (Max) 2021-05-18T16:06:18.772Z,1621353978.772 [DAT](INFO): set transmit power to 8 2021-05-18T16:06:18.772Z,1621353978.772 [DAT](INFO): setting local address to 7 2021-05-18T16:06:18.780Z,1621353978.780 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:18.780Z,1621353978.780 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:06:18.781Z,1621353978.781 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:06:19.172Z,1621353979.172 [DAT](INFO): DAT read: user:5> 2021-05-18T16:06:19.173Z,1621353979.173 [DAT](INFO): DAT read: LocalAddr | 7 2021-05-18T16:06:19.173Z,1621353979.173 [DAT](INFO): set local address to 7 2021-05-18T16:06:19.174Z,1621353979.174 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:06:19.174Z,1621353979.174 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:06:19.174Z,1621353979.174 [DAT](INFO): setting remote address to 0 2021-05-18T16:06:19.182Z,1621353979.182 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:19.579Z,1621353979.579 [DAT](INFO): DAT read: user:6> 2021-05-18T16:06:19.580Z,1621353979.580 [DAT](INFO): DAT read: RemoteAddr | 0 2021-05-18T16:06:19.580Z,1621353979.580 [DAT](INFO): set remote address to 0 2021-05-18T16:06:19.581Z,1621353979.581 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:06:19.581Z,1621353979.581 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:06:19.581Z,1621353979.581 [DAT](INFO): Querying Benthos address 50 with 10 pings in terminal homing one-way mode. 2021-05-18T16:06:19.587Z,1621353979.587 [DAT](INFO): ****** ping requested ****** 2021-05-18T16:06:19.640Z,1621353979.640 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:19.982Z,1621353979.982 [DAT](INFO): DAT read: user:7> 2021-05-18T16:06:19.983Z,1621353979.983 [DAT](INFO): DAT read: Tx time:16:05:52.3213 2021-05-18T16:06:19.983Z,1621353979.983 [DAT](INFO): Ping request sent. 2021-05-18T16:06:19.983Z,1621353979.983 [DAT](INFO): transmitted an acoustic signal 2021-05-18T16:06:19.984Z,1621353979.984 [DAT](INFO): publishing transmit ping time 2021-05-18T16:06:19.984Z,1621353979.984 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.000805 2021-05-18T16:06:19.991Z,1621353979.991 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:20.409Z,1621353980.409 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.425628 2021-05-18T16:06:20.424Z,1621353980.424 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:20.805Z,1621353980.805 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.821888 2021-05-18T16:06:20.812Z,1621353980.812 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:21.201Z,1621353981.201 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.217205 2021-05-18T16:06:21.235Z,1621353981.235 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:21.595Z,1621353981.595 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.611810 2021-05-18T16:06:21.602Z,1621353981.602 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:22.001Z,1621353982.001 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=2.017276 2021-05-18T16:06:22.013Z,1621353982.013 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:22.400Z,1621353982.400 [DAT](INFO): DAT read: Rx Time:16:05:54.4510 2021-05-18T16:06:22.400Z,1621353982.400 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:22.401Z,1621353982.401 [DAT](INFO): DAT read: Bearing 69.4, -2.3 (Local) 2021-05-18T16:06:22.402Z,1621353982.402 [DAT](INFO): Local bearing/azimuth received: Bearing 69.4, -2.3 (Local) 2021-05-18T16:06:22.404Z,1621353982.404 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:22.457Z,1621353982.457 [DAT](INFO): DAT read: 16:05:54.4510 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 432, 0.05,-1.271,-1.528,-1.298,-1.340, PHS= 0.065,-0.144, 0.027, RAW= 140.0, 5.5, CAL= 140.6, 2.3, ROT= 69.4, -2.3 2021-05-18T16:06:22.458Z,1621353982.458 [DAT](INFO): got valid direction response: 16:05:54.4510 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 432, 0.05,-1.271,-1.528,-1.298,-1.340, PHS= 0.065,-0.144, 0.027, RAW= 140.0, 5.5, CAL= 140.6, 2.3, ROT= 69.4, -2.3 2021-05-18T16:06:22.459Z,1621353982.459 [DAT](INFO): #Rx 1: Read range and direction messages. 2021-05-18T16:06:22.468Z,1621353982.468 [DAT](INFO): direction in vehicle frame: [ 0.351558 forward, 0.935305 starboard, -0.040132 keelward ] 2021-05-18T16:06:22.468Z,1621353982.468 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:22.468Z,1621353982.468 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:22.479Z,1621353982.479 [DAT](INFO): checking for new query: numPingsReceived=1 elapsed TxPingTime=2.496021 2021-05-18T16:06:22.498Z,1621353982.498 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:22.508Z,1621353982.508 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.351558 forward, 0.935305 starboard, -0.040132 keelward ] 2021-05-18T16:06:22.509Z,1621353982.509 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:22.519Z,1621353982.519 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998872,-0.047399,-0.002777;0.047453,0.998565,0.024828;0.001596,-0.024932,0.999688 ] 2021-05-18T16:06:22.520Z,1621353982.520 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:22.520Z,1621353982.520 [lab_range_test:A.](INFO): direction in world frame: [ 0.395481 north, 0.918300 east, -0.017874 down ] 2021-05-18T16:06:22.521Z,1621353982.521 [lab_range_test:A.](INFO): relPosInFSK: [ 0.105467 forward, 0.280592 starboard, -0.012040 keelward ] 2021-05-18T16:06:22.522Z,1621353982.522 [lab_range_test:A.](INFO): relPosInNED: [ 0.118644 north, 0.275490 east, -0.005362 down ] 2021-05-18T16:06:22.522Z,1621353982.522 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:22.522Z,1621353982.522 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:22.803Z,1621353982.803 [DAT](INFO): DAT read: Rx Time:16:05:54.9510 2021-05-18T16:06:22.804Z,1621353982.804 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:22.805Z,1621353982.805 [DAT](INFO): DAT read: Bearing 69.9, -1.5 (Local) 2021-05-18T16:06:22.805Z,1621353982.805 [DAT](INFO): Local bearing/azimuth received: Bearing 69.9, -1.5 (Local) 2021-05-18T16:06:22.807Z,1621353982.807 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:22.812Z,1621353982.812 [DAT](INFO): DAT read: 16:05:54.9510 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 496, 0.17,-0.921,-1.169,-0.948,-0.990, PHS= 0.066,-0.135, 0.027, RAW= 139.5, 4.6, CAL= 140.1, 1.5, ROT= 69.9, -1.5 2021-05-18T16:06:22.813Z,1621353982.813 [DAT](INFO): got valid direction response: 16:05:54.9510 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 496, 0.17,-0.921,-1.169,-0.948,-0.990, PHS= 0.066,-0.135, 0.027, RAW= 139.5, 4.6, CAL= 140.1, 1.5, ROT= 69.9, -1.5 2021-05-18T16:06:22.814Z,1621353982.814 [DAT](INFO): #Rx 2: Read range and direction messages. 2021-05-18T16:06:22.815Z,1621353982.815 [DAT](INFO): direction in vehicle frame: [ 0.343542 forward, 0.938772 starboard, -0.026177 keelward ] 2021-05-18T16:06:22.815Z,1621353982.815 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:22.815Z,1621353982.815 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:22.818Z,1621353982.818 [DAT](INFO): checking for new query: numPingsReceived=2 elapsed TxPingTime=2.834561 2021-05-18T16:06:22.828Z,1621353982.828 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:22.830Z,1621353982.830 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.343542 forward, 0.938772 starboard, -0.026177 keelward ] 2021-05-18T16:06:22.830Z,1621353982.830 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:22.832Z,1621353982.832 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998879,-0.047261,-0.002810;0.047316,0.998571,0.024840;0.001632,-0.024945,0.999687 ] 2021-05-18T16:06:22.832Z,1621353982.832 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:22.833Z,1621353982.833 [lab_range_test:A.](INFO): direction in world frame: [ 0.387533 north, 0.921848 east, -0.003815 down ] 2021-05-18T16:06:22.834Z,1621353982.834 [lab_range_test:A.](INFO): relPosInFSK: [ 0.103063 forward, 0.281632 starboard, -0.007853 keelward ] 2021-05-18T16:06:22.835Z,1621353982.835 [lab_range_test:A.](INFO): relPosInNED: [ 0.116260 north, 0.276554 east, -0.001144 down ] 2021-05-18T16:06:22.887Z,1621353982.887 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:22.887Z,1621353982.887 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:23.225Z,1621353983.225 [DAT](INFO): DAT read: Rx Time:16:05:55.4508 2021-05-18T16:06:23.226Z,1621353983.226 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:23.227Z,1621353983.227 [DAT](INFO): DAT read: Bearing 69.3, -1.5 (Local) 2021-05-18T16:06:23.227Z,1621353983.227 [DAT](INFO): Local bearing/azimuth received: Bearing 69.3, -1.5 (Local) 2021-05-18T16:06:23.229Z,1621353983.229 [DAT](INFO): DAT read: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:23.230Z,1621353983.230 [DAT](INFO): unknown deviceResponse_: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:23.234Z,1621353983.234 [DAT](INFO): DAT read: 16:05:55.4508 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.32,-2.394,-2.653,-2.421,-2.466, PHS= 0.068,-0.143, 0.030, RAW= 140.1, 4.7, CAL= 140.7, 1.5, ROT= 69.3, -1.5 2021-05-18T16:06:23.243Z,1621353983.243 [DAT](INFO): got valid direction response: 16:05:55.4508 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.32,-2.394,-2.653,-2.421,-2.466, PHS= 0.068,-0.143, 0.030, RAW= 140.1, 4.7, CAL= 140.7, 1.5, ROT= 69.3, -1.5 2021-05-18T16:06:23.244Z,1621353983.244 [DAT](INFO): #Rx 3: Read direction message, but no range. 2021-05-18T16:06:23.245Z,1621353983.245 [DAT](INFO): direction in vehicle frame: [ 0.353354 forward, 0.935123 starboard, -0.026177 keelward ] 2021-05-18T16:06:23.245Z,1621353983.245 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:23.248Z,1621353983.248 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.264905 2021-05-18T16:06:23.283Z,1621353983.283 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:23.637Z,1621353983.637 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.653573 2021-05-18T16:06:23.653Z,1621353983.653 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:24.025Z,1621353984.025 [DAT](INFO): DAT read: Rx Time:16:05:55.9508 2021-05-18T16:06:24.025Z,1621353984.025 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:24.027Z,1621353984.027 [DAT](INFO): DAT read: Bearing 118.7, 9.8 (Local) 2021-05-18T16:06:24.027Z,1621353984.027 [DAT](INFO): Local bearing/azimuth received: Bearing 118.7, 9.8 (Local) 2021-05-18T16:06:24.029Z,1621353984.029 [DAT](INFO): DAT read: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:24.030Z,1621353984.030 [DAT](INFO): unknown deviceResponse_: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:24.082Z,1621353984.082 [DAT](INFO): DAT read: 16:05:55.9508 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 512,-0.45,-3.049, 0.897, 0.983, 1.486, PHS= 1.745,-0.545,-0.518, RAW= 90.6, -6.0, CAL= 91.3, -9.8, ROT= 118.7, 9.8 2021-05-18T16:06:24.088Z,1621353984.088 [DAT](INFO): got valid direction response: 16:05:55.9508 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 512,-0.45,-3.049, 0.897, 0.983, 1.486, PHS= 1.745,-0.545,-0.518, RAW= 90.6, -6.0, CAL= 91.3, -9.8, ROT= 118.7, 9.8 2021-05-18T16:06:24.089Z,1621353984.089 [DAT](INFO): #Rx 4: Read direction message, but no range. 2021-05-18T16:06:24.090Z,1621353984.090 [DAT](INFO): direction in vehicle frame: [ -0.473216 forward, 0.864347 starboard, 0.170209 keelward ] 2021-05-18T16:06:24.090Z,1621353984.090 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:24.093Z,1621353984.093 [DAT](INFO): checking for new query: numPingsReceived=4 elapsed TxPingTime=4.109994 2021-05-18T16:06:24.121Z,1621353984.121 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:24.419Z,1621353984.419 [DAT](INFO): DAT read: Rx Time:16:05:56.4508 2021-05-18T16:06:24.420Z,1621353984.420 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:24.421Z,1621353984.421 [DAT](INFO): DAT read: Bearing 67.4, -4.5 (Local) 2021-05-18T16:06:24.421Z,1621353984.421 [DAT](INFO): Local bearing/azimuth received: Bearing 67.4, -4.5 (Local) 2021-05-18T16:06:24.423Z,1621353984.423 [DAT](INFO): DAT read: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:24.424Z,1621353984.424 [DAT](INFO): unknown deviceResponse_: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:24.428Z,1621353984.428 [DAT](INFO): DAT read: 16:05:56.4508 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 511,-0.25, 1.271, 0.957, 1.243, 1.197, PHS= 0.069,-0.197, 0.030, RAW= 142.2, 7.8, CAL= 142.6, 4.5, ROT= 67.4, -4.5 2021-05-18T16:06:24.429Z,1621353984.429 [DAT](INFO): got valid direction response: 16:05:56.4508 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 511,-0.25, 1.271, 0.957, 1.243, 1.197, PHS= 0.069,-0.197, 0.030, RAW= 142.2, 7.8, CAL= 142.6, 4.5, ROT= 67.4, -4.5 2021-05-18T16:06:24.430Z,1621353984.430 [DAT](INFO): #Rx 5: Read direction message, but no range. 2021-05-18T16:06:24.431Z,1621353984.431 [DAT](INFO): direction in vehicle frame: [ 0.383111 forward, 0.920364 starboard, -0.078459 keelward ] 2021-05-18T16:06:24.431Z,1621353984.431 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:24.434Z,1621353984.434 [DAT](INFO): checking for new query: numPingsReceived=5 elapsed TxPingTime=4.450599 2021-05-18T16:06:24.465Z,1621353984.465 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:24.823Z,1621353984.823 [DAT](INFO): DAT read: Rx Time:16:05:56.9509 2021-05-18T16:06:24.823Z,1621353984.823 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:24.825Z,1621353984.825 [DAT](INFO): DAT read: Bearing 75.9, -4.2 (Local) 2021-05-18T16:06:24.825Z,1621353984.825 [DAT](INFO): Local bearing/azimuth received: Bearing 75.9, -4.2 (Local) 2021-05-18T16:06:24.835Z,1621353984.835 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:24.840Z,1621353984.840 [DAT](INFO): DAT read: 16:05:56.9509 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 0, 0.68, 0.782,-0.057, 0.551, 0.513, PHS= 0.265,-0.526, 0.024, RAW= 132.7, 6.8, CAL= 134.1, 4.2, ROT= 75.9, -4.2 2021-05-18T16:06:24.841Z,1621353984.841 [DAT](INFO): got valid direction response: 16:05:56.9509 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 0, 0.68, 0.782,-0.057, 0.551, 0.513, PHS= 0.265,-0.526, 0.024, RAW= 132.7, 6.8, CAL= 134.1, 4.2, ROT= 75.9, -4.2 2021-05-18T16:06:24.841Z,1621353984.841 [DAT](INFO): #Rx 6: Read range and direction messages. 2021-05-18T16:06:24.842Z,1621353984.842 [DAT](INFO): direction in vehicle frame: [ 0.242961 forward, 0.967267 starboard, -0.073238 keelward ] 2021-05-18T16:06:24.871Z,1621353984.871 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:24.871Z,1621353984.871 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:24.875Z,1621353984.875 [DAT](INFO): checking for new query: numPingsReceived=6 elapsed TxPingTime=4.891132 2021-05-18T16:06:24.901Z,1621353984.901 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:24.902Z,1621353984.902 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.242961 forward, 0.967267 starboard, -0.073238 keelward ] 2021-05-18T16:06:24.903Z,1621353984.903 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:24.913Z,1621353984.913 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998858,-0.047698,-0.002779;0.047752,0.998552,0.024753;0.001594,-0.024858,0.999690 ] 2021-05-18T16:06:24.914Z,1621353984.914 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:24.914Z,1621353984.914 [lab_range_test:A.](INFO): direction in world frame: [ 0.288755 north, 0.956099 east, -0.049948 down ] 2021-05-18T16:06:24.919Z,1621353984.919 [lab_range_test:A.](INFO): relPosInFSK: [ 0.048592 forward, 0.193453 starboard, -0.014648 keelward ] 2021-05-18T16:06:24.920Z,1621353984.920 [lab_range_test:A.](INFO): relPosInNED: [ 0.057751 north, 0.191220 east, -0.009990 down ] 2021-05-18T16:06:24.921Z,1621353984.921 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:24.921Z,1621353984.921 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:25.237Z,1621353985.237 [DAT](INFO): DAT read: Rx Time:16:05:57.4508 2021-05-18T16:06:25.238Z,1621353985.238 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:25.239Z,1621353985.239 [DAT](INFO): DAT read: Bearing 69.7, -2.8 (Local) 2021-05-18T16:06:25.239Z,1621353985.239 [DAT](INFO): Local bearing/azimuth received: Bearing 69.7, -2.8 (Local) 2021-05-18T16:06:25.241Z,1621353985.241 [DAT](INFO): DAT read: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:25.242Z,1621353985.242 [DAT](INFO): unknown deviceResponse_: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:25.246Z,1621353985.246 [DAT](INFO): DAT read: 16:05:57.4508 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 495,-0.01, 1.855, 1.541, 1.816, 1.770, PHS= 0.082,-0.185, 0.031, RAW= 139.8, 5.9, CAL= 140.3, 2.8, ROT= 69.7, -2.8 2021-05-18T16:06:25.248Z,1621353985.248 [DAT](INFO): got valid direction response: 16:05:57.4508 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 495,-0.01, 1.855, 1.541, 1.816, 1.770, PHS= 0.082,-0.185, 0.031, RAW= 139.8, 5.9, CAL= 140.3, 2.8, ROT= 69.7, -2.8 2021-05-18T16:06:25.248Z,1621353985.248 [DAT](INFO): #Rx 7: Read direction message, but no range. 2021-05-18T16:06:25.249Z,1621353985.249 [DAT](INFO): direction in vehicle frame: [ 0.346522 forward, 0.936769 starboard, -0.048850 keelward ] 2021-05-18T16:06:25.250Z,1621353985.250 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:25.253Z,1621353985.253 [DAT](INFO): checking for new query: numPingsReceived=7 elapsed TxPingTime=5.269158 2021-05-18T16:06:25.301Z,1621353985.301 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:25.645Z,1621353985.645 [DAT](INFO): checking for new query: numPingsReceived=7 elapsed TxPingTime=5.661776 2021-05-18T16:06:25.709Z,1621353985.709 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:26.049Z,1621353986.049 [DAT](INFO): DAT read: Rx Time:16:05:57.9509 2021-05-18T16:06:26.050Z,1621353986.050 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:26.051Z,1621353986.051 [DAT](INFO): DAT read: Bearing 68.3, -7.2 (Local) 2021-05-18T16:06:26.051Z,1621353986.051 [DAT](INFO): Local bearing/azimuth received: Bearing 68.3, -7.2 (Local) 2021-05-18T16:06:26.053Z,1621353986.053 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:26.114Z,1621353986.114 [DAT](INFO): DAT read: 16:05:57.9509 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.59,-1.495,-1.996,-1.558,-1.601, PHS= 0.103,-0.351, 0.028, RAW= 141.2, 10.5, CAL= 141.7, 7.2, ROT= 68.3, -7.2 2021-05-18T16:06:26.115Z,1621353986.115 [DAT](INFO): got valid direction response: 16:05:57.9509 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.59,-1.495,-1.996,-1.558,-1.601, PHS= 0.103,-0.351, 0.028, RAW= 141.2, 10.5, CAL= 141.7, 7.2, ROT= 68.3, -7.2 2021-05-18T16:06:26.116Z,1621353986.116 [DAT](INFO): #Rx 8: Read range and direction messages. 2021-05-18T16:06:26.117Z,1621353986.117 [DAT](INFO): direction in vehicle frame: [ 0.366831 forward, 0.921806 starboard, -0.125333 keelward ] 2021-05-18T16:06:26.117Z,1621353986.117 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:26.117Z,1621353986.117 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:26.124Z,1621353986.124 [DAT](INFO): checking for new query: numPingsReceived=8 elapsed TxPingTime=6.140946 2021-05-18T16:06:26.148Z,1621353986.148 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:26.150Z,1621353986.150 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.366831 forward, 0.921806 starboard, -0.125333 keelward ] 2021-05-18T16:06:26.150Z,1621353986.150 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:26.172Z,1621353986.172 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998845,-0.047981,-0.002674;0.048032,0.998537,0.024830;0.001478,-0.024930,0.999688 ] 2021-05-18T16:06:26.173Z,1621353986.173 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:26.174Z,1621353986.174 [lab_range_test:A.](INFO): direction in world frame: [ 0.410499 north, 0.905981 east, -0.103386 down ] 2021-05-18T16:06:26.196Z,1621353986.196 [lab_range_test:A.](INFO): relPosInFSK: [ 0.073366 forward, 0.184361 starboard, -0.025067 keelward ] 2021-05-18T16:06:26.197Z,1621353986.197 [lab_range_test:A.](INFO): relPosInNED: [ 0.082100 north, 0.181196 east, -0.020677 down ] 2021-05-18T16:06:26.198Z,1621353986.198 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:26.198Z,1621353986.198 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:26.439Z,1621353986.439 [DAT](INFO): DAT read: Rx Time:16:05:58.4508 2021-05-18T16:06:26.440Z,1621353986.440 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:26.441Z,1621353986.441 [DAT](INFO): DAT read: Bearing 70.5, -1.4 (Local) 2021-05-18T16:06:26.441Z,1621353986.441 [DAT](INFO): Local bearing/azimuth received: Bearing 70.5, -1.4 (Local) 2021-05-18T16:06:26.443Z,1621353986.443 [DAT](INFO): DAT read: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:26.444Z,1621353986.444 [DAT](INFO): unknown deviceResponse_: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:26.448Z,1621353986.448 [DAT](INFO): DAT read: 16:05:58.4508 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.22,-3.126, 2.902, 3.126, 3.084, PHS= 0.070,-0.138, 0.027, RAW= 138.8, 4.4, CAL= 139.5, 1.4, ROT= 70.5, -1.4 2021-05-18T16:06:26.450Z,1621353986.450 [DAT](INFO): got valid direction response: 16:05:58.4508 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.22,-3.126, 2.902, 3.126, 3.084, PHS= 0.070,-0.138, 0.027, RAW= 138.8, 4.4, CAL= 139.5, 1.4, ROT= 70.5, -1.4 2021-05-18T16:06:26.450Z,1621353986.450 [DAT](INFO): #Rx 9: Read direction message, but no range. 2021-05-18T16:06:26.465Z,1621353986.465 [DAT](INFO): direction in vehicle frame: [ 0.333707 forward, 0.942360 starboard, -0.024432 keelward ] 2021-05-18T16:06:26.465Z,1621353986.465 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:26.468Z,1621353986.468 [DAT](INFO): checking for new query: numPingsReceived=9 elapsed TxPingTime=6.484658 2021-05-18T16:06:26.588Z,1621353986.588 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:26.843Z,1621353986.843 [DAT](INFO): DAT read: Rx Time:16:05:58.9509 2021-05-18T16:06:26.844Z,1621353986.844 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:26.845Z,1621353986.845 [DAT](INFO): DAT read: Bearing 66.7, -5.0 (Local) 2021-05-18T16:06:26.845Z,1621353986.845 [DAT](INFO): Local bearing/azimuth received: Bearing 66.7, -5.0 (Local) 2021-05-18T16:06:26.847Z,1621353986.847 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:26.852Z,1621353986.852 [DAT](INFO): DAT read: 16:05:58.9509 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.52, 2.678, 2.371, 2.654, 2.610, PHS= 0.064,-0.195, 0.029, RAW= 142.8, 8.4, CAL= 143.3, 5.0, ROT= 66.7, -5.0 2021-05-18T16:06:26.853Z,1621353986.853 [DAT](INFO): got valid direction response: 16:05:58.9509 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.52, 2.678, 2.371, 2.654, 2.610, PHS= 0.064,-0.195, 0.029, RAW= 142.8, 8.4, CAL= 143.3, 5.0, ROT= 66.7, -5.0 2021-05-18T16:06:26.853Z,1621353986.853 [DAT](INFO): #Rx 10: Read range and direction messages. 2021-05-18T16:06:26.854Z,1621353986.854 [DAT](INFO): direction in vehicle frame: [ 0.394040 forward, 0.914951 starboard, -0.087156 keelward ] 2021-05-18T16:06:26.855Z,1621353986.855 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:26.855Z,1621353986.855 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:26.908Z,1621353986.908 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:26.909Z,1621353986.909 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.394040 forward, 0.914951 starboard, -0.087156 keelward ] 2021-05-18T16:06:26.909Z,1621353986.909 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:26.928Z,1621353986.928 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998966,-0.045372,-0.002759;0.045427,0.998653,0.025061;0.001618,-0.025160,0.999682 ] 2021-05-18T16:06:26.928Z,1621353986.928 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:26.929Z,1621353986.929 [lab_range_test:A.](INFO): direction in world frame: [ 0.435056 north, 0.898033 east, -0.065286 down ] 2021-05-18T16:06:26.930Z,1621353986.930 [lab_range_test:A.](INFO): relPosInFSK: [ 0.078808 forward, 0.182990 starboard, -0.017431 keelward ] 2021-05-18T16:06:26.930Z,1621353986.930 [lab_range_test:A.](INFO): relPosInNED: [ 0.087011 north, 0.179607 east, -0.013057 down ] 2021-05-18T16:06:26.943Z,1621353986.943 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:26.943Z,1621353986.943 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:27.280Z,1621353987.280 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:27.709Z,1621353987.709 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:28.112Z,1621353988.112 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:28.487Z,1621353988.487 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:28.896Z,1621353988.896 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:29.292Z,1621353989.292 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:29.699Z,1621353989.699 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:30.104Z,1621353990.104 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:30.512Z,1621353990.512 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:30.923Z,1621353990.923 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:31.317Z,1621353991.317 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:31.713Z,1621353991.713 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:32.120Z,1621353992.120 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:32.121Z,1621353992.121 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:06:32.121Z,1621353992.121 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:06:32.503Z,1621353992.503 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:06:32.503Z,1621353992.503 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:06:32.504Z,1621353992.504 [DAT](INFO): Querying Benthos address 50 with 10 pings in terminal homing one-way mode. 2021-05-18T16:06:32.506Z,1621353992.506 [DAT](INFO): ****** ping requested ****** 2021-05-18T16:06:32.517Z,1621353992.517 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:32.912Z,1621353992.912 [DAT](INFO): DAT read: user:8> 2021-05-18T16:06:32.913Z,1621353992.913 [DAT](INFO): DAT read: Tx time:16:06:05.2212 2021-05-18T16:06:32.914Z,1621353992.914 [DAT](INFO): Ping request sent. 2021-05-18T16:06:32.914Z,1621353992.914 [DAT](INFO): transmitted an acoustic signal 2021-05-18T16:06:32.914Z,1621353992.914 [DAT](INFO): publishing transmit ping time 2021-05-18T16:06:32.915Z,1621353992.915 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.000939 2021-05-18T16:06:32.921Z,1621353992.921 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:33.325Z,1621353993.325 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.411109 2021-05-18T16:06:33.350Z,1621353993.350 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:33.733Z,1621353993.733 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.819601 2021-05-18T16:06:33.764Z,1621353993.764 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:34.160Z,1621353994.160 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.246502 2021-05-18T16:06:34.167Z,1621353994.167 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:34.559Z,1621353994.559 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.645462 2021-05-18T16:06:34.570Z,1621353994.570 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:34.954Z,1621353994.954 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=2.040482 2021-05-18T16:06:34.961Z,1621353994.961 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:35.365Z,1621353995.365 [DAT](INFO): DAT read: Rx Time:16:06:07.3509 2021-05-18T16:06:35.365Z,1621353995.365 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:35.366Z,1621353995.366 [DAT](INFO): DAT read: Bearing 68.2, -4.5 (Local) 2021-05-18T16:06:35.367Z,1621353995.367 [DAT](INFO): Local bearing/azimuth received: Bearing 68.2, -4.5 (Local) 2021-05-18T16:06:35.369Z,1621353995.369 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:35.373Z,1621353995.373 [DAT](INFO): DAT read: 16:06:07.3509 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 465,-0.34,-1.411,-1.749,-1.447,-1.493, PHS= 0.077,-0.212, 0.030, RAW= 141.3, 7.8, CAL= 141.8, 4.5, ROT= 68.2, -4.5 2021-05-18T16:06:35.374Z,1621353995.374 [DAT](INFO): got valid direction response: 16:06:07.3509 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 465,-0.34,-1.411,-1.749,-1.447,-1.493, PHS= 0.077,-0.212, 0.030, RAW= 141.3, 7.8, CAL= 141.8, 4.5, ROT= 68.2, -4.5 2021-05-18T16:06:35.375Z,1621353995.375 [DAT](INFO): #Rx 1: Read range and direction messages. 2021-05-18T16:06:35.376Z,1621353995.376 [DAT](INFO): direction in vehicle frame: [ 0.370223 forward, 0.925624 starboard, -0.078459 keelward ] 2021-05-18T16:06:35.376Z,1621353995.376 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:35.376Z,1621353995.376 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:35.380Z,1621353995.380 [DAT](INFO): checking for new query: numPingsReceived=1 elapsed TxPingTime=2.466006 2021-05-18T16:06:35.386Z,1621353995.386 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:35.388Z,1621353995.388 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.370223 forward, 0.925624 starboard, -0.078459 keelward ] 2021-05-18T16:06:35.388Z,1621353995.388 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:35.390Z,1621353995.390 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998884,-0.047151,-0.002715;0.047204,0.998575,0.024891;0.001538,-0.024991,0.999686 ] 2021-05-18T16:06:35.390Z,1621353995.390 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:35.393Z,1621353995.393 [lab_range_test:A.](INFO): direction in world frame: [ 0.413382 north, 0.908809 east, -0.056400 down ] 2021-05-18T16:06:35.401Z,1621353995.401 [lab_range_test:A.](INFO): relPosInFSK: [ 0.111067 forward, 0.277687 starboard, -0.023538 keelward ] 2021-05-18T16:06:35.475Z,1621353995.475 [lab_range_test:A.](INFO): relPosInNED: [ 0.124015 north, 0.272643 east, -0.016920 down ] 2021-05-18T16:06:35.476Z,1621353995.476 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:35.476Z,1621353995.476 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:35.740Z,1621353995.740 [DAT](INFO): DAT read: Rx Time:16:06:07.8509 2021-05-18T16:06:35.740Z,1621353995.740 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:35.742Z,1621353995.742 [DAT](INFO): DAT read: Bearing 67.8, -5.0 (Local) 2021-05-18T16:06:35.742Z,1621353995.742 [DAT](INFO): Local bearing/azimuth received: Bearing 67.8, -5.0 (Local) 2021-05-18T16:06:35.744Z,1621353995.744 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:35.777Z,1621353995.777 [DAT](INFO): DAT read: 16:06:07.8509 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 497,-0.19,-1.120,-1.448,-1.153,-1.196, PHS= 0.072,-0.207, 0.029, RAW= 141.7, 8.3, CAL= 142.2, 5.0, ROT= 67.8, -5.0 2021-05-18T16:06:35.778Z,1621353995.778 [DAT](INFO): got valid direction response: 16:06:07.8509 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 497,-0.19,-1.120,-1.448,-1.153,-1.196, PHS= 0.072,-0.207, 0.029, RAW= 141.7, 8.3, CAL= 142.2, 5.0, ROT= 67.8, -5.0 2021-05-18T16:06:35.778Z,1621353995.778 [DAT](INFO): #Rx 2: Read range and direction messages. 2021-05-18T16:06:35.799Z,1621353995.799 [DAT](INFO): direction in vehicle frame: [ 0.376403 forward, 0.922347 starboard, -0.087156 keelward ] 2021-05-18T16:06:35.800Z,1621353995.800 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:35.800Z,1621353995.800 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:35.811Z,1621353995.811 [DAT](INFO): checking for new query: numPingsReceived=2 elapsed TxPingTime=2.889102 2021-05-18T16:06:35.826Z,1621353995.826 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:35.839Z,1621353995.839 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.376403 forward, 0.922347 starboard, -0.087156 keelward ] 2021-05-18T16:06:35.840Z,1621353995.840 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:35.842Z,1621353995.842 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998888,-0.047074,-0.002573;0.047123,0.998577,0.024975;0.001394,-0.025069,0.999685 ] 2021-05-18T16:06:35.842Z,1621353995.842 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:35.849Z,1621353995.849 [lab_range_test:A.](INFO): direction in world frame: [ 0.419327 north, 0.905501 east, -0.065061 down ] 2021-05-18T16:06:35.850Z,1621353995.850 [lab_range_test:A.](INFO): relPosInFSK: [ 0.112921 forward, 0.276704 starboard, -0.026147 keelward ] 2021-05-18T16:06:35.850Z,1621353995.850 [lab_range_test:A.](INFO): relPosInNED: [ 0.125798 north, 0.271650 east, -0.019518 down ] 2021-05-18T16:06:35.863Z,1621353995.863 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:35.863Z,1621353995.863 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:36.143Z,1621353996.143 [DAT](INFO): DAT read: Rx Time:16:06:08.3508 2021-05-18T16:06:36.143Z,1621353996.143 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:36.144Z,1621353996.144 [DAT](INFO): DAT read: Bearing 67.2, -5.4 (Local) 2021-05-18T16:06:36.145Z,1621353996.145 [DAT](INFO): Local bearing/azimuth received: Bearing 67.2, -5.4 (Local) 2021-05-18T16:06:36.147Z,1621353996.147 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:36.151Z,1621353996.151 [DAT](INFO): DAT read: 16:06:08.3508 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 496,-0.07,-2.058,-2.365,-2.084,-2.126, PHS= 0.063,-0.195, 0.026, RAW= 142.4, 8.7, CAL= 142.8, 5.4, ROT= 67.2, -5.4 2021-05-18T16:06:36.153Z,1621353996.153 [DAT](INFO): got valid direction response: 16:06:08.3508 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 496,-0.07,-2.058,-2.365,-2.084,-2.126, PHS= 0.063,-0.195, 0.026, RAW= 142.4, 8.7, CAL= 142.8, 5.4, ROT= 67.2, -5.4 2021-05-18T16:06:36.153Z,1621353996.153 [DAT](INFO): #Rx 3: Read range and direction messages. 2021-05-18T16:06:36.154Z,1621353996.154 [DAT](INFO): direction in vehicle frame: [ 0.385796 forward, 0.917772 starboard, -0.094108 keelward ] 2021-05-18T16:06:36.155Z,1621353996.155 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:36.155Z,1621353996.155 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:36.158Z,1621353996.158 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.244065 2021-05-18T16:06:36.164Z,1621353996.164 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:36.165Z,1621353996.165 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.385796 forward, 0.917772 starboard, -0.094108 keelward ] 2021-05-18T16:06:36.166Z,1621353996.166 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:36.168Z,1621353996.168 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998858,-0.047716,-0.002577;0.047765,0.998549,0.024875;0.001386,-0.024969,0.999687 ] 2021-05-18T16:06:36.168Z,1621353996.168 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:36.169Z,1621353996.169 [lab_range_test:A.](INFO): direction in world frame: [ 0.429062 north, 0.900381 east, -0.072244 down ] 2021-05-18T16:06:36.170Z,1621353996.170 [lab_range_test:A.](INFO): relPosInFSK: [ 0.077159 forward, 0.183554 starboard, -0.018822 keelward ] 2021-05-18T16:06:36.170Z,1621353996.170 [lab_range_test:A.](INFO): relPosInNED: [ 0.085812 north, 0.180076 east, -0.014449 down ] 2021-05-18T16:06:36.171Z,1621353996.171 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:36.171Z,1621353996.171 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:36.557Z,1621353996.557 [DAT](INFO): DAT read: Rx Time:16:06:08.8509 2021-05-18T16:06:36.557Z,1621353996.557 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:36.559Z,1621353996.559 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.645040 2021-05-18T16:06:36.598Z,1621353996.598 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:36.965Z,1621353996.965 [DAT](INFO): DAT read: Bearing 67.3, -4.5 (Local) 2021-05-18T16:06:36.966Z,1621353996.966 [DAT](INFO): Local bearing/azimuth received: Bearing 67.3, -4.5 (Local) 2021-05-18T16:06:36.968Z,1621353996.968 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:36.972Z,1621353996.972 [DAT](INFO): DAT read: 16:06:08.8509 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 497, 0.03, 0.122,-0.150, 0.101, 0.060, PHS= 0.058,-0.166, 0.026, RAW= 142.3, 7.9, CAL= 142.7, 4.5, ROT= 67.3, -4.5 2021-05-18T16:06:36.974Z,1621353996.974 [DAT](INFO): got valid direction response: 16:06:08.8509 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 497, 0.03, 0.122,-0.150, 0.101, 0.060, PHS= 0.058,-0.166, 0.026, RAW= 142.3, 7.9, CAL= 142.7, 4.5, ROT= 67.3, -4.5 2021-05-18T16:06:36.974Z,1621353996.974 [DAT](INFO): #Rx 4: Read range and direction messages. 2021-05-18T16:06:36.975Z,1621353996.975 [DAT](INFO): direction in vehicle frame: [ 0.384716 forward, 0.919694 starboard, -0.078459 keelward ] 2021-05-18T16:06:36.975Z,1621353996.975 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:36.978Z,1621353996.978 [DAT](INFO): checking for new query: numPingsReceived=4 elapsed TxPingTime=4.064659 2021-05-18T16:06:36.985Z,1621353996.985 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:36.986Z,1621353996.986 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.384716 forward, 0.919694 starboard, -0.078459 keelward ] 2021-05-18T16:06:36.986Z,1621353996.986 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:36.989Z,1621353996.989 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998917,-0.046449,-0.002726;0.046502,0.998608,0.024912;0.001565,-0.025012,0.999686 ] 2021-05-18T16:06:36.989Z,1621353996.989 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:36.990Z,1621353996.990 [lab_range_test:A.](INFO): direction in world frame: [ 0.426945 north, 0.902506 east, -0.056572 down ] 2021-05-18T16:06:36.990Z,1621353996.990 [lab_range_test:A.](INFO): relPosInFSK: [ 0.115415 forward, 0.275908 starboard, -0.023538 keelward ] 2021-05-18T16:06:37.024Z,1621353997.024 [lab_range_test:A.](INFO): relPosInNED: [ 0.128083 north, 0.270752 east, -0.016971 down ] 2021-05-18T16:06:37.024Z,1621353997.024 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:37.024Z,1621353997.024 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:37.357Z,1621353997.357 [DAT](INFO): DAT read: Rx Time:16:06:09.3508 2021-05-18T16:06:37.357Z,1621353997.357 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:37.359Z,1621353997.359 [DAT](INFO): DAT read: Bearing 69.8, -3.4 (Local) 2021-05-18T16:06:37.359Z,1621353997.359 [DAT](INFO): Local bearing/azimuth received: Bearing 69.8, -3.4 (Local) 2021-05-18T16:06:37.361Z,1621353997.361 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:37.366Z,1621353997.366 [DAT](INFO): DAT read: 16:06:09.3508 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496, 0.14,-0.823,-1.105,-0.857,-0.897, PHS= 0.069,-0.164, 0.025, RAW= 139.7, 6.5, CAL= 140.2, 3.4, ROT= 69.8, -3.4 2021-05-18T16:06:37.367Z,1621353997.367 [DAT](INFO): got valid direction response: 16:06:09.3508 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496, 0.14,-0.823,-1.105,-0.857,-0.897, PHS= 0.069,-0.164, 0.025, RAW= 139.7, 6.5, CAL= 140.2, 3.4, ROT= 69.8, -3.4 2021-05-18T16:06:37.368Z,1621353997.368 [DAT](INFO): #Rx 5: Read range and direction messages. 2021-05-18T16:06:37.369Z,1621353997.369 [DAT](INFO): direction in vehicle frame: [ 0.344690 forward, 0.936841 starboard, -0.059306 keelward ] 2021-05-18T16:06:37.369Z,1621353997.369 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:37.369Z,1621353997.369 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:37.372Z,1621353997.372 [DAT](INFO): checking for new query: numPingsReceived=5 elapsed TxPingTime=4.458795 2021-05-18T16:06:37.411Z,1621353997.411 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:37.412Z,1621353997.412 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.344690 forward, 0.936841 starboard, -0.059306 keelward ] 2021-05-18T16:06:37.412Z,1621353997.412 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:37.414Z,1621353997.414 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998900,-0.046815,-0.002776;0.046870,0.998591,0.024867;0.001608,-0.024970,0.999687 ] 2021-05-18T16:06:37.431Z,1621353997.431 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:37.432Z,1621353997.432 [lab_range_test:A.](INFO): direction in world frame: [ 0.388125 north, 0.920866 east, -0.036948 down ] 2021-05-18T16:06:37.433Z,1621353997.433 [lab_range_test:A.](INFO): relPosInFSK: [ 0.068938 forward, 0.187368 starboard, -0.011861 keelward ] 2021-05-18T16:06:37.433Z,1621353997.433 [lab_range_test:A.](INFO): relPosInNED: [ 0.077625 north, 0.184173 east, -0.007390 down ] 2021-05-18T16:06:37.434Z,1621353997.434 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:37.434Z,1621353997.434 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:37.755Z,1621353997.755 [DAT](INFO): DAT read: Rx Time:16:06:09.8509 2021-05-18T16:06:37.755Z,1621353997.755 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:37.757Z,1621353997.757 [DAT](INFO): DAT read: Bearing 70.3, -2.4 (Local) 2021-05-18T16:06:37.757Z,1621353997.757 [DAT](INFO): Local bearing/azimuth received: Bearing 70.3, -2.4 (Local) 2021-05-18T16:06:37.759Z,1621353997.759 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:37.764Z,1621353997.764 [DAT](INFO): DAT read: 16:06:09.8509 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 497, 0.29, 0.681, 0.408, 0.647, 0.606, PHS= 0.071,-0.154, 0.026, RAW= 139.0, 5.5, CAL= 139.7, 2.4, ROT= 70.3, -2.4 2021-05-18T16:06:37.765Z,1621353997.765 [DAT](INFO): got valid direction response: 16:06:09.8509 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 497, 0.29, 0.681, 0.408, 0.647, 0.606, PHS= 0.071,-0.154, 0.026, RAW= 139.0, 5.5, CAL= 139.7, 2.4, ROT= 70.3, -2.4 2021-05-18T16:06:37.765Z,1621353997.765 [DAT](INFO): #Rx 6: Read range and direction messages. 2021-05-18T16:06:37.766Z,1621353997.766 [DAT](INFO): direction in vehicle frame: [ 0.336800 forward, 0.940645 starboard, -0.041876 keelward ] 2021-05-18T16:06:37.767Z,1621353997.767 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:37.767Z,1621353997.767 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:37.770Z,1621353997.770 [DAT](INFO): checking for new query: numPingsReceived=6 elapsed TxPingTime=4.856300 2021-05-18T16:06:37.777Z,1621353997.777 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:37.778Z,1621353997.778 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.336800 forward, 0.940645 starboard, -0.041876 keelward ] 2021-05-18T16:06:37.778Z,1621353997.778 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:37.812Z,1621353997.812 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998881,-0.047219,-0.002830;0.047275,0.998574,0.024805;0.001655,-0.024911,0.999688 ] 2021-05-18T16:06:37.813Z,1621353997.813 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:37.814Z,1621353997.814 [lab_range_test:A.](INFO): direction in world frame: [ 0.380822 north, 0.924443 east, -0.019483 down ] 2021-05-18T16:06:37.814Z,1621353997.814 [lab_range_test:A.](INFO): relPosInFSK: [ 0.101040 forward, 0.282193 starboard, -0.012563 keelward ] 2021-05-18T16:06:37.816Z,1621353997.816 [lab_range_test:A.](INFO): relPosInNED: [ 0.114247 north, 0.277333 east, -0.005845 down ] 2021-05-18T16:06:37.816Z,1621353997.816 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:37.816Z,1621353997.816 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:38.159Z,1621353998.159 [DAT](INFO): DAT read: Rx Time:16:06:10.3508 2021-05-18T16:06:38.159Z,1621353998.159 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:38.160Z,1621353998.160 [DAT](INFO): DAT read: Bearing 68.0, -5.4 (Local) 2021-05-18T16:06:38.161Z,1621353998.161 [DAT](INFO): Local bearing/azimuth received: Bearing 68.0, -5.4 (Local) 2021-05-18T16:06:38.163Z,1621353998.163 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:38.176Z,1621353998.176 [DAT](INFO): DAT read: 16:06:10.3508 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 497,-0.50,-2.217,-2.549,-2.251,-2.292, PHS= 0.071,-0.212, 0.026, RAW= 141.5, 8.7, CAL= 142.0, 5.4, ROT= 68.0, -5.4 2021-05-18T16:06:38.177Z,1621353998.177 [DAT](INFO): got valid direction response: 16:06:10.3508 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 497,-0.50,-2.217,-2.549,-2.251,-2.292, PHS= 0.071,-0.212, 0.026, RAW= 141.5, 8.7, CAL= 142.0, 5.4, ROT= 68.0, -5.4 2021-05-18T16:06:38.177Z,1621353998.177 [DAT](INFO): #Rx 7: Read range and direction messages. 2021-05-18T16:06:38.178Z,1621353998.178 [DAT](INFO): direction in vehicle frame: [ 0.372944 forward, 0.923069 starboard, -0.094108 keelward ] 2021-05-18T16:06:38.179Z,1621353998.179 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:38.204Z,1621353998.204 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:38.207Z,1621353998.207 [DAT](INFO): checking for new query: numPingsReceived=7 elapsed TxPingTime=5.292852 2021-05-18T16:06:38.295Z,1621353998.295 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:38.297Z,1621353998.297 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.372944 forward, 0.923069 starboard, -0.094108 keelward ] 2021-05-18T16:06:38.297Z,1621353998.297 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:38.315Z,1621353998.315 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998890,-0.047030,-0.002682;0.047082,0.998581,0.024893;0.001508,-0.024992,0.999687 ] 2021-05-18T16:06:38.315Z,1621353998.315 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:38.316Z,1621353998.316 [lab_range_test:A.](INFO): direction in world frame: [ 0.415848 north, 0.906571 east, -0.072101 down ] 2021-05-18T16:06:38.317Z,1621353998.317 [lab_range_test:A.](INFO): relPosInFSK: [ 0.074589 forward, 0.184614 starboard, -0.018822 keelward ] 2021-05-18T16:06:38.318Z,1621353998.318 [lab_range_test:A.](INFO): relPosInNED: [ 0.083170 north, 0.181314 east, -0.014420 down ] 2021-05-18T16:06:38.318Z,1621353998.318 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:38.318Z,1621353998.318 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:38.573Z,1621353998.573 [DAT](INFO): DAT read: Rx Time:16:06:10.8509 2021-05-18T16:06:38.573Z,1621353998.573 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:38.575Z,1621353998.575 [DAT](INFO): DAT read: Bearing 66.2, -6.6 (Local) 2021-05-18T16:06:38.576Z,1621353998.576 [DAT](INFO): Local bearing/azimuth received: Bearing 66.2, -6.6 (Local) 2021-05-18T16:06:38.579Z,1621353998.579 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:38.581Z,1621353998.581 [DAT](ERROR): #Rx 8: Read range message, but no direction. 2021-05-18T16:06:38.581Z,1621353998.581 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:38.584Z,1621353998.584 [DAT](INFO): checking for new query: numPingsReceived=8 elapsed TxPingTime=5.669042 2021-05-18T16:06:38.636Z,1621353998.636 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:38.637Z,1621353998.637 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.372944 forward, 0.923069 starboard, -0.094108 keelward ] 2021-05-18T16:06:38.637Z,1621353998.637 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:38.651Z,1621353998.651 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998864,-0.047576,-0.002675;0.047628,0.998557,0.024813;0.001491,-0.024913,0.999689 ] 2021-05-18T16:06:38.652Z,1621353998.652 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:38.652Z,1621353998.652 [lab_range_test:A.](INFO): direction in world frame: [ 0.416344 north, 0.906338 east, -0.072172 down ] 2021-05-18T16:06:38.653Z,1621353998.653 [lab_range_test:A.](INFO): relPosInFSK: [ 0.111883 forward, 0.276921 starboard, -0.028232 keelward ] 2021-05-18T16:06:38.654Z,1621353998.654 [lab_range_test:A.](INFO): relPosInNED: [ 0.124903 north, 0.271901 east, -0.021652 down ] 2021-05-18T16:06:38.654Z,1621353998.654 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:38.654Z,1621353998.654 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:38.970Z,1621353998.970 [DAT](INFO): DAT read: 16:06:10.8509 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 497,-0.28,-2.593,-2.925,-2.618,-2.659, PHS= 0.062,-0.222, 0.026, RAW= 143.3, 10.0, CAL= 143.8, 6.6, ROT= 66.2, -6.6 2021-05-18T16:06:38.987Z,1621353998.987 [DAT](INFO): got valid direction response: 16:06:10.8509 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 497,-0.28,-2.593,-2.925,-2.618,-2.659, PHS= 0.062,-0.222, 0.026, RAW= 143.3, 10.0, CAL= 143.8, 6.6, ROT= 66.2, -6.6 2021-05-18T16:06:38.988Z,1621353998.988 [DAT](INFO): #Rx 9: Read direction message, but no range. 2021-05-18T16:06:38.989Z,1621353998.989 [DAT](INFO): direction in vehicle frame: [ 0.400871 forward, 0.908896 starboard, -0.114937 keelward ] 2021-05-18T16:06:39.010Z,1621353999.010 [DAT](INFO): checking for new query: numPingsReceived=9 elapsed TxPingTime=6.096294 2021-05-18T16:06:39.038Z,1621353999.038 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:39.385Z,1621353999.385 [DAT](INFO): DAT read: Rx Time:16:06:11.3508 2021-05-18T16:06:39.386Z,1621353999.386 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:39.387Z,1621353999.387 [DAT](INFO): DAT read: Bearing 66.5, -6.4 (Local) 2021-05-18T16:06:39.387Z,1621353999.387 [DAT](INFO): Local bearing/azimuth received: Bearing 66.5, -6.4 (Local) 2021-05-18T16:06:39.389Z,1621353999.389 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:39.394Z,1621353999.394 [DAT](INFO): DAT read: 16:06:11.3508 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 496,-0.15, 2.817, 2.502, 2.793, 2.753, PHS= 0.060,-0.207, 0.025, RAW= 143.0, 9.8, CAL= 143.5, 6.4, ROT= 66.5, -6.4 2021-05-18T16:06:39.395Z,1621353999.395 [DAT](INFO): got valid direction response: 16:06:11.3508 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 496,-0.15, 2.817, 2.502, 2.793, 2.753, PHS= 0.060,-0.207, 0.025, RAW= 143.0, 9.8, CAL= 143.5, 6.4, ROT= 66.5, -6.4 2021-05-18T16:06:39.396Z,1621353999.396 [DAT](INFO): #Rx 10: Read range and direction messages. 2021-05-18T16:06:39.397Z,1621353999.397 [DAT](INFO): direction in vehicle frame: [ 0.396264 forward, 0.911345 starboard, -0.111469 keelward ] 2021-05-18T16:06:39.397Z,1621353999.397 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:39.397Z,1621353999.397 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:39.406Z,1621353999.406 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:39.408Z,1621353999.408 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.396264 forward, 0.911345 starboard, -0.111469 keelward ] 2021-05-18T16:06:39.408Z,1621353999.408 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:39.410Z,1621353999.410 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998861,-0.047640,-0.002805;0.047695,0.998554,0.024786;0.001620,-0.024891,0.999689 ] 2021-05-18T16:06:39.410Z,1621353999.410 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:39.411Z,1621353999.411 [lab_range_test:A.](INFO): direction in world frame: [ 0.439099 north, 0.893924 east, -0.089957 down ] 2021-05-18T16:06:39.412Z,1621353999.412 [lab_range_test:A.](INFO): relPosInFSK: [ 0.079253 forward, 0.182269 starboard, -0.022294 keelward ] 2021-05-18T16:06:39.413Z,1621353999.413 [lab_range_test:A.](INFO): relPosInNED: [ 0.087820 north, 0.178785 east, -0.017991 down ] 2021-05-18T16:06:39.413Z,1621353999.413 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:39.413Z,1621353999.413 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:39.786Z,1621353999.786 [DAT](INFO): DAT read: Rx Time:16:06:11.8509 2021-05-18T16:06:39.786Z,1621353999.786 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:39.787Z,1621353999.787 [DAT](INFO): DAT read: Bearing 66.2, -6.4 (Local) 2021-05-18T16:06:39.788Z,1621353999.788 [DAT](INFO): Local bearing/azimuth received: Bearing 66.2, -6.4 (Local) 2021-05-18T16:06:39.789Z,1621353999.789 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:39.794Z,1621353999.794 [DAT](INFO): DAT read: 16:06:11.8509 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 497,-0.02,-1.928,-2.233,-1.950,-1.989, PHS= 0.057,-0.199, 0.025, RAW= 143.4, 9.8, CAL= 143.8, 6.4, ROT= 66.2, -6.4 2021-05-18T16:06:39.795Z,1621353999.795 [DAT](INFO): got valid direction response: 16:06:11.8509 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 497,-0.02,-1.928,-2.233,-1.950,-1.989, PHS= 0.057,-0.199, 0.025, RAW= 143.4, 9.8, CAL= 143.8, 6.4, ROT= 66.2, -6.4 2021-05-18T16:06:39.796Z,1621353999.796 [DAT](INFO): #Rx 11: Read range and direction messages. 2021-05-18T16:06:39.797Z,1621353999.797 [DAT](INFO): direction in vehicle frame: [ 0.401030 forward, 0.909258 starboard, -0.111469 keelward ] 2021-05-18T16:06:39.797Z,1621353999.797 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:39.797Z,1621353999.797 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:39.868Z,1621353999.868 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:39.869Z,1621353999.869 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.401030 forward, 0.909258 starboard, -0.111469 keelward ] 2021-05-18T16:06:39.869Z,1621353999.869 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:39.880Z,1621353999.880 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998924,-0.046295,-0.002693;0.046348,0.998614,0.024948;0.001534,-0.025046,0.999685 ] 2021-05-18T16:06:39.880Z,1621353999.880 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:39.881Z,1621353999.881 [lab_range_test:A.](INFO): direction in world frame: [ 0.442570 north, 0.892223 east, -0.089830 down ] 2021-05-18T16:06:39.882Z,1621353999.882 [lab_range_test:A.](INFO): relPosInFSK: [ 0.120309 forward, 0.272777 starboard, -0.033441 keelward ] 2021-05-18T16:06:39.883Z,1621353999.883 [lab_range_test:A.](INFO): relPosInNED: [ 0.132771 north, 0.267667 east, -0.026949 down ] 2021-05-18T16:06:39.891Z,1621353999.891 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:39.891Z,1621353999.891 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:40.199Z,1621354000.199 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:40.589Z,1621354000.589 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:40.997Z,1621354000.997 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:41.404Z,1621354001.404 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:41.805Z,1621354001.805 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:42.204Z,1621354002.204 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:42.628Z,1621354002.628 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:43.033Z,1621354003.033 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:43.440Z,1621354003.440 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:43.825Z,1621354003.825 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:44.230Z,1621354004.230 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:44.641Z,1621354004.641 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:45.036Z,1621354005.036 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:45.037Z,1621354005.037 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:06:45.037Z,1621354005.037 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:06:45.448Z,1621354005.448 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:06:45.449Z,1621354005.449 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:06:45.449Z,1621354005.449 [DAT](INFO): Querying Benthos address 50 with 10 pings in terminal homing one-way mode. 2021-05-18T16:06:45.450Z,1621354005.450 [DAT](INFO): ****** ping requested ****** 2021-05-18T16:06:45.494Z,1621354005.494 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:45.853Z,1621354005.853 [DAT](INFO): DAT read: user:9> 2021-05-18T16:06:45.854Z,1621354005.854 [DAT](INFO): DAT read: Tx time:16:06:18.1711 2021-05-18T16:06:45.854Z,1621354005.854 [DAT](INFO): Ping request sent. 2021-05-18T16:06:45.854Z,1621354005.854 [DAT](INFO): transmitted an acoustic signal 2021-05-18T16:06:45.854Z,1621354005.854 [DAT](INFO): publishing transmit ping time 2021-05-18T16:06:45.855Z,1621354005.855 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.001129 2021-05-18T16:06:45.869Z,1621354005.869 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:46.253Z,1621354006.253 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.398932 2021-05-18T16:06:46.285Z,1621354006.285 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:46.646Z,1621354006.646 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.792437 2021-05-18T16:06:46.653Z,1621354006.653 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:47.052Z,1621354007.052 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.197898 2021-05-18T16:06:47.064Z,1621354007.064 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:47.516Z,1621354007.516 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.662337 2021-05-18T16:06:47.523Z,1621354007.523 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:47.922Z,1621354007.922 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=2.067540 2021-05-18T16:06:47.944Z,1621354007.944 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:48.309Z,1621354008.309 [DAT](INFO): DAT read: Rx Time:16:06:20.3007 2021-05-18T16:06:48.309Z,1621354008.309 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:48.311Z,1621354008.311 [DAT](INFO): DAT read: Bearing 70.6, -2.5 (Local) 2021-05-18T16:06:48.311Z,1621354008.311 [DAT](INFO): Local bearing/azimuth received: Bearing 70.6, -2.5 (Local) 2021-05-18T16:06:48.313Z,1621354008.313 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:48.322Z,1621354008.322 [DAT](INFO): DAT read: 16:06:20.3007 LVL= 32752, 32753, 32754, 32755, AGC= 68, IDX= 208, 0.05, 0.755, 0.470, 0.717, 0.675, PHS= 0.075,-0.162, 0.026, RAW= 138.7, 5.6, CAL= 139.4, 2.5, ROT= 70.6, -2.5 2021-05-18T16:06:48.327Z,1621354008.327 [DAT](INFO): got valid direction response: 16:06:20.3007 LVL= 32752, 32753, 32754, 32755, AGC= 68, IDX= 208, 0.05, 0.755, 0.470, 0.717, 0.675, PHS= 0.075,-0.162, 0.026, RAW= 138.7, 5.6, CAL= 139.4, 2.5, ROT= 70.6, -2.5 2021-05-18T16:06:48.328Z,1621354008.328 [DAT](INFO): #Rx 1: Read range and direction messages. 2021-05-18T16:06:48.329Z,1621354008.329 [DAT](INFO): direction in vehicle frame: [ 0.331845 forward, 0.942325 starboard, -0.043619 keelward ] 2021-05-18T16:06:48.329Z,1621354008.329 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:48.329Z,1621354008.329 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:48.357Z,1621354008.357 [DAT](INFO): checking for new query: numPingsReceived=1 elapsed TxPingTime=2.502650 2021-05-18T16:06:48.392Z,1621354008.392 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:48.393Z,1621354008.393 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.331845 forward, 0.942325 starboard, -0.043619 keelward ] 2021-05-18T16:06:48.393Z,1621354008.393 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:48.403Z,1621354008.403 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998899,-0.046819,-0.002833;0.046876,0.998590,0.024910;0.001662,-0.025015,0.999686 ] 2021-05-18T16:06:48.404Z,1621354008.404 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:48.404Z,1621354008.404 [lab_range_test:A.](INFO): direction in world frame: [ 0.375579 north, 0.926551 east, -0.021073 down ] 2021-05-18T16:06:48.405Z,1621354008.405 [lab_range_test:A.](INFO): relPosInFSK: [ 0.099554 forward, 0.282697 starboard, -0.013086 keelward ] 2021-05-18T16:06:48.406Z,1621354008.406 [lab_range_test:A.](INFO): relPosInNED: [ 0.112674 north, 0.277965 east, -0.006322 down ] 2021-05-18T16:06:48.406Z,1621354008.406 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:48.406Z,1621354008.406 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:48.705Z,1621354008.705 [DAT](INFO): DAT read: Rx Time:16:06:20.8006 2021-05-18T16:06:48.705Z,1621354008.705 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:48.707Z,1621354008.707 [DAT](INFO): DAT read: Bearing 70.4, -2.9 (Local) 2021-05-18T16:06:48.707Z,1621354008.707 [DAT](INFO): Local bearing/azimuth received: Bearing 70.4, -2.9 (Local) 2021-05-18T16:06:48.709Z,1621354008.709 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:48.713Z,1621354008.713 [DAT](INFO): DAT read: 16:06:20.8006 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 495, 0.16,-0.119,-0.394,-0.154,-0.194, PHS= 0.070,-0.157, 0.024, RAW= 139.0, 6.0, CAL= 139.6, 2.9, ROT= 70.4, -2.9 2021-05-18T16:06:48.715Z,1621354008.715 [DAT](INFO): got valid direction response: 16:06:20.8006 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 495, 0.16,-0.119,-0.394,-0.154,-0.194, PHS= 0.070,-0.157, 0.024, RAW= 139.0, 6.0, CAL= 139.6, 2.9, ROT= 70.4, -2.9 2021-05-18T16:06:48.715Z,1621354008.715 [DAT](INFO): #Rx 2: Read range and direction messages. 2021-05-18T16:06:48.716Z,1621354008.716 [DAT](INFO): direction in vehicle frame: [ 0.335022 forward, 0.940851 starboard, -0.050593 keelward ] 2021-05-18T16:06:48.716Z,1621354008.716 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:48.716Z,1621354008.716 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:48.720Z,1621354008.720 [DAT](INFO): checking for new query: numPingsReceived=2 elapsed TxPingTime=2.865671 2021-05-18T16:06:48.726Z,1621354008.726 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:48.727Z,1621354008.727 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.335022 forward, 0.940851 starboard, -0.050593 keelward ] 2021-05-18T16:06:48.727Z,1621354008.727 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:48.730Z,1621354008.730 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998937,-0.046001,-0.002803;0.046057,0.998627,0.024975;0.001650,-0.025077,0.999684 ] 2021-05-18T16:06:48.730Z,1621354008.730 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:48.731Z,1621354008.731 [lab_range_test:A.](INFO): direction in world frame: [ 0.377915 north, 0.925416 east, -0.028018 down ] 2021-05-18T16:06:48.732Z,1621354008.732 [lab_range_test:A.](INFO): relPosInFSK: [ 0.067004 forward, 0.188170 starboard, -0.010119 keelward ] 2021-05-18T16:06:48.732Z,1621354008.732 [lab_range_test:A.](INFO): relPosInNED: [ 0.075583 north, 0.185083 east, -0.005604 down ] 2021-05-18T16:06:48.733Z,1621354008.733 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:48.733Z,1621354008.733 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:49.093Z,1621354009.093 [DAT](INFO): DAT read: Rx Time:16:06:21.3005 2021-05-18T16:06:49.094Z,1621354009.094 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:49.095Z,1621354009.095 [DAT](INFO): DAT read: Bearing 70.7, -2.2 (Local) 2021-05-18T16:06:49.095Z,1621354009.095 [DAT](INFO): Local bearing/azimuth received: Bearing 70.7, -2.2 (Local) 2021-05-18T16:06:49.097Z,1621354009.097 [DAT](INFO): DAT read: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:49.098Z,1621354009.098 [DAT](INFO): unknown deviceResponse_: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:06:49.102Z,1621354009.102 [DAT](INFO): DAT read: 16:06:21.3005 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 510, 0.31,-1.009,-1.273,-1.043,-1.083, PHS= 0.070,-0.146, 0.025, RAW= 138.6, 5.2, CAL= 139.3, 2.2, ROT= 70.7, -2.2 2021-05-18T16:06:49.103Z,1621354009.103 [DAT](INFO): got valid direction response: 16:06:21.3005 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 510, 0.31,-1.009,-1.273,-1.043,-1.083, PHS= 0.070,-0.146, 0.025, RAW= 138.6, 5.2, CAL= 139.3, 2.2, ROT= 70.7, -2.2 2021-05-18T16:06:49.104Z,1621354009.104 [DAT](INFO): #Rx 3: Read direction message, but no range. 2021-05-18T16:06:49.105Z,1621354009.105 [DAT](INFO): direction in vehicle frame: [ 0.330271 forward, 0.943105 starboard, -0.038388 keelward ] 2021-05-18T16:06:49.105Z,1621354009.105 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:49.108Z,1621354009.108 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.254255 2021-05-18T16:06:49.115Z,1621354009.115 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:49.474Z,1621354009.474 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.620519 2021-05-18T16:06:49.519Z,1621354009.519 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:49.875Z,1621354009.875 [DAT](INFO): DAT read: Rx Time:16:06:21.8006 2021-05-18T16:06:49.876Z,1621354009.876 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:49.877Z,1621354009.877 [DAT](INFO): DAT read: Bearing 121.5, 7.1 (Local) 2021-05-18T16:06:49.877Z,1621354009.877 [DAT](INFO): Local bearing/azimuth received: Bearing 121.5, 7.1 (Local) 2021-05-18T16:06:49.879Z,1621354009.879 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:49.884Z,1621354009.884 [DAT](INFO): DAT read: 16:06:21.8006 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 512,-0.45,-1.612, 2.859, 2.848,-2.887, PHS= 1.271,-0.493,-0.563, RAW= 88.1, -2.4, CAL= 88.5, -7.1, ROT= 121.5, 7.1 2021-05-18T16:06:49.885Z,1621354009.885 [DAT](INFO): got valid direction response: 16:06:21.8006 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 512,-0.45,-1.612, 2.859, 2.848,-2.887, PHS= 1.271,-0.493,-0.563, RAW= 88.1, -2.4, CAL= 88.5, -7.1, ROT= 121.5, 7.1 2021-05-18T16:06:49.885Z,1621354009.885 [DAT](INFO): #Rx 4: Read range and direction messages. 2021-05-18T16:06:49.886Z,1621354009.886 [DAT](INFO): direction in vehicle frame: [ -0.518492 forward, 0.846102 starboard, 0.123601 keelward ] 2021-05-18T16:06:49.887Z,1621354009.887 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:49.887Z,1621354009.887 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:49.890Z,1621354009.890 [DAT](INFO): checking for new query: numPingsReceived=4 elapsed TxPingTime=4.035968 2021-05-18T16:06:49.935Z,1621354009.935 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:49.944Z,1621354009.944 [lab_range_test:A.](INFO): direction in vehicle frame: [ -0.518492 forward, 0.846102 starboard, 0.123601 keelward ] 2021-05-18T16:06:49.944Z,1621354009.944 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:49.946Z,1621354009.946 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998916,-0.046468,-0.002775;0.046523,0.998607,0.024894;0.001614,-0.024996,0.999686 ] 2021-05-18T16:06:49.947Z,1621354009.947 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:49.956Z,1621354009.956 [lab_range_test:A.](INFO): direction in world frame: [ -0.478367 north, 0.865927 east, 0.146064 down ] 2021-05-18T16:06:49.956Z,1621354009.956 [lab_range_test:A.](INFO): relPosInFSK: [ -0.103698 forward, 0.169220 starboard, 0.024720 keelward ] 2021-05-18T16:06:49.957Z,1621354009.957 [lab_range_test:A.](INFO): relPosInNED: [ -0.095673 north, 0.173185 east, 0.029213 down ] 2021-05-18T16:06:49.957Z,1621354009.957 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:49.958Z,1621354009.958 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:50.291Z,1621354010.291 [DAT](INFO): DAT read: Rx Time:16:06:22.3006 2021-05-18T16:06:50.291Z,1621354010.291 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:50.292Z,1621354010.292 [DAT](INFO): DAT read: Bearing 67.6, -5.6 (Local) 2021-05-18T16:06:50.293Z,1621354010.293 [DAT](INFO): Local bearing/azimuth received: Bearing 67.6, -5.6 (Local) 2021-05-18T16:06:50.325Z,1621354010.325 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:50.338Z,1621354010.338 [DAT](INFO): DAT read: 16:06:22.3006 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 511,-0.27, 3.084, 2.742, 3.050, 3.008, PHS= 0.072,-0.221, 0.028, RAW= 141.9, 8.9, CAL= 142.4, 5.6, ROT= 67.6, -5.6 2021-05-18T16:06:50.344Z,1621354010.344 [DAT](INFO): got valid direction response: 16:06:22.3006 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 511,-0.27, 3.084, 2.742, 3.050, 3.008, PHS= 0.072,-0.221, 0.028, RAW= 141.9, 8.9, CAL= 142.4, 5.6, ROT= 67.6, -5.6 2021-05-18T16:06:50.345Z,1621354010.345 [DAT](INFO): #Rx 5: Read range and direction messages. 2021-05-18T16:06:50.346Z,1621354010.346 [DAT](INFO): direction in vehicle frame: [ 0.379252 forward, 0.920134 starboard, -0.097583 keelward ] 2021-05-18T16:06:50.346Z,1621354010.346 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:50.346Z,1621354010.346 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:50.361Z,1621354010.361 [DAT](INFO): checking for new query: numPingsReceived=5 elapsed TxPingTime=4.507289 2021-05-18T16:06:50.384Z,1621354010.384 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:50.386Z,1621354010.386 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.379252 forward, 0.920134 starboard, -0.097583 keelward ] 2021-05-18T16:06:50.386Z,1621354010.386 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:50.396Z,1621354010.396 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998841,-0.048062,-0.002746;0.048115,0.998535,0.024749;0.001552,-0.024852,0.999690 ] 2021-05-18T16:06:50.397Z,1621354010.397 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:50.397Z,1621354010.397 [lab_range_test:A.](INFO): direction in world frame: [ 0.422933 north, 0.902983 east, -0.075822 down ] 2021-05-18T16:06:50.398Z,1621354010.398 [lab_range_test:A.](INFO): relPosInFSK: [ 0.075850 forward, 0.184027 starboard, -0.019517 keelward ] 2021-05-18T16:06:50.408Z,1621354010.408 [lab_range_test:A.](INFO): relPosInNED: [ 0.084587 north, 0.180597 east, -0.015164 down ] 2021-05-18T16:06:50.410Z,1621354010.410 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:50.431Z,1621354010.431 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:50.688Z,1621354010.688 [DAT](INFO): DAT read: Rx Time:16:06:22.8007 2021-05-18T16:06:50.688Z,1621354010.688 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:50.689Z,1621354010.689 [DAT](INFO): DAT read: Bearing 75.9, -4.9 (Local) 2021-05-18T16:06:50.690Z,1621354010.690 [DAT](INFO): Local bearing/azimuth received: Bearing 75.9, -4.9 (Local) 2021-05-18T16:06:50.692Z,1621354010.692 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:50.697Z,1621354010.697 [DAT](INFO): DAT read: 16:06:22.8007 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.65, 2.700, 1.853, 2.469, 2.438, PHS= 0.258,-0.541, 0.016, RAW= 132.8, 7.6, CAL= 134.1, 4.9, ROT= 75.9, -4.9 2021-05-18T16:06:50.698Z,1621354010.698 [DAT](INFO): got valid direction response: 16:06:22.8007 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.65, 2.700, 1.853, 2.469, 2.438, PHS= 0.258,-0.541, 0.016, RAW= 132.8, 7.6, CAL= 134.1, 4.9, ROT= 75.9, -4.9 2021-05-18T16:06:50.698Z,1621354010.698 [DAT](INFO): #Rx 6: Read range and direction messages. 2021-05-18T16:06:50.700Z,1621354010.700 [DAT](INFO): direction in vehicle frame: [ 0.242725 forward, 0.966327 starboard, -0.085417 keelward ] 2021-05-18T16:06:50.700Z,1621354010.700 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:50.700Z,1621354010.700 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:50.703Z,1621354010.703 [DAT](INFO): checking for new query: numPingsReceived=6 elapsed TxPingTime=4.849138 2021-05-18T16:06:50.709Z,1621354010.709 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:50.711Z,1621354010.711 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.242725 forward, 0.966327 starboard, -0.085417 keelward ] 2021-05-18T16:06:50.711Z,1621354010.711 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:50.713Z,1621354010.713 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998891,-0.047000,-0.002873;0.047057,0.998583,0.024833;0.001702,-0.024941,0.999687 ] 2021-05-18T16:06:50.713Z,1621354010.713 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:50.714Z,1621354010.714 [lab_range_test:A.](INFO): direction in world frame: [ 0.287782 north, 0.955681 east, -0.062091 down ] 2021-05-18T16:06:50.767Z,1621354010.767 [lab_range_test:A.](INFO): relPosInFSK: [ 0.072817 forward, 0.289898 starboard, -0.025625 keelward ] 2021-05-18T16:06:50.768Z,1621354010.768 [lab_range_test:A.](INFO): relPosInNED: [ 0.086335 north, 0.286704 east, -0.018627 down ] 2021-05-18T16:06:50.768Z,1621354010.768 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:50.768Z,1621354010.768 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:51.087Z,1621354011.087 [DAT](INFO): DAT read: Rx Time:16:06:23.3006 2021-05-18T16:06:51.087Z,1621354011.087 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:51.088Z,1621354011.088 [DAT](INFO): DAT read: Bearing 66.2, -6.4 (Local) 2021-05-18T16:06:51.089Z,1621354011.089 [DAT](INFO): Local bearing/azimuth received: Bearing 66.2, -6.4 (Local) 2021-05-18T16:06:51.091Z,1621354011.091 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:51.103Z,1621354011.103 [DAT](INFO): DAT read: 16:06:23.3006 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495,-0.02,-2.578,-2.881,-2.599,-2.638, PHS= 0.056,-0.198, 0.024, RAW= 143.3, 9.8, CAL= 143.8, 6.4, ROT= 66.2, -6.4 2021-05-18T16:06:51.105Z,1621354011.105 [DAT](INFO): got valid direction response: 16:06:23.3006 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495,-0.02,-2.578,-2.881,-2.599,-2.638, PHS= 0.056,-0.198, 0.024, RAW= 143.3, 9.8, CAL= 143.8, 6.4, ROT= 66.2, -6.4 2021-05-18T16:06:51.105Z,1621354011.105 [DAT](INFO): #Rx 7: Read range and direction messages. 2021-05-18T16:06:51.106Z,1621354011.106 [DAT](INFO): direction in vehicle frame: [ 0.401030 forward, 0.909258 starboard, -0.111469 keelward ] 2021-05-18T16:06:51.106Z,1621354011.106 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:51.106Z,1621354011.106 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:51.122Z,1621354011.122 [DAT](INFO): checking for new query: numPingsReceived=7 elapsed TxPingTime=5.267857 2021-05-18T16:06:51.141Z,1621354011.141 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:51.142Z,1621354011.142 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.401030 forward, 0.909258 starboard, -0.111469 keelward ] 2021-05-18T16:06:51.142Z,1621354011.142 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:51.156Z,1621354011.156 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998943,-0.045877,-0.002817;0.045933,0.998632,0.024975;0.001668,-0.025078,0.999684 ] 2021-05-18T16:06:51.157Z,1621354011.157 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:51.158Z,1621354011.158 [lab_range_test:A.](INFO): direction in world frame: [ 0.442186 north, 0.892411 east, -0.089855 down ] 2021-05-18T16:06:51.158Z,1621354011.158 [lab_range_test:A.](INFO): relPosInFSK: [ 0.080206 forward, 0.181852 starboard, -0.022294 keelward ] 2021-05-18T16:06:51.167Z,1621354011.167 [lab_range_test:A.](INFO): relPosInNED: [ 0.088437 north, 0.178482 east, -0.017971 down ] 2021-05-18T16:06:51.168Z,1621354011.168 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:51.168Z,1621354011.168 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:51.513Z,1621354011.513 [DAT](INFO): DAT read: Rx Time:16:06:23.8007 2021-05-18T16:06:51.514Z,1621354011.514 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:51.517Z,1621354011.517 [DAT](INFO): DAT read: Bearing 69.5, -7.2 (Local) 2021-05-18T16:06:51.517Z,1621354011.517 [DAT](INFO): Local bearing/azimuth received: Bearing 69.5, -7.2 (Local) 2021-05-18T16:06:51.519Z,1621354011.519 [DAT](INFO): checking for new query: numPingsReceived=7 elapsed TxPingTime=5.664252 2021-05-18T16:06:51.533Z,1621354011.533 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:51.910Z,1621354011.910 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:51.915Z,1621354011.915 [DAT](INFO): DAT read: 16:06:23.8007 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 0, 0.60, 0.340,-0.197, 0.261, 0.221, PHS= 0.115,-0.374, 0.025, RAW= 140.0, 10.4, CAL= 140.5, 7.2, ROT= 69.5, -7.2 2021-05-18T16:06:51.916Z,1621354011.916 [DAT](INFO): got valid direction response: 16:06:23.8007 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 0, 0.60, 0.340,-0.197, 0.261, 0.221, PHS= 0.115,-0.374, 0.025, RAW= 140.0, 10.4, CAL= 140.5, 7.2, ROT= 69.5, -7.2 2021-05-18T16:06:51.917Z,1621354011.917 [DAT](INFO): #Rx 8: Read range and direction messages. 2021-05-18T16:06:51.918Z,1621354011.918 [DAT](INFO): direction in vehicle frame: [ 0.347446 forward, 0.929286 starboard, -0.125333 keelward ] 2021-05-18T16:06:51.918Z,1621354011.918 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:51.921Z,1621354011.921 [DAT](INFO): checking for new query: numPingsReceived=8 elapsed TxPingTime=6.067114 2021-05-18T16:06:51.968Z,1621354011.968 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:51.969Z,1621354011.969 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.347446 forward, 0.929286 starboard, -0.125333 keelward ] 2021-05-18T16:06:51.969Z,1621354011.969 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:51.979Z,1621354011.979 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998889,-0.047034,-0.002809;0.047089,0.998581,0.024870;0.001635,-0.024975,0.999687 ] 2021-05-18T16:06:51.980Z,1621354011.980 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:51.981Z,1621354011.981 [lab_range_test:A.](INFO): direction in world frame: [ 0.390614 north, 0.914756 east, -0.103159 down ] 2021-05-18T16:06:51.981Z,1621354011.981 [lab_range_test:A.](INFO): relPosInFSK: [ 0.104234 forward, 0.278786 starboard, -0.037600 keelward ] 2021-05-18T16:06:51.982Z,1621354011.982 [lab_range_test:A.](INFO): relPosInNED: [ 0.117184 north, 0.274427 east, -0.030948 down ] 2021-05-18T16:06:51.982Z,1621354011.982 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:51.983Z,1621354011.983 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:52.310Z,1621354012.310 [DAT](INFO): DAT read: Rx Time:16:06:24.3006 2021-05-18T16:06:52.310Z,1621354012.310 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:52.311Z,1621354012.311 [DAT](INFO): DAT read: Bearing 68.0, -4.6 (Local) 2021-05-18T16:06:52.312Z,1621354012.312 [DAT](INFO): Local bearing/azimuth received: Bearing 68.0, -4.6 (Local) 2021-05-18T16:06:52.314Z,1621354012.314 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:06:52.318Z,1621354012.318 [DAT](INFO): DAT read: 16:06:24.3006 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.23,-1.198,-1.456,-1.220,-1.257, PHS= 0.056,-0.155, 0.022, RAW= 141.5, 7.9, CAL= 142.0, 4.6, ROT= 68.0, -4.6 2021-05-18T16:06:52.319Z,1621354012.319 [DAT](INFO): got valid direction response: 16:06:24.3006 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.23,-1.198,-1.456,-1.220,-1.257, PHS= 0.056,-0.155, 0.022, RAW= 141.5, 7.9, CAL= 142.0, 4.6, ROT= 68.0, -4.6 2021-05-18T16:06:52.320Z,1621354012.320 [DAT](INFO): #Rx 9: Read range and direction messages. 2021-05-18T16:06:52.321Z,1621354012.321 [DAT](INFO): direction in vehicle frame: [ 0.373400 forward, 0.924197 starboard, -0.080199 keelward ] 2021-05-18T16:06:52.321Z,1621354012.321 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:52.321Z,1621354012.321 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:52.324Z,1621354012.324 [DAT](INFO): checking for new query: numPingsReceived=9 elapsed TxPingTime=6.470436 2021-05-18T16:06:52.331Z,1621354012.331 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:52.332Z,1621354012.332 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.373400 forward, 0.924197 starboard, -0.080199 keelward ] 2021-05-18T16:06:52.332Z,1621354012.332 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:52.334Z,1621354012.334 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998841,-0.048044,-0.002775;0.048098,0.998535,0.024798;0.001580,-0.024902,0.999689 ] 2021-05-18T16:06:52.335Z,1621354012.335 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:06:52.336Z,1621354012.336 [lab_range_test:A.](INFO): direction in world frame: [ 0.417293 north, 0.906901 east, -0.058292 down ] 2021-05-18T16:06:52.336Z,1621354012.336 [lab_range_test:A.](INFO): relPosInFSK: [ 0.074680 forward, 0.184839 starboard, -0.016040 keelward ] 2021-05-18T16:06:52.337Z,1621354012.337 [lab_range_test:A.](INFO): relPosInNED: [ 0.083459 north, 0.181380 east, -0.011658 down ] 2021-05-18T16:06:52.337Z,1621354012.337 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:52.337Z,1621354012.337 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:52.703Z,1621354012.703 [DAT](INFO): DAT read: Rx Time:16:06:24.8007 2021-05-18T16:06:52.703Z,1621354012.703 [DAT](INFO): received an acoustic signal 2021-05-18T16:06:52.705Z,1621354012.705 [DAT](INFO): DAT read: Bearing 65.9, -7.1 (Local) 2021-05-18T16:06:52.705Z,1621354012.705 [DAT](INFO): Local bearing/azimuth received: Bearing 65.9, -7.1 (Local) 2021-05-18T16:06:52.707Z,1621354012.707 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:06:52.712Z,1621354012.712 [DAT](INFO): DAT read: 16:06:24.8007 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.53,-1.763,-2.084,-1.785,-1.824, PHS= 0.057,-0.216, 0.024, RAW= 143.7, 10.5, CAL= 144.1, 7.1, ROT= 65.9, -7.1 2021-05-18T16:06:52.713Z,1621354012.713 [DAT](INFO): got valid direction response: 16:06:24.8007 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.53,-1.763,-2.084,-1.785,-1.824, PHS= 0.057,-0.216, 0.024, RAW= 143.7, 10.5, CAL= 144.1, 7.1, ROT= 65.9, -7.1 2021-05-18T16:06:52.714Z,1621354012.714 [DAT](INFO): #Rx 10: Read range and direction messages. 2021-05-18T16:06:52.715Z,1621354012.715 [DAT](INFO): direction in vehicle frame: [ 0.405199 forward, 0.905835 starboard, -0.123601 keelward ] 2021-05-18T16:06:52.715Z,1621354012.715 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:06:52.715Z,1621354012.715 [DAT](INFO): publishing direction and range info 2021-05-18T16:06:52.789Z,1621354012.789 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:52.790Z,1621354012.790 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.405199 forward, 0.905835 starboard, -0.123601 keelward ] 2021-05-18T16:06:52.790Z,1621354012.790 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:06:52.800Z,1621354012.800 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998844,-0.047998,-0.002611;0.048048,0.998536,0.024834;0.001416,-0.024931,0.999688 ] 2021-05-18T16:06:52.801Z,1621354012.801 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:06:52.802Z,1621354012.802 [lab_range_test:A.](INFO): direction in world frame: [ 0.448079 north, 0.888141 east, -0.102126 down ] 2021-05-18T16:06:52.802Z,1621354012.802 [lab_range_test:A.](INFO): relPosInFSK: [ 0.121560 forward, 0.271750 starboard, -0.037080 keelward ] 2021-05-18T16:06:52.815Z,1621354012.815 [lab_range_test:A.](INFO): relPosInNED: [ 0.134424 north, 0.266442 east, -0.030638 down ] 2021-05-18T16:06:52.816Z,1621354012.816 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:06:52.816Z,1621354012.816 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:06:53.128Z,1621354013.128 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:53.522Z,1621354013.522 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:53.924Z,1621354013.924 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:54.345Z,1621354014.345 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:54.749Z,1621354014.749 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:55.161Z,1621354015.161 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:55.541Z,1621354015.541 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:55.944Z,1621354015.944 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:56.352Z,1621354016.352 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:56.749Z,1621354016.749 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:57.153Z,1621354017.153 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:57.580Z,1621354017.580 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:57.988Z,1621354017.988 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:57.988Z,1621354017.988 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:06:57.989Z,1621354017.989 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:06:58.372Z,1621354018.372 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:06:58.372Z,1621354018.372 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:06:58.372Z,1621354018.372 [DAT](INFO): Querying Benthos address 50 with 10 pings in terminal homing one-way mode. 2021-05-18T16:06:58.373Z,1621354018.373 [DAT](INFO): ****** ping requested ****** 2021-05-18T16:06:58.396Z,1621354018.396 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:58.762Z,1621354018.762 [DAT](INFO): DAT read: user:10> 2021-05-18T16:06:58.763Z,1621354018.763 [DAT](INFO): DAT read: Tx time:16:06:31.1210 2021-05-18T16:06:58.763Z,1621354018.763 [DAT](INFO): Ping request sent. 2021-05-18T16:06:58.763Z,1621354018.763 [DAT](INFO): transmitted an acoustic signal 2021-05-18T16:06:58.764Z,1621354018.764 [DAT](INFO): publishing transmit ping time 2021-05-18T16:06:58.764Z,1621354018.764 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.000799 2021-05-18T16:06:58.776Z,1621354018.776 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:59.166Z,1621354019.166 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.402304 2021-05-18T16:06:59.183Z,1621354019.183 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:59.577Z,1621354019.577 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.813892 2021-05-18T16:06:59.592Z,1621354019.592 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:06:59.982Z,1621354019.982 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.218623 2021-05-18T16:07:00.013Z,1621354020.013 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:00.397Z,1621354020.397 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.633507 2021-05-18T16:07:00.468Z,1621354020.468 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:00.801Z,1621354020.801 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=2.037843 2021-05-18T16:07:00.813Z,1621354020.813 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:01.325Z,1621354021.325 [DAT](INFO): DAT read: Rx Time:16:06:33.2507 2021-05-18T16:07:01.326Z,1621354021.326 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:01.327Z,1621354021.327 [DAT](INFO): DAT read: Bearing 66.3, -6.0 (Local) 2021-05-18T16:07:01.327Z,1621354021.327 [DAT](INFO): Local bearing/azimuth received: Bearing 66.3, -6.0 (Local) 2021-05-18T16:07:01.329Z,1621354021.329 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:01.334Z,1621354021.334 [DAT](INFO): DAT read: 16:06:33.2507 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 465,-0.34, 0.718, 0.394, 0.694, 0.651, PHS= 0.063,-0.213, 0.028, RAW= 143.3, 9.4, CAL= 143.7, 6.0, ROT= 66.3, -6.0 2021-05-18T16:07:01.386Z,1621354021.386 [DAT](INFO): got valid direction response: 16:06:33.2507 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 465,-0.34, 0.718, 0.394, 0.694, 0.651, PHS= 0.063,-0.213, 0.028, RAW= 143.3, 9.4, CAL= 143.7, 6.0, ROT= 66.3, -6.0 2021-05-18T16:07:01.395Z,1621354021.395 [DAT](INFO): #Rx 1: Read range and direction messages. 2021-05-18T16:07:01.396Z,1621354021.396 [DAT](INFO): direction in vehicle frame: [ 0.399746 forward, 0.910647 starboard, -0.104528 keelward ] 2021-05-18T16:07:01.396Z,1621354021.396 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:01.397Z,1621354021.397 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:01.408Z,1621354021.408 [DAT](INFO): checking for new query: numPingsReceived=1 elapsed TxPingTime=2.644995 2021-05-18T16:07:01.435Z,1621354021.435 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:01.436Z,1621354021.436 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.399746 forward, 0.910647 starboard, -0.104528 keelward ] 2021-05-18T16:07:01.437Z,1621354021.437 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:01.452Z,1621354021.452 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998886,-0.047102,-0.002756;0.047156,0.998578,0.024847;0.001582,-0.024949,0.999687 ] 2021-05-18T16:07:01.453Z,1621354021.453 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:01.454Z,1621354021.454 [lab_range_test:A.](INFO): direction in world frame: [ 0.442078 north, 0.893131 east, -0.082971 down ] 2021-05-18T16:07:01.465Z,1621354021.465 [lab_range_test:A.](INFO): relPosInFSK: [ 0.119924 forward, 0.273194 starboard, -0.031359 keelward ] 2021-05-18T16:07:01.479Z,1621354021.479 [lab_range_test:A.](INFO): relPosInNED: [ 0.132623 north, 0.267939 east, -0.024891 down ] 2021-05-18T16:07:01.480Z,1621354021.480 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:01.481Z,1621354021.481 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:01.626Z,1621354021.626 [DAT](INFO): DAT read: Rx Time:16:06:33.7507 2021-05-18T16:07:01.626Z,1621354021.626 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:01.632Z,1621354021.632 [DAT](INFO): DAT read: Bearing 66.0, -6.4 (Local) 2021-05-18T16:07:01.633Z,1621354021.633 [DAT](INFO): Local bearing/azimuth received: Bearing 66.0, -6.4 (Local) 2021-05-18T16:07:01.643Z,1621354021.643 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:01.656Z,1621354021.656 [DAT](INFO): DAT read: 16:06:33.7507 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 497,-0.18, 0.420, 0.084, 0.396, 0.353, PHS= 0.064,-0.225, 0.028, RAW= 143.5, 9.8, CAL= 144.0, 6.4, ROT= 66.0, -6.4 2021-05-18T16:07:01.657Z,1621354021.657 [DAT](INFO): got valid direction response: 16:06:33.7507 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 497,-0.18, 0.420, 0.084, 0.396, 0.353, PHS= 0.064,-0.225, 0.028, RAW= 143.5, 9.8, CAL= 144.0, 6.4, ROT= 66.0, -6.4 2021-05-18T16:07:01.657Z,1621354021.657 [DAT](INFO): #Rx 2: Read range and direction messages. 2021-05-18T16:07:01.658Z,1621354021.658 [DAT](INFO): direction in vehicle frame: [ 0.404202 forward, 0.907852 starboard, -0.111469 keelward ] 2021-05-18T16:07:01.663Z,1621354021.663 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:01.663Z,1621354021.663 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:01.666Z,1621354021.666 [DAT](INFO): checking for new query: numPingsReceived=2 elapsed TxPingTime=2.902662 2021-05-18T16:07:01.682Z,1621354021.682 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:01.687Z,1621354021.687 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.404202 forward, 0.907852 starboard, -0.111469 keelward ] 2021-05-18T16:07:01.688Z,1621354021.688 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:01.690Z,1621354021.690 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998900,-0.046824,-0.002686;0.046877,0.998590,0.024923;0.001516,-0.025021,0.999686 ] 2021-05-18T16:07:01.690Z,1621354021.690 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:01.695Z,1621354021.695 [lab_range_test:A.](INFO): direction in world frame: [ 0.446145 north, 0.890435 east, -0.089894 down ] 2021-05-18T16:07:01.696Z,1621354021.696 [lab_range_test:A.](INFO): relPosInFSK: [ 0.121261 forward, 0.272356 starboard, -0.033441 keelward ] 2021-05-18T16:07:01.697Z,1621354021.697 [lab_range_test:A.](INFO): relPosInNED: [ 0.133844 north, 0.267130 east, -0.026968 down ] 2021-05-18T16:07:01.697Z,1621354021.697 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:01.697Z,1621354021.697 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:02.024Z,1621354022.024 [DAT](INFO): DAT read: Rx Time:16:06:34.2506 2021-05-18T16:07:02.024Z,1621354022.024 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:02.025Z,1621354022.025 [DAT](INFO): DAT read: Bearing 67.2, -6.4 (Local) 2021-05-18T16:07:02.026Z,1621354022.026 [DAT](INFO): Local bearing/azimuth received: Bearing 67.2, -6.4 (Local) 2021-05-18T16:07:02.028Z,1621354022.028 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:02.032Z,1621354022.032 [DAT](INFO): DAT read: 16:06:34.2506 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.06,-0.455,-0.795,-0.486,-0.526, PHS= 0.067,-0.224, 0.025, RAW= 142.3, 9.7, CAL= 142.8, 6.4, ROT= 67.2, -6.4 2021-05-18T16:07:02.033Z,1621354022.033 [DAT](INFO): got valid direction response: 16:06:34.2506 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.06,-0.455,-0.795,-0.486,-0.526, PHS= 0.067,-0.224, 0.025, RAW= 142.3, 9.7, CAL= 142.8, 6.4, ROT= 67.2, -6.4 2021-05-18T16:07:02.034Z,1621354022.034 [DAT](INFO): #Rx 3: Read range and direction messages. 2021-05-18T16:07:02.035Z,1621354022.035 [DAT](INFO): direction in vehicle frame: [ 0.385101 forward, 0.916118 starboard, -0.111469 keelward ] 2021-05-18T16:07:02.035Z,1621354022.035 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:02.035Z,1621354022.035 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:02.038Z,1621354022.038 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.274692 2021-05-18T16:07:02.044Z,1621354022.044 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:02.045Z,1621354022.045 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.385101 forward, 0.916118 starboard, -0.111469 keelward ] 2021-05-18T16:07:02.046Z,1621354022.046 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:02.048Z,1621354022.048 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998933,-0.046113,-0.002729;0.046167,0.998621,0.024976;0.001573,-0.025075,0.999684 ] 2021-05-18T16:07:02.048Z,1621354022.048 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:07:02.049Z,1621354022.049 [lab_range_test:A.](INFO): direction in world frame: [ 0.426808 north, 0.899892 east, -0.089604 down ] 2021-05-18T16:07:02.050Z,1621354022.050 [lab_range_test:A.](INFO): relPosInFSK: [ 0.077020 forward, 0.183224 starboard, -0.022294 keelward ] 2021-05-18T16:07:02.050Z,1621354022.050 [lab_range_test:A.](INFO): relPosInNED: [ 0.085362 north, 0.179978 east, -0.017921 down ] 2021-05-18T16:07:02.051Z,1621354022.051 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:02.102Z,1621354022.102 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:02.427Z,1621354022.427 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.663707 2021-05-18T16:07:02.433Z,1621354022.433 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:02.803Z,1621354022.803 [DAT](INFO): DAT read: Rx Time:16:06:34.7506 2021-05-18T16:07:02.804Z,1621354022.804 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:02.805Z,1621354022.805 [DAT](INFO): DAT read: Bearing 70.2, -3.2 (Local) 2021-05-18T16:07:02.805Z,1621354022.805 [DAT](INFO): Local bearing/azimuth received: Bearing 70.2, -3.2 (Local) 2021-05-18T16:07:02.815Z,1621354022.815 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:02.852Z,1621354022.852 [DAT](INFO): DAT read: 16:06:34.7506 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496, 0.05, 1.313, 1.030, 1.278, 1.238, PHS= 0.071,-0.164, 0.025, RAW= 139.2, 6.3, CAL= 139.8, 3.2, ROT= 70.2, -3.2 2021-05-18T16:07:02.854Z,1621354022.854 [DAT](INFO): got valid direction response: 16:06:34.7506 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496, 0.05, 1.313, 1.030, 1.278, 1.238, PHS= 0.071,-0.164, 0.025, RAW= 139.2, 6.3, CAL= 139.8, 3.2, ROT= 70.2, -3.2 2021-05-18T16:07:02.854Z,1621354022.854 [DAT](INFO): #Rx 4: Read range and direction messages. 2021-05-18T16:07:02.871Z,1621354022.871 [DAT](INFO): direction in vehicle frame: [ 0.338210 forward, 0.939414 starboard, -0.055822 keelward ] 2021-05-18T16:07:02.872Z,1621354022.872 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:02.872Z,1621354022.872 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:02.887Z,1621354022.887 [DAT](INFO): checking for new query: numPingsReceived=4 elapsed TxPingTime=4.111339 2021-05-18T16:07:02.902Z,1621354022.902 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:02.908Z,1621354022.908 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.338210 forward, 0.939414 starboard, -0.055822 keelward ] 2021-05-18T16:07:02.908Z,1621354022.908 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:02.910Z,1621354022.910 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998913,-0.046544,-0.002723;0.046597,0.998603,0.024933;0.001558,-0.025033,0.999685 ] 2021-05-18T16:07:02.910Z,1621354022.910 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:07:02.928Z,1621354022.928 [lab_range_test:A.](INFO): direction in world frame: [ 0.381529 north, 0.923757 east, -0.033302 down ] 2021-05-18T16:07:02.928Z,1621354022.928 [lab_range_test:A.](INFO): relPosInFSK: [ 0.067642 forward, 0.187883 starboard, -0.011164 keelward ] 2021-05-18T16:07:02.929Z,1621354022.929 [lab_range_test:A.](INFO): relPosInNED: [ 0.076306 north, 0.184751 east, -0.006660 down ] 2021-05-18T16:07:02.929Z,1621354022.929 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:02.929Z,1621354022.929 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:03.221Z,1621354023.221 [DAT](INFO): DAT read: Rx Time:16:06:35.2505 2021-05-18T16:07:03.222Z,1621354023.222 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:03.223Z,1621354023.223 [DAT](INFO): DAT read: Bearing 70.3, -3.5 (Local) 2021-05-18T16:07:03.223Z,1621354023.223 [DAT](INFO): Local bearing/azimuth received: Bearing 70.3, -3.5 (Local) 2021-05-18T16:07:03.225Z,1621354023.225 [DAT](INFO): DAT read: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:07:03.226Z,1621354023.226 [DAT](INFO): unknown deviceResponse_: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:07:03.230Z,1621354023.230 [DAT](INFO): DAT read: 16:06:35.2505 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 495, 0.17, 0.417, 0.141, 0.382, 0.344, PHS= 0.068,-0.159, 0.023, RAW= 139.1, 6.6, CAL= 139.7, 3.5, ROT= 70.3, -3.5 2021-05-18T16:07:03.231Z,1621354023.231 [DAT](INFO): got valid direction response: 16:06:35.2505 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 495, 0.17, 0.417, 0.141, 0.382, 0.344, PHS= 0.068,-0.159, 0.023, RAW= 139.1, 6.6, CAL= 139.7, 3.5, ROT= 70.3, -3.5 2021-05-18T16:07:03.232Z,1621354023.232 [DAT](INFO): #Rx 5: Read direction message, but no range. 2021-05-18T16:07:03.233Z,1621354023.233 [DAT](INFO): direction in vehicle frame: [ 0.336466 forward, 0.939715 starboard, -0.061049 keelward ] 2021-05-18T16:07:03.233Z,1621354023.233 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:03.236Z,1621354023.236 [DAT](INFO): checking for new query: numPingsReceived=5 elapsed TxPingTime=4.472531 2021-05-18T16:07:03.242Z,1621354023.242 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:03.626Z,1621354023.626 [DAT](INFO): DAT read: Rx Time:16:06:35.7506 2021-05-18T16:07:03.626Z,1621354023.626 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:03.627Z,1621354023.627 [DAT](INFO): DAT read: Bearing 65.5, -8.0 (Local) 2021-05-18T16:07:03.628Z,1621354023.628 [DAT](INFO): Local bearing/azimuth received: Bearing 65.5, -8.0 (Local) 2021-05-18T16:07:03.630Z,1621354023.630 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:03.642Z,1621354023.642 [DAT](INFO): DAT read: 16:06:35.7506 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.53,-0.840,-1.182,-0.863,-0.900, PHS= 0.056,-0.238, 0.022, RAW= 144.0, 11.4, CAL= 144.5, 8.0, ROT= 65.5, -8.0 2021-05-18T16:07:03.674Z,1621354023.674 [DAT](INFO): got valid direction response: 16:06:35.7506 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.53,-0.840,-1.182,-0.863,-0.900, PHS= 0.056,-0.238, 0.022, RAW= 144.0, 11.4, CAL= 144.5, 8.0, ROT= 65.5, -8.0 2021-05-18T16:07:03.677Z,1621354023.677 [DAT](INFO): #Rx 6: Read range and direction messages. 2021-05-18T16:07:03.678Z,1621354023.678 [DAT](INFO): direction in vehicle frame: [ 0.410658 forward, 0.901106 starboard, -0.139173 keelward ] 2021-05-18T16:07:03.711Z,1621354023.711 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:03.711Z,1621354023.711 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:03.714Z,1621354023.714 [DAT](INFO): checking for new query: numPingsReceived=6 elapsed TxPingTime=4.950624 2021-05-18T16:07:03.753Z,1621354023.753 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:03.754Z,1621354023.754 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.410658 forward, 0.901106 starboard, -0.139173 keelward ] 2021-05-18T16:07:03.754Z,1621354023.754 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:03.765Z,1621354023.765 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998875,-0.047335,-0.002834;0.047391,0.998568,0.024838;0.001655,-0.024944,0.999687 ] 2021-05-18T16:07:03.765Z,1621354023.765 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:07:03.766Z,1621354023.766 [lab_range_test:A.](INFO): direction in world frame: [ 0.452670 north, 0.883848 east, -0.117912 down ] 2021-05-18T16:07:03.775Z,1621354023.775 [lab_range_test:A.](INFO): relPosInFSK: [ 0.082132 forward, 0.180221 starboard, -0.027835 keelward ] 2021-05-18T16:07:03.776Z,1621354023.776 [lab_range_test:A.](INFO): relPosInNED: [ 0.090534 north, 0.176770 east, -0.023582 down ] 2021-05-18T16:07:03.776Z,1621354023.776 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:03.776Z,1621354023.776 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:04.033Z,1621354024.033 [DAT](INFO): DAT read: Rx Time:16:06:36.2505 2021-05-18T16:07:04.033Z,1621354024.033 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:04.035Z,1621354024.035 [DAT](INFO): DAT read: Bearing 67.6, -5.9 (Local) 2021-05-18T16:07:04.035Z,1621354024.035 [DAT](INFO): Local bearing/azimuth received: Bearing 67.6, -5.9 (Local) 2021-05-18T16:07:04.037Z,1621354024.037 [DAT](INFO): DAT read: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:07:04.038Z,1621354024.038 [DAT](INFO): unknown deviceResponse_: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:07:04.042Z,1621354024.042 [DAT](INFO): DAT read: 16:06:36.2505 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.44,-0.983,-1.304,-1.013,-1.052, PHS= 0.066,-0.207, 0.024, RAW= 141.9, 9.3, CAL= 142.4, 5.9, ROT= 67.6, -5.9 2021-05-18T16:07:04.043Z,1621354024.043 [DAT](INFO): got valid direction response: 16:06:36.2505 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.44,-0.983,-1.304,-1.013,-1.052, PHS= 0.066,-0.207, 0.024, RAW= 141.9, 9.3, CAL= 142.4, 5.9, ROT= 67.6, -5.9 2021-05-18T16:07:04.044Z,1621354024.044 [DAT](INFO): #Rx 7: Read direction message, but no range. 2021-05-18T16:07:04.045Z,1621354024.045 [DAT](INFO): direction in vehicle frame: [ 0.379052 forward, 0.919649 starboard, -0.102793 keelward ] 2021-05-18T16:07:04.045Z,1621354024.045 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:04.048Z,1621354024.048 [DAT](INFO): checking for new query: numPingsReceived=7 elapsed TxPingTime=5.284819 2021-05-18T16:07:04.055Z,1621354024.055 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:04.423Z,1621354024.423 [DAT](INFO): checking for new query: numPingsReceived=7 elapsed TxPingTime=5.659582 2021-05-18T16:07:04.459Z,1621354024.459 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:04.827Z,1621354024.827 [DAT](INFO): DAT read: Rx Time:16:06:36.7507 2021-05-18T16:07:04.827Z,1621354024.827 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:04.829Z,1621354024.829 [DAT](INFO): DAT read: Bearing 67.5, -6.4 (Local) 2021-05-18T16:07:04.829Z,1621354024.829 [DAT](INFO): Local bearing/azimuth received: Bearing 67.5, -6.4 (Local) 2021-05-18T16:07:04.831Z,1621354024.831 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:04.836Z,1621354024.836 [DAT](INFO): DAT read: 16:06:36.7507 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 1,-0.25,-0.230,-0.569,-0.263,-0.302, PHS= 0.068,-0.223, 0.024, RAW= 142.0, 9.7, CAL= 142.5, 6.4, ROT= 67.5, -6.4 2021-05-18T16:07:04.837Z,1621354024.837 [DAT](INFO): got valid direction response: 16:06:36.7507 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 1,-0.25,-0.230,-0.569,-0.263,-0.302, PHS= 0.068,-0.223, 0.024, RAW= 142.0, 9.7, CAL= 142.5, 6.4, ROT= 67.5, -6.4 2021-05-18T16:07:04.838Z,1621354024.838 [DAT](INFO): #Rx 8: Read range and direction messages. 2021-05-18T16:07:04.839Z,1621354024.839 [DAT](INFO): direction in vehicle frame: [ 0.380299 forward, 0.918122 starboard, -0.111469 keelward ] 2021-05-18T16:07:04.839Z,1621354024.839 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:04.839Z,1621354024.839 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:04.842Z,1621354024.842 [DAT](INFO): checking for new query: numPingsReceived=8 elapsed TxPingTime=6.078659 2021-05-18T16:07:04.890Z,1621354024.890 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:04.896Z,1621354024.896 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.380299 forward, 0.918122 starboard, -0.111469 keelward ] 2021-05-18T16:07:04.896Z,1621354024.896 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:04.898Z,1621354024.898 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998977,-0.045144,-0.002769;0.045199,0.998664,0.025038;0.001635,-0.025137,0.999683 ] 2021-05-18T16:07:04.898Z,1621354024.898 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:04.899Z,1621354024.899 [lab_range_test:A.](INFO): direction in world frame: [ 0.421225 north, 0.902529 east, -0.089499 down ] 2021-05-18T16:07:04.900Z,1621354024.900 [lab_range_test:A.](INFO): relPosInFSK: [ 0.114090 forward, 0.275437 starboard, -0.033441 keelward ] 2021-05-18T16:07:04.901Z,1621354024.901 [lab_range_test:A.](INFO): relPosInNED: [ 0.126368 north, 0.270759 east, -0.026850 down ] 2021-05-18T16:07:04.901Z,1621354024.901 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:04.901Z,1621354024.901 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:05.233Z,1621354025.233 [DAT](INFO): DAT read: Rx Time:16:06:37.2506 2021-05-18T16:07:05.234Z,1621354025.234 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:05.235Z,1621354025.235 [DAT](INFO): DAT read: Bearing 66.6, -7.0 (Local) 2021-05-18T16:07:05.235Z,1621354025.235 [DAT](INFO): Local bearing/azimuth received: Bearing 66.6, -7.0 (Local) 2021-05-18T16:07:05.237Z,1621354025.237 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:05.242Z,1621354025.242 [DAT](INFO): DAT read: 16:06:37.2506 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.12,-1.811,-2.161,-1.840,-1.880, PHS= 0.065,-0.237, 0.025, RAW= 142.9, 10.4, CAL= 143.4, 7.0, ROT= 66.6, -7.0 2021-05-18T16:07:05.243Z,1621354025.243 [DAT](INFO): got valid direction response: 16:06:37.2506 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.12,-1.811,-2.161,-1.840,-1.880, PHS= 0.065,-0.237, 0.025, RAW= 142.9, 10.4, CAL= 143.4, 7.0, ROT= 66.6, -7.0 2021-05-18T16:07:05.244Z,1621354025.244 [DAT](INFO): #Rx 9: Read range and direction messages. 2021-05-18T16:07:05.245Z,1621354025.245 [DAT](INFO): direction in vehicle frame: [ 0.394188 forward, 0.910914 starboard, -0.121869 keelward ] 2021-05-18T16:07:05.245Z,1621354025.245 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:05.245Z,1621354025.245 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:05.248Z,1621354025.248 [DAT](INFO): checking for new query: numPingsReceived=9 elapsed TxPingTime=6.484839 2021-05-18T16:07:05.255Z,1621354025.255 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:05.256Z,1621354025.256 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.394188 forward, 0.910914 starboard, -0.121869 keelward ] 2021-05-18T16:07:05.256Z,1621354025.256 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:05.258Z,1621354025.258 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998975,-0.045189,-0.002780;0.045244,0.998662,0.025052;0.001644,-0.025152,0.999682 ] 2021-05-18T16:07:05.259Z,1621354025.259 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:07:05.260Z,1621354025.260 [lab_range_test:A.](INFO): direction in world frame: [ 0.434797 north, 0.894947 east, -0.100106 down ] 2021-05-18T16:07:05.260Z,1621354025.260 [lab_range_test:A.](INFO): relPosInFSK: [ 0.078838 forward, 0.182183 starboard, -0.024374 keelward ] 2021-05-18T16:07:05.261Z,1621354025.261 [lab_range_test:A.](INFO): relPosInNED: [ 0.086959 north, 0.178989 east, -0.020021 down ] 2021-05-18T16:07:05.261Z,1621354025.261 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:05.262Z,1621354025.262 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:05.646Z,1621354025.646 [DAT](INFO): DAT read: Rx Time:16:06:37.7507 2021-05-18T16:07:05.646Z,1621354025.646 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:05.647Z,1621354025.647 [DAT](INFO): DAT read: Bearing 66.1, -7.1 (Local) 2021-05-18T16:07:05.648Z,1621354025.648 [DAT](INFO): Local bearing/azimuth received: Bearing 66.1, -7.1 (Local) 2021-05-18T16:07:05.650Z,1621354025.650 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:05.654Z,1621354025.654 [DAT](INFO): DAT read: 16:06:37.7507 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 497,-0.00, 0.364, 0.063, 0.344, 0.307, PHS= 0.053,-0.200, 0.022, RAW= 143.4, 10.5, CAL= 143.9, 7.1, ROT= 66.1, -7.1 2021-05-18T16:07:05.669Z,1621354025.669 [DAT](INFO): got valid direction response: 16:06:37.7507 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 497,-0.00, 0.364, 0.063, 0.344, 0.307, PHS= 0.053,-0.200, 0.022, RAW= 143.4, 10.5, CAL= 143.9, 7.1, ROT= 66.1, -7.1 2021-05-18T16:07:05.670Z,1621354025.670 [DAT](INFO): #Rx 10: Read range and direction messages. 2021-05-18T16:07:05.671Z,1621354025.671 [DAT](INFO): direction in vehicle frame: [ 0.402035 forward, 0.907243 starboard, -0.123601 keelward ] 2021-05-18T16:07:05.671Z,1621354025.671 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:05.671Z,1621354025.671 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:05.729Z,1621354025.729 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:05.730Z,1621354025.730 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.402035 forward, 0.907243 starboard, -0.123601 keelward ] 2021-05-18T16:07:05.731Z,1621354025.731 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:05.733Z,1621354025.733 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998982,-0.045025,-0.002801;0.045081,0.998669,0.025064;0.001668,-0.025165,0.999682 ] 2021-05-18T16:07:05.733Z,1621354025.733 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:05.734Z,1621354025.734 [lab_range_test:A.](INFO): direction in world frame: [ 0.442319 north, 0.891045 east, -0.101949 down ] 2021-05-18T16:07:05.735Z,1621354025.735 [lab_range_test:A.](INFO): relPosInFSK: [ 0.120611 forward, 0.272173 starboard, -0.037080 keelward ] 2021-05-18T16:07:05.766Z,1621354025.766 [lab_range_test:A.](INFO): relPosInNED: [ 0.132696 north, 0.267313 east, -0.030585 down ] 2021-05-18T16:07:05.767Z,1621354025.767 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:05.767Z,1621354025.767 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:06.068Z,1621354026.068 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:06.441Z,1621354026.441 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:06.852Z,1621354026.852 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:07.281Z,1621354027.281 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:07.684Z,1621354027.684 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:08.070Z,1621354028.070 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:08.465Z,1621354028.465 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:08.875Z,1621354028.875 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:09.293Z,1621354029.293 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:09.693Z,1621354029.693 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:10.106Z,1621354030.106 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:10.493Z,1621354030.493 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:10.888Z,1621354030.888 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:10.889Z,1621354030.889 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:07:10.889Z,1621354030.889 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:07:11.286Z,1621354031.286 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:07:11.286Z,1621354031.286 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:07:11.286Z,1621354031.286 [DAT](INFO): Querying Benthos address 50 with 10 pings in terminal homing one-way mode. 2021-05-18T16:07:11.288Z,1621354031.288 [DAT](INFO): ****** ping requested ****** 2021-05-18T16:07:11.294Z,1621354031.294 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:11.692Z,1621354031.692 [DAT](INFO): DAT read: user:11> 2021-05-18T16:07:11.693Z,1621354031.693 [DAT](INFO): DAT read: Tx time:16:06:44.0209 2021-05-18T16:07:11.693Z,1621354031.693 [DAT](INFO): Ping request sent. 2021-05-18T16:07:11.694Z,1621354031.694 [DAT](INFO): transmitted an acoustic signal 2021-05-18T16:07:11.694Z,1621354031.694 [DAT](INFO): publishing transmit ping time 2021-05-18T16:07:11.694Z,1621354031.694 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.000766 2021-05-18T16:07:11.711Z,1621354031.711 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:12.106Z,1621354032.106 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.411427 2021-05-18T16:07:12.131Z,1621354032.131 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:12.521Z,1621354032.521 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.826984 2021-05-18T16:07:12.533Z,1621354032.533 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:12.917Z,1621354032.917 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.223112 2021-05-18T16:07:12.952Z,1621354032.952 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:13.325Z,1621354033.325 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.631037 2021-05-18T16:07:13.337Z,1621354033.337 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:13.720Z,1621354033.720 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=2.026590 2021-05-18T16:07:13.727Z,1621354033.727 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:14.116Z,1621354034.116 [DAT](INFO): DAT read: Rx Time:16:06:46.1505 2021-05-18T16:07:14.117Z,1621354034.117 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:14.118Z,1621354034.118 [DAT](INFO): DAT read: Bearing 70.6, -2.5 (Local) 2021-05-18T16:07:14.118Z,1621354034.118 [DAT](INFO): Local bearing/azimuth received: Bearing 70.6, -2.5 (Local) 2021-05-18T16:07:14.120Z,1621354034.120 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:14.125Z,1621354034.125 [DAT](INFO): DAT read: 16:06:46.1505 LVL= 32752, 32753, 32754, 32755, AGC= 68, IDX= 208, 0.05, 2.878, 2.598, 2.841, 2.800, PHS= 0.074,-0.158, 0.026, RAW= 138.7, 5.5, CAL= 139.4, 2.5, ROT= 70.6, -2.5 2021-05-18T16:07:14.126Z,1621354034.126 [DAT](INFO): got valid direction response: 16:06:46.1505 LVL= 32752, 32753, 32754, 32755, AGC= 68, IDX= 208, 0.05, 2.878, 2.598, 2.841, 2.800, PHS= 0.074,-0.158, 0.026, RAW= 138.7, 5.5, CAL= 139.4, 2.5, ROT= 70.6, -2.5 2021-05-18T16:07:14.126Z,1621354034.126 [DAT](INFO): #Rx 1: Read range and direction messages. 2021-05-18T16:07:14.160Z,1621354034.160 [DAT](INFO): direction in vehicle frame: [ 0.331845 forward, 0.942325 starboard, -0.043619 keelward ] 2021-05-18T16:07:14.160Z,1621354034.160 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:14.160Z,1621354034.160 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:14.172Z,1621354034.172 [DAT](INFO): checking for new query: numPingsReceived=1 elapsed TxPingTime=2.478565 2021-05-18T16:07:14.202Z,1621354034.202 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:14.211Z,1621354034.211 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.331845 forward, 0.942325 starboard, -0.043619 keelward ] 2021-05-18T16:07:14.211Z,1621354034.211 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:14.213Z,1621354034.213 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998884,-0.047160,-0.002611;0.047210,0.998574,0.024915;0.001433,-0.025011,0.999686 ] 2021-05-18T16:07:14.214Z,1621354034.214 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:14.214Z,1621354034.214 [lab_range_test:A.](INFO): direction in world frame: [ 0.375900 north, 0.926423 east, -0.020994 down ] 2021-05-18T16:07:14.223Z,1621354034.223 [lab_range_test:A.](INFO): relPosInFSK: [ 0.099554 forward, 0.282697 starboard, -0.013086 keelward ] 2021-05-18T16:07:14.224Z,1621354034.224 [lab_range_test:A.](INFO): relPosInNED: [ 0.112770 north, 0.277927 east, -0.006298 down ] 2021-05-18T16:07:14.225Z,1621354034.225 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:14.225Z,1621354034.225 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:14.532Z,1621354034.532 [DAT](INFO): DAT read: Rx Time:16:06:46.6505 2021-05-18T16:07:14.532Z,1621354034.532 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:14.534Z,1621354034.534 [DAT](INFO): DAT read: Bearing 69.6, -2.8 (Local) 2021-05-18T16:07:14.534Z,1621354034.534 [DAT](INFO): Local bearing/azimuth received: Bearing 69.6, -2.8 (Local) 2021-05-18T16:07:14.536Z,1621354034.536 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:14.541Z,1621354034.541 [DAT](INFO): DAT read: 16:06:46.6505 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 496, 0.17,-3.113, 2.913,-3.141, 3.102, PHS= 0.064,-0.145, 0.025, RAW= 139.9, 5.9, CAL= 140.4, 2.8, ROT= 69.6, -2.8 2021-05-18T16:07:14.542Z,1621354034.542 [DAT](INFO): got valid direction response: 16:06:46.6505 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 496, 0.17,-3.113, 2.913,-3.141, 3.102, PHS= 0.064,-0.145, 0.025, RAW= 139.9, 5.9, CAL= 140.4, 2.8, ROT= 69.6, -2.8 2021-05-18T16:07:14.543Z,1621354034.543 [DAT](INFO): #Rx 2: Read range and direction messages. 2021-05-18T16:07:14.544Z,1621354034.544 [DAT](INFO): direction in vehicle frame: [ 0.348156 forward, 0.936163 starboard, -0.048850 keelward ] 2021-05-18T16:07:14.544Z,1621354034.544 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:14.544Z,1621354034.544 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:14.547Z,1621354034.547 [DAT](INFO): checking for new query: numPingsReceived=2 elapsed TxPingTime=2.853643 2021-05-18T16:07:14.554Z,1621354034.554 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:14.555Z,1621354034.555 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.348156 forward, 0.936163 starboard, -0.048850 keelward ] 2021-05-18T16:07:14.555Z,1621354034.555 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:14.557Z,1621354034.557 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998960,-0.045516,-0.002742;0.045571,0.998648,0.025018;0.001600,-0.025117,0.999683 ] 2021-05-18T16:07:14.558Z,1621354034.558 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:14.558Z,1621354034.558 [lab_range_test:A.](INFO): direction in world frame: [ 0.390377 north, 0.920277 east, -0.026368 down ] 2021-05-18T16:07:14.559Z,1621354034.559 [lab_range_test:A.](INFO): relPosInFSK: [ 0.104447 forward, 0.280849 starboard, -0.014655 keelward ] 2021-05-18T16:07:14.560Z,1621354034.560 [lab_range_test:A.](INFO): relPosInNED: [ 0.117113 north, 0.276083 east, -0.007910 down ] 2021-05-18T16:07:14.560Z,1621354034.560 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:14.561Z,1621354034.561 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:15.048Z,1621354035.048 [DAT](INFO): DAT read: Rx Time:16:06:47.1504 2021-05-18T16:07:15.048Z,1621354035.048 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:15.050Z,1621354035.050 [DAT](INFO): DAT read: Bearing 69.7, -4.0 (Local) 2021-05-18T16:07:15.050Z,1621354035.050 [DAT](INFO): Local bearing/azimuth received: Bearing 69.7, -4.0 (Local) 2021-05-18T16:07:15.052Z,1621354035.052 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:15.057Z,1621354035.057 [DAT](INFO): DAT read: 16:06:47.1504 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 495, 0.32, 1.612, 1.326, 1.578, 1.539, PHS= 0.068,-0.169, 0.023, RAW= 139.7, 7.2, CAL= 140.3, 4.0, ROT= 69.7, -4.0 2021-05-18T16:07:15.058Z,1621354035.058 [DAT](INFO): got valid direction response: 16:06:47.1504 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 495, 0.32, 1.612, 1.326, 1.578, 1.539, PHS= 0.068,-0.169, 0.023, RAW= 139.7, 7.2, CAL= 140.3, 4.0, ROT= 69.7, -4.0 2021-05-18T16:07:15.058Z,1621354035.058 [DAT](INFO): #Rx 3: Read range and direction messages. 2021-05-18T16:07:15.059Z,1621354035.059 [DAT](INFO): direction in vehicle frame: [ 0.346091 forward, 0.935604 starboard, -0.069756 keelward ] 2021-05-18T16:07:15.060Z,1621354035.060 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:15.060Z,1621354035.060 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:15.063Z,1621354035.063 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.369120 2021-05-18T16:07:15.069Z,1621354035.069 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:15.070Z,1621354035.070 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.346091 forward, 0.935604 starboard, -0.069756 keelward ] 2021-05-18T16:07:15.071Z,1621354035.071 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:15.073Z,1621354035.073 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998922,-0.046323,-0.002872;0.046380,0.998613,0.024918;0.001714,-0.025024,0.999685 ] 2021-05-18T16:07:15.073Z,1621354035.073 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:07:15.074Z,1621354035.074 [lab_range_test:A.](INFO): direction in world frame: [ 0.388991 north, 0.920020 east, -0.047416 down ] 2021-05-18T16:07:15.075Z,1621354035.075 [lab_range_test:A.](INFO): relPosInFSK: [ 0.069218 forward, 0.187121 starboard, -0.013951 keelward ] 2021-05-18T16:07:15.076Z,1621354035.076 [lab_range_test:A.](INFO): relPosInNED: [ 0.077798 north, 0.184004 east, -0.009483 down ] 2021-05-18T16:07:15.076Z,1621354035.076 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:15.076Z,1621354035.076 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:15.355Z,1621354035.355 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.660675 2021-05-18T16:07:15.394Z,1621354035.394 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:15.774Z,1621354035.774 [DAT](INFO): DAT read: Rx Time:16:06:47.6505 2021-05-18T16:07:15.774Z,1621354035.774 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:15.804Z,1621354035.804 [DAT](INFO): DAT read: Bearing 68.1, -5.1 (Local) 2021-05-18T16:07:15.804Z,1621354035.804 [DAT](INFO): Local bearing/azimuth received: Bearing 68.1, -5.1 (Local) 2021-05-18T16:07:15.806Z,1621354035.806 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:15.813Z,1621354035.813 [DAT](INFO): DAT read: 16:06:47.6505 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 1,-0.44, 1.667, 1.346, 1.634, 1.593, PHS= 0.070,-0.203, 0.026, RAW= 141.4, 8.4, CAL= 141.9, 5.1, ROT= 68.1, -5.1 2021-05-18T16:07:15.814Z,1621354035.814 [DAT](INFO): got valid direction response: 16:06:47.6505 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 1,-0.44, 1.667, 1.346, 1.634, 1.593, PHS= 0.070,-0.203, 0.026, RAW= 141.4, 8.4, CAL= 141.9, 5.1, ROT= 68.1, -5.1 2021-05-18T16:07:15.815Z,1621354035.815 [DAT](INFO): #Rx 4: Read range and direction messages. 2021-05-18T16:07:15.857Z,1621354035.857 [DAT](INFO): direction in vehicle frame: [ 0.371511 forward, 0.924163 starboard, -0.088894 keelward ] 2021-05-18T16:07:15.858Z,1621354035.858 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:15.858Z,1621354035.858 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:15.881Z,1621354035.881 [DAT](INFO): checking for new query: numPingsReceived=4 elapsed TxPingTime=4.187637 2021-05-18T16:07:15.913Z,1621354035.913 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:15.914Z,1621354035.914 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.371511 forward, 0.924163 starboard, -0.088894 keelward ] 2021-05-18T16:07:15.915Z,1621354035.915 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:15.925Z,1621354035.925 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998944,-0.045860,-0.002795;0.045916,0.998634,0.024954;0.001647,-0.025056,0.999685 ] 2021-05-18T16:07:15.925Z,1621354035.925 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:15.926Z,1621354035.926 [lab_range_test:A.](INFO): direction in world frame: [ 0.413406 north, 0.908090 east, -0.066843 down ] 2021-05-18T16:07:15.935Z,1621354035.935 [lab_range_test:A.](INFO): relPosInFSK: [ 0.111453 forward, 0.277249 starboard, -0.026668 keelward ] 2021-05-18T16:07:15.936Z,1621354035.936 [lab_range_test:A.](INFO): relPosInNED: [ 0.124022 north, 0.272427 east, -0.020053 down ] 2021-05-18T16:07:15.936Z,1621354035.936 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:15.936Z,1621354035.936 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:16.173Z,1621354036.173 [DAT](INFO): DAT read: Rx Time:16:06:48.1505 2021-05-18T16:07:16.174Z,1621354036.174 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:16.175Z,1621354036.175 [DAT](INFO): DAT read: Bearing 67.1, -6.7 (Local) 2021-05-18T16:07:16.175Z,1621354036.175 [DAT](INFO): Local bearing/azimuth received: Bearing 67.1, -6.7 (Local) 2021-05-18T16:07:16.177Z,1621354036.177 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:16.182Z,1621354036.182 [DAT](INFO): DAT read: 16:06:48.1505 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.26, 0.129,-0.210, 0.098, 0.060, PHS= 0.065,-0.226, 0.024, RAW= 142.4, 10.1, CAL= 142.9, 6.7, ROT= 67.1, -6.7 2021-05-18T16:07:16.183Z,1621354036.183 [DAT](INFO): got valid direction response: 16:06:48.1505 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.26, 0.129,-0.210, 0.098, 0.060, PHS= 0.065,-0.226, 0.024, RAW= 142.4, 10.1, CAL= 142.9, 6.7, ROT= 67.1, -6.7 2021-05-18T16:07:16.184Z,1621354036.184 [DAT](INFO): #Rx 5: Read range and direction messages. 2021-05-18T16:07:16.185Z,1621354036.185 [DAT](INFO): direction in vehicle frame: [ 0.386467 forward, 0.914894 starboard, -0.116671 keelward ] 2021-05-18T16:07:16.185Z,1621354036.185 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:16.185Z,1621354036.185 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:16.188Z,1621354036.188 [DAT](INFO): checking for new query: numPingsReceived=5 elapsed TxPingTime=4.494644 2021-05-18T16:07:16.195Z,1621354036.195 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:16.196Z,1621354036.196 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.386467 forward, 0.914894 starboard, -0.116671 keelward ] 2021-05-18T16:07:16.196Z,1621354036.196 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:16.198Z,1621354036.198 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998891,-0.046988,-0.002816;0.047044,0.998584,0.024841;0.001644,-0.024946,0.999687 ] 2021-05-18T16:07:16.198Z,1621354036.198 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:16.199Z,1621354036.199 [lab_range_test:A.](INFO): direction in world frame: [ 0.428887 north, 0.898350 east, -0.094996 down ] 2021-05-18T16:07:16.200Z,1621354036.200 [lab_range_test:A.](INFO): relPosInFSK: [ 0.115940 forward, 0.274468 starboard, -0.035001 keelward ] 2021-05-18T16:07:16.201Z,1621354036.201 [lab_range_test:A.](INFO): relPosInNED: [ 0.128666 north, 0.269505 east, -0.028499 down ] 2021-05-18T16:07:16.201Z,1621354036.201 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:16.201Z,1621354036.201 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:16.539Z,1621354036.539 [DAT](INFO): DAT read: Rx Time:16:06:48.6505 2021-05-18T16:07:16.539Z,1621354036.539 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:16.541Z,1621354036.541 [DAT](INFO): DAT read: Bearing 67.1, -7.1 (Local) 2021-05-18T16:07:16.541Z,1621354036.541 [DAT](INFO): Local bearing/azimuth received: Bearing 67.1, -7.1 (Local) 2021-05-18T16:07:16.543Z,1621354036.543 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:16.552Z,1621354036.552 [DAT](INFO): DAT read: 16:06:48.6505 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.12,-0.185,-0.536,-0.217,-0.255, PHS= 0.066,-0.237, 0.023, RAW= 142.4, 10.4, CAL= 142.9, 7.1, ROT= 67.1, -7.1 2021-05-18T16:07:16.553Z,1621354036.553 [DAT](INFO): got valid direction response: 16:06:48.6505 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.12,-0.185,-0.536,-0.217,-0.255, PHS= 0.066,-0.237, 0.023, RAW= 142.4, 10.4, CAL= 142.9, 7.1, ROT= 67.1, -7.1 2021-05-18T16:07:16.554Z,1621354036.554 [DAT](INFO): #Rx 6: Read range and direction messages. 2021-05-18T16:07:16.555Z,1621354036.555 [DAT](INFO): direction in vehicle frame: [ 0.386140 forward, 0.914122 starboard, -0.123601 keelward ] 2021-05-18T16:07:16.559Z,1621354036.559 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:16.559Z,1621354036.559 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:16.562Z,1621354036.562 [DAT](INFO): checking for new query: numPingsReceived=6 elapsed TxPingTime=4.868578 2021-05-18T16:07:16.601Z,1621354036.601 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:16.602Z,1621354036.602 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.386140 forward, 0.914122 starboard, -0.123601 keelward ] 2021-05-18T16:07:16.602Z,1621354036.602 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:16.625Z,1621354036.625 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998899,-0.046820,-0.002799;0.046876,0.998591,0.024858;0.001632,-0.024962,0.999687 ] 2021-05-18T16:07:16.625Z,1621354036.625 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:16.626Z,1621354036.626 [lab_range_test:A.](INFO): direction in world frame: [ 0.428363 north, 0.897840 east, -0.101920 down ] 2021-05-18T16:07:16.627Z,1621354036.627 [lab_range_test:A.](INFO): relPosInFSK: [ 0.115842 forward, 0.274237 starboard, -0.037080 keelward ] 2021-05-18T16:07:16.640Z,1621354036.640 [lab_range_test:A.](INFO): relPosInNED: [ 0.128509 north, 0.269352 east, -0.030576 down ] 2021-05-18T16:07:16.640Z,1621354036.640 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:16.640Z,1621354036.640 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:16.942Z,1621354036.942 [DAT](INFO): DAT read: Rx Time:16:06:49.1504 2021-05-18T16:07:16.943Z,1621354036.943 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:16.944Z,1621354036.944 [DAT](INFO): DAT read: Bearing 66.1, -7.1 (Local) 2021-05-18T16:07:16.944Z,1621354036.944 [DAT](INFO): Local bearing/azimuth received: Bearing 66.1, -7.1 (Local) 2021-05-18T16:07:16.946Z,1621354036.946 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:16.955Z,1621354036.955 [DAT](INFO): DAT read: 16:06:49.1504 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.00,-0.306,-0.606,-0.326,-0.363, PHS= 0.053,-0.199, 0.021, RAW= 143.5, 10.5, CAL= 143.9, 7.1, ROT= 66.1, -7.1 2021-05-18T16:07:16.956Z,1621354036.956 [DAT](INFO): got valid direction response: 16:06:49.1504 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.00,-0.306,-0.606,-0.326,-0.363, PHS= 0.053,-0.199, 0.021, RAW= 143.5, 10.5, CAL= 143.9, 7.1, ROT= 66.1, -7.1 2021-05-18T16:07:16.957Z,1621354036.957 [DAT](INFO): #Rx 7: Read range and direction messages. 2021-05-18T16:07:16.958Z,1621354036.958 [DAT](INFO): direction in vehicle frame: [ 0.402035 forward, 0.907243 starboard, -0.123601 keelward ] 2021-05-18T16:07:16.958Z,1621354036.958 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:16.958Z,1621354036.958 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:16.998Z,1621354036.998 [DAT](INFO): checking for new query: numPingsReceived=7 elapsed TxPingTime=5.304082 2021-05-18T16:07:17.013Z,1621354037.013 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:17.014Z,1621354037.014 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.402035 forward, 0.907243 starboard, -0.123601 keelward ] 2021-05-18T16:07:17.014Z,1621354037.014 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:17.036Z,1621354037.036 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998949,-0.045760,-0.002809;0.045816,0.998637,0.024998;0.001662,-0.025100,0.999684 ] 2021-05-18T16:07:17.036Z,1621354037.036 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:07:17.037Z,1621354037.037 [lab_range_test:A.](INFO): direction in world frame: [ 0.442973 north, 0.890712 east, -0.102013 down ] 2021-05-18T16:07:17.037Z,1621354037.037 [lab_range_test:A.](INFO): relPosInFSK: [ 0.080407 forward, 0.181449 starboard, -0.024720 keelward ] 2021-05-18T16:07:17.038Z,1621354037.038 [lab_range_test:A.](INFO): relPosInNED: [ 0.088595 north, 0.178142 east, -0.020403 down ] 2021-05-18T16:07:17.038Z,1621354037.038 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:17.039Z,1621354037.039 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:17.342Z,1621354037.342 [DAT](INFO): checking for new query: numPingsReceived=7 elapsed TxPingTime=5.648634 2021-05-18T16:07:17.410Z,1621354037.410 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:17.752Z,1621354037.752 [DAT](INFO): DAT read: Rx Time:16:06:49.6505 2021-05-18T16:07:17.752Z,1621354037.752 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:17.753Z,1621354037.753 [DAT](INFO): DAT read: Bearing 69.7, -7.9 (Local) 2021-05-18T16:07:17.754Z,1621354037.754 [DAT](INFO): Local bearing/azimuth received: Bearing 69.7, -7.9 (Local) 2021-05-18T16:07:17.756Z,1621354037.756 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:17.761Z,1621354037.761 [DAT](INFO): DAT read: 16:06:49.6505 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 0, 0.66, 1.927, 1.364, 1.841, 1.807, PHS= 0.117,-0.399, 0.019, RAW= 139.7, 11.1, CAL= 140.3, 7.9, ROT= 69.7, -7.9 2021-05-18T16:07:17.762Z,1621354037.762 [DAT](INFO): got valid direction response: 16:06:49.6505 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 0, 0.66, 1.927, 1.364, 1.841, 1.807, PHS= 0.117,-0.399, 0.019, RAW= 139.7, 11.1, CAL= 140.3, 7.9, ROT= 69.7, -7.9 2021-05-18T16:07:17.762Z,1621354037.762 [DAT](INFO): #Rx 8: Read range and direction messages. 2021-05-18T16:07:17.764Z,1621354037.764 [DAT](INFO): direction in vehicle frame: [ 0.343643 forward, 0.928988 starboard, -0.137445 keelward ] 2021-05-18T16:07:17.764Z,1621354037.764 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:17.764Z,1621354037.764 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:17.767Z,1621354037.767 [DAT](INFO): checking for new query: numPingsReceived=8 elapsed TxPingTime=6.073829 2021-05-18T16:07:17.814Z,1621354037.814 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:17.820Z,1621354037.820 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.343643 forward, 0.928988 starboard, -0.137445 keelward ] 2021-05-18T16:07:17.820Z,1621354037.820 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:17.822Z,1621354037.822 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998930,-0.046156,-0.002775;0.046211,0.998620,0.024970;0.001619,-0.025072,0.999684 ] 2021-05-18T16:07:17.822Z,1621354037.822 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:17.844Z,1621354037.844 [lab_range_test:A.](INFO): direction in world frame: [ 0.385982 north, 0.915290 east, -0.115158 down ] 2021-05-18T16:07:17.846Z,1621354037.846 [lab_range_test:A.](INFO): relPosInFSK: [ 0.103093 forward, 0.278696 starboard, -0.041233 keelward ] 2021-05-18T16:07:17.856Z,1621354037.856 [lab_range_test:A.](INFO): relPosInNED: [ 0.115795 north, 0.274587 east, -0.034547 down ] 2021-05-18T16:07:17.857Z,1621354037.857 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:17.857Z,1621354037.857 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:18.154Z,1621354038.154 [DAT](INFO): DAT read: Rx Time:16:06:50.1504 2021-05-18T16:07:18.155Z,1621354038.155 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:18.156Z,1621354038.156 [DAT](INFO): DAT read: Bearing 68.5, -5.2 (Local) 2021-05-18T16:07:18.156Z,1621354038.156 [DAT](INFO): Local bearing/azimuth received: Bearing 68.5, -5.2 (Local) 2021-05-18T16:07:18.158Z,1621354038.158 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:18.163Z,1621354038.163 [DAT](INFO): DAT read: 16:06:50.1504 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.24, 1.051, 0.793, 1.027, 0.992, PHS= 0.054,-0.155, 0.019, RAW= 141.0, 8.4, CAL= 141.5, 5.2, ROT= 68.5, -5.2 2021-05-18T16:07:18.164Z,1621354038.164 [DAT](INFO): got valid direction response: 16:06:50.1504 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.24, 1.051, 0.793, 1.027, 0.992, PHS= 0.054,-0.155, 0.019, RAW= 141.0, 8.4, CAL= 141.5, 5.2, ROT= 68.5, -5.2 2021-05-18T16:07:18.165Z,1621354038.165 [DAT](INFO): #Rx 9: Read range and direction messages. 2021-05-18T16:07:18.166Z,1621354038.166 [DAT](INFO): direction in vehicle frame: [ 0.364993 forward, 0.926588 starboard, -0.090633 keelward ] 2021-05-18T16:07:18.166Z,1621354038.166 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:18.166Z,1621354038.166 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:18.169Z,1621354038.169 [DAT](INFO): checking for new query: numPingsReceived=9 elapsed TxPingTime=6.475844 2021-05-18T16:07:18.208Z,1621354038.208 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:18.209Z,1621354038.209 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.364993 forward, 0.926588 starboard, -0.090633 keelward ] 2021-05-18T16:07:18.210Z,1621354038.210 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:18.240Z,1621354038.240 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998895,-0.046925,-0.002666;0.046977,0.998585,0.024910;0.001494,-0.025007,0.999686 ] 2021-05-18T16:07:18.240Z,1621354038.240 [lab_range_test:A.](INFO): rangeToContact_ = 0.200000 m 2021-05-18T16:07:18.241Z,1621354038.241 [lab_range_test:A.](INFO): direction in world frame: [ 0.407982 north, 0.910417 east, -0.068496 down ] 2021-05-18T16:07:18.242Z,1621354038.242 [lab_range_test:A.](INFO): relPosInFSK: [ 0.072999 forward, 0.185318 starboard, -0.018127 keelward ] 2021-05-18T16:07:18.242Z,1621354038.242 [lab_range_test:A.](INFO): relPosInNED: [ 0.081596 north, 0.182083 east, -0.013699 down ] 2021-05-18T16:07:18.251Z,1621354038.251 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:18.251Z,1621354038.251 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:18.578Z,1621354038.578 [DAT](INFO): DAT read: Rx Time:16:06:50.6505 2021-05-18T16:07:18.578Z,1621354038.578 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:18.580Z,1621354038.580 [DAT](INFO): DAT read: Bearing 66.8, -7.2 (Local) 2021-05-18T16:07:18.580Z,1621354038.580 [DAT](INFO): Local bearing/azimuth received: Bearing 66.8, -7.2 (Local) 2021-05-18T16:07:18.582Z,1621354038.582 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:18.586Z,1621354038.586 [DAT](INFO): DAT read: 16:06:50.6505 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 0, 0.51, 0.444, 0.125, 0.418, 0.382, PHS= 0.058,-0.213, 0.021, RAW= 142.7, 10.5, CAL= 143.2, 7.2, ROT= 66.8, -7.2 2021-05-18T16:07:18.588Z,1621354038.588 [DAT](INFO): got valid direction response: 16:06:50.6505 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 0, 0.51, 0.444, 0.125, 0.418, 0.382, PHS= 0.058,-0.213, 0.021, RAW= 142.7, 10.5, CAL= 143.2, 7.2, ROT= 66.8, -7.2 2021-05-18T16:07:18.588Z,1621354038.588 [DAT](INFO): #Rx 10: Read range and direction messages. 2021-05-18T16:07:18.589Z,1621354038.589 [DAT](INFO): direction in vehicle frame: [ 0.390836 forward, 0.911888 starboard, -0.125333 keelward ] 2021-05-18T16:07:18.590Z,1621354038.590 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:18.590Z,1621354038.590 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:18.599Z,1621354038.599 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:18.600Z,1621354038.600 [lab_range_test:A.](INFO): direction in vehicle frame: [ 0.390836 forward, 0.911888 starboard, -0.125333 keelward ] 2021-05-18T16:07:18.600Z,1621354038.600 [lab_range_test:A.](DEBUG): processing response from DAT 2021-05-18T16:07:18.602Z,1621354038.602 [lab_range_test:A.](INFO): rotationFromVehicleToNavigationFrame_ = [ 0.998955,-0.045632,-0.002658;0.045685,0.998642,0.025022;0.001512,-0.025117,0.999683 ] 2021-05-18T16:07:18.603Z,1621354038.603 [lab_range_test:A.](INFO): rangeToContact_ = 0.300000 m 2021-05-18T16:07:18.604Z,1621354038.604 [lab_range_test:A.](INFO): direction in world frame: [ 0.431897 north, 0.895963 east, -0.103515 down ] 2021-05-18T16:07:18.605Z,1621354038.605 [lab_range_test:A.](INFO): relPosInFSK: [ 0.117251 forward, 0.273566 starboard, -0.037600 keelward ] 2021-05-18T16:07:18.605Z,1621354038.605 [lab_range_test:A.](INFO): relPosInNED: [ 0.129569 north, 0.268789 east, -0.031055 down ] 2021-05-18T16:07:18.606Z,1621354038.606 [lab_range_test:A.](DEBUG): Combining 10 samples. 2021-05-18T16:07:18.606Z,1621354038.606 [lab_range_test:A.](DEBUG): Could not read vehicle position; cannot calculate contact position. 2021-05-18T16:07:18.996Z,1621354038.996 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:19.393Z,1621354039.393 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:19.782Z,1621354039.782 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:20.180Z,1621354040.180 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:20.589Z,1621354040.589 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:20.988Z,1621354040.988 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:21.417Z,1621354041.417 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:21.821Z,1621354041.821 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:22.211Z,1621354042.211 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:22.608Z,1621354042.608 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:23.014Z,1621354043.014 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:23.426Z,1621354043.426 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:23.822Z,1621354043.822 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:23.822Z,1621354043.822 [lab_range_test:A.](INFO): update period (5.000000 s) has elapsed, querying... 2021-05-18T16:07:23.822Z,1621354043.822 [lab_range_test:A.](INFO): *** querying DAT *** 2021-05-18T16:07:24.229Z,1621354044.229 [DAT](INFO): ****** received valid address query ****** 2021-05-18T16:07:24.229Z,1621354044.229 [DAT](INFO): ****** received valid ping request ****** 2021-05-18T16:07:24.229Z,1621354044.229 [DAT](INFO): Querying Benthos address 50 with 10 pings in terminal homing one-way mode. 2021-05-18T16:07:24.231Z,1621354044.231 [DAT](INFO): ****** ping requested ****** 2021-05-18T16:07:24.285Z,1621354044.285 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:24.637Z,1621354044.637 [DAT](INFO): DAT read: user:12> 2021-05-18T16:07:24.638Z,1621354044.638 [DAT](INFO): DAT read: Tx time:16:06:56.9708 2021-05-18T16:07:24.638Z,1621354044.638 [DAT](INFO): Ping request sent. 2021-05-18T16:07:24.638Z,1621354044.638 [DAT](INFO): transmitted an acoustic signal 2021-05-18T16:07:24.639Z,1621354044.639 [DAT](INFO): publishing transmit ping time 2021-05-18T16:07:24.639Z,1621354044.639 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.001248 2021-05-18T16:07:24.646Z,1621354044.646 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:25.033Z,1621354045.033 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.394332 2021-05-18T16:07:25.067Z,1621354045.067 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:25.432Z,1621354045.432 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=0.793342 2021-05-18T16:07:25.484Z,1621354045.484 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:25.839Z,1621354045.839 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.201137 2021-05-18T16:07:25.846Z,1621354045.846 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:26.252Z,1621354046.252 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=1.613890 2021-05-18T16:07:26.265Z,1621354046.265 [lab_range_test:A.](DEBUG): Tracking... 2021-05-18T16:07:26.653Z,1621354046.653 [DAT](INFO): checking for new query: numPingsReceived=0 elapsed TxPingTime=2.014780 2021-05-18T16:07:26.684Z,1621354046.684 [lab_range_test](INFO): Timed out from 2021-05-18T16:05:26.3Z 2021-05-18T16:07:26.684Z,1621354046.684 [MissionManager](INFO): lab_range_test is completed. 2021-05-18T16:07:26.684Z,1621354046.684 [MissionManager](INFO): Uninitializing Mission lab_range_test 2021-05-18T16:07:26.684Z,1621354046.684 [lab_range_test] Stopped 2021-05-18T16:07:26.684Z,1621354046.684 [lab_range_test](DEBUG): Aggregate::uninitialize lab_range_test 2021-05-18T16:07:26.684Z,1621354046.684 [lab_range_test:A.] Stopped 2021-05-18T16:07:26.684Z,1621354046.684 [lab_range_test:A.](DEBUG): Uninitializing Tracking. 2021-05-18T16:07:26.684Z,1621354046.684 [lab_range_test:B.Wait] Stopped 2021-05-18T16:07:26.685Z,1621354046.685 [lab_range_test:B.Wait](DEBUG): Uninitialize Wait Component. 2021-05-18T16:07:27.057Z,1621354047.057 [DAT](INFO): DAT read: Rx Time:16:06:59.1004 2021-05-18T16:07:27.058Z,1621354047.058 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:27.059Z,1621354047.059 [DAT](INFO): DAT read: Bearing 65.4, -6.9 (Local) 2021-05-18T16:07:27.059Z,1621354047.059 [DAT](INFO): Local bearing/azimuth received: Bearing 65.4, -6.9 (Local) 2021-05-18T16:07:27.061Z,1621354047.061 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:27.066Z,1621354047.066 [DAT](INFO): DAT read: 16:06:59.1004 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 209,-0.39, 2.942, 2.633, 2.924, 2.884, PHS= 0.054,-0.207, 0.025, RAW= 144.1, 10.3, CAL= 144.6, 6.9, ROT= 65.4, -6.9 2021-05-18T16:07:27.067Z,1621354047.067 [DAT](INFO): got valid direction response: 16:06:59.1004 LVL= 32752, 32753, 32754, 32755, AGC= 69, IDX= 209,-0.39, 2.942, 2.633, 2.924, 2.884, PHS= 0.054,-0.207, 0.025, RAW= 144.1, 10.3, CAL= 144.6, 6.9, ROT= 65.4, -6.9 2021-05-18T16:07:27.068Z,1621354047.068 [DAT](INFO): #Rx 1: Read range and direction messages. 2021-05-18T16:07:27.069Z,1621354047.069 [DAT](INFO): direction in vehicle frame: [ 0.413266 forward, 0.902651 starboard, -0.120137 keelward ] 2021-05-18T16:07:27.069Z,1621354047.069 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:27.069Z,1621354047.069 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:27.072Z,1621354047.072 [DAT](INFO): checking for new query: numPingsReceived=1 elapsed TxPingTime=2.434280 2021-05-18T16:07:27.111Z,1621354047.111 [MissionManager](IMPORTANT): Started mission Default 2021-05-18T16:07:27.112Z,1621354047.112 [Default] Running Loop=1 2021-05-18T16:07:27.112Z,1621354047.112 [Default](DEBUG): Aggregate::initialize Default 2021-05-18T16:07:27.112Z,1621354047.112 [Default:B.GoToSurface] Running Loop=1 2021-05-18T16:07:27.112Z,1621354047.112 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2021-05-18T16:07:27.112Z,1621354047.112 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2021-05-18T16:07:27.112Z,1621354047.112 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2021-05-18T16:07:27.113Z,1621354047.113 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2021-05-18T16:07:27.113Z,1621354047.113 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2021-05-18T16:07:27.113Z,1621354047.113 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2021-05-18T16:07:27.114Z,1621354047.114 [Default:A.Wait] Running Loop=1 2021-05-18T16:07:27.114Z,1621354047.114 [Default:A.Wait](DEBUG): Initialize Wait Component. 2021-05-18T16:07:27.448Z,1621354047.448 [DAT](INFO): DAT read: Rx Time:16:06:59.6004 2021-05-18T16:07:27.448Z,1621354047.448 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:27.449Z,1621354047.449 [DAT](INFO): DAT read: Bearing 65.3, -7.3 (Local) 2021-05-18T16:07:27.449Z,1621354047.449 [DAT](INFO): Local bearing/azimuth received: Bearing 65.3, -7.3 (Local) 2021-05-18T16:07:27.452Z,1621354047.452 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:27.457Z,1621354047.457 [DAT](INFO): DAT read: 16:06:59.6004 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 496,-0.22, 1.398, 1.069, 1.378, 1.338, PHS= 0.056,-0.224, 0.025, RAW= 144.2, 10.7, CAL= 144.7, 7.3, ROT= 65.3, -7.3 2021-05-18T16:07:27.458Z,1621354047.458 [DAT](INFO): got valid direction response: 16:06:59.6004 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 496,-0.22, 1.398, 1.069, 1.378, 1.338, PHS= 0.056,-0.224, 0.025, RAW= 144.2, 10.7, CAL= 144.7, 7.3, ROT= 65.3, -7.3 2021-05-18T16:07:27.459Z,1621354047.459 [DAT](INFO): #Rx 2: Read range and direction messages. 2021-05-18T16:07:27.460Z,1621354047.460 [DAT](INFO): direction in vehicle frame: [ 0.414480 forward, 0.901144 starboard, -0.127065 keelward ] 2021-05-18T16:07:27.460Z,1621354047.460 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:27.460Z,1621354047.460 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:27.463Z,1621354047.463 [DAT](INFO): checking for new query: numPingsReceived=2 elapsed TxPingTime=2.825137 2021-05-18T16:07:27.872Z,1621354047.872 [DAT](INFO): DAT read: Rx Time:16:07:00.1004 2021-05-18T16:07:27.873Z,1621354047.873 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:27.874Z,1621354047.874 [DAT](INFO): DAT read: Bearing 67.9, -5.4 (Local) 2021-05-18T16:07:27.874Z,1621354047.874 [DAT](INFO): Local bearing/azimuth received: Bearing 67.9, -5.4 (Local) 2021-05-18T16:07:27.881Z,1621354047.881 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:27.890Z,1621354047.890 [DAT](INFO): DAT read: 16:07:00.1004 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.09, 1.724, 1.384, 1.689, 1.646, PHS= 0.074,-0.219, 0.028, RAW= 141.6, 8.7, CAL= 142.1, 5.4, ROT= 67.9, -5.4 2021-05-18T16:07:27.895Z,1621354047.895 [DAT](INFO): got valid direction response: 16:07:00.1004 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.09, 1.724, 1.384, 1.689, 1.646, PHS= 0.074,-0.219, 0.028, RAW= 141.6, 8.7, CAL= 142.1, 5.4, ROT= 67.9, -5.4 2021-05-18T16:07:27.896Z,1621354047.896 [DAT](INFO): #Rx 3: Read range and direction messages. 2021-05-18T16:07:27.897Z,1621354047.897 [DAT](INFO): direction in vehicle frame: [ 0.374555 forward, 0.922417 starboard, -0.094108 keelward ] 2021-05-18T16:07:27.897Z,1621354047.897 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:27.897Z,1621354047.897 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:27.904Z,1621354047.904 [DAT](INFO): checking for new query: numPingsReceived=3 elapsed TxPingTime=3.265945 2021-05-18T16:07:28.534Z,1621354048.534 [DAT](INFO): DAT read: Rx Time:16:07:00.6003 2021-05-18T16:07:28.534Z,1621354048.534 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:28.536Z,1621354048.536 [DAT](INFO): DAT read: Bearing 67.1, -5.8 (Local) 2021-05-18T16:07:28.536Z,1621354048.536 [DAT](INFO): Local bearing/azimuth received: Bearing 67.1, -5.8 (Local) 2021-05-18T16:07:28.538Z,1621354048.538 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:28.542Z,1621354048.542 [DAT](INFO): DAT read: 16:07:00.6003 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.02, 1.606, 1.322, 1.583, 1.546, PHS= 0.056,-0.180, 0.023, RAW= 142.5, 9.2, CAL= 142.9, 5.8, ROT= 67.1, -5.8 2021-05-18T16:07:28.544Z,1621354048.544 [DAT](INFO): got valid direction response: 16:07:00.6003 LVL= 32752, 32753, 32754, 32755, AGC= 67, IDX= 495, 0.02, 1.606, 1.322, 1.583, 1.546, PHS= 0.056,-0.180, 0.023, RAW= 142.5, 9.2, CAL= 142.9, 5.8, ROT= 67.1, -5.8 2021-05-18T16:07:28.544Z,1621354048.544 [DAT](INFO): #Rx 4: Read range and direction messages. 2021-05-18T16:07:28.548Z,1621354048.548 [DAT](INFO): direction in vehicle frame: [ 0.387132 forward, 0.916470 starboard, -0.101056 keelward ] 2021-05-18T16:07:28.550Z,1621354048.550 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:28.550Z,1621354048.550 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:28.557Z,1621354048.557 [DAT](INFO): checking for new query: numPingsReceived=4 elapsed TxPingTime=3.918932 2021-05-18T16:07:28.873Z,1621354048.873 [DAT](INFO): DAT read: Rx Time:16:07:01.1004 2021-05-18T16:07:28.874Z,1621354048.874 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:28.875Z,1621354048.875 [DAT](INFO): DAT read: Bearing 67.0, -8.6 (Local) 2021-05-18T16:07:28.875Z,1621354048.875 [DAT](INFO): Local bearing/azimuth received: Bearing 67.0, -8.6 (Local) 2021-05-18T16:07:28.877Z,1621354048.877 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:28.894Z,1621354048.894 [DAT](INFO): DAT read: 16:07:01.1004 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.59,-1.764,-2.246,-1.814,-1.852, PHS= 0.084,-0.350, 0.023, RAW= 142.5, 11.9, CAL= 143.0, 8.6, ROT= 67.0, -8.6 2021-05-18T16:07:28.903Z,1621354048.903 [DAT](INFO): got valid direction response: 16:07:01.1004 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.59,-1.764,-2.246,-1.814,-1.852, PHS= 0.084,-0.350, 0.023, RAW= 142.5, 11.9, CAL= 143.0, 8.6, ROT= 67.0, -8.6 2021-05-18T16:07:28.904Z,1621354048.904 [DAT](INFO): #Rx 5: Read range and direction messages. 2021-05-18T16:07:28.905Z,1621354048.905 [DAT](INFO): direction in vehicle frame: [ 0.386338 forward, 0.910155 starboard, -0.149535 keelward ] 2021-05-18T16:07:28.905Z,1621354048.905 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:28.905Z,1621354048.905 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:28.916Z,1621354048.916 [DAT](INFO): checking for new query: numPingsReceived=5 elapsed TxPingTime=4.278138 2021-05-18T16:07:29.153Z,1621354049.153 [DAT](INFO): checking for new query: numPingsReceived=5 elapsed TxPingTime=4.514958 2021-05-18T16:07:29.553Z,1621354049.553 [DAT](INFO): DAT read: Rx Time:16:07:01.6002 2021-05-18T16:07:29.554Z,1621354049.554 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:29.555Z,1621354049.555 [DAT](INFO): DAT read: Bearing 70.4, -3.4 (Local) 2021-05-18T16:07:29.555Z,1621354049.555 [DAT](INFO): Local bearing/azimuth received: Bearing 70.4, -3.4 (Local) 2021-05-18T16:07:29.557Z,1621354049.557 [DAT](INFO): DAT read: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:07:29.558Z,1621354049.558 [DAT](INFO): unknown deviceResponse_: Range 7 to 50 : 0.0 m (trip time 0.0 ms) speed 0.0 2021-05-18T16:07:29.566Z,1621354049.566 [DAT](INFO): DAT read: 16:07:01.6002 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 495, 0.27, 2.250, 1.961, 2.212, 2.173, PHS= 0.073,-0.168, 0.024, RAW= 138.9, 6.5, CAL= 139.6, 3.4, ROT= 70.4, -3.4 2021-05-18T16:07:29.572Z,1621354049.572 [DAT](INFO): got valid direction response: 16:07:01.6002 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 495, 0.27, 2.250, 1.961, 2.212, 2.173, PHS= 0.073,-0.168, 0.024, RAW= 138.9, 6.5, CAL= 139.6, 3.4, ROT= 70.4, -3.4 2021-05-18T16:07:29.573Z,1621354049.573 [DAT](INFO): #Rx 6: Read direction message, but no range. 2021-05-18T16:07:29.574Z,1621354049.574 [DAT](INFO): direction in vehicle frame: [ 0.334861 forward, 0.940399 starboard, -0.059306 keelward ] 2021-05-18T16:07:29.574Z,1621354049.574 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:29.581Z,1621354049.581 [DAT](INFO): checking for new query: numPingsReceived=6 elapsed TxPingTime=4.942842 2021-05-18T16:07:29.934Z,1621354049.934 [DAT](INFO): DAT read: Rx Time:16:07:02.1003 2021-05-18T16:07:29.935Z,1621354049.935 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:29.936Z,1621354049.936 [DAT](INFO): DAT read: Bearing 66.1, -6.6 (Local) 2021-05-18T16:07:29.936Z,1621354049.936 [DAT](INFO): Local bearing/azimuth received: Bearing 66.1, -6.6 (Local) 2021-05-18T16:07:29.938Z,1621354049.938 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:29.951Z,1621354049.951 [DAT](INFO): DAT read: 16:07:02.1003 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.51, 2.320, 2.016, 2.299, 2.260, PHS= 0.056,-0.200, 0.024, RAW= 143.5, 10.0, CAL= 143.9, 6.6, ROT= 66.1, -6.6 2021-05-18T16:07:29.952Z,1621354049.952 [DAT](INFO): got valid direction response: 16:07:02.1003 LVL= 32752, 32753, 32754, 32755, AGC= 70, IDX= 0, 0.51, 2.320, 2.016, 2.299, 2.260, PHS= 0.056,-0.200, 0.024, RAW= 143.5, 10.0, CAL= 143.9, 6.6, ROT= 66.1, -6.6 2021-05-18T16:07:29.953Z,1621354049.953 [DAT](INFO): #Rx 7: Read range and direction messages. 2021-05-18T16:07:29.954Z,1621354049.954 [DAT](INFO): direction in vehicle frame: [ 0.402457 forward, 0.908195 starboard, -0.114937 keelward ] 2021-05-18T16:07:29.954Z,1621354049.954 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:29.954Z,1621354049.954 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:29.961Z,1621354049.961 [DAT](INFO): checking for new query: numPingsReceived=7 elapsed TxPingTime=5.323099 2021-05-18T16:07:30.339Z,1621354050.339 [DAT](INFO): DAT read: Rx Time:16:07:02.6003 2021-05-18T16:07:30.340Z,1621354050.340 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:30.342Z,1621354050.342 [DAT](INFO): DAT read: Bearing 66.9, -7.1 (Local) 2021-05-18T16:07:30.343Z,1621354050.343 [DAT](INFO): Local bearing/azimuth received: Bearing 66.9, -7.1 (Local) 2021-05-18T16:07:30.405Z,1621354050.405 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:30.422Z,1621354050.422 [DAT](INFO): DAT read: 16:07:02.6003 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.30, 0.040,-0.322, 0.007,-0.032, PHS= 0.068,-0.246, 0.024, RAW= 142.6, 10.5, CAL= 143.1, 7.1, ROT= 66.9, -7.1 2021-05-18T16:07:30.451Z,1621354050.451 [DAT](INFO): got valid direction response: 16:07:02.6003 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.30, 0.040,-0.322, 0.007,-0.032, PHS= 0.068,-0.246, 0.024, RAW= 142.6, 10.5, CAL= 143.1, 7.1, ROT= 66.9, -7.1 2021-05-18T16:07:30.464Z,1621354050.464 [DAT](INFO): #Rx 8: Read range and direction messages. 2021-05-18T16:07:30.464Z,1621354050.464 [DAT](INFO): direction in vehicle frame: [ 0.389329 forward, 0.912768 starboard, -0.123601 keelward ] 2021-05-18T16:07:30.465Z,1621354050.465 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:30.465Z,1621354050.465 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:30.480Z,1621354050.480 [DAT](INFO): checking for new query: numPingsReceived=8 elapsed TxPingTime=5.841905 2021-05-18T16:07:30.732Z,1621354050.732 [DAT](INFO): checking for new query: numPingsReceived=8 elapsed TxPingTime=6.093433 2021-05-18T16:07:31.135Z,1621354051.135 [DAT](INFO): DAT read: Rx Time:16:07:03.1004 2021-05-18T16:07:31.135Z,1621354051.135 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:31.136Z,1621354051.136 [DAT](INFO): DAT read: Bearing 67.3, -6.6 (Local) 2021-05-18T16:07:31.137Z,1621354051.137 [DAT](INFO): Local bearing/azimuth received: Bearing 67.3, -6.6 (Local) 2021-05-18T16:07:31.139Z,1621354051.139 [DAT](INFO): DAT read: Range 7 to 50 : 0.3 m (trip time 0.2 ms) speed 0.0 2021-05-18T16:07:31.148Z,1621354051.148 [DAT](INFO): DAT read: 16:07:03.1004 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 497,-0.16, 1.573, 1.222, 1.540, 1.500, PHS= 0.069,-0.234, 0.025, RAW= 142.3, 9.9, CAL= 142.7, 6.6, ROT= 67.3, -6.6 2021-05-18T16:07:31.149Z,1621354051.149 [DAT](INFO): got valid direction response: 16:07:03.1004 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 497,-0.16, 1.573, 1.222, 1.540, 1.500, PHS= 0.069,-0.234, 0.025, RAW= 142.3, 9.9, CAL= 142.7, 6.6, ROT= 67.3, -6.6 2021-05-18T16:07:31.149Z,1621354051.149 [DAT](INFO): #Rx 9: Read range and direction messages. 2021-05-18T16:07:31.150Z,1621354051.150 [DAT](INFO): direction in vehicle frame: [ 0.383348 forward, 0.916424 starboard, -0.114937 keelward ] 2021-05-18T16:07:31.150Z,1621354051.150 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:31.151Z,1621354051.151 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:31.222Z,1621354051.222 [DAT](INFO): checking for new query: numPingsReceived=9 elapsed TxPingTime=6.583511 2021-05-18T16:07:31.564Z,1621354051.564 [DAT](INFO): DAT read: Rx Time:16:07:03.6003 2021-05-18T16:07:31.565Z,1621354051.565 [DAT](INFO): received an acoustic signal 2021-05-18T16:07:31.566Z,1621354051.566 [DAT](INFO): DAT read: Bearing 67.6, -6.2 (Local) 2021-05-18T16:07:31.566Z,1621354051.566 [DAT](INFO): Local bearing/azimuth received: Bearing 67.6, -6.2 (Local) 2021-05-18T16:07:31.568Z,1621354051.568 [DAT](INFO): DAT read: Range 7 to 50 : 0.2 m (trip time 0.1 ms) speed 0.0 2021-05-18T16:07:31.577Z,1621354051.577 [DAT](INFO): DAT read: 16:07:03.6003 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.03, 0.744, 0.405, 0.711, 0.671, PHS= 0.069,-0.222, 0.025, RAW= 142.0, 9.5, CAL= 142.4, 6.2, ROT= 67.6, -6.2 2021-05-18T16:07:31.578Z,1621354051.578 [DAT](INFO): got valid direction response: 16:07:03.6003 LVL= 32752, 32753, 32754, 32755, AGC= 66, IDX= 496,-0.03, 0.744, 0.405, 0.711, 0.671, PHS= 0.069,-0.222, 0.025, RAW= 142.0, 9.5, CAL= 142.4, 6.2, ROT= 67.6, -6.2 2021-05-18T16:07:31.583Z,1621354051.583 [DAT](INFO): #Rx 10: Read range and direction messages. 2021-05-18T16:07:31.584Z,1621354051.584 [DAT](INFO): direction in vehicle frame: [ 0.378841 forward, 0.919138 starboard, -0.107999 keelward ] 2021-05-18T16:07:31.584Z,1621354051.584 [DAT](INFO): not publishing receive ping time as it could be a packet for anyone 2021-05-18T16:07:31.584Z,1621354051.584 [DAT](INFO): publishing direction and range info 2021-05-18T16:07:40.488Z,1621354060.488 [Default:A.Wait](INFO): Done Waiting. 2021-05-18T16:07:40.488Z,1621354060.488 [Default:A.Wait] Stopped 2021-05-18T16:07:40.488Z,1621354060.488 [Default:A.Wait](DEBUG): Uninitialize Wait Component. 2021-05-18T16:07:40.865Z,1621354060.865 [Default:CheckIn] Running Loop=1 2021-05-18T16:07:40.865Z,1621354060.865 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn 2021-05-18T16:07:40.865Z,1621354060.865 [Default:CheckIn:Read_GPS] Running Loop=1