2025-08-23T21:14:38.343Z,1755983678.343 [CommandExec](IMPORTANT): got command restart logs 2025-08-23T21:14:38.754Z,1755983678.754 [DAT](INFO): Requesting device enable set for address 50. 2025-08-23T21:14:39.007Z,1755983679.007 [DAT](INFO): DAT read: user:1541> 2025-08-23T21:14:39.007Z,1755983679.007 [DAT](INFO): DAT read: Tx time:21:14:38.6943 2025-08-23T21:14:39.008Z,1755983679.008 [DAT](INFO): Ping request sent. 2025-08-23T21:14:39.008Z,1755983679.008 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:14:39.008Z,1755983679.008 [DAT](INFO): publishing transmit ping time 2025-08-23T21:14:39.008Z,1755983679.008 [DAT](INFO): Requesting device enable set for address 50. 2025-08-23T21:14:39.261Z,1755983679.261 [DAT](INFO): Requesting device enable set for address 50. 2025-08-23T21:14:39.591Z,1755983679.591 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-08-23T21:14:39.711Z,1755983679.711 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-08-23T21:14:39.987Z,1755983679.987 [CTD_Seabird](ERROR): Failed to parse device response: 2025-08-23T21:14:41.527Z,1755983681.527 [DAT](INFO): DAT read: Rx Time:21:14:40.5922 2025-08-23T21:14:41.527Z,1755983681.527 [DAT](INFO): Rx dataTimestamp_ set to:1755983681.526793 2025-08-23T21:14:42.030Z,1755983682.030 [DAT](INFO): DAT read: OK 2025-08-23T21:14:42.031Z,1755983682.031 [DAT](INFO): unknown deviceResponse_: OK 2025-08-23T21:14:42.031Z,1755983682.031 [DAT](INFO): DAT read: user:1542> 2025-08-23T21:14:42.032Z,1755983682.032 [DAT](INFO): DAT read: Tx time:21:14:41.6943 2025-08-23T21:14:42.032Z,1755983682.032 [DAT](INFO): Ping request sent. 2025-08-23T21:14:42.032Z,1755983682.032 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:14:42.032Z,1755983682.032 [DAT](INFO): publishing transmit ping time 2025-08-23T21:14:43.139Z,1755983683.139 [DockingStepper](INFO): Changing to mode: 1 2025-08-23T21:14:44.299Z,1755983684.299 [DAT](INFO): DAT read: Rx Time:21:14:43.5923 2025-08-23T21:14:44.299Z,1755983684.299 [DAT](INFO): Rx dataTimestamp_ set to:1755983684.298916 2025-08-23T21:14:44.804Z,1755983684.804 [DAT](INFO): DAT read: OK 2025-08-23T21:14:44.804Z,1755983684.804 [DAT](INFO): unknown deviceResponse_: OK 2025-08-23T21:14:45.055Z,1755983685.055 [DAT](INFO): DAT read: user:1543> 2025-08-23T21:14:45.055Z,1755983685.055 [DAT](INFO): DAT read: Tx time:21:14:44.6943 2025-08-23T21:14:45.056Z,1755983685.056 [DAT](INFO): Ping request sent. 2025-08-23T21:14:45.056Z,1755983685.056 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:14:45.056Z,1755983685.056 [DAT](INFO): publishing transmit ping time 2025-08-23T21:14:47.323Z,1755983687.323 [DAT](INFO): DAT read: Rx Time:21:14:46.5928 2025-08-23T21:14:47.323Z,1755983687.323 [DAT](INFO): Rx dataTimestamp_ set to:1755983687.323002 2025-08-23T21:14:47.826Z,1755983687.826 [DAT](INFO): DAT read: OK 2025-08-23T21:14:47.827Z,1755983687.827 [DAT](INFO): unknown deviceResponse_: OK 2025-08-23T21:15:23.951Z,1755983723.951 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00022901024483,35.0, .7, 0 2025-08-23T21:16:34.179Z,1755983794.179 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00022901035488,35.0, +10.1, 90.4, 0 2025-08-23T21:16:36.249Z,1755983796.249 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-23T21:16:36.270Z,1755983796.270 [DAT](DEBUG): Acoustic response timeout 2025-08-23T21:16:36.271Z,1755983796.271 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:16:36.522Z,1755983796.522 [DAT](INFO): DAT read: user:1544> 2025-08-23T21:16:36.523Z,1755983796.523 [DAT](INFO): DAT read: Tx time:21:16:36.1951 2025-08-23T21:16:36.523Z,1755983796.523 [DAT](INFO): Ping request sent. 2025-08-23T21:16:36.524Z,1755983796.524 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:16:36.524Z,1755983796.524 [DAT](INFO): publishing transmit ping time 2025-08-23T21:16:36.524Z,1755983796.524 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000752 2025-08-23T21:16:36.775Z,1755983796.775 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251005 2025-08-23T21:16:37.027Z,1755983797.027 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503023 2025-08-23T21:16:37.279Z,1755983797.279 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755002 2025-08-23T21:16:37.531Z,1755983797.531 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006982 2025-08-23T21:16:37.782Z,1755983797.782 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258870 2025-08-23T21:16:38.037Z,1755983798.037 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.512874 2025-08-23T21:16:38.287Z,1755983798.287 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763485 2025-08-23T21:16:38.538Z,1755983798.538 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014810 2025-08-23T21:16:38.790Z,1755983798.790 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266887 2025-08-23T21:16:39.045Z,1755983799.045 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.521048 2025-08-23T21:16:39.297Z,1755983799.297 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772637 2025-08-23T21:16:39.547Z,1755983799.547 [DAT](INFO): DAT read: Rx Time:21:16:38.6019 2025-08-23T21:16:39.547Z,1755983799.547 [DAT](INFO): Rx dataTimestamp_ set to:1755983799.546695 2025-08-23T21:16:39.548Z,1755983799.548 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.024002 2025-08-23T21:16:39.799Z,1755983799.799 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275003 2025-08-23T21:16:40.066Z,1755983800.066 [DAT](INFO): DAT read: 21:16:38.6019 LVL= 12528, 12785, 9618, 27475, AGC= 44, IDX= 8, 0.02,-2.177,-2.026,-2.571,-0.933, PHS=-1.142,-1.048,-1.682, RAW= 22.1, 66.6, CAL= 21.3, 69.2, ROT= 128.7, -69.2 2025-08-23T21:16:40.069Z,1755983800.069 [DAT](INFO): got valid direction response: 21:16:38.6019 LVL= 12528, 12785, 9618, 27475, AGC= 44, IDX= 8, 0.02,-2.177,-2.026,-2.571,-0.933, PHS=-1.142,-1.048,-1.682, RAW= 22.1, 66.6, CAL= 21.3, 69.2, ROT= 128.7, -69.2 2025-08-23T21:16:40.073Z,1755983800.073 [DAT](INFO): DAT read: Range 11 to 50 : 2.0 m (Round-trip 2.7 ms) speed 0.0 m/s 2025-08-23T21:16:40.087Z,1755983800.087 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:16:40.088Z,1755983800.088 [DAT](INFO): direction in FSK: [-0.222028,0.277136,0.934826] 2025-08-23T21:16:40.088Z,1755983800.088 [DAT](INFO): publishing direction and range info 2025-08-23T21:17:54.987Z,1755983874.987 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-08-23T21:18:36.627Z,1755983916.627 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-23T21:18:36.802Z,1755983916.802 [DAT](DEBUG): Acoustic response timeout 2025-08-23T21:18:36.803Z,1755983916.803 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:18:37.055Z,1755983917.055 [DAT](INFO): DAT read: user:1545> 2025-08-23T21:18:37.055Z,1755983917.055 [DAT](INFO): DAT read: Tx time:21:18:36.6950 2025-08-23T21:18:37.056Z,1755983917.056 [DAT](INFO): Ping request sent. 2025-08-23T21:18:37.056Z,1755983917.056 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:18:37.056Z,1755983917.056 [DAT](INFO): publishing transmit ping time 2025-08-23T21:18:37.056Z,1755983917.056 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000749 2025-08-23T21:18:37.307Z,1755983917.307 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250773 2025-08-23T21:18:37.558Z,1755983917.558 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502717 2025-08-23T21:18:37.814Z,1755983917.814 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.757349 2025-08-23T21:18:38.062Z,1755983918.062 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006694 2025-08-23T21:18:38.315Z,1755983918.315 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258771 2025-08-23T21:18:38.567Z,1755983918.567 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510827 2025-08-23T21:18:38.819Z,1755983918.819 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762819 2025-08-23T21:18:39.071Z,1755983919.071 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015180 2025-08-23T21:18:39.323Z,1755983919.323 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266809 2025-08-23T21:18:39.574Z,1755983919.574 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518736 2025-08-23T21:18:39.829Z,1755983919.829 [DAT](INFO): DAT read: Rx Time:21:18:39.1017 2025-08-23T21:18:39.831Z,1755983919.831 [DAT](INFO): Rx dataTimestamp_ set to:1755983919.829676 2025-08-23T21:18:39.832Z,1755983919.832 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.776335 2025-08-23T21:18:40.079Z,1755983920.079 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022876 2025-08-23T21:18:40.333Z,1755983920.333 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.276639 2025-08-23T21:18:40.588Z,1755983920.588 [DAT](INFO): DAT read: 21:18:39.1017 LVL= 20928, 12673, 16322, 32755, AGC= 43, IDX= 439, 0.11,-0.965,-0.945,-1.581, 0.235, PHS=-1.098,-1.135,-1.861, RAW= 32.4, 62.8, CAL= 31.3, 65.8, ROT= 118.7, -65.8 2025-08-23T21:18:40.589Z,1755983920.589 [DAT](INFO): got valid direction response: 21:18:39.1017 LVL= 20928, 12673, 16322, 32755, AGC= 43, IDX= 439, 0.11,-0.965,-0.945,-1.581, 0.235, PHS=-1.098,-1.135,-1.861, RAW= 32.4, 62.8, CAL= 31.3, 65.8, ROT= 118.7, -65.8 2025-08-23T21:18:40.590Z,1755983920.590 [DAT](INFO): DAT read: Bearing 39.3, 23.7 (Local) 2025-08-23T21:18:40.590Z,1755983920.590 [DAT](INFO): Local bearing/azimuth received: Bearing 39.3, 23.7 (Local) 2025-08-23T21:18:40.591Z,1755983920.591 [DAT](INFO): DAT read: Range 11 to 50 : 1.9 m (Round-trip 2.6 ms) speed 0.0 m/s 2025-08-23T21:18:40.592Z,1755983920.592 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:18:40.593Z,1755983920.593 [DAT](INFO): direction in FSK: [-0.196855,0.359562,0.912120] 2025-08-23T21:18:40.593Z,1755983920.593 [DAT](INFO): publishing direction and range info 2025-08-23T21:18:59.248Z,1755983939.248 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00022901062001,35.0, +10.1, 0.0,1490.4,WS,-32768,-32768,-32768,V 2025-08-23T21:20:36.633Z,1755984036.633 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-23T21:20:36.722Z,1755984036.722 [DAT](DEBUG): Acoustic response timeout 2025-08-23T21:20:36.723Z,1755984036.723 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:20:36.977Z,1755984036.977 [DAT](INFO): DAT read: user:1546> 2025-08-23T21:20:36.977Z,1755984036.977 [DAT](INFO): DAT read: Tx time:21:20:36.6450 2025-08-23T21:20:36.978Z,1755984036.978 [DAT](INFO): Ping request sent. 2025-08-23T21:20:36.978Z,1755984036.978 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:20:36.978Z,1755984036.978 [DAT](INFO): publishing transmit ping time 2025-08-23T21:20:36.979Z,1755984036.979 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000770 2025-08-23T21:20:37.230Z,1755984037.230 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.252605 2025-08-23T21:20:37.483Z,1755984037.483 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.504814 2025-08-23T21:20:37.734Z,1755984037.734 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.756631 2025-08-23T21:20:37.987Z,1755984037.987 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.008666 2025-08-23T21:20:38.239Z,1755984038.239 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.260756 2025-08-23T21:20:38.490Z,1755984038.490 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.512572 2025-08-23T21:20:38.743Z,1755984038.743 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.764658 2025-08-23T21:20:38.999Z,1755984038.999 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.021169 2025-08-23T21:20:39.250Z,1755984039.250 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.272566 2025-08-23T21:20:39.503Z,1755984039.503 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.525062 2025-08-23T21:20:39.755Z,1755984039.755 [DAT](INFO): DAT read: Rx Time:21:20:39.0517 2025-08-23T21:20:39.755Z,1755984039.755 [DAT](INFO): Rx dataTimestamp_ set to:1755984039.754911 2025-08-23T21:20:39.756Z,1755984039.756 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.777906 2025-08-23T21:20:40.007Z,1755984040.007 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.029152 2025-08-23T21:20:40.261Z,1755984040.261 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.282681 2025-08-23T21:20:40.515Z,1755984040.515 [DAT](INFO): DAT read: 21:20:39.0517 LVL= 22768, 13105, 16690, 32755, AGC= 44, IDX= 440,-0.26, 1.099, 1.077, 0.334, 2.261, PHS=-1.060,-1.139,-1.972, RAW= 34.5, 59.3, CAL= 33.2, 62.8, ROT= 116.8, -62.8 2025-08-23T21:20:40.516Z,1755984040.516 [DAT](INFO): got valid direction response: 21:20:39.0517 LVL= 22768, 13105, 16690, 32755, AGC= 44, IDX= 440,-0.26, 1.099, 1.077, 0.334, 2.261, PHS=-1.060,-1.139,-1.972, RAW= 34.5, 59.3, CAL= 33.2, 62.8, ROT= 116.8, -62.8 2025-08-23T21:20:40.517Z,1755984040.517 [DAT](INFO): DAT read: Bearing 43.6, 28.0 (Local) 2025-08-23T21:20:40.517Z,1755984040.517 [DAT](INFO): Local bearing/azimuth received: Bearing 43.6, 28.0 (Local) 2025-08-23T21:20:40.517Z,1755984040.517 [DAT](INFO): #Rx 1: Read direction message, but no range. 2025-08-23T21:20:40.518Z,1755984040.518 [DAT](INFO): direction in FSK: [-0.206095,0.407999,0.889416] 2025-08-23T21:20:47.078Z,1755984047.078 [DAT](INFO): Reached modem response timeout 2025-08-23T21:21:07.317Z,1755984067.317 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, -29.89, , -5.81, 8.34, 0.00 2025-08-23T21:21:19.436Z,1755984079.436 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, -29.87, , -5.81, 8.35, 0.00 2025-08-23T21:22:36.991Z,1755984156.991 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-23T21:22:37.058Z,1755984157.058 [DAT](DEBUG): Acoustic response timeout 2025-08-23T21:22:37.059Z,1755984157.059 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:22:37.313Z,1755984157.313 [DAT](INFO): DAT read: Range 11r:1547> 2025-08-23T21:22:37.315Z,1755984157.315 [DAT](INFO): unknown deviceResponse_: Range 11r:1547> 2025-08-23T21:22:37.316Z,1755984157.316 [DAT](INFO): DAT read: Tx time:21:22:36.9950 2025-08-23T21:22:37.318Z,1755984157.318 [DAT](INFO): Ping request sent. 2025-08-23T21:22:37.318Z,1755984157.318 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:22:37.319Z,1755984157.319 [DAT](INFO): publishing transmit ping time 2025-08-23T21:22:37.321Z,1755984157.321 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.002747 2025-08-23T21:22:37.563Z,1755984157.563 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.245204 2025-08-23T21:22:37.815Z,1755984157.815 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.497279 2025-08-23T21:22:38.067Z,1755984158.067 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.749261 2025-08-23T21:22:38.320Z,1755984158.320 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.002562 2025-08-23T21:22:38.570Z,1755984158.570 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.253146 2025-08-23T21:22:38.823Z,1755984158.823 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.505230 2025-08-23T21:22:39.075Z,1755984159.075 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.757243 2025-08-23T21:22:39.329Z,1755984159.329 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.011554 2025-08-23T21:22:39.579Z,1755984159.579 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.261232 2025-08-23T21:22:39.831Z,1755984159.831 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.513273 2025-08-23T21:22:40.083Z,1755984160.083 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.765342 2025-08-23T21:22:40.337Z,1755984160.337 [DAT](INFO): DAT read: Rx Time:21:22:39.4017 2025-08-23T21:22:40.339Z,1755984160.339 [DAT](INFO): Rx dataTimestamp_ set to:1755984160.337546 2025-08-23T21:22:40.340Z,1755984160.340 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022501 2025-08-23T21:22:40.586Z,1755984160.586 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.269156 2025-08-23T21:22:40.844Z,1755984160.844 [DAT](INFO): DAT read: 21:22:39.4017 LVL= 21552, 11617, 14914, 32755, AGC= 43, IDX= 440,-0.47,-1.054,-1.121,-1.836, 0.101, PHS=-1.053,-1.177,-1.981, RAW= 37.1, 59.6, CAL= 35.7, 63.1, ROT= 114.3, -63.1 2025-08-23T21:22:40.845Z,1755984160.845 [DAT](INFO): got valid direction response: 21:22:39.4017 LVL= 21552, 11617, 14914, 32755, AGC= 43, IDX= 440,-0.47,-1.054,-1.121,-1.836, 0.101, PHS=-1.053,-1.177,-1.981, RAW= 37.1, 59.6, CAL= 35.7, 63.1, ROT= 114.3, -63.1 2025-08-23T21:22:40.846Z,1755984160.846 [DAT](INFO): DAT read: Bearing 40.2, 28.2 (Local) 2025-08-23T21:22:40.846Z,1755984160.846 [DAT](INFO): Local bearing/azimuth received: Bearing 40.2, 28.2 (Local) 2025-08-23T21:22:40.847Z,1755984160.847 [DAT](INFO): DAT read: Range 11 to 50 : 1.9 m (Round-trip 2.6 ms) speed 0.0 m/s 2025-08-23T21:22:40.848Z,1755984160.848 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:22:40.849Z,1755984160.849 [DAT](INFO): direction in FSK: [-0.186183,0.412350,0.891798] 2025-08-23T21:22:40.849Z,1755984160.849 [DAT](INFO): publishing direction and range info 2025-08-23T21:23:18.640Z,1755984198.640 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size. 2025-08-23T21:24:37.085Z,1755984277.085 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-23T21:24:37.096Z,1755984277.096 [DAT](DEBUG): Acoustic response timeout 2025-08-23T21:24:37.097Z,1755984277.097 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:24:37.346Z,1755984277.346 [DAT](INFO): DAT read: user:1548> 2025-08-23T21:24:37.347Z,1755984277.347 [DAT](INFO): DAT read: Tx time:21:24:36.9952 2025-08-23T21:24:37.347Z,1755984277.347 [DAT](INFO): Ping request sent. 2025-08-23T21:24:37.348Z,1755984277.348 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:24:37.348Z,1755984277.348 [DAT](INFO): publishing transmit ping time 2025-08-23T21:24:37.348Z,1755984277.348 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000758 2025-08-23T21:24:37.599Z,1755984277.599 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251064 2025-08-23T21:24:37.851Z,1755984277.851 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503727 2025-08-23T21:24:38.105Z,1755984278.105 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.756889 2025-08-23T21:24:38.355Z,1755984278.355 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.007207 2025-08-23T21:24:38.609Z,1755984278.609 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.261431 2025-08-23T21:24:38.858Z,1755984278.858 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510901 2025-08-23T21:24:39.113Z,1755984279.113 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.765164 2025-08-23T21:24:39.363Z,1755984279.363 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015068 2025-08-23T21:24:39.614Z,1755984279.614 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266888 2025-08-23T21:24:39.868Z,1755984279.868 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.520075 2025-08-23T21:24:40.121Z,1755984280.121 [DAT](INFO): DAT read: Rx Time:21:24:39.4019 2025-08-23T21:24:40.122Z,1755984280.122 [DAT](INFO): Rx dataTimestamp_ set to:1755984280.121512 2025-08-23T21:24:40.124Z,1755984280.124 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.776204 2025-08-23T21:24:40.370Z,1755984280.370 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022919 2025-08-23T21:24:40.625Z,1755984280.625 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.277017 2025-08-23T21:24:40.880Z,1755984280.880 [DAT](INFO): DAT read: 21:24:39.4019 LVL= 22160, 10609, 15954, 31443, AGC= 43, IDX= 439, 0.23,-0.457,-0.505,-1.369, 0.706, PHS=-1.061,-1.166,-2.118, RAW= 35.2, 56.7, CAL= 33.7, 60.5, ROT= 116.3, -60.5 2025-08-23T21:24:40.881Z,1755984280.881 [DAT](INFO): got valid direction response: 21:24:39.4019 LVL= 22160, 10609, 15954, 31443, AGC= 43, IDX= 439, 0.23,-0.457,-0.505,-1.369, 0.706, PHS=-1.061,-1.166,-2.118, RAW= 35.2, 56.7, CAL= 33.7, 60.5, ROT= 116.3, -60.5 2025-08-23T21:24:40.882Z,1755984280.882 [DAT](INFO): DAT read: Bearing 44.9, 30.3 (Local) 2025-08-23T21:24:40.883Z,1755984280.883 [DAT](INFO): Local bearing/azimuth received: Bearing 44.9, 30.3 (Local) 2025-08-23T21:24:40.884Z,1755984280.884 [DAT](INFO): DAT read: Range 11 to 50 : 1.9 m (Round-trip 2.6 ms) speed 0.0 m/s 2025-08-23T21:24:40.884Z,1755984280.884 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:24:40.886Z,1755984280.886 [DAT](INFO): direction in FSK: [-0.218179,0.441451,0.870356] 2025-08-23T21:24:40.886Z,1755984280.886 [DAT](INFO): publishing direction and range info 2025-08-23T21:26:37.376Z,1755984397.376 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-23T21:26:37.439Z,1755984397.439 [DAT](DEBUG): Acoustic response timeout 2025-08-23T21:26:37.439Z,1755984397.439 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:26:37.690Z,1755984397.690 [DAT](INFO): DAT read: user:1549> 2025-08-23T21:26:37.691Z,1755984397.691 [DAT](INFO): DAT read: Tx time:21:26:37.3454 2025-08-23T21:26:37.691Z,1755984397.691 [DAT](INFO): Ping request sent. 2025-08-23T21:26:37.691Z,1755984397.691 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:26:37.692Z,1755984397.692 [DAT](INFO): publishing transmit ping time 2025-08-23T21:26:37.692Z,1755984397.692 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000758 2025-08-23T21:26:37.943Z,1755984397.943 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251017 2025-08-23T21:26:38.195Z,1755984398.195 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503402 2025-08-23T21:26:38.447Z,1755984398.447 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755003 2025-08-23T21:26:38.699Z,1755984398.699 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.007060 2025-08-23T21:26:38.951Z,1755984398.951 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258969 2025-08-23T21:26:39.203Z,1755984399.203 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511518 2025-08-23T21:26:39.455Z,1755984399.455 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763101 2025-08-23T21:26:39.706Z,1755984399.706 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014945 2025-08-23T21:26:39.958Z,1755984399.958 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266965 2025-08-23T21:26:40.211Z,1755984400.211 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519587 2025-08-23T21:26:40.462Z,1755984400.462 [DAT](INFO): DAT read: Rx Time:21:26:39.7522 2025-08-23T21:26:40.463Z,1755984400.463 [DAT](INFO): Rx dataTimestamp_ set to:1755984400.462636 2025-08-23T21:26:40.463Z,1755984400.463 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771964 2025-08-23T21:26:40.714Z,1755984400.714 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022947 2025-08-23T21:26:40.968Z,1755984400.968 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.276555 2025-08-23T21:26:41.224Z,1755984401.224 [DAT](INFO): DAT read: 21:26:39.7522 LVL= 24032, 13329, 18978, 32755, AGC= 44, IDX= 440,-0.02,-2.207,-2.208,-3.085,-1.065, PHS=-1.040,-1.097,-2.064, RAW= 32.9, 56.1, CAL= 31.5, 59.9, ROT= 118.5, -59.9 2025-08-23T21:26:41.226Z,1755984401.226 [DAT](INFO): got valid direction response: 21:26:39.7522 LVL= 24032, 13329, 18978, 32755, AGC= 44, IDX= 440,-0.02,-2.207,-2.208,-3.085,-1.065, PHS=-1.040,-1.097,-2.064, RAW= 32.9, 56.1, CAL= 31.5, 59.9, ROT= 118.5, -59.9 2025-08-23T21:26:41.226Z,1755984401.226 [DAT](INFO): DAT read: Bearing 50.5, 30.6 (Local) 2025-08-23T21:26:41.227Z,1755984401.227 [DAT](INFO): Local bearing/azimuth received: Bearing 50.5, 30.6 (Local) 2025-08-23T21:26:41.228Z,1755984401.228 [DAT](INFO): DAT read: Range 11 to 50 : 2.0 m (Round-trip 2.7 ms) speed 0.0 m/s 2025-08-23T21:26:41.229Z,1755984401.229 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:26:41.230Z,1755984401.230 [DAT](INFO): direction in FSK: [-0.239300,0.440736,0.865151] 2025-08-23T21:26:41.230Z,1755984401.230 [DAT](INFO): publishing direction and range info 2025-08-23T21:27:19.806Z,1755984439.806 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for water velocity. Device response is::WS,-32768,-32768,-32:8,-32768,-32768,V 2025-08-23T21:27:55.379Z,1755984475.379 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-08-23T21:28:29.745Z,1755984509.745 [RDI_Pathfinder](ERROR): DVL uart error: serial timeout 2025-08-23T21:28:29.746Z,1755984509.746 [RDI_Pathfinder] Communications Fault, FailCount= 1 2025-08-23T21:28:29.746Z,1755984509.746 [RDI_Pathfinder](ERROR): Communications Fault 2025-08-23T21:28:29.843Z,1755984509.843 [CBIT](ERROR): Communications Fault in component: RDI_Pathfinder 2025-08-23T21:28:30.111Z,1755984510.111 [RDI_Pathfinder](INFO): Powering down 2025-08-23T21:28:30.972Z,1755984510.972 [CBIT](INFO): Clearing failed state for component RDI_Pathfinder 2025-08-23T21:28:30.972Z,1755984510.972 [RDI_Pathfinder] No Fault, FailCount= 1 2025-08-23T21:28:31.307Z,1755984511.307 [RDI_Pathfinder](IMPORTANT): Expecting PD13 message format 2025-08-23T21:28:37.384Z,1755984517.384 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-23T21:28:37.530Z,1755984517.530 [DAT](DEBUG): Acoustic response timeout 2025-08-23T21:28:37.531Z,1755984517.531 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:28:37.783Z,1755984517.783 [DAT](INFO): DAT read: user:1550> 2025-08-23T21:28:37.783Z,1755984517.783 [DAT](INFO): DAT read: Tx time:21:28:37.4456 2025-08-23T21:28:37.784Z,1755984517.784 [DAT](INFO): Ping request sent. 2025-08-23T21:28:37.784Z,1755984517.784 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:28:37.784Z,1755984517.784 [DAT](INFO): publishing transmit ping time 2025-08-23T21:28:37.784Z,1755984517.784 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000750 2025-08-23T21:28:38.034Z,1755984518.034 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250768 2025-08-23T21:28:38.287Z,1755984518.287 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503059 2025-08-23T21:28:38.539Z,1755984518.539 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754827 2025-08-23T21:28:38.790Z,1755984518.790 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006768 2025-08-23T21:28:39.043Z,1755984519.043 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259368 2025-08-23T21:28:39.295Z,1755984519.295 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510832 2025-08-23T21:28:39.547Z,1755984519.547 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762987 2025-08-23T21:28:39.799Z,1755984519.799 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014901 2025-08-23T21:28:40.051Z,1755984520.051 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266830 2025-08-23T21:28:40.303Z,1755984520.303 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518801 2025-08-23T21:28:40.555Z,1755984520.555 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770794 2025-08-23T21:28:40.807Z,1755984520.807 [DAT](INFO): DAT read: Rx Time:21:28:39.8523 2025-08-23T21:28:40.807Z,1755984520.807 [DAT](INFO): Rx dataTimestamp_ set to:1755984520.806735 2025-08-23T21:28:40.808Z,1755984520.808 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023883 2025-08-23T21:28:41.061Z,1755984521.061 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.277025 2025-08-23T21:28:41.316Z,1755984521.316 [DAT](INFO): DAT read: 21:28:39.8523 LVL= 22576, 12257, 18162, 31139, AGC= 43, IDX= 440,-0.47, 2.562, 2.559, 1.733,-2.569, PHS=-1.050,-1.110,-2.026, RAW= 33.1, 57.4, CAL= 31.8, 61.0, ROT= 118.2, -61.0 2025-08-23T21:28:41.317Z,1755984521.317 [DAT](INFO): got valid direction response: 21:28:39.8523 LVL= 22576, 12257, 18162, 31139, AGC= 43, IDX= 440,-0.47, 2.562, 2.559, 1.733,-2.569, PHS=-1.050,-1.110,-2.026, RAW= 33.1, 57.4, CAL= 31.8, 61.0, ROT= 118.2, -61.0 2025-08-23T21:28:41.318Z,1755984521.318 [DAT](INFO): DAT read: Bearing 48.6, 29.2 (Local) 2025-08-23T21:28:41.318Z,1755984521.318 [DAT](INFO): Local bearing/azimuth received: Bearing 48.6, 29.2 (Local) 2025-08-23T21:28:41.319Z,1755984521.319 [DAT](INFO): DAT read: Range 11 to 50 : 1.9 m (Round-trip 2.6 ms) speed 0.0 m/s 2025-08-23T21:28:41.320Z,1755984521.320 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:28:41.321Z,1755984521.321 [DAT](INFO): direction in FSK: [-0.229097,0.427264,0.874620] 2025-08-23T21:28:41.321Z,1755984521.321 [DAT](INFO): publishing direction and range info 2025-08-23T21:29:49.726Z,1755984589.726 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.78, 86.55, 81.45, 84.85 2025-08-23T21:30:37.415Z,1755984637.415 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-23T21:30:37.570Z,1755984637.570 [DAT](DEBUG): Acoustic response timeout 2025-08-23T21:30:37.570Z,1755984637.570 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:30:37.823Z,1755984637.823 [DAT](INFO): DAT read: user:1551> 2025-08-23T21:30:37.824Z,1755984637.824 [DAT](INFO): DAT read: Tx time:21:30:37.4958 2025-08-23T21:30:37.824Z,1755984637.824 [DAT](INFO): Ping request sent. 2025-08-23T21:30:37.824Z,1755984637.824 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:30:37.824Z,1755984637.824 [DAT](INFO): publishing transmit ping time 2025-08-23T21:30:37.825Z,1755984637.825 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000760 2025-08-23T21:30:38.074Z,1755984638.074 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250173 2025-08-23T21:30:38.327Z,1755984638.327 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502249 2025-08-23T21:30:38.579Z,1755984638.579 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754302 2025-08-23T21:30:38.830Z,1755984638.830 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006146 2025-08-23T21:30:39.082Z,1755984639.082 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258182 2025-08-23T21:30:39.338Z,1755984639.338 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.513715 2025-08-23T21:30:39.587Z,1755984639.587 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762190 2025-08-23T21:30:39.839Z,1755984639.839 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014802 2025-08-23T21:30:40.091Z,1755984640.091 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266208 2025-08-23T21:30:40.342Z,1755984640.342 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518161 2025-08-23T21:30:40.595Z,1755984640.595 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770455 2025-08-23T21:30:40.847Z,1755984640.847 [DAT](INFO): DAT read: Rx Time:21:30:39.9025 2025-08-23T21:30:40.847Z,1755984640.847 [DAT](INFO): Rx dataTimestamp_ set to:1755984640.846802 2025-08-23T21:30:40.848Z,1755984640.848 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023333 2025-08-23T21:30:41.098Z,1755984641.098 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274150 2025-08-23T21:30:41.358Z,1755984641.358 [DAT](INFO): DAT read: 21:30:39.9025 LVL= 22512, 13665, 18930, 31315, AGC= 43, IDX= 440,-0.21, 2.252, 2.254, 1.428,-2.879, PHS=-1.051,-1.106,-2.020, RAW= 32.9, 57.4, CAL= 31.5, 61.1, ROT= 118.5, -61.1 2025-08-23T21:30:41.359Z,1755984641.359 [DAT](INFO): got valid direction response: 21:30:39.9025 LVL= 22512, 13665, 18930, 31315, AGC= 43, IDX= 440,-0.21, 2.252, 2.254, 1.428,-2.879, PHS=-1.051,-1.106,-2.020, RAW= 32.9, 57.4, CAL= 31.5, 61.1, ROT= 118.5, -61.1 2025-08-23T21:30:41.360Z,1755984641.360 [DAT](INFO): DAT read: Bearing 50.1, 29.7 (Local) 2025-08-23T21:30:41.360Z,1755984641.360 [DAT](INFO): Local bearing/azimuth received: Bearing 50.1, 29.7 (Local) 2025-08-23T21:30:41.362Z,1755984641.362 [DAT](INFO): DAT read: Range 11 to 50 : 1.9 m (Round-trip 2.6 ms) speed 0.0 m/s 2025-08-23T21:30:41.362Z,1755984641.362 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:30:41.365Z,1755984641.365 [DAT](INFO): direction in FSK: [-0.230602,0.424717,0.875465] 2025-08-23T21:30:41.386Z,1755984641.386 [DAT](INFO): publishing direction and range info 2025-08-23T21:32:09.888Z,1755984729.888 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, +0.01, ,+0.01, 8.34, 0.00 2025-08-23T21:32:37.768Z,1755984757.768 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-23T21:32:37.859Z,1755984757.859 [DAT](DEBUG): Acoustic response timeout 2025-08-23T21:32:37.859Z,1755984757.859 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:32:38.112Z,1755984758.112 [DAT](INFO): DAT read: user:1552> 2025-08-23T21:32:38.115Z,1755984758.115 [DAT](INFO): DAT read: Tx time:21:32:37.7960 2025-08-23T21:32:38.116Z,1755984758.116 [DAT](INFO): Ping request sent. 2025-08-23T21:32:38.116Z,1755984758.116 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:32:38.116Z,1755984758.116 [DAT](INFO): publishing transmit ping time 2025-08-23T21:32:38.119Z,1755984758.119 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.002971 2025-08-23T21:32:38.362Z,1755984758.362 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.246821 2025-08-23T21:32:38.615Z,1755984758.615 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.499417 2025-08-23T21:32:38.866Z,1755984758.866 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.750827 2025-08-23T21:32:39.121Z,1755984759.121 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005098 2025-08-23T21:32:39.371Z,1755984759.371 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.255161 2025-08-23T21:32:39.623Z,1755984759.623 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.506900 2025-08-23T21:32:39.875Z,1755984759.875 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.758881 2025-08-23T21:32:40.126Z,1755984760.126 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.010813 2025-08-23T21:32:40.379Z,1755984760.379 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.263372 2025-08-23T21:32:40.631Z,1755984760.631 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.515173 2025-08-23T21:32:40.883Z,1755984760.883 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.766835 2025-08-23T21:32:41.137Z,1755984761.137 [DAT](INFO): DAT read: Rx Time:21:32:40.2028 2025-08-23T21:32:41.139Z,1755984761.139 [DAT](INFO): Rx dataTimestamp_ set to:1755984761.137688 2025-08-23T21:32:41.140Z,1755984761.140 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.024240 2025-08-23T21:32:41.386Z,1755984761.386 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.270759 2025-08-23T21:32:41.644Z,1755984761.644 [DAT](INFO): DAT read: 21:32:40.2028 LVL= 24176, 12273, 16034, 32019, AGC= 44, IDX= 440,-0.17, 1.998, 1.972, 1.100, 3.134, PHS=-1.034,-1.117,-2.078, RAW= 34.1, 56.1, CAL= 32.7, 59.9, ROT= 117.3, -59.9 2025-08-23T21:32:41.645Z,1755984761.645 [DAT](INFO): got valid direction response: 21:32:40.2028 LVL= 24176, 12273, 16034, 32019, AGC= 44, IDX= 440,-0.17, 1.998, 1.972, 1.100, 3.134, PHS=-1.034,-1.117,-2.078, RAW= 34.1, 56.1, CAL= 32.7, 59.9, ROT= 117.3, -59.9 2025-08-23T21:32:41.646Z,1755984761.646 [DAT](INFO): DAT read: Bearing 51.2, 30.3 (Local) 2025-08-23T21:32:41.646Z,1755984761.646 [DAT](INFO): Local bearing/azimuth received: Bearing 51.2, 30.3 (Local) 2025-08-23T21:32:41.647Z,1755984761.647 [DAT](INFO): DAT read: Range 11 to 50 : 1.9 m (Round-trip 2.6 ms) speed 0.0 m/s 2025-08-23T21:32:41.648Z,1755984761.648 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:32:41.649Z,1755984761.649 [DAT](INFO): direction in FSK: [-0.230018,0.445651,0.865151] 2025-08-23T21:32:41.649Z,1755984761.649 [DAT](INFO): publishing direction and range info 2025-08-23T21:33:25.021Z,1755984805.021 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.11, 85.87, 81.79, 84.51 2025-08-23T21:34:38.174Z,1755984878.174 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-23T21:34:38.398Z,1755984878.398 [DAT](DEBUG): Acoustic response timeout 2025-08-23T21:34:38.399Z,1755984878.399 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:34:38.651Z,1755984878.651 [DAT](INFO): DAT read: user:1553> 2025-08-23T21:34:38.652Z,1755984878.652 [DAT](INFO): DAT read: Tx time:21:34:38.2962 2025-08-23T21:34:38.652Z,1755984878.652 [DAT](INFO): Ping request sent. 2025-08-23T21:34:38.653Z,1755984878.653 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:34:38.653Z,1755984878.653 [DAT](INFO): publishing transmit ping time 2025-08-23T21:34:38.654Z,1755984878.654 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001392 2025-08-23T21:34:38.905Z,1755984878.905 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251945 2025-08-23T21:34:39.155Z,1755984879.155 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501937 2025-08-23T21:34:39.407Z,1755984879.407 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754713 2025-08-23T21:34:39.658Z,1755984879.658 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005908 2025-08-23T21:34:39.922Z,1755984879.922 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.268473 2025-08-23T21:34:40.171Z,1755984880.171 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.518084 2025-08-23T21:34:40.423Z,1755984880.423 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.769902 2025-08-23T21:34:40.675Z,1755984880.675 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.021927 2025-08-23T21:34:40.929Z,1755984880.929 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.276092 2025-08-23T21:34:41.178Z,1755984881.178 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.525857 2025-08-23T21:34:41.431Z,1755984881.431 [DAT](INFO): DAT read: Rx Time:21:34:40.7030 2025-08-23T21:34:41.431Z,1755984881.431 [DAT](INFO): Rx dataTimestamp_ set to:1755984881.430826 2025-08-23T21:34:41.432Z,1755984881.432 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.779098 2025-08-23T21:34:41.683Z,1755984881.683 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.029952 2025-08-23T21:34:41.939Z,1755984881.939 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.285388 2025-08-23T21:34:42.193Z,1755984882.193 [DAT](INFO): DAT read: 21:34:40.7030 LVL= 28896, 15137, 18738, 31043, AGC= 43, IDX= 439, 0.14, 2.288, 2.316, 1.400,-2.829, PHS=-1.064,-1.093,-2.098, RAW= 31.4, 55.9, CAL= 30.0, 59.6, ROT= 120.0, -59.6 2025-08-23T21:34:42.195Z,1755984882.195 [DAT](INFO): got valid direction response: 21:34:40.7030 LVL= 28896, 15137, 18738, 31043, AGC= 43, IDX= 439, 0.14, 2.288, 2.316, 1.400,-2.829, PHS=-1.064,-1.093,-2.098, RAW= 31.4, 55.9, CAL= 30.0, 59.6, ROT= 120.0, -59.6 2025-08-23T21:34:42.196Z,1755984882.196 [DAT](INFO): DAT read: Bearing 57.3, 30.3 (Local) 2025-08-23T21:34:42.196Z,1755984882.196 [DAT](INFO): Local bearing/azimuth received: Bearing 57.3, 30.3 (Local) 2025-08-23T21:34:42.198Z,1755984882.198 [DAT](INFO): DAT read: Range 11 to 50 : 1.9 m (Round-trip 2.6 ms) speed 0.0 m/s 2025-08-23T21:34:42.199Z,1755984882.199 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:34:42.201Z,1755984882.201 [DAT](INFO): direction in FSK: [-0.253017,0.438238,0.862514] 2025-08-23T21:34:42.201Z,1755984882.201 [DAT](INFO): publishing direction and range info 2025-08-23T21:35:39.600Z,1755984939.600 [BPC1](ERROR): Battery stick #5 (s/n: 00C2) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-23T21:35:39.607Z,1755984939.607 [BPC1](ERROR): Battery stick #10 (s/n: 00BE) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48E0. 2025-08-23T21:35:39.608Z,1755984939.608 [BPC1](ERROR): Battery stick #17 (s/n: 00C9) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-08-23T21:35:39.609Z,1755984939.609 [BPC1](ERROR): Battery stick #26 (s/n: 0112) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-23T21:35:39.610Z,1755984939.610 [BPC1](ERROR): Battery stick #27 (s/n: 00AF) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4A50. 2025-08-23T21:35:39.611Z,1755984939.611 [BPC1](ERROR): Battery stick #37 (s/n: 00A3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-23T21:35:39.611Z,1755984939.611 [BPC1](ERROR): Battery stick #44 (s/n: 00E4) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0. 2025-08-23T21:35:39.612Z,1755984939.612 [BPC1](ERROR): Battery stick #58 (s/n: 00F3) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x4AD0. 2025-08-23T21:35:39.613Z,1755984939.613 [BPC1](INFO): Calculating totals. Valid battery stick count: 30. Valid reserve battery stick count: 3. 2025-08-23T21:35:39.618Z,1755984939.618 [BPC1](FAULT): Failed to receive data from 26 sticks prior to timeout. Will not retry this scan cycle. Missing stick IDs are: 1, 2, 3, 4, 5, 6, 7, 8, 10, 11, 12, 13, 14, 15, 16, 17, 18, 26, 27, 33, 34, 36, 37, 39, 44, 58. 2025-08-23T21:35:50.065Z,1755984950.065 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.00, 80.78, 85.20, 84.86 2025-08-23T21:36:24.855Z,1755984984.855 [DAT](INFO): DAT read: user:1554>Rx Time:21:36:24.1291 2025-08-23T21:36:24.856Z,1755984984.856 [DAT](INFO): Rx dataTimestamp_ set to:1755984984.855312 2025-08-23T21:36:25.615Z,1755984985.615 [DAT](INFO): DAT read: 21:36:24.1291 LVL= 22752, 13601, 18978, 30435, AGC= 44, IDX= 224,-0.19,-2.248,-2.234,-3.084,-1.093, PHS=-1.053,-1.096,-2.036, RAW= 32.2, 57.0, CAL= 30.8, 60.6, ROT= 119.2, -60.6 2025-08-23T21:36:25.616Z,1755984985.616 [DAT](INFO): got valid direction response: 21:36:24.1291 LVL= 22752, 13601, 18978, 30435, AGC= 44, IDX= 224,-0.19,-2.248,-2.234,-3.084,-1.093, PHS=-1.053,-1.096,-2.036, RAW= 32.2, 57.0, CAL= 30.8, 60.6, ROT= 119.2, -60.6 2025-08-23T21:36:25.617Z,1755984985.617 [DAT](INFO): DAT read: 2025-08-23T21:36:25.622Z,1755984985.622 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-08-23T21:36:25.623Z,1755984985.623 [DAT](INFO): commRate: 600 2025-08-23T21:36:25.623Z,1755984985.623 [DAT](INFO): DAT read: Tx time:21:36:25.1954 2025-08-23T21:36:25.623Z,1755984985.623 [DAT](INFO): Ping request sent. 2025-08-23T21:36:25.624Z,1755984985.624 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:36:25.624Z,1755984985.624 [DAT](INFO): #Rx 2: Read direction message, but no range. 2025-08-23T21:36:25.625Z,1755984985.625 [DAT](INFO): direction in FSK: [-0.239492,0.428521,0.871214] 2025-08-23T21:36:25.625Z,1755984985.625 [DAT](INFO): publishing transmit ping time 2025-08-23T21:36:25.628Z,1755984985.628 [DAT](INFO): publishing transmit ping time 2025-08-23T21:36:32.919Z,1755984992.919 [DAT](INFO): DAT read: Rx Time:21:36:32.0291 2025-08-23T21:36:32.919Z,1755984992.919 [DAT](INFO): Rx dataTimestamp_ set to:1755984992.918789 2025-08-23T21:36:33.426Z,1755984993.426 [DAT](INFO): DAT read: 21:36:32.0291 LVL= 23904, 13249, 18402, 31219, AGC= 43, IDX= 464,-0.08, 1.368, 1.395, 0.452, 2.523, PHS=-1.053,-1.083,-2.116, RAW= 31.4, 55.1, CAL= 30.0, 59.0, ROT= 120.0, -59.0 2025-08-23T21:36:33.427Z,1755984993.427 [DAT](INFO): got valid direction response: 21:36:32.0291 LVL= 23904, 13249, 18402, 31219, AGC= 43, IDX= 464,-0.08, 1.368, 1.395, 0.452, 2.523, PHS=-1.053,-1.083,-2.116, RAW= 31.4, 55.1, CAL= 30.0, 59.0, ROT= 120.0, -59.0 2025-08-23T21:36:33.427Z,1755984993.427 [DAT](INFO): #Rx 3: Read direction message, but no range. 2025-08-23T21:36:33.428Z,1755984993.428 [DAT](INFO): direction in FSK: [-0.257519,0.446036,0.857167] 2025-08-23T21:36:33.676Z,1755984993.676 [DAT](INFO): DAT read: 2025-08-23T21:36:33.677Z,1755984993.677 [DAT](INFO): DAT read: DATA(0005):stop 2025-08-23T21:36:33.677Z,1755984993.677 [DAT](INFO): Got DATA 5 2025-08-23T21:36:33.678Z,1755984993.678 [DAT](INFO): DAT read: 2025-08-23T21:36:33.679Z,1755984993.679 [DAT](INFO): DAT read: Source:050 Destination:011 2025-08-23T21:36:33.679Z,1755984993.679 [DAT](INFO): Got Src/Dest after DATA 2025-08-23T21:36:33.679Z,1755984993.679 [DAT](INFO): DATA Src=50, Dst=11 2025-08-23T21:36:33.680Z,1755984993.680 [DAT](INFO): DAT read: CRC:Pass MPD:03.4 PSNR:18.1 AGC:43 SPD:+0.0 CCERR:013 2025-08-23T21:36:33.680Z,1755984993.680 [DAT](INFO): Got CRC:Pass 2025-08-23T21:36:33.680Z,1755984993.680 [DAT](INFO): Got CRC:Pass 2025-08-23T21:36:33.681Z,1755984993.681 [DAT](INFO): Incoming data is intended for us 2025-08-23T21:36:33.681Z,1755984993.681 [DAT](INFO): Received command: stop 2025-08-23T21:36:33.681Z,1755984993.681 [DAT](INFO): #Outgoing data=1 2025-08-23T21:36:33.681Z,1755984993.681 [DAT](INFO): Sending ack 2025-08-23T21:36:33.681Z,1755984993.681 [DAT](INFO): DAT read: 2025-08-23T21:36:33.682Z,1755984993.682 [DAT](INFO): DAT read: 2025-08-23T21:36:33.682Z,1755984993.682 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-08-23T21:36:33.754Z,1755984993.754 [CommandExec](IMPORTANT): got command stop 2025-08-23T21:36:33.755Z,1755984993.755 [CommandExec](IMPORTANT): Scheduling is paused 2025-08-23T21:36:33.755Z,1755984993.755 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2025-08-23T21:36:33.790Z,1755984993.790 [MissionManager](INFO): MissionManager is completed. 2025-08-23T21:36:33.790Z,1755984993.790 [MissionManager](INFO): Uninitializing Mission OnDock 2025-08-23T21:36:33.790Z,1755984993.790 [OnDock] Stopped 2025-08-23T21:36:33.790Z,1755984993.790 [OnDock](DEBUG): Aggregate::uninitialize OnDock 2025-08-23T21:36:33.790Z,1755984993.790 [OnDock:StandardEnvelopes] Stopped 2025-08-23T21:36:33.790Z,1755984993.790 [OnDock:StandardEnvelopes](DEBUG): Aggregate::uninitialize OnDock:StandardEnvelopes 2025-08-23T21:36:33.790Z,1755984993.790 [OnDock:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-08-23T21:36:33.790Z,1755984993.790 [OnDock:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:BackseatDriver] Stopped 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:BackseatDriver](DEBUG): Aggregate::uninitialize OnDock:BackseatDriver 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:BackseatDriver:A.BackseatDriver] Stopped 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:PowerOnly] Stopped 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:PowerOnly](DEBUG): Aggregate::uninitialize OnDock:PowerOnly 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:PowerOnly:E.Wait] Stopped 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-08-23T21:36:33.791Z,1755984993.791 [OnDock:dataRead] Stopped 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:dataRead](DEBUG): Aggregate::uninitialize OnDock:dataRead 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:dataRead:A] Stopped 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:J.] Stopped 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:J.](DEBUG): Uninitializing TrackAcousticContact. 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:PeriodicCheck] Stopped 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:PeriodicCheck](DEBUG): Aggregate::uninitialize OnDock:PeriodicCheck 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:PeriodicCheck:CheckIP] Stopped 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:PeriodicCheck:CheckIP](DEBUG): Aggregate::uninitialize OnDock:PeriodicCheck:CheckIP 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:PeriodicCheck:CheckIP:B.Wait] Stopped 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:PeriodicCheck:CheckIP:B.Wait](DEBUG): Uninitialize Wait Component. 2025-08-23T21:36:33.792Z,1755984993.792 [OnDock:N.Docked] Stopped 2025-08-23T21:36:33.926Z,1755984993.926 [DAT](INFO): setting remote address to 50 2025-08-23T21:36:34.119Z,1755984994.119 [MissionManager](IMPORTANT): Started mission DefaultWithUndock 2025-08-23T21:36:34.119Z,1755984994.119 [DefaultWithUndock] Running Loop=1 2025-08-23T21:36:34.119Z,1755984994.119 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock 2025-08-23T21:36:34.120Z,1755984994.120 [DefaultWithUndock:A.Wait] Running Loop=1 2025-08-23T21:36:34.120Z,1755984994.120 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component. 2025-08-23T21:36:34.178Z,1755984994.178 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:34.430Z,1755984994.430 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:34.682Z,1755984994.682 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:34.934Z,1755984994.934 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:35.187Z,1755984995.187 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:35.438Z,1755984995.438 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:35.690Z,1755984995.690 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:35.942Z,1755984995.942 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:36.194Z,1755984996.194 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:36.446Z,1755984996.446 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:36.698Z,1755984996.698 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:36.950Z,1755984996.950 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:37.202Z,1755984997.202 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:37.454Z,1755984997.454 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-23T21:36:37.708Z,1755984997.708 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:36:37.4454 2025-08-23T21:36:37.708Z,1755984997.708 [DAT](DEBUG): Re-entering command mode due to unexpected online mode. 2025-08-23T21:36:37.762Z,1755984997.762 [DAT](INFO): entering command mode 2025-08-23T21:36:37.762Z,1755984997.762 [DAT](ERROR): Failure setting remote address to 50 2025-08-23T21:36:37.958Z,1755984997.958 [DAT](INFO): DAT read: 2025-08-23T21:36:37.959Z,1755984997.959 [DAT](INFO): DAT read: user:1554> 2025-08-23T21:36:37.959Z,1755984997.959 [DAT](INFO): setting remote address to 50 2025-08-23T21:36:38.210Z,1755984998.210 [DAT](INFO): DAT read: user:1554> 2025-08-23T21:36:38.211Z,1755984998.211 [DAT](INFO): DAT read: RemoteAddr | 50 2025-08-23T21:36:38.212Z,1755984998.212 [DAT](INFO): set remote address to 50 2025-08-23T21:36:38.212Z,1755984998.212 [DAT](INFO): entering online mode 2025-08-23T21:36:38.462Z,1755984998.462 [DAT](INFO): DAT read: user:1555> 2025-08-23T21:36:38.463Z,1755984998.463 [DAT](INFO): DAT read: 2025-08-23T21:36:38.464Z,1755984998.464 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-08-23T21:36:38.464Z,1755984998.464 [DAT](INFO): commRate: 600 2025-08-23T21:36:38.464Z,1755984998.464 [DAT](INFO): online mode acknowledged 2025-08-23T21:36:38.465Z,1755984998.465 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-08-23T21:36:41.742Z,1755985001.742 [DAT](INFO): DAT read: Forwarding Delay UpTx time:21:36:41.4454 2025-08-23T21:36:41.743Z,1755985001.743 [DAT](DEBUG): In parseResponses, sent ack so set commsState_ = SENDING_VERIFIED 2025-08-23T21:36:41.743Z,1755985001.743 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-08-23T21:37:04.417Z,1755985024.417 [DefaultWithUndock:A.Wait](INFO): Done Waiting. 2025-08-23T21:37:04.417Z,1755985024.417 [DefaultWithUndock:A.Wait] Stopped 2025-08-23T21:37:04.418Z,1755985024.418 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component. 2025-08-23T21:37:04.418Z,1755985024.418 [DefaultWithUndock:LeaveDock] Running Loop=1 2025-08-23T21:37:04.418Z,1755985024.418 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock 2025-08-23T21:37:04.418Z,1755985024.418 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2025-08-23T21:37:04.418Z,1755985024.418 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact. 2025-08-23T21:37:04.418Z,1755985024.418 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1 2025-08-23T21:37:04.418Z,1755985024.418 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-08-23T21:37:04.418Z,1755985024.418 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-08-23T21:37:04.803Z,1755985024.803 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-08-23T21:37:04.803Z,1755985024.803 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-08-23T21:37:04.804Z,1755985024.804 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock at depth 65.594162 m. 2025-08-23T21:37:04.805Z,1755985024.805 [DefaultWithUndock:LeaveDock:A.](ERROR): Failed to read sound speed 2025-08-23T21:37:05.612Z,1755985025.612 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-08-23T21:37:05.727Z,1755985025.727 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-08-23T21:37:07.591Z,1755985027.591 [CTD_Seabird](ERROR): Failed to parse device response: 2025-08-23T21:37:09.303Z,1755985029.303 [DockingStepper](INFO): Changing to mode: 3 2025-08-23T21:37:14.542Z,1755985034.542 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-23T21:37:14.774Z,1755985034.774 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:37:14.774Z,1755985034.774 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:37:14.826Z,1755985034.826 [DAT](INFO): entering command mode 2025-08-23T21:37:15.026Z,1755985035.026 [DAT](INFO): DAT read: 2025-08-23T21:37:15.027Z,1755985035.027 [DAT](INFO): DAT read: user:1556> 2025-08-23T21:37:15.027Z,1755985035.027 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:37:15.027Z,1755985035.027 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:37:15.028Z,1755985035.028 [DAT](INFO): setting remote address to 0 2025-08-23T21:37:15.278Z,1755985035.278 [DAT](INFO): DAT read: user:1556> 2025-08-23T21:37:15.279Z,1755985035.279 [DAT](INFO): DAT read: RemoteAddr | 0 2025-08-23T21:37:15.280Z,1755985035.280 [DAT](INFO): set remote address to 0 2025-08-23T21:37:15.280Z,1755985035.280 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:37:15.280Z,1755985035.280 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:37:15.281Z,1755985035.281 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:37:15.369Z,1755985035.369 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-23T21:37:15.369Z,1755985035.369 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Engaging thruster for 10.0 seconds (max) to disengage. 2025-08-23T21:37:15.532Z,1755985035.532 [DAT](INFO): DAT read: user:1557> 2025-08-23T21:37:15.533Z,1755985035.533 [DAT](INFO): DAT read: Tx time:21:37:15.1981 2025-08-23T21:37:15.533Z,1755985035.533 [DAT](INFO): Ping request sent. 2025-08-23T21:37:15.533Z,1755985035.533 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:37:15.534Z,1755985035.534 [DAT](INFO): publishing transmit ping time 2025-08-23T21:37:15.534Z,1755985035.534 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000878 2025-08-23T21:37:15.728Z,1755985035.728 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-23T21:37:15.783Z,1755985035.783 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.249341 2025-08-23T21:37:16.035Z,1755985036.035 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501335 2025-08-23T21:37:16.118Z,1755985036.118 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-23T21:37:16.287Z,1755985036.287 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753279 2025-08-23T21:37:16.539Z,1755985036.539 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005411 2025-08-23T21:37:16.539Z,1755985036.539 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-23T21:37:16.791Z,1755985036.791 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.257490 2025-08-23T21:37:16.932Z,1755985036.932 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-23T21:37:17.043Z,1755985037.043 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.509379 2025-08-23T21:37:17.306Z,1755985037.306 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.772988 2025-08-23T21:37:17.357Z,1755985037.357 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-23T21:37:17.547Z,1755985037.547 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.013230 2025-08-23T21:37:17.737Z,1755985037.737 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-23T21:37:17.800Z,1755985037.800 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266272 2025-08-23T21:37:18.050Z,1755985038.050 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.517183 2025-08-23T21:37:18.137Z,1755985038.137 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-23T21:37:18.305Z,1755985038.305 [DAT](INFO): DAT read: Rx Time:21:37:17.6049 2025-08-23T21:37:18.306Z,1755985038.306 [DAT](INFO): Rx dataTimestamp_ set to:1755985038.305838 2025-08-23T21:37:18.307Z,1755985038.307 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.773670 2025-08-23T21:37:18.555Z,1755985038.555 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.021327 2025-08-23T21:37:18.575Z,1755985038.575 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-23T21:37:18.809Z,1755985038.809 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275394 2025-08-23T21:37:18.942Z,1755985038.942 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-23T21:37:19.064Z,1755985039.064 [DAT](INFO): DAT read: 21:37:17.6049 LVL= 23152, 8113, 26674, 23763, AGC= 44, IDX= 103, 0.05, 1.197, 0.675,-0.177, 2.035, PHS=-0.736,-1.315,-2.256, RAW= 52.2, 48.9, CAL= 49.5, 53.5, ROT= 100.5, -53.5 2025-08-23T21:37:19.065Z,1755985039.065 [DAT](INFO): got valid direction response: 21:37:17.6049 LVL= 23152, 8113, 26674, 23763, AGC= 44, IDX= 103, 0.05, 1.197, 0.675,-0.177, 2.035, PHS=-0.736,-1.315,-2.256, RAW= 52.2, 48.9, CAL= 49.5, 53.5, ROT= 100.5, -53.5 2025-08-23T21:37:19.066Z,1755985039.066 [DAT](INFO): DAT read: Bearing 53.5, 43.4 (Local) 2025-08-23T21:37:19.066Z,1755985039.066 [DAT](INFO): Local bearing/azimuth received: Bearing 53.5, 43.4 (Local) 2025-08-23T21:37:19.068Z,1755985039.068 [DAT](INFO): DAT read: Range 11 to 50 : 1.9 m (Round-trip 2.6 ms) speed 0.0 m/s 2025-08-23T21:37:19.068Z,1755985039.068 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:37:19.069Z,1755985039.069 [DAT](INFO): direction in FSK: [-0.108398,0.584862,0.803857] 2025-08-23T21:37:19.070Z,1755985039.070 [DAT](INFO): publishing direction and range info 2025-08-23T21:37:24.627Z,1755985044.627 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-23T21:37:24.854Z,1755985044.854 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:37:24.854Z,1755985044.854 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:37:24.855Z,1755985044.855 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:37:25.107Z,1755985045.107 [DAT](INFO): DAT read: user:1558> 2025-08-23T21:37:25.108Z,1755985045.108 [DAT](INFO): DAT read: Tx time:21:37:24.7466 2025-08-23T21:37:25.108Z,1755985045.108 [DAT](INFO): Ping request sent. 2025-08-23T21:37:25.109Z,1755985045.109 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:37:25.109Z,1755985045.109 [DAT](INFO): publishing transmit ping time 2025-08-23T21:37:25.110Z,1755985045.110 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001185 2025-08-23T21:37:25.361Z,1755985045.361 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.252176 2025-08-23T21:37:25.463Z,1755985045.463 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Thruster off. 2025-08-23T21:37:25.610Z,1755985045.610 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501921 2025-08-23T21:37:25.863Z,1755985045.863 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754522 2025-08-23T21:37:26.114Z,1755985046.114 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005928 2025-08-23T21:37:26.370Z,1755985046.370 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.260466 2025-08-23T21:37:26.619Z,1755985046.619 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510012 2025-08-23T21:37:26.871Z,1755985046.871 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762077 2025-08-23T21:37:27.122Z,1755985047.122 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.013905 2025-08-23T21:37:27.380Z,1755985047.380 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.268265 2025-08-23T21:37:27.627Z,1755985047.627 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518013 2025-08-23T21:37:27.879Z,1755985047.879 [DAT](INFO): DAT read: Rx Time:21:37:27.1537 2025-08-23T21:37:27.880Z,1755985047.880 [DAT](INFO): Rx dataTimestamp_ set to:1755985047.879594 2025-08-23T21:37:27.881Z,1755985047.881 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772166 2025-08-23T21:37:28.131Z,1755985048.131 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.021997 2025-08-23T21:37:28.384Z,1755985048.384 [DAT](INFO): DAT read: Range 11 to 50 : 2.1 m (Round-trip 2.9 ms) speed -0.1 m/s 2025-08-23T21:37:28.384Z,1755985048.384 [DAT](ERROR): #Rx 1: Read range message, but no direction. 2025-08-23T21:37:34.714Z,1755985054.714 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-23T21:37:34.946Z,1755985054.946 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:37:34.946Z,1755985054.946 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:37:34.947Z,1755985054.947 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:37:35.199Z,1755985055.199 [DAT](INFO): DAT read: user:1559> 2025-08-23T21:37:35.200Z,1755985055.200 [DAT](INFO): DAT read: Tx time:21:37:34.8466 2025-08-23T21:37:35.200Z,1755985055.200 [DAT](INFO): Ping request sent. 2025-08-23T21:37:35.200Z,1755985055.200 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:37:35.201Z,1755985055.201 [DAT](INFO): publishing transmit ping time 2025-08-23T21:37:35.202Z,1755985055.202 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001129 2025-08-23T21:37:35.450Z,1755985055.450 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.249952 2025-08-23T21:37:35.702Z,1755985055.702 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501955 2025-08-23T21:37:35.955Z,1755985055.955 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754960 2025-08-23T21:37:36.207Z,1755985056.207 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006341 2025-08-23T21:37:36.458Z,1755985056.458 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.257986 2025-08-23T21:37:36.712Z,1755985056.712 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511295 2025-08-23T21:37:36.962Z,1755985056.962 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761974 2025-08-23T21:37:37.215Z,1755985057.215 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014471 2025-08-23T21:37:37.467Z,1755985057.467 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266020 2025-08-23T21:37:37.718Z,1755985057.718 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.517974 2025-08-23T21:37:37.971Z,1755985057.971 [DAT](INFO): DAT read: Rx Time:21:37:37.2551 2025-08-23T21:37:37.972Z,1755985057.972 [DAT](INFO): Rx dataTimestamp_ set to:1755985057.971408 2025-08-23T21:37:37.973Z,1755985057.973 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772041 2025-08-23T21:37:38.223Z,1755985058.223 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022094 2025-08-23T21:37:38.477Z,1755985058.477 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275756 2025-08-23T21:37:38.732Z,1755985058.732 [DAT](INFO): DAT read: 21:37:37.2551 LVL= 32752, 32753, 32754, 32755, AGC= 47, IDX= 441, 0.19, 2.844, 0.996, 1.609, 2.774, PHS= 0.172,-1.733,-1.209, RAW= 105.4, 29.9, CAL= 103.4, 36.9, ROT= 46.6, -36.9 2025-08-23T21:37:38.733Z,1755985058.733 [DAT](INFO): got valid direction response: 21:37:37.2551 LVL= 32752, 32753, 32754, 32755, AGC= 47, IDX= 441, 0.19, 2.844, 0.996, 1.609, 2.774, PHS= 0.172,-1.733,-1.209, RAW= 105.4, 29.9, CAL= 103.4, 36.9, ROT= 46.6, -36.9 2025-08-23T21:37:38.738Z,1755985058.738 [DAT](INFO): DAT read: Bearing 334.5, 39.0 (Local) 2025-08-23T21:37:38.738Z,1755985058.738 [DAT](INFO): Local bearing/azimuth received: Bearing 334.5, 39.0 (Local) 2025-08-23T21:37:38.739Z,1755985058.739 [DAT](INFO): DAT read: Range 11 to 50 : 3.2 m (Round-trip 4.3 ms) speed -0.1 m/s 2025-08-23T21:37:38.740Z,1755985058.740 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:37:38.741Z,1755985058.741 [DAT](INFO): direction in FSK: [0.549453,0.581031,0.600420] 2025-08-23T21:37:38.741Z,1755985058.741 [DAT](INFO): publishing direction and range info 2025-08-23T21:37:44.839Z,1755985064.839 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-23T21:37:45.035Z,1755985065.035 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:37:45.035Z,1755985065.035 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:37:45.035Z,1755985065.035 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:37:45.286Z,1755985065.286 [DAT](INFO): DAT read: user:1560> 2025-08-23T21:37:45.287Z,1755985065.287 [DAT](INFO): DAT read: Tx time:21:37:44.9466 2025-08-23T21:37:45.287Z,1755985065.287 [DAT](INFO): Ping request sent. 2025-08-23T21:37:45.287Z,1755985065.287 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:37:45.288Z,1755985065.288 [DAT](INFO): publishing transmit ping time 2025-08-23T21:37:45.288Z,1755985065.288 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000760 2025-08-23T21:37:45.539Z,1755985065.539 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251016 2025-08-23T21:37:45.791Z,1755985065.791 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503047 2025-08-23T21:37:46.043Z,1755985066.043 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755079 2025-08-23T21:37:46.294Z,1755985066.294 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006995 2025-08-23T21:37:46.547Z,1755985066.547 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259772 2025-08-23T21:37:46.804Z,1755985066.804 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.516321 2025-08-23T21:37:47.050Z,1755985067.050 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762962 2025-08-23T21:37:47.303Z,1755985067.303 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015057 2025-08-23T21:37:47.554Z,1755985067.554 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266939 2025-08-23T21:37:47.807Z,1755985067.807 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519006 2025-08-23T21:37:48.059Z,1755985068.059 [DAT](INFO): DAT read: Rx Time:21:37:47.3570 2025-08-23T21:37:48.059Z,1755985068.059 [DAT](INFO): Rx dataTimestamp_ set to:1755985068.058826 2025-08-23T21:37:48.060Z,1755985068.060 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772188 2025-08-23T21:37:48.311Z,1755985068.311 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023015 2025-08-23T21:37:48.565Z,1755985068.565 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.276861 2025-08-23T21:37:48.828Z,1755985068.828 [DAT](INFO): DAT read: 21:37:47.3570 LVL= 21792, 26529, 30546, 32755, AGC= 39, IDX= 445,-0.21, 2.522, 0.148, 1.343, 1.652, PHS= 0.972,-1.459,-0.352, RAW= 117.0, 8.0, CAL= 118.3, 9.1, ROT= 31.7, -9.1 2025-08-23T21:37:48.829Z,1755985068.829 [DAT](INFO): got valid direction response: 21:37:47.3570 LVL= 21792, 26529, 30546, 32755, AGC= 39, IDX= 445,-0.21, 2.522, 0.148, 1.343, 1.652, PHS= 0.972,-1.459,-0.352, RAW= 117.0, 8.0, CAL= 118.3, 9.1, ROT= 31.7, -9.1 2025-08-23T21:37:48.830Z,1755985068.830 [DAT](INFO): DAT read: Bearing 291.5, 34.6 (Local) 2025-08-23T21:37:48.830Z,1755985068.830 [DAT](INFO): Local bearing/azimuth received: Bearing 291.5, 34.6 (Local) 2025-08-23T21:37:48.832Z,1755985068.832 [DAT](INFO): DAT read: Range 11 to 50 : 4.6 m (Round-trip 6.2 ms) speed -0.1 m/s 2025-08-23T21:37:48.832Z,1755985068.832 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:37:48.833Z,1755985068.833 [DAT](INFO): direction in FSK: [0.840103,0.518858,0.158158] 2025-08-23T21:37:48.833Z,1755985068.833 [DAT](INFO): publishing direction and range info 2025-08-23T21:37:54.940Z,1755985074.940 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-23T21:37:55.122Z,1755985075.122 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:37:55.122Z,1755985075.122 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:37:55.123Z,1755985075.123 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:37:55.374Z,1755985075.374 [DAT](INFO): DAT read: user:1561> 2025-08-23T21:37:55.375Z,1755985075.375 [DAT](INFO): DAT read: Tx time:21:37:55.0466 2025-08-23T21:37:55.375Z,1755985075.375 [DAT](INFO): Ping request sent. 2025-08-23T21:37:55.376Z,1755985075.376 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:37:55.376Z,1755985075.376 [DAT](INFO): publishing transmit ping time 2025-08-23T21:37:55.376Z,1755985075.376 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000752 2025-08-23T21:37:55.627Z,1755985075.627 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250891 2025-08-23T21:37:55.693Z,1755985075.693 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-08-23T21:37:55.878Z,1755985075.878 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502871 2025-08-23T21:37:56.131Z,1755985076.131 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755036 2025-08-23T21:37:56.383Z,1755985076.383 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.007068 2025-08-23T21:37:56.634Z,1755985076.634 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258871 2025-08-23T21:37:56.886Z,1755985076.886 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510847 2025-08-23T21:37:57.139Z,1755985077.139 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762932 2025-08-23T21:37:57.391Z,1755985077.391 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014912 2025-08-23T21:37:57.642Z,1755985077.642 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266845 2025-08-23T21:37:57.895Z,1755985077.895 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518940 2025-08-23T21:37:58.149Z,1755985078.149 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772859 2025-08-23T21:37:58.399Z,1755985078.399 [DAT](INFO): DAT read: Rx Time:21:37:57.4591 2025-08-23T21:37:58.399Z,1755985078.399 [DAT](INFO): Rx dataTimestamp_ set to:1755985078.398869 2025-08-23T21:37:58.400Z,1755985078.400 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.024111 2025-08-23T21:37:58.651Z,1755985078.651 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274930 2025-08-23T21:37:58.930Z,1755985078.930 [DAT](INFO): DAT read: 21:37:57.4591 LVL= 22160, 29665, 29266, 32755, AGC= 42, IDX= 450, 0.13,-2.434, 1.513, 2.507, 2.912, PHS= 1.039,-1.354,-0.449, RAW= 112.0, 7.4, CAL= 113.5, 8.3, ROT= 36.5, -8.3 2025-08-23T21:37:58.931Z,1755985078.931 [DAT](INFO): got valid direction response: 21:37:57.4591 LVL= 22160, 29665, 29266, 32755, AGC= 42, IDX= 450, 0.13,-2.434, 1.513, 2.507, 2.912, PHS= 1.039,-1.354,-0.449, RAW= 112.0, 7.4, CAL= 113.5, 8.3, ROT= 36.5, -8.3 2025-08-23T21:37:58.932Z,1755985078.932 [DAT](INFO): DAT read: Bearing 284.6, 37.0 (Local) 2025-08-23T21:37:58.932Z,1755985078.932 [DAT](INFO): Local bearing/azimuth received: Bearing 284.6, 37.0 (Local) 2025-08-23T21:37:58.946Z,1755985078.946 [DAT](INFO): DAT read: Range 11 to 50 : 6.2 m (Round-trip 8.3 ms) speed -0.2 m/s 2025-08-23T21:37:58.947Z,1755985078.947 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:37:58.948Z,1755985078.948 [DAT](INFO): direction in FSK: [0.795437,0.588593,0.144356] 2025-08-23T21:37:58.948Z,1755985078.948 [DAT](INFO): publishing direction and range info 2025-08-23T21:38:05.035Z,1755985085.035 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-23T21:38:05.203Z,1755985085.203 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:38:05.203Z,1755985085.203 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:38:05.203Z,1755985085.203 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:38:05.464Z,1755985085.464 [DAT](INFO): DAT read: user:1562> 2025-08-23T21:38:05.465Z,1755985085.465 [DAT](INFO): DAT read: Tx time:21:38:05.0966 2025-08-23T21:38:05.465Z,1755985085.465 [DAT](INFO): Ping request sent. 2025-08-23T21:38:05.465Z,1755985085.465 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:38:05.466Z,1755985085.466 [DAT](INFO): publishing transmit ping time 2025-08-23T21:38:05.467Z,1755985085.467 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001918 2025-08-23T21:38:05.714Z,1755985085.714 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.249375 2025-08-23T21:38:05.969Z,1755985085.969 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503590 2025-08-23T21:38:06.219Z,1755985086.219 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753880 2025-08-23T21:38:06.470Z,1755985086.470 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005458 2025-08-23T21:38:06.723Z,1755985086.723 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.257464 2025-08-23T21:38:06.978Z,1755985086.978 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.512013 2025-08-23T21:38:07.227Z,1755985087.227 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761466 2025-08-23T21:38:07.479Z,1755985087.479 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.013562 2025-08-23T21:38:07.731Z,1755985087.731 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.265492 2025-08-23T21:38:07.985Z,1755985087.985 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519802 2025-08-23T21:38:08.235Z,1755985088.235 [DAT](INFO): DAT read: Rx Time:21:38:07.5114 2025-08-23T21:38:08.235Z,1755985088.235 [DAT](INFO): Rx dataTimestamp_ set to:1755985088.234758 2025-08-23T21:38:08.236Z,1755985088.236 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770570 2025-08-23T21:38:08.487Z,1755985088.487 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.021527 2025-08-23T21:38:08.741Z,1755985088.741 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275140 2025-08-23T21:38:09.037Z,1755985089.037 [DAT](INFO): DAT read: 21:38:07.5114 LVL= 19440, 32753, 32242, 32755, AGC= 46, IDX= 441, 0.00, 0.419,-1.916,-0.932,-0.545, PHS= 1.066,-1.326,-0.431, RAW= 111.7, 6.7, CAL= 113.2, 7.5, ROT= 36.8, -7.5 2025-08-23T21:38:09.044Z,1755985089.044 [DAT](INFO): got valid direction response: 21:38:07.5114 LVL= 19440, 32753, 32242, 32755, AGC= 46, IDX= 441, 0.00, 0.419,-1.916,-0.932,-0.545, PHS= 1.066,-1.326,-0.431, RAW= 111.7, 6.7, CAL= 113.2, 7.5, ROT= 36.8, -7.5 2025-08-23T21:38:09.051Z,1755985089.051 [DAT](INFO): DAT read: Bearing 281.0, 34.8 (Local) 2025-08-23T21:38:09.052Z,1755985089.052 [DAT](INFO): Local bearing/azimuth received: Bearing 281.0, 34.8 (Local) 2025-08-23T21:38:09.075Z,1755985089.075 [DAT](INFO): DAT read: Range 11 to 50 : 7.9 m (Round-trip 10.6 ms) speed -0.1 m/s 2025-08-23T21:38:09.076Z,1755985089.076 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:38:09.077Z,1755985089.077 [DAT](INFO): direction in FSK: [0.793881,0.593899,0.130526] 2025-08-23T21:38:09.077Z,1755985089.077 [DAT](INFO): publishing direction and range info 2025-08-23T21:38:09.167Z,1755985089.167 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2025-08-23T21:38:15.198Z,1755985095.198 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-23T21:38:15.294Z,1755985095.294 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:38:15.294Z,1755985095.294 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:38:15.295Z,1755985095.295 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:38:15.547Z,1755985095.547 [DAT](INFO): DAT read: user:1563> 2025-08-23T21:38:15.548Z,1755985095.548 [DAT](INFO): DAT read: Tx time:21:38:15.1967 2025-08-23T21:38:15.548Z,1755985095.548 [DAT](INFO): Ping request sent. 2025-08-23T21:38:15.548Z,1755985095.548 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:38:15.549Z,1755985095.549 [DAT](INFO): publishing transmit ping time 2025-08-23T21:38:15.550Z,1755985095.550 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001057 2025-08-23T21:38:15.798Z,1755985095.798 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250332 2025-08-23T21:38:16.051Z,1755985096.051 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502414 2025-08-23T21:38:16.303Z,1755985096.303 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754452 2025-08-23T21:38:16.554Z,1755985096.555 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006386 2025-08-23T21:38:16.807Z,1755985096.807 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258442 2025-08-23T21:38:17.059Z,1755985097.059 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511192 2025-08-23T21:38:17.311Z,1755985097.311 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762653 2025-08-23T21:38:17.563Z,1755985097.563 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014499 2025-08-23T21:38:17.814Z,1755985097.814 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266307 2025-08-23T21:38:18.067Z,1755985098.067 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518392 2025-08-23T21:38:18.319Z,1755985098.319 [DAT](INFO): DAT read: Rx Time:21:38:17.6135 2025-08-23T21:38:18.319Z,1755985098.319 [DAT](INFO): Rx dataTimestamp_ set to:1755985098.318862 2025-08-23T21:38:18.320Z,1755985098.320 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771610 2025-08-23T21:38:18.571Z,1755985098.571 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022400 2025-08-23T21:38:18.825Z,1755985098.825 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.276224 2025-08-23T21:38:19.080Z,1755985099.080 [DAT](INFO): DAT read: 21:38:17.6135 LVL= 23008, 32753, 30786, 32755, AGC= 42, IDX= 447,-0.46, 1.606,-0.585, 0.445, 0.753, PHS= 0.955,-1.293,-0.352, RAW= 114.6, 7.1, CAL= 116.0, 8.1, ROT= 34.0, -8.1 2025-08-23T21:38:19.081Z,1755985099.081 [DAT](INFO): got valid direction response: 21:38:17.6135 LVL= 23008, 32753, 30786, 32755, AGC= 42, IDX= 447,-0.46, 1.606,-0.585, 0.445, 0.753, PHS= 0.955,-1.293,-0.352, RAW= 114.6, 7.1, CAL= 116.0, 8.1, ROT= 34.0, -8.1 2025-08-23T21:38:19.082Z,1755985099.082 [DAT](INFO): DAT read: Bearing 282.7, 35.5 (Local) 2025-08-23T21:38:19.082Z,1755985099.082 [DAT](INFO): Local bearing/azimuth received: Bearing 282.7, 35.5 (Local) 2025-08-23T21:38:19.083Z,1755985099.083 [DAT](INFO): DAT read: Range 11 to 50 : 9.4 m (Round-trip 12.6 ms) speed -0.2 m/s 2025-08-23T21:38:19.084Z,1755985099.084 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:38:19.085Z,1755985099.085 [DAT](INFO): direction in FSK: [0.820767,0.553614,0.140901] 2025-08-23T21:38:19.085Z,1755985099.085 [DAT](INFO): publishing direction and range info 2025-08-23T21:38:25.219Z,1755985105.219 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-23T21:38:25.374Z,1755985105.374 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:38:25.374Z,1755985105.374 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:38:25.375Z,1755985105.375 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:38:25.626Z,1755985105.626 [DAT](INFO): DAT read: user:1564> 2025-08-23T21:38:25.627Z,1755985105.627 [DAT](INFO): DAT read: Tx time:21:38:25.2967 2025-08-23T21:38:25.628Z,1755985105.628 [DAT](INFO): Ping request sent. 2025-08-23T21:38:25.628Z,1755985105.628 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:38:25.628Z,1755985105.628 [DAT](INFO): publishing transmit ping time 2025-08-23T21:38:25.628Z,1755985105.628 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000747 2025-08-23T21:38:25.879Z,1755985105.879 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250822 2025-08-23T21:38:26.131Z,1755985106.131 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502811 2025-08-23T21:38:26.387Z,1755985106.387 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.758950 2025-08-23T21:38:26.639Z,1755985106.639 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.010859 2025-08-23T21:38:26.890Z,1755985106.890 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.262778 2025-08-23T21:38:27.143Z,1755985107.143 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.514812 2025-08-23T21:38:27.395Z,1755985107.395 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.767011 2025-08-23T21:38:27.647Z,1755985107.647 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.018913 2025-08-23T21:38:27.899Z,1755985107.899 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.270989 2025-08-23T21:38:28.151Z,1755985108.151 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.522849 2025-08-23T21:38:28.406Z,1755985108.406 [DAT](INFO): DAT read: Rx Time:21:38:27.7157 2025-08-23T21:38:28.407Z,1755985108.407 [DAT](INFO): Rx dataTimestamp_ set to:1755985108.406598 2025-08-23T21:38:28.407Z,1755985108.407 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.779760 2025-08-23T21:38:28.659Z,1755985108.659 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.030814 2025-08-23T21:38:28.911Z,1755985108.911 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.282894 2025-08-23T21:38:29.168Z,1755985109.168 [DAT](INFO): DAT read: 21:38:27.7157 LVL= 25392, 32753, 32754, 32755, AGC= 44, IDX= 452, 0.20,-0.851,-2.932,-1.878,-1.564, PHS= 0.815,-1.323,-0.358, RAW= 116.8, 9.4, CAL= 118.0, 10.5, ROT= 32.0, -10.5 2025-08-23T21:38:29.169Z,1755985109.169 [DAT](INFO): got valid direction response: 21:38:27.7157 LVL= 25392, 32753, 32754, 32755, AGC= 44, IDX= 452, 0.20,-0.851,-2.932,-1.878,-1.564, PHS= 0.815,-1.323,-0.358, RAW= 116.8, 9.4, CAL= 118.0, 10.5, ROT= 32.0, -10.5 2025-08-23T21:38:29.170Z,1755985109.170 [DAT](INFO): DAT read: Bearing 287.3, 33.8 (Local) 2025-08-23T21:38:29.170Z,1755985109.170 [DAT](INFO): Local bearing/azimuth received: Bearing 287.3, 33.8 (Local) 2025-08-23T21:38:29.171Z,1755985109.171 [DAT](INFO): DAT read: Range 11 to 50 : 11.1 m (Round-trip 14.8 ms) speed -0.2 m/s 2025-08-23T21:38:29.172Z,1755985109.172 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:38:29.173Z,1755985109.173 [DAT](INFO): direction in FSK: [0.833847,0.521046,0.182236] 2025-08-23T21:38:29.173Z,1755985109.173 [DAT](INFO): publishing direction and range info 2025-08-23T21:38:29.270Z,1755985109.270 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: 11.10 m. Transitioning docking module to standby. 2025-08-23T21:38:29.679Z,1755985109.679 [DockingStepper](INFO): Changing to mode: 1 2025-08-23T21:38:35.301Z,1755985115.301 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-23T21:38:35.470Z,1755985115.470 [DAT](INFO): ****** received valid address query ****** 2025-08-23T21:38:35.470Z,1755985115.470 [DAT](INFO): ****** received valid ping request ****** 2025-08-23T21:38:35.471Z,1755985115.471 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-23T21:38:35.723Z,1755985115.723 [DAT](INFO): DAT read: user:1565> 2025-08-23T21:38:35.723Z,1755985115.723 [DAT](INFO): DAT read: Tx time:21:38:35.3967 2025-08-23T21:38:35.724Z,1755985115.724 [DAT](INFO): Ping request sent. 2025-08-23T21:38:35.724Z,1755985115.724 [DAT](INFO): transmitted an acoustic signal 2025-08-23T21:38:35.724Z,1755985115.724 [DAT](INFO): publishing transmit ping time 2025-08-23T21:38:35.726Z,1755985115.726 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001801 2025-08-23T21:38:35.748Z,1755985115.748 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby. 2025-08-23T21:38:35.974Z,1755985115.974 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250627 2025-08-23T21:38:36.103Z,1755985116.103 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete. 2025-08-23T21:38:36.103Z,1755985116.103 [DefaultWithUndock:LeaveDock:B.Undock] Stopped 2025-08-23T21:38:36.103Z,1755985116.103 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock 2025-08-23T21:38:36.103Z,1755985116.103 [DefaultWithUndock:LeaveDock] Stopped 2025-08-23T21:38:36.104Z,1755985116.104 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock 2025-08-23T21:38:36.104Z,1755985116.104 [DefaultWithUndock:LeaveDock:A.] Stopped 2025-08-23T21:38:36.104Z,1755985116.104 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact. 2025-08-23T21:38:36.104Z,1755985116.104 [DefaultWithUndock:SurfaceDefault] Running Loop=1 2025-08-23T21:38:36.104Z,1755985116.104 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault 2025-08-23T21:38:36.104Z,1755985116.104 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1 2025-08-23T21:38:36.104Z,1755985116.104 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-23T21:38:36.104Z,1755985116.104 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-08-23T21:38:36.105Z,1755985116.105 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-08-23T21:38:36.105Z,1755985116.105 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-08-23T21:38:36.106Z,1755985116.106 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-08-23T21:38:36.106Z,1755985116.106 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-23T21:38:36.106Z,1755985116.106 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-23T21:38:36.227Z,1755985116.227 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502687 2025-08-23T21:38:36.478Z,1755985116.478 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754663 2025-08-23T21:38:36.730Z,1755985116.730 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006655 2025-08-23T21:38:36.911Z,1755985116.911 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -24.00 mm (2 active estimators). 2025-08-23T21:38:36.982Z,1755985116.982 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258666 2025-08-23T21:38:37.186Z,1755985117.186 [Radio_Surface](INFO): Powering up 2025-08-23T21:38:37.235Z,1755985117.235 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510898 2025-08-23T21:38:37.487Z,1755985117.487 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763512 2025-08-23T21:38:37.739Z,1755985117.739 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014749 2025-08-23T21:38:37.990Z,1755985117.990 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266669 2025-08-23T21:38:38.243Z,1755985118.243 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518685 2025-08-23T21:38:38.494Z,1755985118.494 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770616 2025-08-23T21:38:38.747Z,1755985118.747 [DAT](INFO): DAT read: Rx Time:21:38:37.8177 2025-08-23T21:38:38.747Z,1755985118.747 [DAT](INFO): Rx dataTimestamp_ set to:1755985118.746703 2025-08-23T21:38:38.748Z,1755985118.748 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023730 2025-08-23T21:38:38.999Z,1755985118.999 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275306 2025-08-23T21:38:39.256Z,1755985119.256 [DAT](INFO): DAT read: 21:38:37.8177 LVL= 22880, 32753, 29170, 32755, AGC= 49, IDX= 442,-0.28, 1.351,-0.710, 0.451, 0.723, PHS= 0.730,-1.388,-0.316, RAW= 120.4, 10.6, CAL= 121.2, 11.8, ROT= 28.8, -11.8 2025-08-23T21:38:39.257Z,1755985119.257 [DAT](INFO): got valid direction response: 21:38:37.8177 LVL= 22880, 32753, 29170, 32755, AGC= 49, IDX= 442,-0.28, 1.351,-0.710, 0.451, 0.723, PHS= 0.730,-1.388,-0.316, RAW= 120.4, 10.6, CAL= 121.2, 11.8, ROT= 28.8, -11.8 2025-08-23T21:38:39.258Z,1755985119.258 [DAT](INFO): DAT read: Bearing 291.3, 28.4 (Local) 2025-08-23T21:38:39.258Z,1755985119.258 [DAT](INFO): Local bearing/azimuth received: Bearing 291.3, 28.4 (Local) 2025-08-23T21:38:39.259Z,1755985119.259 [DAT](INFO): DAT read: Range 11 to 50 : 12.6 m (Round-trip 16.8 ms) speed -0.2 m/s 2025-08-23T21:38:39.260Z,1755985119.260 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-23T21:38:39.261Z,1755985119.261 [DAT](INFO): direction in FSK: [0.857788,0.471573,0.204496] 2025-08-23T21:38:39.261Z,1755985119.261 [DAT](INFO): publishing direction and range info 2025-08-23T21:38:42.438Z,1755985122.438 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.11 2025-08-23T21:38:42.439Z,1755985122.439 [Radio_Surface](INFO): No local IP found 2025-08-23T21:39:25.399Z,1755985165.399 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, -6.95 +9.10, +0.53, 24.91, 0.00 2025-08-23T21:41:04.206Z,1755985264.206 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-23T21:41:05.210Z,1755985265.210 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-23T21:41:05.210Z,1755985265.210 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-23T21:41:08.840Z,1755985268.840 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1 2025-08-23T21:41:08.840Z,1755985268.840 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-08-23T21:41:08.841Z,1755985268.841 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1 2025-08-23T21:41:35.334Z,1755985295.334 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-23T21:41:35.468Z,1755985295.468 [NAL9602](INFO): SBD MO Status=0, MOMSN=1036, MT Status=0, MTMSN=0 2025-08-23T21:41:35.468Z,1755985295.468 [NAL9602](INFO): No messages in MT queue 2025-08-23T21:41:36.338Z,1755985296.338 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-23T21:41:36.684Z,1755985296.684 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214136.00,A,3646.72499,N,12151.57902,W,0.292,286.54,230825,,,A*7C 2025-08-23T21:41:36.686Z,1755985296.686 [NAL9602](INFO): GPS fix at 20250823T214136: (36.778750, -121.859650) 2025-08-23T21:41:36.718Z,1755985296.718 [UniversalFixResidualReporter](INFO): Fix residual: 0.3 %DT, over the last 3818.8 m. Residual distance 12.0 m at bearing 93.4 degrees. Fix at (36.7788, -121.8596) with 477.4 m made good. 2025-08-23T21:41:36.719Z,1755985296.719 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped 2025-08-23T21:41:36.719Z,1755985296.719 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1 2025-08-23T21:41:59.889Z,1755985319.889 [NAL9602](INFO): SBD MO Status=2, MOMSN=1037, MT Status=2, MTMSN=0 2025-08-23T21:41:59.889Z,1755985319.889 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-23T21:42:06.459Z,1755985326.459 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-23T21:42:07.462Z,1755985327.462 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-23T21:42:36.183Z,1755985356.183 [DataOverHttps](IMPORTANT): SBD MTMSN=20250823T214235 2025-08-23T21:42:36.186Z,1755985356.186 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003249 2025-08-23T21:42:43.721Z,1755985363.721 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250823T184502/Courier0008.lzma 2025-08-23T21:42:43.724Z,1755985363.724 [DataOverHttps](INFO): Received command: schedule clear;schedule resume;restart logs