2025-09-20T19:00:13.111Z,1758394813.111 [sample_on_dock:N.Execute](INFO): Executing command restart logs 2025-09-20T19:00:13.111Z,1758394813.111 [sample_on_dock:N.Execute] Stopped 2025-09-20T19:00:13.111Z,1758394813.111 [sample_on_dock:P.Docked] Running Loop=1 2025-09-20T19:00:13.111Z,1758394813.111 [sample_on_dock:P.Docked](DEBUG): Initialize. 2025-09-20T19:00:13.113Z,1758394813.113 [sample_on_dock:P.Docked](DEBUG): Initializing internal variables to default values. 2025-09-20T19:00:13.166Z,1758394813.166 [CommandExec](IMPORTANT): got command restart logs 2025-09-20T19:00:13.628Z,1758394813.628 [DAT](INFO): entering command mode 2025-09-20T19:00:13.829Z,1758394813.829 [DAT](INFO): DAT read: 2025-09-20T19:00:13.829Z,1758394813.829 [DAT](INFO): DAT read: user:1329> 2025-09-20T19:00:13.830Z,1758394813.830 [DAT](INFO): Requesting device enable set for address 50. 2025-09-20T19:00:14.081Z,1758394814.081 [DAT](INFO): DAT read: user:1329> 2025-09-20T19:00:14.082Z,1758394814.082 [DAT](INFO): DAT read: Tx time:19:00:15.3132 2025-09-20T19:00:14.082Z,1758394814.082 [DAT](INFO): Ping request sent. 2025-09-20T19:00:14.082Z,1758394814.082 [DAT](INFO): transmitted an acoustic signal 2025-09-20T19:00:14.082Z,1758394814.082 [DAT](INFO): publishing transmit ping time 2025-09-20T19:00:14.083Z,1758394814.083 [DAT](INFO): Requesting device enable set for address 50. 2025-09-20T19:00:14.333Z,1758394814.333 [DAT](INFO): Requesting device enable set for address 50. 2025-09-20T19:00:14.363Z,1758394814.363 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-09-20T19:00:14.481Z,1758394814.481 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-09-20T19:00:16.349Z,1758394816.349 [DAT](INFO): DAT read: Rx Time:19:00:17.1963 2025-09-20T19:00:16.350Z,1758394816.350 [DAT](INFO): Rx dataTimestamp_ set to:1758394816.349249 2025-09-20T19:00:16.860Z,1758394816.860 [DAT](INFO): DAT read: 19:00:17.1963 LVL= 19264, 32753, 23458, 32755, AGC= 46, IDX= 267, 0.25, 2.071, 0.175, 1.642, 1.786, PHS= 0.386,-1.566,-0.188, RAW= 133.4, 15.5, CAL= 132.3, 16.6, ROT= 17.7, -16.6 2025-09-20T19:00:16.862Z,1758394816.862 [DAT](INFO): got valid direction response: 19:00:17.1963 LVL= 19264, 32753, 23458, 32755, AGC= 46, IDX= 267, 0.25, 2.071, 0.175, 1.642, 1.786, PHS= 0.386,-1.566,-0.188, RAW= 133.4, 15.5, CAL= 132.3, 16.6, ROT= 17.7, -16.6 2025-09-20T19:00:16.862Z,1758394816.862 [DAT](INFO): DAT read: OK 2025-09-20T19:00:16.862Z,1758394816.862 [DAT](INFO): unknown deviceResponse_: OK 2025-09-20T19:00:16.863Z,1758394816.863 [DAT](INFO): DAT read: user:1330> 2025-09-20T19:00:16.863Z,1758394816.863 [DAT](INFO): #Rx 3: Read direction message, but no range. 2025-09-20T19:00:16.864Z,1758394816.864 [DAT](INFO): direction in FSK: [0.912957,0.291362,0.285688] 2025-09-20T19:00:17.105Z,1758394817.105 [DAT](INFO): DAT read: Tx time:19:00:18.3132 2025-09-20T19:00:17.105Z,1758394817.105 [DAT](INFO): Ping request sent. 2025-09-20T19:00:17.105Z,1758394817.105 [DAT](INFO): transmitted an acoustic signal 2025-09-20T19:00:17.106Z,1758394817.106 [DAT](INFO): publishing transmit ping time 2025-09-20T19:00:18.021Z,1758394818.021 [DockingStepper](INFO): Changing to mode: 1 2025-09-20T19:00:19.373Z,1758394819.373 [DAT](INFO): DAT read: Rx Time:19:00:20.1968 2025-09-20T19:00:19.373Z,1758394819.373 [DAT](INFO): Rx dataTimestamp_ set to:1758394819.373197 2025-09-20T19:00:19.881Z,1758394819.881 [DAT](INFO): DAT read: 19:00:20.1968 LVL= 21824, 30801, 24754, 32755, AGC= 46, IDX= 432,-0.13, 1.166,-0.790, 0.737, 0.784, PHS= 0.485,-1.529,-0.090, RAW= 133.9, 12.6, CAL= 133.3, 13.7, ROT= 16.7, -13.7 2025-09-20T19:00:19.882Z,1758394819.882 [DAT](INFO): got valid direction response: 19:00:20.1968 LVL= 21824, 30801, 24754, 32755, AGC= 46, IDX= 432,-0.13, 1.166,-0.790, 0.737, 0.784, PHS= 0.485,-1.529,-0.090, RAW= 133.9, 12.6, CAL= 133.3, 13.7, ROT= 16.7, -13.7 2025-09-20T19:00:19.883Z,1758394819.883 [DAT](INFO): DAT read: OK 2025-09-20T19:00:19.884Z,1758394819.884 [DAT](INFO): unknown deviceResponse_: OK 2025-09-20T19:00:19.886Z,1758394819.886 [DAT](INFO): DAT read: user:1331> 2025-09-20T19:00:19.888Z,1758394819.888 [DAT](INFO): #Rx 4: Read direction message, but no range. 2025-09-20T19:00:19.889Z,1758394819.889 [DAT](INFO): direction in FSK: [0.930572,0.279185,0.236838] 2025-09-20T19:00:20.129Z,1758394820.129 [DAT](INFO): DAT read: Tx time:19:00:21.3132 2025-09-20T19:00:20.129Z,1758394820.129 [DAT](INFO): Ping request sent. 2025-09-20T19:00:20.129Z,1758394820.129 [DAT](INFO): transmitted an acoustic signal 2025-09-20T19:00:20.130Z,1758394820.130 [DAT](INFO): publishing transmit ping time 2025-09-20T19:00:21.138Z,1758394821.138 [DAT](FAULT): Buffer send receipt timeout failure. 2025-09-20T19:00:21.138Z,1758394821.138 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER 2025-09-20T19:00:21.389Z,1758394821.389 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-09-20T19:00:21.641Z,1758394821.641 [DAT](INFO): entering online mode 2025-09-20T19:00:21.893Z,1758394821.893 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:00:22.146Z,1758394822.146 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:00:22.397Z,1758394822.397 [DAT](INFO): DAT read: Rx Time:19:00:23.1972 2025-09-20T19:00:22.397Z,1758394822.397 [DAT](INFO): Rx dataTimestamp_ set to:1758394822.397026 2025-09-20T19:00:22.398Z,1758394822.398 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:00:22.649Z,1758394822.649 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:00:22.906Z,1758394822.906 [DAT](INFO): DAT read: 19:00:23.1972 LVL= 15456, 28577, 22450, 32707, AGC= 43, IDX= 437,-0.34, 0.785,-1.264, 0.165, 0.286, PHS= 0.601,-1.504,-0.165, RAW= 128.9, 11.6, CAL= 128.7, 12.8, ROT= 21.3, -12.8 2025-09-20T19:00:22.907Z,1758394822.907 [DAT](INFO): got valid direction response: 19:00:23.1972 LVL= 15456, 28577, 22450, 32707, AGC= 43, IDX= 437,-0.34, 0.785,-1.264, 0.165, 0.286, PHS= 0.601,-1.504,-0.165, RAW= 128.9, 11.6, CAL= 128.7, 12.8, ROT= 21.3, -12.8 2025-09-20T19:00:22.907Z,1758394822.907 [DAT](INFO): DAT read: OK 2025-09-20T19:00:22.908Z,1758394822.908 [DAT](INFO): unknown deviceResponse_: OK 2025-09-20T19:00:22.908Z,1758394822.908 [DAT](INFO): DAT read: user:1332> 2025-09-20T19:00:22.909Z,1758394822.909 [DAT](INFO): DAT read: 2025-09-20T19:00:22.910Z,1758394822.910 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-09-20T19:00:22.910Z,1758394822.910 [DAT](INFO): commRate: 600 2025-09-20T19:00:22.910Z,1758394822.910 [DAT](INFO): online mode acknowledged 2025-09-20T19:00:22.911Z,1758394822.911 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-09-20T19:00:22.911Z,1758394822.911 [DAT](INFO): #Rx 5: Read direction message, but no range. 2025-09-20T19:00:22.913Z,1758394822.913 [DAT](INFO): direction in FSK: [0.908538,0.354224,0.221548] 2025-09-20T19:00:26.178Z,1758394826.178 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:00:27.5130 2025-09-20T19:00:26.178Z,1758394826.178 [DAT](DEBUG): In parseResponses, sent ack so set commsState_ = SENDING_VERIFIED 2025-09-20T19:00:26.178Z,1758394826.178 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-09-20T19:01:11.310Z,1758394871.310 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00032722485, +11.1, 0.0,1493.7, 0 2025-09-20T19:01:34.289Z,1758394894.289 [DAT](INFO): DAT read: Rx Time:19:01:35.1563 2025-09-20T19:01:34.289Z,1758394894.289 [DAT](INFO): Rx dataTimestamp_ set to:1758394894.289109 2025-09-20T19:01:35.050Z,1758394895.050 [DAT](INFO): DAT read: 19:01:35.1563 LVL= 21376, 32753, 23218, 32755, AGC= 54, IDX= 510, 0.36, 2.634, 0.647, 2.068, 2.206, PHS= 0.530,-1.514,-0.182, RAW= 129.9, 12.9, CAL= 129.4, 14.1, ROT= 20.6, -14.1 2025-09-20T19:01:35.051Z,1758394895.051 [DAT](INFO): got valid direction response: 19:01:35.1563 LVL= 21376, 32753, 23218, 32755, AGC= 54, IDX= 510, 0.36, 2.634, 0.647, 2.068, 2.206, PHS= 0.530,-1.514,-0.182, RAW= 129.9, 12.9, CAL= 129.4, 14.1, ROT= 20.6, -14.1 2025-09-20T19:01:35.052Z,1758394895.052 [DAT](INFO): DAT read: 2025-09-20T19:01:35.069Z,1758394895.069 [DAT](INFO): DAT read: DATA(0005):stop 2025-09-20T19:01:35.070Z,1758394895.070 [DAT](INFO): Got DATA 5 2025-09-20T19:01:35.070Z,1758394895.070 [DAT](INFO): DAT read: 2025-09-20T19:01:35.071Z,1758394895.071 [DAT](INFO): DAT read: Source:050 Destination:011 2025-09-20T19:01:35.071Z,1758394895.071 [DAT](INFO): Got Src/Dest after DATA 2025-09-20T19:01:35.071Z,1758394895.071 [DAT](INFO): DATA Src=50, Dst=11 2025-09-20T19:01:35.073Z,1758394895.073 [DAT](INFO): DAT read: CRC:Pass MPD:00.3 PSNR:17.0 AGC:51 SPD:-0.1 CCERR:012 2025-09-20T19:01:35.073Z,1758394895.073 [DAT](INFO): Got CRC:Pass 2025-09-20T19:01:35.073Z,1758394895.073 [DAT](INFO): Got CRC:Pass 2025-09-20T19:01:35.073Z,1758394895.073 [DAT](INFO): Incoming data is intended for us 2025-09-20T19:01:35.073Z,1758394895.073 [DAT](INFO): Received command: stop 2025-09-20T19:01:35.074Z,1758394895.074 [DAT](INFO): Sending ack 2025-09-20T19:01:35.074Z,1758394895.074 [DAT](INFO): DAT read: 2025-09-20T19:01:35.075Z,1758394895.075 [DAT](INFO): DAT read: 2025-09-20T19:01:35.075Z,1758394895.075 [DAT](INFO): #Rx 6: Read direction message, but no range. 2025-09-20T19:01:35.076Z,1758394895.076 [DAT](INFO): direction in FSK: [0.907858,0.341241,0.243615] 2025-09-20T19:01:35.141Z,1758394895.141 [CommandExec](IMPORTANT): got command stop 2025-09-20T19:01:35.141Z,1758394895.141 [CommandExec](IMPORTANT): Scheduling is paused 2025-09-20T19:01:35.141Z,1758394895.141 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2025-09-20T19:01:35.192Z,1758394895.192 [MissionManager](INFO): MissionManager is completed. 2025-09-20T19:01:35.193Z,1758394895.193 [MissionManager](INFO): Uninitializing Mission sample_on_dock 2025-09-20T19:01:35.193Z,1758394895.193 [sample_on_dock] Stopped 2025-09-20T19:01:35.193Z,1758394895.193 [sample_on_dock](DEBUG): Aggregate::uninitialize sample_on_dock 2025-09-20T19:01:35.193Z,1758394895.193 [sample_on_dock:A.AbortSample] Stopped 2025-09-20T19:01:35.193Z,1758394895.193 [sample_on_dock:A.AbortSample](INFO): Uninitializing AbortSample. 2025-09-20T19:01:35.193Z,1758394895.193 [sample_on_dock:StandardEnvelopes] Stopped 2025-09-20T19:01:35.193Z,1758394895.193 [sample_on_dock:StandardEnvelopes](DEBUG): Aggregate::uninitialize sample_on_dock:StandardEnvelopes 2025-09-20T19:01:35.193Z,1758394895.193 [sample_on_dock:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-09-20T19:01:35.193Z,1758394895.193 [sample_on_dock:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:BackseatDriver] Stopped 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:BackseatDriver](DEBUG): Aggregate::uninitialize sample_on_dock:BackseatDriver 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:BackseatDriver:A.BackseatDriver] Stopped 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:PowerOnly] Stopped 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:PowerOnly](DEBUG): Aggregate::uninitialize sample_on_dock:PowerOnly 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:PowerOnly:E.Wait] Stopped 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:dataRead] Stopped 2025-09-20T19:01:35.194Z,1758394895.194 [sample_on_dock:dataRead](DEBUG): Aggregate::uninitialize sample_on_dock:dataRead 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:dataRead:A] Stopped 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:Science] Stopped 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:Science](DEBUG): Aggregate::uninitialize sample_on_dock:Science 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:Science:B] Stopped 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:Science:C] Stopped 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:Science:E] Stopped 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:Science:OceanCurrent] Stopped 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:Science:OceanCurrent](DEBUG): Aggregate::uninitialize sample_on_dock:Science:OceanCurrent 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:Science:OceanCurrent:A.] Stopped 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:L.] Stopped 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:L.](DEBUG): Uninitializing TrackAcousticContact. 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:ManageSample] Stopped 2025-09-20T19:01:35.195Z,1758394895.195 [sample_on_dock:ManageSample](DEBUG): Aggregate::uninitialize sample_on_dock:ManageSample 2025-09-20T19:01:35.196Z,1758394895.196 [sample_on_dock:ManageSample:Sample] Stopped 2025-09-20T19:01:35.196Z,1758394895.196 [sample_on_dock:ManageSample:Sample](DEBUG): Aggregate::uninitialize sample_on_dock:ManageSample:Sample 2025-09-20T19:01:35.196Z,1758394895.196 [sample_on_dock:ManageSample:Sample:A.Wait] Stopped 2025-09-20T19:01:35.196Z,1758394895.196 [sample_on_dock:ManageSample:Sample:A.Wait](DEBUG): Uninitialize Wait Component. 2025-09-20T19:01:35.196Z,1758394895.196 [sample_on_dock:P.Docked] Stopped 2025-09-20T19:01:35.348Z,1758394895.348 [DAT](INFO): entering command mode 2025-09-20T19:01:35.392Z,1758394895.392 [WetLabsBB2FL](INFO): Powering down 2025-09-20T19:01:35.547Z,1758394895.547 [MissionManager](IMPORTANT): Started mission DefaultWithUndock 2025-09-20T19:01:35.547Z,1758394895.547 [DefaultWithUndock] Running Loop=1 2025-09-20T19:01:35.548Z,1758394895.548 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock 2025-09-20T19:01:35.549Z,1758394895.549 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:35.553Z,1758394895.553 [DefaultWithUndock:A.Wait] Running Loop=1 2025-09-20T19:01:35.553Z,1758394895.553 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component. 2025-09-20T19:01:35.801Z,1758394895.801 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:36.053Z,1758394896.053 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:36.305Z,1758394896.305 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:36.557Z,1758394896.557 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:36.809Z,1758394896.809 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:37.061Z,1758394897.061 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:37.313Z,1758394897.313 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:37.565Z,1758394897.565 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:37.817Z,1758394897.817 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:38.070Z,1758394898.070 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:38.321Z,1758394898.321 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:38.573Z,1758394898.573 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:01:39.9132 2025-09-20T19:01:38.574Z,1758394898.574 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:38.825Z,1758394898.825 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:39.077Z,1758394899.077 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:39.329Z,1758394899.329 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:39.581Z,1758394899.581 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:39.833Z,1758394899.833 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:40.085Z,1758394900.085 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:40.337Z,1758394900.337 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:40.589Z,1758394900.589 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:40.844Z,1758394900.844 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:41.093Z,1758394901.093 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:41.345Z,1758394901.345 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:41.597Z,1758394901.597 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:41.849Z,1758394901.849 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:42.101Z,1758394902.101 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:42.353Z,1758394902.353 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:42.605Z,1758394902.605 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:42.857Z,1758394902.857 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:43.109Z,1758394903.109 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:43.362Z,1758394903.362 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:43.613Z,1758394903.613 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:43.865Z,1758394903.865 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:44.117Z,1758394904.117 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:44.369Z,1758394904.369 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:44.621Z,1758394904.621 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:44.873Z,1758394904.873 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:45.125Z,1758394905.125 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:45.377Z,1758394905.377 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:45.629Z,1758394905.629 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:45.881Z,1758394905.881 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:46.133Z,1758394906.133 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:46.385Z,1758394906.385 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:46.637Z,1758394906.637 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:46.889Z,1758394906.889 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:47.141Z,1758394907.141 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:47.393Z,1758394907.393 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:47.653Z,1758394907.653 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:47.897Z,1758394907.897 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:48.149Z,1758394908.149 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:48.401Z,1758394908.401 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:48.653Z,1758394908.653 [DAT](INFO): DAT read: Rx Time:19:01:49.4578 2025-09-20T19:01:48.654Z,1758394908.654 [DAT](INFO): Rx dataTimestamp_ set to:1758394908.653370 2025-09-20T19:01:48.654Z,1758394908.654 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:48.917Z,1758394908.917 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:49.169Z,1758394909.169 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:49.426Z,1758394909.426 [DAT](INFO): DAT read: 19:01:49.4578 LVL= 21392, 32753, 27634, 32755, AGC= 53, IDX= 462, 0.30,-2.346, 1.946,-2.900,-2.709, PHS= 0.465,-1.584,-0.235, RAW= 130.4, 14.9, CAL= 129.5, 16.0, ROT= 20.5, -16.0 2025-09-20T19:01:49.428Z,1758394909.428 [DAT](INFO): got valid direction response: 19:01:49.4578 LVL= 21392, 32753, 27634, 32755, AGC= 53, IDX= 462, 0.30,-2.346, 1.946,-2.900,-2.709, PHS= 0.465,-1.584,-0.235, RAW= 130.4, 14.9, CAL= 129.5, 16.0, ROT= 20.5, -16.0 2025-09-20T19:01:49.428Z,1758394909.428 [DAT](INFO): DAT read: 2025-09-20T19:01:49.429Z,1758394909.429 [DAT](INFO): DAT read: DATA(0005):stop 2025-09-20T19:01:49.429Z,1758394909.429 [DAT](INFO): Got DATA 5 2025-09-20T19:01:49.430Z,1758394909.430 [DAT](INFO): DAT read: 2025-09-20T19:01:49.431Z,1758394909.431 [DAT](INFO): DAT read: Source:050 Destination:011 2025-09-20T19:01:49.431Z,1758394909.431 [DAT](INFO): Got Src/Dest after DATA 2025-09-20T19:01:49.431Z,1758394909.431 [DAT](INFO): DATA Src=50, Dst=11 2025-09-20T19:01:49.432Z,1758394909.432 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:16.1 AGC:49 SPD:-0.3 CCERR:013 2025-09-20T19:01:49.432Z,1758394909.432 [DAT](INFO): Got CRC:Pass 2025-09-20T19:01:49.433Z,1758394909.433 [DAT](INFO): Got CRC:Pass 2025-09-20T19:01:49.433Z,1758394909.433 [DAT](INFO): Incoming data is intended for us 2025-09-20T19:01:49.433Z,1758394909.433 [DAT](INFO): Received command: stop 2025-09-20T19:01:49.433Z,1758394909.433 [DAT](INFO): #Outgoing data=1 2025-09-20T19:01:49.433Z,1758394909.433 [DAT](INFO): Sending ack 2025-09-20T19:01:49.433Z,1758394909.433 [DAT](INFO): DAT read: 2025-09-20T19:01:49.434Z,1758394909.434 [DAT](INFO): DAT read: 2025-09-20T19:01:49.434Z,1758394909.434 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-09-20T19:01:49.434Z,1758394909.434 [DAT](INFO): #Rx 7: Read direction message, but no range. 2025-09-20T19:01:49.435Z,1758394909.435 [DAT](INFO): direction in FSK: [0.900387,0.336641,0.275637] 2025-09-20T19:01:49.442Z,1758394909.442 [CommandExec](IMPORTANT): got command stop 2025-09-20T19:01:49.460Z,1758394909.460 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:01:49.673Z,1758394909.673 [DAT](INFO): entering online mode 2025-09-20T19:01:49.924Z,1758394909.924 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:50.177Z,1758394910.177 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:50.429Z,1758394910.429 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:50.680Z,1758394910.680 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:50.933Z,1758394910.933 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:51.185Z,1758394911.185 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:51.436Z,1758394911.436 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:51.689Z,1758394911.689 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:51.941Z,1758394911.941 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:52.193Z,1758394912.193 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:52.445Z,1758394912.445 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:52.697Z,1758394912.697 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:52.954Z,1758394912.954 [DAT](INFO): DAT read: Forwarding Delay UpTx time:19:01:54.2632 2025-09-20T19:01:52.954Z,1758394912.954 [DAT](DEBUG): Re-entering command mode due to unexpected online mode. 2025-09-20T19:01:52.955Z,1758394912.955 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:53.205Z,1758394913.205 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:53.457Z,1758394913.457 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:53.710Z,1758394913.710 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:53.961Z,1758394913.961 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:54.213Z,1758394914.213 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:54.465Z,1758394914.465 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:54.717Z,1758394914.717 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:54.969Z,1758394914.969 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:55.220Z,1758394915.220 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:55.473Z,1758394915.473 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:55.725Z,1758394915.725 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:55.977Z,1758394915.977 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:56.231Z,1758394916.231 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:56.485Z,1758394916.485 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:56.737Z,1758394916.737 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:56.989Z,1758394916.989 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:57.241Z,1758394917.241 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:57.492Z,1758394917.492 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:57.744Z,1758394917.744 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:57.997Z,1758394917.997 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:58.249Z,1758394918.249 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:58.501Z,1758394918.501 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:58.753Z,1758394918.753 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:59.004Z,1758394919.004 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:59.259Z,1758394919.259 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:59.509Z,1758394919.509 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:01:59.761Z,1758394919.761 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:00.013Z,1758394920.013 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:00.265Z,1758394920.265 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:00.517Z,1758394920.517 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:00.769Z,1758394920.769 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:01.021Z,1758394921.021 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:01.273Z,1758394921.273 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:01.525Z,1758394921.525 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:01.781Z,1758394921.781 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:02.032Z,1758394922.032 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:02.285Z,1758394922.285 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:02.537Z,1758394922.537 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:02.789Z,1758394922.789 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:03.041Z,1758394923.041 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:03.293Z,1758394923.293 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:03.544Z,1758394923.544 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:03.797Z,1758394923.797 [DAT](INFO): DAT read: Rx Time:19:02:04.6095 2025-09-20T19:02:03.798Z,1758394923.798 [DAT](INFO): Rx dataTimestamp_ set to:1758394923.797423 2025-09-20T19:02:03.798Z,1758394923.798 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:04.050Z,1758394924.050 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:04.301Z,1758394924.301 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:04.559Z,1758394924.559 [DAT](INFO): DAT read: 19:02:04.6095 LVL= 26864, 32753, 32754, 32755, AGC= 52, IDX= 447, 0.41,-2.037, 2.333,-2.837,-2.479, PHS= 0.544,-1.426,-0.403, RAW= 121.3, 14.9, CAL= 121.7, 16.2, ROT= 28.3, -16.2 2025-09-20T19:02:04.560Z,1758394924.560 [DAT](INFO): got valid direction response: 19:02:04.6095 LVL= 26864, 32753, 32754, 32755, AGC= 52, IDX= 447, 0.41,-2.037, 2.333,-2.837,-2.479, PHS= 0.544,-1.426,-0.403, RAW= 121.3, 14.9, CAL= 121.7, 16.2, ROT= 28.3, -16.2 2025-09-20T19:02:04.560Z,1758394924.560 [DAT](INFO): DAT read: 2025-09-20T19:02:04.561Z,1758394924.561 [DAT](INFO): DAT read: DATA(0005):stop 2025-09-20T19:02:04.561Z,1758394924.561 [DAT](INFO): Got DATA 5 2025-09-20T19:02:04.561Z,1758394924.561 [DAT](INFO): DAT read: 2025-09-20T19:02:04.562Z,1758394924.562 [DAT](INFO): DAT read: Source:050 Destination:011 2025-09-20T19:02:04.562Z,1758394924.562 [DAT](INFO): Got Src/Dest after DATA 2025-09-20T19:02:04.563Z,1758394924.563 [DAT](INFO): DATA Src=50, Dst=11 2025-09-20T19:02:04.564Z,1758394924.564 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:16.9 AGC:51 SPD:-0.3 CCERR:013 2025-09-20T19:02:04.564Z,1758394924.564 [DAT](INFO): Got CRC:Pass 2025-09-20T19:02:04.564Z,1758394924.564 [DAT](INFO): Got CRC:Pass 2025-09-20T19:02:04.564Z,1758394924.564 [DAT](INFO): Incoming data is intended for us 2025-09-20T19:02:04.564Z,1758394924.564 [DAT](INFO): Received command: stop 2025-09-20T19:02:04.565Z,1758394924.565 [DAT](INFO): #Outgoing data=1 2025-09-20T19:02:04.565Z,1758394924.565 [DAT](INFO): Sending ack 2025-09-20T19:02:04.565Z,1758394924.565 [DAT](INFO): DAT read: 2025-09-20T19:02:04.565Z,1758394924.565 [DAT](INFO): DAT read: 2025-09-20T19:02:04.566Z,1758394924.566 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:04.567Z,1758394924.567 [CommandExec](IMPORTANT): got command stop 2025-09-20T19:02:04.805Z,1758394924.805 [DAT](DEBUG): checking for online mode acknowledgment 2025-09-20T19:02:04.806Z,1758394924.806 [DAT](FAULT): failed to enter online mode 2025-09-20T19:02:04.806Z,1758394924.806 [DAT](FAULT): Failure returning to online mode 2025-09-20T19:02:04.806Z,1758394924.806 [DAT] Communications Fault, FailCount= 1 2025-09-20T19:02:04.806Z,1758394924.806 [DAT](ERROR): Communications Fault 2025-09-20T19:02:04.861Z,1758394924.861 [DAT](INFO): entering command mode 2025-09-20T19:02:05.141Z,1758394925.141 [CBIT](ERROR): Communications Fault in component: DAT 2025-09-20T19:02:05.268Z,1758394925.268 [DAT](INFO): Powering down 2025-09-20T19:02:05.839Z,1758394925.839 [DefaultWithUndock:A.Wait](INFO): Done Waiting. 2025-09-20T19:02:05.839Z,1758394925.839 [DefaultWithUndock:A.Wait] Stopped 2025-09-20T19:02:05.839Z,1758394925.839 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component. 2025-09-20T19:02:05.840Z,1758394925.840 [DefaultWithUndock:LeaveDock] Running Loop=1 2025-09-20T19:02:05.840Z,1758394925.840 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock 2025-09-20T19:02:05.840Z,1758394925.840 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2025-09-20T19:02:05.840Z,1758394925.840 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact. 2025-09-20T19:02:05.840Z,1758394925.840 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1 2025-09-20T19:02:05.840Z,1758394925.840 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-09-20T19:02:05.840Z,1758394925.840 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-09-20T19:02:06.298Z,1758394926.298 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-09-20T19:02:06.299Z,1758394926.299 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-09-20T19:02:06.299Z,1758394926.299 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached from dock at depth 64.369720 m. 2025-09-20T19:02:06.454Z,1758394926.454 [CBIT](INFO): Clearing failed state for component DAT 2025-09-20T19:02:06.454Z,1758394926.454 [DAT] No Fault, FailCount= 1 2025-09-20T19:02:07.138Z,1758394927.138 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-09-20T19:02:07.257Z,1758394927.257 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-09-20T19:02:08.496Z,1758394928.496 [DAT](INFO): Powering up 2025-09-20T19:02:08.496Z,1758394928.496 [DAT](DEBUG): Initializing DAT. 2025-09-20T19:02:09.653Z,1758394929.653 [CTD_Seabird](ERROR): Failed to parse device response: 2025-09-20T19:02:10.737Z,1758394930.737 [DockingStepper](INFO): Changing to mode: 3 2025-09-20T19:02:15.940Z,1758394935.940 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-09-20T19:02:16.748Z,1758394936.748 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2025-09-20T19:02:20.355Z,1758394940.355 [DAT](INFO): DAT read: 2025-09-20T19:02:20.356Z,1758394940.356 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-09-20T19:02:22.121Z,1758394942.121 [DAT](INFO): DAT read: MF Frequency Band 2025-09-20T19:02:22.122Z,1758394942.122 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-09-20T19:02:22.123Z,1758394942.123 [DAT](INFO): DAT read: Sep 20 2025 19:02:18 2025-09-20T19:02:23.389Z,1758394943.389 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-09-20T19:02:23.390Z,1758394943.390 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-09-20T19:02:23.391Z,1758394943.391 [DAT](INFO): commRate: 600 2025-09-20T19:02:25.456Z,1758394945.456 [DAT](INFO): entering command mode 2025-09-20T19:02:25.657Z,1758394945.657 [DAT](INFO): DAT read: 2025-09-20T19:02:25.657Z,1758394945.657 [DAT](INFO): DAT read: user:1> 2025-09-20T19:02:25.657Z,1758394945.657 [DAT](INFO): setting verbose to 3 2025-09-20T19:02:25.909Z,1758394945.909 [DAT](INFO): DAT read: user:1> 2025-09-20T19:02:25.910Z,1758394945.910 [DAT](INFO): DAT read: Verbose | 3 2025-09-20T19:02:25.910Z,1758394945.910 [DAT](INFO): set verbose to 3 2025-09-20T19:02:25.910Z,1758394945.910 [DAT](INFO): setting DatVerbose to 27440 2025-09-20T19:02:26.037Z,1758394946.037 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-09-20T19:02:26.161Z,1758394946.161 [DAT](INFO): DAT read: user:2> 2025-09-20T19:02:26.162Z,1758394946.162 [DAT](INFO): DAT read: DatVerbose | 27440 2025-09-20T19:02:26.162Z,1758394946.162 [DAT](INFO): set DatVerbose to 27440 2025-09-20T19:02:26.162Z,1758394946.162 [DAT](INFO): setting transmit power to 8 2025-09-20T19:02:26.413Z,1758394946.413 [DAT](INFO): DAT read: user:3> 2025-09-20T19:02:26.414Z,1758394946.414 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-09-20T19:02:26.414Z,1758394946.414 [DAT](INFO): set transmit power to 8 2025-09-20T19:02:26.414Z,1758394946.414 [DAT](INFO): setting local address to 11 2025-09-20T19:02:26.665Z,1758394946.665 [DAT](INFO): DAT read: user:4> 2025-09-20T19:02:26.666Z,1758394946.666 [DAT](INFO): DAT read: LocalAddr | 11 2025-09-20T19:02:26.666Z,1758394946.666 [DAT](INFO): set local address to 11 2025-09-20T19:02:26.667Z,1758394946.667 [DAT](INFO): Setting time to: 19:2:26 And date to:9/20/2025 2025-09-20T19:02:26.924Z,1758394946.924 [DAT](INFO): DAT read: user:5> 2025-09-20T19:02:26.925Z,1758394946.925 [DAT](INFO): DAT read: Sat Sep 20, 2025 19:02:26 2025-09-20T19:02:26.925Z,1758394946.925 [DAT](INFO): Local DAT time set to Sat Sep 20, 2025 19:02:26 2025-09-20T19:02:26.926Z,1758394946.926 [DAT](INFO): setting remote address to 50 2025-09-20T19:02:26.926Z,1758394946.926 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:02:26.926Z,1758394946.926 [DAT](INFO): setting remote address to 0 2025-09-20T19:02:27.177Z,1758394947.177 [DAT](INFO): DAT read: user:6> 2025-09-20T19:02:27.178Z,1758394947.178 [DAT](INFO): DAT read: RemoteAddr | 50 2025-09-20T19:02:27.178Z,1758394947.178 [DAT](ERROR): failed to set remote address to 0, device returned 50 instead. 2025-09-20T19:02:27.178Z,1758394947.178 [DAT] Communications Fault, FailCount= 2 2025-09-20T19:02:27.179Z,1758394947.179 [DAT](ERROR): Communications Fault 2025-09-20T19:02:27.179Z,1758394947.179 [DAT](INFO): DAT read: user:7> 2025-09-20T19:02:27.180Z,1758394947.180 [DAT](INFO): DAT read: RemoteAddr | 0 2025-09-20T19:02:27.181Z,1758394947.181 [DAT](INFO): set remote address to 0 2025-09-20T19:02:27.181Z,1758394947.181 [DAT](INFO): setting remote address to 50 2025-09-20T19:02:27.181Z,1758394947.181 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:02:27.181Z,1758394947.181 [DAT](INFO): setting remote address to 0 2025-09-20T19:02:27.349Z,1758394947.349 [CBIT](ERROR): Communications Fault in component: DAT 2025-09-20T19:02:27.584Z,1758394947.584 [DAT](INFO): Powering down 2025-09-20T19:02:28.545Z,1758394948.545 [CBIT](INFO): Clearing failed state for component DAT 2025-09-20T19:02:28.545Z,1758394948.545 [DAT] No Fault, FailCount= 2 2025-09-20T19:02:30.812Z,1758394950.812 [DAT](INFO): Powering up 2025-09-20T19:02:30.812Z,1758394950.812 [DAT](DEBUG): Initializing DAT. 2025-09-20T19:02:36.141Z,1758394956.141 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-09-20T19:02:36.967Z,1758394956.967 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: nan m. Transitioning docking module to standby. 2025-09-20T19:02:37.352Z,1758394957.352 [DockingStepper](INFO): Changing to mode: 1 2025-09-20T19:02:42.681Z,1758394962.681 [DAT](INFO): DAT read: 2025-09-20T19:02:42.681Z,1758394962.681 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-09-20T19:02:43.420Z,1758394963.420 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby. 2025-09-20T19:02:43.835Z,1758394963.835 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete. 2025-09-20T19:02:43.835Z,1758394963.835 [DefaultWithUndock:LeaveDock:B.Undock] Stopped 2025-09-20T19:02:43.836Z,1758394963.836 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock 2025-09-20T19:02:43.836Z,1758394963.836 [DefaultWithUndock:LeaveDock] Stopped 2025-09-20T19:02:43.836Z,1758394963.836 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock 2025-09-20T19:02:43.836Z,1758394963.836 [DefaultWithUndock:LeaveDock:A.] Stopped 2025-09-20T19:02:43.836Z,1758394963.836 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact. 2025-09-20T19:02:43.836Z,1758394963.836 [DefaultWithUndock:SurfaceDefault] Running Loop=1 2025-09-20T19:02:43.837Z,1758394963.837 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault 2025-09-20T19:02:43.837Z,1758394963.837 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1 2025-09-20T19:02:43.837Z,1758394963.837 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-09-20T19:02:43.837Z,1758394963.837 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-09-20T19:02:43.837Z,1758394963.837 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-09-20T19:02:43.838Z,1758394963.838 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-09-20T19:02:43.838Z,1758394963.838 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-09-20T19:02:43.838Z,1758394963.838 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-09-20T19:02:43.839Z,1758394963.839 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-09-20T19:02:44.453Z,1758394964.453 [DAT](INFO): DAT read: MF Frequency Band 2025-09-20T19:02:44.454Z,1758394964.454 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-09-20T19:02:44.455Z,1758394964.455 [DAT](INFO): DAT read: Sep 20 2025 19:02:38 2025-09-20T19:02:44.677Z,1758394964.677 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -24.00 mm (1 active estimators). 2025-09-20T19:02:44.856Z,1758394964.856 [Radio_Surface](INFO): Powering up 2025-09-20T19:02:45.713Z,1758394965.713 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-09-20T19:02:45.714Z,1758394965.714 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-09-20T19:02:45.715Z,1758394965.715 [DAT](INFO): commRate: 600 2025-09-20T19:02:47.780Z,1758394967.780 [DAT](INFO): entering command mode 2025-09-20T19:02:47.981Z,1758394967.981 [DAT](INFO): DAT read: 2025-09-20T19:02:47.981Z,1758394967.981 [DAT](INFO): DAT read: user:1> 2025-09-20T19:02:47.981Z,1758394967.981 [DAT](INFO): setting verbose to 3 2025-09-20T19:02:48.233Z,1758394968.233 [DAT](INFO): DAT read: user:1> 2025-09-20T19:02:48.234Z,1758394968.234 [DAT](INFO): DAT read: Verbose | 3 2025-09-20T19:02:48.234Z,1758394968.234 [DAT](INFO): set verbose to 3 2025-09-20T19:02:48.234Z,1758394968.234 [DAT](INFO): setting DatVerbose to 27440 2025-09-20T19:02:48.485Z,1758394968.485 [DAT](INFO): DAT read: user:2> 2025-09-20T19:02:48.486Z,1758394968.486 [DAT](INFO): DAT read: DatVerbose | 27440 2025-09-20T19:02:48.486Z,1758394968.486 [DAT](INFO): set DatVerbose to 27440 2025-09-20T19:02:48.486Z,1758394968.486 [DAT](INFO): setting transmit power to 8 2025-09-20T19:02:48.737Z,1758394968.737 [DAT](INFO): DAT read: user:3> 2025-09-20T19:02:48.738Z,1758394968.738 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-09-20T19:02:48.738Z,1758394968.738 [DAT](INFO): set transmit power to 8 2025-09-20T19:02:48.738Z,1758394968.738 [DAT](INFO): setting local address to 11 2025-09-20T19:02:48.989Z,1758394968.989 [DAT](INFO): DAT read: user:4> 2025-09-20T19:02:48.990Z,1758394968.990 [DAT](INFO): DAT read: LocalAddr | 11 2025-09-20T19:02:48.990Z,1758394968.990 [DAT](INFO): set local address to 11 2025-09-20T19:02:48.991Z,1758394968.991 [DAT](INFO): Setting time to: 19:2:48 And date to:9/20/2025 2025-09-20T19:02:49.241Z,1758394969.241 [DAT](INFO): DAT read: user:5> 2025-09-20T19:02:49.242Z,1758394969.242 [DAT](INFO): DAT read: Sat Sep 20, 2025 19:02:48 2025-09-20T19:02:49.242Z,1758394969.242 [DAT](INFO): Local DAT time set to Sat Sep 20, 2025 19:02:48 2025-09-20T19:02:49.243Z,1758394969.243 [DAT](INFO): setting remote address to 50 2025-09-20T19:02:49.243Z,1758394969.243 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:02:49.243Z,1758394969.243 [DAT](INFO): setting remote address to 0 2025-09-20T19:02:49.494Z,1758394969.494 [DAT](INFO): DAT read: user:6> 2025-09-20T19:02:49.495Z,1758394969.495 [DAT](INFO): DAT read: RemoteAddr | 50 2025-09-20T19:02:49.495Z,1758394969.495 [DAT](ERROR): failed to set remote address to 0, device returned 50 instead. 2025-09-20T19:02:49.495Z,1758394969.495 [DAT] Communications Fault, FailCount= 3 2025-09-20T19:02:49.495Z,1758394969.495 [DAT](ERROR): Communications Fault 2025-09-20T19:02:49.496Z,1758394969.496 [DAT](INFO): DAT read: user:7> 2025-09-20T19:02:49.497Z,1758394969.497 [DAT](INFO): DAT read: RemoteAddr | 0 2025-09-20T19:02:49.497Z,1758394969.497 [DAT](INFO): set remote address to 0 2025-09-20T19:02:49.498Z,1758394969.498 [DAT](INFO): setting remote address to 50 2025-09-20T19:02:49.498Z,1758394969.498 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:02:49.498Z,1758394969.498 [DAT](INFO): setting remote address to 0 2025-09-20T19:02:49.639Z,1758394969.639 [CBIT](ERROR): Communications Fault in component: DAT 2025-09-20T19:02:49.912Z,1758394969.912 [DAT](INFO): Powering down 2025-09-20T19:02:50.110Z,1758394970.110 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.11 2025-09-20T19:02:50.111Z,1758394970.111 [Radio_Surface](INFO): No local IP found 2025-09-20T19:02:50.844Z,1758394970.844 [CBIT](INFO): Clearing failed state for component DAT 2025-09-20T19:02:50.844Z,1758394970.844 [DAT] No Fault, FailCount= 3 2025-09-20T19:02:53.152Z,1758394973.152 [DAT](INFO): Powering up 2025-09-20T19:02:53.153Z,1758394973.153 [DAT](DEBUG): Initializing DAT. 2025-09-20T19:03:04.997Z,1758394984.997 [DAT](INFO): DAT read: 2025-09-20T19:03:04.997Z,1758394984.997 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-09-20T19:03:06.761Z,1758394986.761 [DAT](INFO): DAT read: MF Frequency Band 2025-09-20T19:03:06.762Z,1758394986.762 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-09-20T19:03:06.763Z,1758394986.763 [DAT](INFO): DAT read: Sep 20 2025 19:03:00 2025-09-20T19:03:08.027Z,1758394988.027 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-09-20T19:03:08.029Z,1758394988.029 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-09-20T19:03:08.029Z,1758394988.029 [DAT](INFO): commRate: 600 2025-09-20T19:03:10.088Z,1758394990.088 [DAT](INFO): entering command mode 2025-09-20T19:03:10.289Z,1758394990.289 [DAT](INFO): DAT read: 2025-09-20T19:03:10.289Z,1758394990.289 [DAT](INFO): DAT read: user:1> 2025-09-20T19:03:10.289Z,1758394990.289 [DAT](INFO): setting verbose to 3 2025-09-20T19:03:10.542Z,1758394990.542 [DAT](INFO): DAT read: user:1> 2025-09-20T19:03:10.545Z,1758394990.545 [DAT](INFO): DAT read: Verbose | 3 2025-09-20T19:03:10.545Z,1758394990.545 [DAT](INFO): set verbose to 3 2025-09-20T19:03:10.545Z,1758394990.545 [DAT](INFO): setting DatVerbose to 27440 2025-09-20T19:03:10.793Z,1758394990.793 [DAT](INFO): DAT read: user:2> 2025-09-20T19:03:10.794Z,1758394990.794 [DAT](INFO): DAT read: DatVerbose | 27440 2025-09-20T19:03:10.794Z,1758394990.794 [DAT](INFO): set DatVerbose to 27440 2025-09-20T19:03:10.794Z,1758394990.794 [DAT](INFO): setting transmit power to 8 2025-09-20T19:03:11.045Z,1758394991.045 [DAT](INFO): DAT read: user:3> 2025-09-20T19:03:11.046Z,1758394991.046 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-09-20T19:03:11.046Z,1758394991.046 [DAT](INFO): set transmit power to 8 2025-09-20T19:03:11.046Z,1758394991.046 [DAT](INFO): setting local address to 11 2025-09-20T19:03:11.297Z,1758394991.297 [DAT](INFO): DAT read: user:4> 2025-09-20T19:03:11.298Z,1758394991.298 [DAT](INFO): DAT read: LocalAddr | 11 2025-09-20T19:03:11.298Z,1758394991.298 [DAT](INFO): set local address to 11 2025-09-20T19:03:11.299Z,1758394991.299 [DAT](INFO): Setting time to: 19:3:11 And date to:9/20/2025 2025-09-20T19:03:11.549Z,1758394991.549 [DAT](INFO): DAT read: user:5> 2025-09-20T19:03:11.550Z,1758394991.550 [DAT](INFO): DAT read: Sat Sep 20, 2025 19:03:11 2025-09-20T19:03:11.550Z,1758394991.550 [DAT](INFO): Local DAT time set to Sat Sep 20, 2025 19:03:11 2025-09-20T19:03:11.551Z,1758394991.551 [DAT](INFO): setting remote address to 50 2025-09-20T19:03:11.551Z,1758394991.551 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:03:11.551Z,1758394991.551 [DAT](INFO): setting remote address to 0 2025-09-20T19:03:11.801Z,1758394991.801 [DAT](INFO): DAT read: user:6> 2025-09-20T19:03:11.803Z,1758394991.803 [DAT](INFO): DAT read: RemoteAddr | 50 2025-09-20T19:03:11.804Z,1758394991.804 [DAT](ERROR): failed to set remote address to 0, device returned 50 instead. 2025-09-20T19:03:11.804Z,1758394991.804 [DAT] Communications Fault, FailCount= 4 2025-09-20T19:03:11.804Z,1758394991.804 [DAT](ERROR): Communications Fault 2025-09-20T19:03:11.805Z,1758394991.805 [DAT](INFO): DAT read: user:7> 2025-09-20T19:03:11.807Z,1758394991.807 [DAT](INFO): DAT read: RemoteAddr | 0 2025-09-20T19:03:11.807Z,1758394991.807 [DAT](INFO): set remote address to 0 2025-09-20T19:03:11.808Z,1758394991.808 [DAT](INFO): setting remote address to 50 2025-09-20T19:03:11.808Z,1758394991.808 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:03:11.808Z,1758394991.808 [DAT](INFO): setting remote address to 0 2025-09-20T19:03:11.836Z,1758394991.836 [CBIT](ERROR): Communications Fault in component: DAT 2025-09-20T19:03:12.213Z,1758394992.213 [DAT](INFO): Powering down 2025-09-20T19:03:13.071Z,1758394993.071 [CBIT](INFO): Clearing failed state for component DAT 2025-09-20T19:03:13.071Z,1758394993.071 [DAT] No Fault, FailCount= 4 2025-09-20T19:03:15.440Z,1758394995.440 [DAT](INFO): Powering up 2025-09-20T19:03:15.441Z,1758394995.441 [DAT](DEBUG): Initializing DAT. 2025-09-20T19:03:27.285Z,1758395007.285 [DAT](INFO): DAT read: 2025-09-20T19:03:27.285Z,1758395007.285 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-09-20T19:03:29.051Z,1758395009.051 [DAT](INFO): DAT read: MF Frequency Band 2025-09-20T19:03:29.052Z,1758395009.052 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-09-20T19:03:29.052Z,1758395009.052 [DAT](INFO): DAT read: Sep 20 2025 19:03:23 2025-09-20T19:03:30.312Z,1758395010.312 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-09-20T19:03:30.314Z,1758395010.314 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-09-20T19:03:30.314Z,1758395010.314 [DAT](INFO): commRate: 600 2025-09-20T19:03:31.494Z,1758395011.494 [RDI_Pathfinder](ERROR): only read -1 of 1 data item for altitude. Device response is::BD, -11.61, -4.46, -0.34, 2025-09-20T19:03:32.380Z,1758395012.380 [DAT](INFO): entering command mode 2025-09-20T19:03:32.577Z,1758395012.577 [DAT](INFO): DAT read: 2025-09-20T19:03:32.577Z,1758395012.577 [DAT](INFO): DAT read: user:1> 2025-09-20T19:03:32.577Z,1758395012.577 [DAT](INFO): setting verbose to 3 2025-09-20T19:03:32.829Z,1758395012.829 [DAT](INFO): DAT read: user:1> 2025-09-20T19:03:32.830Z,1758395012.830 [DAT](INFO): DAT read: Verbose | 3 2025-09-20T19:03:32.830Z,1758395012.830 [DAT](INFO): set verbose to 3 2025-09-20T19:03:32.830Z,1758395012.830 [DAT](INFO): setting DatVerbose to 27440 2025-09-20T19:03:33.081Z,1758395013.081 [DAT](INFO): DAT read: user:2> 2025-09-20T19:03:33.082Z,1758395013.082 [DAT](INFO): DAT read: DatVerbose | 27440 2025-09-20T19:03:33.082Z,1758395013.082 [DAT](INFO): set DatVerbose to 27440 2025-09-20T19:03:33.082Z,1758395013.082 [DAT](INFO): setting transmit power to 8 2025-09-20T19:03:33.335Z,1758395013.335 [DAT](INFO): DAT read: user:3> 2025-09-20T19:03:33.338Z,1758395013.338 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-09-20T19:03:33.339Z,1758395013.339 [DAT](INFO): set transmit power to 8 2025-09-20T19:03:33.340Z,1758395013.340 [DAT](INFO): setting local address to 11 2025-09-20T19:03:33.585Z,1758395013.585 [DAT](INFO): DAT read: user:4> 2025-09-20T19:03:33.587Z,1758395013.587 [DAT](INFO): DAT read: LocalAddr | 11 2025-09-20T19:03:33.587Z,1758395013.587 [DAT](INFO): set local address to 11 2025-09-20T19:03:33.588Z,1758395013.588 [DAT](INFO): Setting time to: 19:3:33 And date to:9/20/2025 2025-09-20T19:03:33.837Z,1758395013.837 [DAT](INFO): DAT read: user:5> 2025-09-20T19:03:33.837Z,1758395013.837 [DAT](INFO): DAT read: Sat Sep 20, 2025 19:03:33 2025-09-20T19:03:33.838Z,1758395013.838 [DAT](INFO): Local DAT time set to Sat Sep 20, 2025 19:03:33 2025-09-20T19:03:33.838Z,1758395013.838 [DAT](INFO): setting remote address to 50 2025-09-20T19:03:33.839Z,1758395013.839 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:03:33.839Z,1758395013.839 [DAT](INFO): setting remote address to 0 2025-09-20T19:03:34.089Z,1758395014.089 [DAT](INFO): DAT read: user:6> 2025-09-20T19:03:34.090Z,1758395014.090 [DAT](INFO): DAT read: RemoteAddr | 50 2025-09-20T19:03:34.090Z,1758395014.090 [DAT](ERROR): failed to set remote address to 0, device returned 50 instead. 2025-09-20T19:03:34.090Z,1758395014.090 [DAT] Communications Fault, FailCount= 5 2025-09-20T19:03:34.091Z,1758395014.091 [DAT](ERROR): Communications Fault 2025-09-20T19:03:34.091Z,1758395014.091 [DAT](INFO): DAT read: user:7> 2025-09-20T19:03:34.093Z,1758395014.093 [DAT](INFO): DAT read: RemoteAddr | 0 2025-09-20T19:03:34.093Z,1758395014.093 [DAT](INFO): set remote address to 0 2025-09-20T19:03:34.094Z,1758395014.094 [DAT](INFO): setting remote address to 50 2025-09-20T19:03:34.094Z,1758395014.094 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:03:34.094Z,1758395014.094 [DAT](INFO): setting remote address to 0 2025-09-20T19:03:34.497Z,1758395014.497 [DAT](INFO): Powering down 2025-09-20T19:03:34.572Z,1758395014.572 [CBIT](ERROR): Communications Fault in component: DAT 2025-09-20T19:03:35.703Z,1758395015.703 [CBIT](INFO): Clearing failed state for component DAT 2025-09-20T19:03:35.703Z,1758395015.703 [DAT] No Fault, FailCount= 5 2025-09-20T19:03:36.726Z,1758395016.726 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS2512220,35.0, +11.1, 0.0,1493.7, 0 2025-09-20T19:03:37.725Z,1758395017.725 [DAT](INFO): Powering up 2025-09-20T19:03:37.725Z,1758395017.725 [DAT](DEBUG): Initializing DAT. 2025-09-20T19:03:49.574Z,1758395029.574 [DAT](INFO): DAT read: 2025-09-20T19:03:49.577Z,1758395029.577 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-09-20T19:03:51.337Z,1758395031.337 [DAT](INFO): DAT read: MF Frequency Band 2025-09-20T19:03:51.339Z,1758395031.339 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-09-20T19:03:51.339Z,1758395031.339 [DAT](INFO): DAT read: Sep 20 2025 19:03:45 2025-09-20T19:03:52.600Z,1758395032.600 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-09-20T19:03:52.603Z,1758395032.603 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-09-20T19:03:52.606Z,1758395032.606 [DAT](INFO): commRate: 600 2025-09-20T19:03:54.673Z,1758395034.673 [DAT](INFO): entering command mode 2025-09-20T19:03:54.864Z,1758395034.864 [DAT](INFO): DAT read: 2025-09-20T19:03:54.865Z,1758395034.865 [DAT](INFO): DAT read: user:1> 2025-09-20T19:03:54.865Z,1758395034.865 [DAT](INFO): setting verbose to 3 2025-09-20T19:03:55.117Z,1758395035.117 [DAT](INFO): DAT read: user:1> 2025-09-20T19:03:55.118Z,1758395035.118 [DAT](INFO): DAT read: Verbose | 3 2025-09-20T19:03:55.118Z,1758395035.118 [DAT](INFO): set verbose to 3 2025-09-20T19:03:55.118Z,1758395035.118 [DAT](INFO): setting DatVerbose to 27440 2025-09-20T19:03:55.369Z,1758395035.369 [DAT](INFO): DAT read: user:2> 2025-09-20T19:03:55.370Z,1758395035.370 [DAT](INFO): DAT read: DatVerbose | 27440 2025-09-20T19:03:55.370Z,1758395035.370 [DAT](INFO): set DatVerbose to 27440 2025-09-20T19:03:55.371Z,1758395035.371 [DAT](INFO): setting transmit power to 8 2025-09-20T19:03:55.623Z,1758395035.623 [DAT](INFO): DAT read: user:3> 2025-09-20T19:03:55.625Z,1758395035.625 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-09-20T19:03:55.626Z,1758395035.626 [DAT](INFO): set transmit power to 8 2025-09-20T19:03:55.626Z,1758395035.626 [DAT](INFO): setting local address to 11 2025-09-20T19:03:55.873Z,1758395035.873 [DAT](INFO): DAT read: user:4> 2025-09-20T19:03:55.874Z,1758395035.874 [DAT](INFO): DAT read: LocalAddr | 11 2025-09-20T19:03:55.874Z,1758395035.874 [DAT](INFO): set local address to 11 2025-09-20T19:03:55.875Z,1758395035.875 [DAT](INFO): Setting time to: 19:3:55 And date to:9/20/2025 2025-09-20T19:03:56.125Z,1758395036.125 [DAT](INFO): DAT read: user:5> 2025-09-20T19:03:56.126Z,1758395036.126 [DAT](INFO): DAT read: Sat Sep 20, 2025 19:03:55 2025-09-20T19:03:56.126Z,1758395036.126 [DAT](INFO): Local DAT time set to Sat Sep 20, 2025 19:03:55 2025-09-20T19:03:56.127Z,1758395036.127 [DAT](INFO): setting remote address to 50 2025-09-20T19:03:56.127Z,1758395036.127 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:03:56.127Z,1758395036.127 [DAT](INFO): setting remote address to 0 2025-09-20T19:03:56.377Z,1758395036.377 [DAT](INFO): DAT read: user:6> 2025-09-20T19:03:56.378Z,1758395036.378 [DAT](INFO): DAT read: RemoteAddr | 50 2025-09-20T19:03:56.378Z,1758395036.378 [DAT](ERROR): failed to set remote address to 0, device returned 50 instead. 2025-09-20T19:03:56.378Z,1758395036.378 [DAT] Communications Fault, FailCount= 6 2025-09-20T19:03:56.378Z,1758395036.378 [DAT](ERROR): Communications Fault 2025-09-20T19:03:56.379Z,1758395036.379 [DAT](INFO): DAT read: user:7> 2025-09-20T19:03:56.380Z,1758395036.380 [DAT](INFO): DAT read: RemoteAddr | 0 2025-09-20T19:03:56.381Z,1758395036.381 [DAT](INFO): set remote address to 0 2025-09-20T19:03:56.381Z,1758395036.381 [DAT](INFO): setting remote address to 50 2025-09-20T19:03:56.381Z,1758395036.381 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:03:56.381Z,1758395036.381 [DAT](INFO): setting remote address to 0 2025-09-20T19:03:56.595Z,1758395036.595 [CBIT](ERROR): Communications Fault in component: DAT 2025-09-20T19:03:56.784Z,1758395036.784 [DAT](INFO): Powering down 2025-09-20T19:03:57.907Z,1758395037.907 [CBIT](INFO): Clearing failed state for component DAT 2025-09-20T19:03:57.907Z,1758395037.907 [DAT] No Fault, FailCount= 6 2025-09-20T19:04:00.012Z,1758395040.012 [DAT](INFO): Powering up 2025-09-20T19:04:00.012Z,1758395040.012 [DAT](DEBUG): Initializing DAT. 2025-09-20T19:04:11.859Z,1758395051.859 [DAT](INFO): DAT read: 2025-09-20T19:04:11.860Z,1758395051.860 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-09-20T19:04:13.625Z,1758395053.625 [DAT](INFO): DAT read: MF Frequency Band 2025-09-20T19:04:13.626Z,1758395053.626 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-09-20T19:04:13.627Z,1758395053.627 [DAT](INFO): DAT read: Sep 20 2025 19:04:07 2025-09-20T19:04:14.888Z,1758395054.888 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-09-20T19:04:14.892Z,1758395054.892 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-09-20T19:04:14.893Z,1758395054.893 [DAT](INFO): commRate: 600 2025-09-20T19:04:16.956Z,1758395056.956 [DAT](INFO): entering command mode 2025-09-20T19:04:17.152Z,1758395057.152 [DAT](INFO): DAT read: 2025-09-20T19:04:17.153Z,1758395057.153 [DAT](INFO): DAT read: user:1> 2025-09-20T19:04:17.153Z,1758395057.153 [DAT](INFO): setting verbose to 3 2025-09-20T19:04:17.405Z,1758395057.405 [DAT](INFO): DAT read: user:1> 2025-09-20T19:04:17.406Z,1758395057.406 [DAT](INFO): DAT read: Verbose | 3 2025-09-20T19:04:17.406Z,1758395057.406 [DAT](INFO): set verbose to 3 2025-09-20T19:04:17.406Z,1758395057.406 [DAT](INFO): setting DatVerbose to 27440 2025-09-20T19:04:17.657Z,1758395057.657 [DAT](INFO): DAT read: user:2> 2025-09-20T19:04:17.658Z,1758395057.658 [DAT](INFO): DAT read: DatVerbose | 27440 2025-09-20T19:04:17.658Z,1758395057.658 [DAT](INFO): set DatVerbose to 27440 2025-09-20T19:04:17.658Z,1758395057.658 [DAT](INFO): setting transmit power to 8 2025-09-20T19:04:17.909Z,1758395057.909 [DAT](INFO): DAT read: user:3> 2025-09-20T19:04:17.910Z,1758395057.910 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-09-20T19:04:17.910Z,1758395057.910 [DAT](INFO): set transmit power to 8 2025-09-20T19:04:17.910Z,1758395057.910 [DAT](INFO): setting local address to 11 2025-09-20T19:04:18.161Z,1758395058.161 [DAT](INFO): DAT read: user:4> 2025-09-20T19:04:18.162Z,1758395058.162 [DAT](INFO): DAT read: LocalAddr | 11 2025-09-20T19:04:18.162Z,1758395058.162 [DAT](INFO): set local address to 11 2025-09-20T19:04:18.163Z,1758395058.163 [DAT](INFO): Setting time to: 19:4:18 And date to:9/20/2025 2025-09-20T19:04:18.414Z,1758395058.414 [DAT](INFO): DAT read: user:5> 2025-09-20T19:04:18.415Z,1758395058.415 [DAT](INFO): DAT read: Sat Sep 20, 2025 19:04:18 2025-09-20T19:04:18.416Z,1758395058.416 [DAT](INFO): Local DAT time set to Sat Sep 20, 2025 19:04:18 2025-09-20T19:04:18.416Z,1758395058.416 [DAT](INFO): setting remote address to 50 2025-09-20T19:04:18.417Z,1758395058.417 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:04:18.417Z,1758395058.417 [DAT](INFO): setting remote address to 0 2025-09-20T19:04:18.665Z,1758395058.665 [DAT](INFO): DAT read: user:6> 2025-09-20T19:04:18.666Z,1758395058.666 [DAT](INFO): DAT read: RemoteAddr | 50 2025-09-20T19:04:18.666Z,1758395058.666 [DAT](ERROR): failed to set remote address to 0, device returned 50 instead. 2025-09-20T19:04:18.666Z,1758395058.666 [DAT] Communications Fault, FailCount= 7 2025-09-20T19:04:18.666Z,1758395058.666 [DAT](ERROR): Communications Fault 2025-09-20T19:04:18.667Z,1758395058.667 [DAT](INFO): DAT read: user:7> 2025-09-20T19:04:18.668Z,1758395058.668 [DAT](INFO): DAT read: RemoteAddr | 0 2025-09-20T19:04:18.669Z,1758395058.669 [DAT](INFO): set remote address to 0 2025-09-20T19:04:18.669Z,1758395058.669 [DAT](INFO): setting remote address to 50 2025-09-20T19:04:18.669Z,1758395058.669 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:04:18.669Z,1758395058.669 [DAT](INFO): setting remote address to 0 2025-09-20T19:04:19.011Z,1758395059.011 [CBIT](ERROR): Communications Fault in component: DAT 2025-09-20T19:04:19.072Z,1758395059.072 [DAT](INFO): Powering down 2025-09-20T19:04:20.107Z,1758395060.107 [CBIT](INFO): Clearing failed state for component DAT 2025-09-20T19:04:20.107Z,1758395060.107 [DAT] No Fault, FailCount= 7 2025-09-20T19:04:22.300Z,1758395062.300 [DAT](INFO): Powering up 2025-09-20T19:04:22.300Z,1758395062.300 [DAT](DEBUG): Initializing DAT. 2025-09-20T19:04:34.153Z,1758395074.153 [DAT](INFO): DAT read: 2025-09-20T19:04:34.154Z,1758395074.154 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-09-20T19:04:35.917Z,1758395075.917 [DAT](INFO): DAT read: MF Frequency Band 2025-09-20T19:04:35.918Z,1758395075.918 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-09-20T19:04:35.919Z,1758395075.919 [DAT](INFO): DAT read: Sep 20 2025 19:04:30 2025-09-20T19:04:37.181Z,1758395077.181 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-09-20T19:04:37.182Z,1758395077.182 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-09-20T19:04:37.183Z,1758395077.183 [DAT](INFO): commRate: 600 2025-09-20T19:04:39.252Z,1758395079.252 [DAT](INFO): entering command mode 2025-09-20T19:04:39.453Z,1758395079.453 [DAT](INFO): DAT read: 2025-09-20T19:04:39.454Z,1758395079.454 [DAT](INFO): DAT read: user:1> 2025-09-20T19:04:39.454Z,1758395079.454 [DAT](INFO): setting verbose to 3 2025-09-20T19:04:39.705Z,1758395079.705 [DAT](INFO): DAT read: user:1> 2025-09-20T19:04:39.706Z,1758395079.706 [DAT](INFO): DAT read: Verbose | 3 2025-09-20T19:04:39.706Z,1758395079.706 [DAT](INFO): set verbose to 3 2025-09-20T19:04:39.706Z,1758395079.706 [DAT](INFO): setting DatVerbose to 27440 2025-09-20T19:04:39.957Z,1758395079.957 [DAT](INFO): DAT read: user:2> 2025-09-20T19:04:39.958Z,1758395079.958 [DAT](INFO): DAT read: DatVerbose | 27440 2025-09-20T19:04:39.958Z,1758395079.958 [DAT](INFO): set DatVerbose to 27440 2025-09-20T19:04:39.958Z,1758395079.958 [DAT](INFO): setting transmit power to 8 2025-09-20T19:04:40.209Z,1758395080.209 [DAT](INFO): DAT read: user:3> 2025-09-20T19:04:40.210Z,1758395080.210 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-09-20T19:04:40.210Z,1758395080.210 [DAT](INFO): set transmit power to 8 2025-09-20T19:04:40.210Z,1758395080.210 [DAT](INFO): setting local address to 11 2025-09-20T19:04:40.461Z,1758395080.461 [DAT](INFO): DAT read: user:4> 2025-09-20T19:04:40.462Z,1758395080.462 [DAT](INFO): DAT read: LocalAddr | 11 2025-09-20T19:04:40.462Z,1758395080.462 [DAT](INFO): set local address to 11 2025-09-20T19:04:40.463Z,1758395080.463 [DAT](INFO): Setting time to: 19:4:40 And date to:9/20/2025 2025-09-20T19:04:40.713Z,1758395080.713 [DAT](INFO): DAT read: user:5> 2025-09-20T19:04:40.714Z,1758395080.714 [DAT](INFO): DAT read: Sat Sep 20, 2025 19:04:40 2025-09-20T19:04:40.714Z,1758395080.714 [DAT](INFO): Local DAT time set to Sat Sep 20, 2025 19:04:40 2025-09-20T19:04:40.715Z,1758395080.715 [DAT](INFO): setting remote address to 50 2025-09-20T19:04:40.715Z,1758395080.715 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:04:40.715Z,1758395080.715 [DAT](INFO): setting remote address to 0 2025-09-20T19:04:40.965Z,1758395080.965 [DAT](INFO): DAT read: user:6> 2025-09-20T19:04:40.966Z,1758395080.966 [DAT](INFO): DAT read: RemoteAddr | 50 2025-09-20T19:04:40.966Z,1758395080.966 [DAT](ERROR): failed to set remote address to 0, device returned 50 instead. 2025-09-20T19:04:40.967Z,1758395080.967 [DAT] Communications Fault, FailCount= 8 2025-09-20T19:04:40.967Z,1758395080.967 [DAT](ERROR): Communications Fault 2025-09-20T19:04:40.967Z,1758395080.967 [DAT](INFO): DAT read: user:7> 2025-09-20T19:04:40.968Z,1758395080.968 [DAT](INFO): DAT read: RemoteAddr | 0 2025-09-20T19:04:40.969Z,1758395080.969 [DAT](INFO): set remote address to 0 2025-09-20T19:04:40.969Z,1758395080.969 [DAT](INFO): setting remote address to 50 2025-09-20T19:04:40.971Z,1758395080.971 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:04:40.972Z,1758395080.972 [DAT](INFO): setting remote address to 0 2025-09-20T19:04:41.167Z,1758395081.167 [CBIT](ERROR): Communications Fault in component: DAT 2025-09-20T19:04:41.168Z,1758395081.168 [CBIT](FAULT): Communications Fault in component: DAT 2025-09-20T19:04:41.378Z,1758395081.378 [DAT](INFO): Powering down 2025-09-20T19:04:54.748Z,1758395094.748 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-09-20T19:04:55.752Z,1758395095.752 [DataOverHttps](INFO): Radio surface powered ON. 2025-09-20T19:04:55.752Z,1758395095.752 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:05:25.876Z,1758395125.876 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-09-20T19:05:26.882Z,1758395126.882 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:05:31.487Z,1758395131.487 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1 2025-09-20T19:05:31.487Z,1758395131.487 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-09-20T19:05:31.487Z,1758395131.487 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1 2025-09-20T19:05:57.004Z,1758395157.004 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-09-20T19:05:58.008Z,1758395158.008 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:06:04.189Z,1758395164.189 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-09-20T19:06:04.268Z,1758395164.268 [NAL9602](ERROR): received: +CSQ:1 OK31, 2, 0, 0, 0 OK 2025-09-20T19:06:28.128Z,1758395188.128 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-09-20T19:06:29.132Z,1758395189.132 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:06:38.272Z,1758395198.272 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003081 2025-09-20T19:06:39.272Z,1758395199.272 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:06:47.880Z,1758395207.880 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:06:56.616Z,1758395216.616 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:07:05.296Z,1758395225.296 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:07:13.832Z,1758395233.832 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:07:22.624Z,1758395242.624 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:07:27.826Z,1758395247.826 [NAL9602](INFO): SBD MO Status=0, MOMSN=1931, MT Status=0, MTMSN=0 2025-09-20T19:07:27.827Z,1758395247.827 [NAL9602](INFO): No messages in MT queue 2025-09-20T19:07:29.039Z,1758395249.039 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,190728.00,A,3646.73362,N,12151.57913,W,0.680,307.38,200925,,,A*7F 2025-09-20T19:07:29.041Z,1758395249.041 [NAL9602](INFO): GPS fix at 20250920T190728: (36.778894, -121.859652) 2025-09-20T19:07:29.094Z,1758395249.094 [UniversalFixResidualReporter](INFO): Fix residual: 0.5 %DT, over the last 2931.4 m. Residual distance 14.3 m at bearing -77.8 degrees. Fix at (36.7789, -121.8596) with 407.1 m made good. 2025-09-20T19:07:29.094Z,1758395249.094 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped 2025-09-20T19:07:29.095Z,1758395249.095 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1 2025-09-20T19:07:38.153Z,1758395258.153 [DataOverHttps](INFO): Sending 284 bytes from file Logs/20250919T193451/Courier0015.lzma 2025-09-20T19:07:39.154Z,1758395259.154 [DataOverHttps](INFO): Moved sent file to Logs/20250919T193451/Courier0015.lzma.bak 2025-09-20T19:07:39.154Z,1758395259.154 [DataOverHttps](INFO): SBD MOMSN=26047599 2025-09-20T19:07:55.525Z,1758395275.525 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250919T193451/Courier0018.lzma 2025-09-20T19:07:56.526Z,1758395276.526 [DataOverHttps](INFO): Moved sent file to Logs/20250919T193451/Courier0018.lzma.bak 2025-09-20T19:07:56.526Z,1758395276.526 [DataOverHttps](INFO): SBD MOMSN=26047611 2025-09-20T19:08:01.357Z,1758395281.357 [NAL9602](INFO): Not Powering down - fast GPS 2025-09-20T19:08:14.561Z,1758395294.561 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250919T235024/Courier0000.lzma 2025-09-20T19:08:15.562Z,1758395295.562 [DataOverHttps](INFO): Moved sent file to Logs/20250919T235024/Courier0000.lzma.bak 2025-09-20T19:08:15.562Z,1758395295.562 [DataOverHttps](INFO): SBD MOMSN=26047615 2025-09-20T19:08:31.805Z,1758395311.805 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250919T235024/Courier0003.lzma 2025-09-20T19:08:33.241Z,1758395313.241 [DataOverHttps](INFO): Moved sent file to Logs/20250919T235024/Courier0003.lzma.bak 2025-09-20T19:08:33.241Z,1758395313.241 [DataOverHttps](INFO): SBD MOMSN=26047618 2025-09-20T19:08:49.161Z,1758395329.161 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250919T235024/Courier0006.lzma 2025-09-20T19:08:50.162Z,1758395330.162 [DataOverHttps](INFO): Moved sent file to Logs/20250919T235024/Courier0006.lzma.bak 2025-09-20T19:08:50.162Z,1758395330.162 [DataOverHttps](INFO): SBD MOMSN=26047620 2025-09-20T19:09:11.029Z,1758395351.029 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250919T235024/Courier0009.lzma 2025-09-20T19:09:12.030Z,1758395352.030 [DataOverHttps](INFO): Moved sent file to Logs/20250919T235024/Courier0009.lzma.bak 2025-09-20T19:09:12.030Z,1758395352.030 [DataOverHttps](INFO): SBD MOMSN=26047622 2025-09-20T19:09:28.373Z,1758395368.373 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250919T235024/Courier0012.lzma 2025-09-20T19:09:29.374Z,1758395369.374 [DataOverHttps](INFO): Moved sent file to Logs/20250919T235024/Courier0012.lzma.bak 2025-09-20T19:09:29.374Z,1758395369.374 [DataOverHttps](INFO): SBD MOMSN=26047624 2025-09-20T19:09:41.243Z,1758395381.243 [CBIT](INFO): Clearing failed state for component DAT 2025-09-20T19:09:41.243Z,1758395381.243 [DAT] No Fault, FailCount= 8 2025-09-20T19:09:41.317Z,1758395381.317 [DAT](INFO): Powering up 2025-09-20T19:09:41.318Z,1758395381.318 [DAT](DEBUG): Initializing DAT. 2025-09-20T19:09:45.705Z,1758395385.705 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20250920T001340/Courier0000.lzma 2025-09-20T19:09:46.706Z,1758395386.706 [DataOverHttps](INFO): Moved sent file to Logs/20250920T001340/Courier0000.lzma.bak 2025-09-20T19:09:46.706Z,1758395386.706 [DataOverHttps](INFO): SBD MOMSN=26047626 2025-09-20T19:09:53.162Z,1758395393.162 [DAT](INFO): DAT read: 2025-09-20T19:09:53.413Z,1758395393.413 [DAT](INFO): DAT read: Teledyne Benthos DAT-900 Series 2025-09-20T19:09:54.932Z,1758395394.932 [DAT](INFO): DAT read: MF Frequency Band 2025-09-20T19:09:55.181Z,1758395395.181 [DAT](INFO): DAT read: Directional Acoustic Transponder version 8.15.0 2025-09-20T19:09:55.182Z,1758395395.182 [DAT](INFO): DAT read: Sep 20 2025 19:09:49 2025-09-20T19:09:56.189Z,1758395396.189 [DAT](INFO): DAT read: Features enabled [Bearing] 2025-09-20T19:09:56.190Z,1758395396.190 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-09-20T19:09:56.191Z,1758395396.191 [DAT](INFO): commRate: 600 2025-09-20T19:09:58.260Z,1758395398.260 [DAT](INFO): entering command mode 2025-09-20T19:09:58.460Z,1758395398.460 [DAT](INFO): DAT read: 2025-09-20T19:09:58.461Z,1758395398.461 [DAT](INFO): DAT read: uer:1> 2025-09-20T19:09:58.461Z,1758395398.461 [DAT](INFO): unknown deviceResponse_: uer:1> 2025-09-20T19:09:58.461Z,1758395398.461 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:09:58.713Z,1758395398.713 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:09:58.965Z,1758395398.965 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:09:59.216Z,1758395399.216 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:09:59.468Z,1758395399.468 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:09:59.720Z,1758395399.720 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:09:59.972Z,1758395399.972 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:00.225Z,1758395400.225 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:00.476Z,1758395400.476 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:00.728Z,1758395400.728 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:00.981Z,1758395400.981 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:01.233Z,1758395401.233 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:01.485Z,1758395401.485 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:01.738Z,1758395401.738 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:01.989Z,1758395401.989 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:02.249Z,1758395402.249 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:02.500Z,1758395402.500 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:02.752Z,1758395402.752 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:03.005Z,1758395403.005 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:03.257Z,1758395403.257 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:03.509Z,1758395403.509 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:03.761Z,1758395403.761 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:04.013Z,1758395404.013 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:04.157Z,1758395404.157 [DataOverHttps](INFO): Sending 462 bytes from file Logs/20250920T070029/Courier0000.lzma 2025-09-20T19:10:04.264Z,1758395404.264 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:04.516Z,1758395404.516 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:04.768Z,1758395404.768 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:05.020Z,1758395405.020 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:05.158Z,1758395405.158 [DataOverHttps](INFO): Moved sent file to Logs/20250920T070029/Courier0000.lzma.bak 2025-09-20T19:10:05.159Z,1758395405.159 [DataOverHttps](INFO): SBD MOMSN=26047629 2025-09-20T19:10:05.273Z,1758395405.273 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:05.525Z,1758395405.525 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:05.776Z,1758395405.776 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:06.029Z,1758395406.029 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:06.280Z,1758395406.280 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:06.532Z,1758395406.532 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:06.785Z,1758395406.785 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:07.037Z,1758395407.037 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:07.288Z,1758395407.288 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:07.541Z,1758395407.541 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:07.792Z,1758395407.792 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:08.044Z,1758395408.044 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:08.301Z,1758395408.301 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:08.553Z,1758395408.553 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:08.805Z,1758395408.805 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:09.057Z,1758395409.057 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:09.308Z,1758395409.308 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:09.561Z,1758395409.561 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:09.812Z,1758395409.812 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:10.064Z,1758395410.064 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:10.317Z,1758395410.317 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:10.568Z,1758395410.568 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:10.820Z,1758395410.820 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:11.073Z,1758395411.073 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:11.324Z,1758395411.324 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:11.576Z,1758395411.576 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:11.829Z,1758395411.829 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:12.080Z,1758395412.080 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:12.332Z,1758395412.332 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:12.585Z,1758395412.585 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:12.836Z,1758395412.836 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:13.089Z,1758395413.089 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:13.340Z,1758395413.340 [DAT](DEBUG): checking for command mode acknowledgment 2025-09-20T19:10:13.340Z,1758395413.340 [DAT](FAULT): failed to enter command mode 2025-09-20T19:10:13.644Z,1758395413.644 [DAT](INFO): entering command mode 2025-09-20T19:10:13.845Z,1758395413.845 [DAT](INFO): DAT read: user:1> 2025-09-20T19:10:13.845Z,1758395413.845 [DAT](INFO): DAT read: Command '+++' not found 2025-09-20T19:10:13.846Z,1758395413.846 [DAT](INFO): DAT read: Error 2025-09-20T19:10:13.846Z,1758395413.846 [DAT](INFO): setting verbose to 3 2025-09-20T19:10:14.097Z,1758395414.097 [DAT](INFO): DAT read: user:2> 2025-09-20T19:10:14.098Z,1758395414.098 [DAT](INFO): DAT read: Verbose | 3 2025-09-20T19:10:14.098Z,1758395414.098 [DAT](INFO): set verbose to 3 2025-09-20T19:10:14.098Z,1758395414.098 [DAT](INFO): setting DatVerbose to 27440 2025-09-20T19:10:14.350Z,1758395414.350 [DAT](INFO): DAT read: user:3> 2025-09-20T19:10:14.351Z,1758395414.351 [DAT](INFO): DAT read: DatVerbose | 27440 2025-09-20T19:10:14.351Z,1758395414.351 [DAT](INFO): set DatVerbose to 27440 2025-09-20T19:10:14.351Z,1758395414.351 [DAT](INFO): setting transmit power to 8 2025-09-20T19:10:14.601Z,1758395414.601 [DAT](INFO): DAT read: user:4> 2025-09-20T19:10:14.602Z,1758395414.602 [DAT](INFO): DAT read: TxPower | 8 (Max) 2025-09-20T19:10:14.602Z,1758395414.602 [DAT](INFO): set transmit power to 8 2025-09-20T19:10:14.602Z,1758395414.602 [DAT](INFO): setting local address to 11 2025-09-20T19:10:14.853Z,1758395414.853 [DAT](INFO): DAT read: user:5> 2025-09-20T19:10:14.854Z,1758395414.854 [DAT](INFO): DAT read: LocalAddr | 11 2025-09-20T19:10:14.854Z,1758395414.854 [DAT](INFO): set local address to 11 2025-09-20T19:10:14.855Z,1758395414.855 [DAT](INFO): Setting time to: 19:10:14 And date to:9/20/2025 2025-09-20T19:10:15.105Z,1758395415.105 [DAT](INFO): DAT read: user:6> 2025-09-20T19:10:15.106Z,1758395415.106 [DAT](INFO): DAT read: Sat Sep 20, 2025 19:10:14 2025-09-20T19:10:15.106Z,1758395415.106 [DAT](INFO): Local DAT time set to Sat Sep 20, 2025 19:10:14 2025-09-20T19:10:15.107Z,1758395415.107 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:10:15.107Z,1758395415.107 [DAT](INFO): setting remote address to 0 2025-09-20T19:10:15.357Z,1758395415.357 [DAT](INFO): DAT read: user:7> 2025-09-20T19:10:15.358Z,1758395415.358 [DAT](INFO): DAT read: RemoteAddr | 0 2025-09-20T19:10:15.358Z,1758395415.358 [DAT](INFO): set remote address to 0 2025-09-20T19:10:15.358Z,1758395415.358 [DAT](DEBUG): Acoustic response timeout 2025-09-20T19:10:15.359Z,1758395415.359 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-20T19:10:15.609Z,1758395415.609 [DAT](INFO): DAT read: user:8> 2025-09-20T19:10:15.609Z,1758395415.609 [DAT](INFO): DAT read: Tx time:19:10:14.6636 2025-09-20T19:10:15.610Z,1758395415.610 [DAT](INFO): Ping request sent. 2025-09-20T19:10:15.610Z,1758395415.610 [DAT](INFO): transmitted an acoustic signal 2025-09-20T19:10:15.610Z,1758395415.610 [DAT](INFO): publishing transmit ping time 2025-09-20T19:10:15.610Z,1758395415.610 [DAT](INFO): Failure count cleared after critical for DAT 2025-09-20T19:10:15.611Z,1758395415.611 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000847 2025-09-20T19:10:15.861Z,1758395415.861 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251300 2025-09-20T19:10:16.113Z,1758395416.113 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503104 2025-09-20T19:10:16.365Z,1758395416.365 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755023 2025-09-20T19:10:16.617Z,1758395416.617 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.007079 2025-09-20T19:10:16.871Z,1758395416.871 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.261045 2025-09-20T19:10:17.121Z,1758395417.121 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510926 2025-09-20T19:10:17.373Z,1758395417.373 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763084 2025-09-20T19:10:17.625Z,1758395417.625 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015133 2025-09-20T19:10:17.877Z,1758395417.877 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.267060 2025-09-20T19:10:18.129Z,1758395418.129 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519377 2025-09-20T19:10:18.381Z,1758395418.381 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771064 2025-09-20T19:10:18.633Z,1758395418.633 [DAT](INFO): DAT read: Rx Time:19:10:17.1880 2025-09-20T19:10:18.633Z,1758395418.633 [DAT](INFO): Rx dataTimestamp_ set to:1758395418.633172 2025-09-20T19:10:18.634Z,1758395418.634 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.024168 2025-09-20T19:10:18.887Z,1758395418.887 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.277210 2025-09-20T19:10:19.138Z,1758395419.138 [DAT](INFO): DAT read: Range 11 to 50 : 90.2 m (Round-trip 120.3 ms) speed -0.4 m/s 2025-09-20T19:10:19.139Z,1758395419.139 [DAT](ERROR): #Rx 1: Read range message, but no direction. 2025-09-20T19:10:19.389Z,1758395419.389 [DAT](INFO): DAT read: user:9> 2025-09-20T19:10:19.390Z,1758395419.390 [DAT](INFO): DAT read: Tx time:19:10:18.4626 2025-09-20T19:10:19.390Z,1758395419.390 [DAT](INFO): Ping request sent. 2025-09-20T19:10:19.390Z,1758395419.390 [DAT](INFO): transmitted an acoustic signal 2025-09-20T19:10:19.390Z,1758395419.390 [DAT](INFO): publishing transmit ping time 2025-09-20T19:10:21.851Z,1758395421.851 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250920T070029/Courier0003.lzma 2025-09-20T19:10:21.909Z,1758395421.909 [DAT](INFO): DAT read: Rx Time:19:10:20.4858 2025-09-20T19:10:21.909Z,1758395421.909 [DAT](INFO): Rx dataTimestamp_ set to:1758395421.909110 2025-09-20T19:10:22.417Z,1758395422.417 [DAT](INFO): DAT read: 19:10:20.4858 LVL= 19808, 22481, 22082, 24227, AGC= 73, IDX= 438,-0.46,-0.557,-0.943,-1.794,-0.840, PHS= 0.385,-0.058,-0.998, RAW= 48.3, 11.0, CAL= 45.6, 12.2, ROT= 104.4, -12.2 2025-09-20T19:10:22.418Z,1758395422.418 [DAT](INFO): got valid direction response: 19:10:20.4858 LVL= 19808, 22481, 22082, 24227, AGC= 73, IDX= 438,-0.46,-0.557,-0.943,-1.794,-0.840, PHS= 0.385,-0.058,-0.998, RAW= 48.3, 11.0, CAL= 45.6, 12.2, ROT= 104.4, -12.2 2025-09-20T19:10:22.419Z,1758395422.419 [DAT](INFO): DAT read: OK 2025-09-20T19:10:22.419Z,1758395422.419 [DAT](INFO): unknown deviceResponse_: OK 2025-09-20T19:10:22.419Z,1758395422.419 [DAT](INFO): DAT read: user:10> 2025-09-20T19:10:22.421Z,1758395422.421 [DAT](INFO): DAT read: Tx time:19:10:21.6126 2025-09-20T19:10:22.421Z,1758395422.421 [DAT](INFO): Ping request sent. 2025-09-20T19:10:22.421Z,1758395422.421 [DAT](INFO): transmitted an acoustic signal 2025-09-20T19:10:22.421Z,1758395422.421 [DAT](INFO): #Rx 2: Read direction message, but no range. 2025-09-20T19:10:22.422Z,1758395422.422 [DAT](INFO): direction in FSK: [-0.243073,0.946709,0.211325] 2025-09-20T19:10:22.422Z,1758395422.422 [DAT](INFO): publishing transmit ping time 2025-09-20T19:10:22.425Z,1758395422.425 [DAT](INFO): publishing transmit ping time 2025-09-20T19:10:22.854Z,1758395422.854 [DataOverHttps](INFO): Moved sent file to Logs/20250920T070029/Courier0003.lzma.bak 2025-09-20T19:10:22.854Z,1758395422.854 [DataOverHttps](INFO): SBD MOMSN=26047634 2025-09-20T19:10:24.933Z,1758395424.933 [DAT](INFO): DAT read: Rx Time:19:10:23.6360 2025-09-20T19:10:24.934Z,1758395424.934 [DAT](INFO): Rx dataTimestamp_ set to:1758395424.933299 2025-09-20T19:10:25.689Z,1758395425.689 [DAT](INFO): DAT read: OK 2025-09-20T19:10:25.689Z,1758395425.689 [DAT](INFO): unknown deviceResponse_: OK 2025-09-20T19:10:25.689Z,1758395425.689 [DAT](INFO): DAT read: user:11> 2025-09-20T19:10:25.690Z,1758395425.690 [DAT](INFO): DAT read: Tx time:19:10:24.7626 2025-09-20T19:10:25.690Z,1758395425.690 [DAT](INFO): Ping request sent. 2025-09-20T19:10:25.690Z,1758395425.690 [DAT](INFO): transmitted an acoustic signal 2025-09-20T19:10:25.691Z,1758395425.691 [DAT](INFO): publishing transmit ping time 2025-09-20T19:10:28.209Z,1758395428.209 [DAT](INFO): DAT read: Rx Time:19:10:26.7862 2025-09-20T19:10:28.209Z,1758395428.209 [DAT](INFO): Rx dataTimestamp_ set to:1758395428.209179 2025-09-20T19:10:28.713Z,1758395428.713 [DAT](INFO): DAT read: OK 2025-09-20T19:10:28.713Z,1758395428.713 [DAT](INFO): unknown deviceResponse_: OK 2025-09-20T19:10:40.887Z,1758395440.887 [DataOverHttps](INFO): Sending 323 bytes from file Logs/20250920T190013/Courier0000.lzma 2025-09-20T19:10:41.878Z,1758395441.878 [DataOverHttps](INFO): Moved sent file to Logs/20250920T190013/Courier0000.lzma.bak 2025-09-20T19:10:41.878Z,1758395441.878 [DataOverHttps](INFO): SBD MOMSN=26047636 2025-09-20T19:10:59.403Z,1758395459.403 [DataOverHttps](INFO): Sending 702 bytes from file Logs/20250919T193451/Express0016.lzma 2025-09-20T19:11:00.402Z,1758395460.402 [DataOverHttps](INFO): Moved sent file to Logs/20250919T193451/Express0016.lzma.bak 2025-09-20T19:11:00.402Z,1758395460.402 [DataOverHttps](INFO): SBD MOMSN=26047640 2025-09-20T19:11:17.820Z,1758395477.820 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20250919T193451/Express0019.lzma 2025-09-20T19:11:18.818Z,1758395478.818 [DataOverHttps](INFO): Moved sent file to Logs/20250919T193451/Express0019.lzma.bak 2025-09-20T19:11:18.818Z,1758395478.818 [DataOverHttps](INFO): SBD MOMSN=26047653 2025-09-20T19:11:35.123Z,1758395495.123 [DataOverHttps](INFO): Sending 541 bytes from file Logs/20250919T235024/Express0001.lzma 2025-09-20T19:11:36.110Z,1758395496.110 [DataOverHttps](INFO): Moved sent file to Logs/20250919T235024/Express0001.lzma.bak 2025-09-20T19:11:36.110Z,1758395496.110 [DataOverHttps](INFO): SBD MOMSN=26047656 2025-09-20T19:11:52.857Z,1758395512.857 [DataOverHttps](INFO): Sending 573 bytes from file Logs/20250919T235024/Express0004.lzma 2025-09-20T19:11:53.854Z,1758395513.854 [DataOverHttps](INFO): Moved sent file to Logs/20250919T235024/Express0004.lzma.bak 2025-09-20T19:11:53.854Z,1758395513.854 [DataOverHttps](INFO): SBD MOMSN=26047659 2025-09-20T19:12:10.155Z,1758395530.155 [DataOverHttps](INFO): Sending 696 bytes from file Logs/20250919T235024/Express0007.lzma 2025-09-20T19:12:11.154Z,1758395531.154 [DataOverHttps](INFO): Moved sent file to Logs/20250919T235024/Express0007.lzma.bak 2025-09-20T19:12:11.154Z,1758395531.154 [DataOverHttps](INFO): SBD MOMSN=26047663 2025-09-20T19:12:28.430Z,1758395548.430 [DataOverHttps](INFO): Sending 326 bytes from file Logs/20250919T235024/Express0010.lzma 2025-09-20T19:12:29.430Z,1758395549.430 [DataOverHttps](INFO): Moved sent file to Logs/20250919T235024/Express0010.lzma.bak 2025-09-20T19:12:29.430Z,1758395549.430 [DataOverHttps](INFO): SBD MOMSN=26047671 2025-09-20T19:12:45.522Z,1758395565.522 [DataOverHttps](INFO): Sending 465 bytes from file Logs/20250919T235024/Express0013.lzma 2025-09-20T19:12:46.522Z,1758395566.522 [DataOverHttps](INFO): Moved sent file to Logs/20250919T235024/Express0013.lzma.bak 2025-09-20T19:12:46.522Z,1758395566.522 [DataOverHttps](INFO): SBD MOMSN=26047681 2025-09-20T19:13:04.949Z,1758395584.949 [DataOverHttps](INFO): Sending 1653 bytes from file Logs/20250920T001340/Express0001.lzma 2025-09-20T19:13:05.946Z,1758395585.946 [DataOverHttps](INFO): Moved sent file to Logs/20250920T001340/Express0001.lzma.bak 2025-09-20T19:13:05.946Z,1758395585.946 [DataOverHttps](INFO): SBD MOMSN=26047686 2025-09-20T19:13:22.253Z,1758395602.253 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20250920T001340/Express0004.lzma 2025-09-20T19:13:23.254Z,1758395603.254 [DataOverHttps](INFO): Moved sent file to Logs/20250920T001340/Express0004.lzma.bak 2025-09-20T19:13:23.254Z,1758395603.254 [DataOverHttps](INFO): SBD MOMSN=26047726 2025-09-20T19:13:39.939Z,1758395619.939 [DataOverHttps](INFO): Sending 3146 bytes from file Logs/20250920T070029/Express0001.lzma 2025-09-20T19:13:40.934Z,1758395620.934 [DataOverHttps](INFO): Moved sent file to Logs/20250920T070029/Express0001.lzma.bak 2025-09-20T19:13:40.934Z,1758395620.934 [DataOverHttps](INFO): SBD MOMSN=26047729 2025-09-20T19:13:57.400Z,1758395637.400 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20250920T070029/Express0004.lzma 2025-09-20T19:13:58.402Z,1758395638.402 [DataOverHttps](INFO): Moved sent file to Logs/20250920T070029/Express0004.lzma.bak 2025-09-20T19:13:58.402Z,1758395638.402 [DataOverHttps](INFO): SBD MOMSN=26047826 2025-09-20T19:14:17.138Z,1758395657.138 [DataOverHttps](INFO): Sending 929 bytes from file Logs/20250920T190013/Express0001.lzma 2025-09-20T19:14:17.168Z,1758395657.168 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.00, 689.11, 767.96, 713.11, 2025-09-20T19:14:18.134Z,1758395658.134 [DataOverHttps](INFO): Moved sent file to Logs/20250920T190013/Express0001.lzma.bak 2025-09-20T19:14:18.134Z,1758395658.134 [DataOverHttps](INFO): SBD MOMSN=26047829 2025-09-20T19:14:19.588Z,1758395659.588 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped 2025-09-20T19:14:19.588Z,1758395659.588 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1 2025-09-20T19:14:19.588Z,1758395659.588 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-09-20T19:14:27.757Z,1758395667.757 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:14:36.958Z,1758395676.958 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for water velocity. Device response is::WS, +14, -50, 2025-09-20T19:14:37.416Z,1758395677.416 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:14:47.340Z,1758395687.340 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:14:56.392Z,1758395696.392 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:15:04.984Z,1758395704.984 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:15:13.612Z,1758395713.612 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:15:22.268Z,1758395722.268 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:15:25.048Z,1758395725.048 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.00, 685.68, 778.25, 717.11 2025-09-20T19:15:27.109Z,1758395727.109 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, -23.88, 77, 0.00 2025-09-20T19:15:31.022Z,1758395731.022 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:15:37.161Z,1758395737.161 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, -23.73, +66.64, -200 2025-09-20T19:15:39.639Z,1758395739.639 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:15:48.176Z,1758395748.176 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:15:56.932Z,1758395756.932 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:16:06.968Z,1758395766.968 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:16:15.624Z,1758395775.624 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:16:24.392Z,1758395784.392 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:16:33.077Z,1758395793.077 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:16:41.585Z,1758395801.585 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:16:50.288Z,1758395810.288 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:16:59.040Z,1758395819.040 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:17:07.696Z,1758395827.696 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:17:16.509Z,1758395836.509 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:17:25.112Z,1758395845.112 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:17:33.668Z,1758395853.668 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:17:42.504Z,1758395862.504 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:17:50.045Z,1758395870.045 [DataOverHttps](IMPORTANT): SBD MTMSN=20250920T191749 2025-09-20T19:17:57.788Z,1758395877.788 [DataOverHttps](INFO): Received command: restart sys 2025-09-20T19:17:57.790Z,1758395877.790 [CommandExec](IMPORTANT): got command restart system 2025-09-20T19:17:59.793Z,1758395879.793 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-20T19:17:59.884Z,1758395879.884 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:17:59.884Z,1758395879.884 [CommandExec](INFO): Uninitializing the command executive. 2025-09-20T19:17:59.885Z,1758395879.885 [CommandExec](INFO): Uninitializing the command scheduler. 2025-09-20T19:17:59.885Z,1758395879.885 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:00.084Z,1758395880.084 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-09-20T19:18:00.084Z,1758395880.084 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-09-20T19:18:00.084Z,1758395880.084 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:00.085Z,1758395880.085 [NavChartDb](INFO): Join timeout helper Thread ID is 4580 2025-09-20T19:18:00.444Z,1758395880.444 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:00.444Z,1758395880.444 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:00.464Z,1758395880.464 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-09-20T19:18:00.464Z,1758395880.464 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:00.465Z,1758395880.465 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4581 2025-09-20T19:18:00.704Z,1758395880.704 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:00.704Z,1758395880.704 [WetLabsBB2FL](INFO): Powering down 2025-09-20T19:18:00.705Z,1758395880.705 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:00.708Z,1758395880.708 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-09-20T19:18:00.708Z,1758395880.708 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:00.709Z,1758395880.709 [CTD_Seabird](INFO): Join timeout helper Thread ID is 4582 2025-09-20T19:18:00.756Z,1758395880.756 [CTD_Seabird](INFO): Powering down 2025-09-20T19:18:00.768Z,1758395880.768 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:00.768Z,1758395880.768 [CTD_Seabird](INFO): Powering down 2025-09-20T19:18:00.780Z,1758395880.780 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:00.788Z,1758395880.788 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-09-20T19:18:00.788Z,1758395880.788 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:00.789Z,1758395880.789 [Radio_Surface](INFO): Join timeout helper Thread ID is 4583 2025-09-20T19:18:00.824Z,1758395880.824 [Radio_Surface](INFO): Powering down 2025-09-20T19:18:00.825Z,1758395880.825 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:00.825Z,1758395880.825 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:00.828Z,1758395880.828 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2025-09-20T19:18:00.828Z,1758395880.828 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:00.828Z,1758395880.828 [Onboard](INFO): Join timeout helper Thread ID is 4584 2025-09-20T19:18:02.036Z,1758395882.036 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:02.037Z,1758395882.037 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:02.061Z,1758395882.061 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2025-09-20T19:18:02.061Z,1758395882.061 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:02.062Z,1758395882.062 [DataOverHttps](INFO): Join timeout helper Thread ID is 4585 2025-09-20T19:18:02.804Z,1758395882.804 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:02.805Z,1758395882.805 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:02.813Z,1758395882.813 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2025-09-20T19:18:02.813Z,1758395882.813 [DAT ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:02.813Z,1758395882.813 [DAT](INFO): Join timeout helper Thread ID is 4586 2025-09-20T19:18:02.996Z,1758395882.996 [DAT](INFO): Powering down 2025-09-20T19:18:02.997Z,1758395882.997 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:02.998Z,1758395882.998 [DAT](INFO): Powering down 2025-09-20T19:18:02.998Z,1758395882.998 [DAT ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.033Z,1758395883.033 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2025-09-20T19:18:03.033Z,1758395883.033 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.034Z,1758395883.034 [BackseatComponent](INFO): Join timeout helper Thread ID is 4587 2025-09-20T19:18:03.236Z,1758395883.236 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:03.236Z,1758395883.236 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.249Z,1758395883.249 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2025-09-20T19:18:03.249Z,1758395883.249 [logger ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.249Z,1758395883.249 [logger](INFO): Join timeout helper Thread ID is 4588 2025-09-20T19:18:03.252Z,1758395883.252 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:03.252Z,1758395883.252 [logger ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.269Z,1758395883.269 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2025-09-20T19:18:03.269Z,1758395883.269 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.269Z,1758395883.269 [CommandLine](INFO): Join timeout helper Thread ID is 4589 2025-09-20T19:18:03.344Z,1758395883.344 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:03.344Z,1758395883.344 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.349Z,1758395883.349 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2025-09-20T19:18:03.349Z,1758395883.349 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.349Z,1758395883.349 [CommandExec](INFO): Join timeout helper Thread ID is 4590 2025-09-20T19:18:03.350Z,1758395883.350 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2025-09-20T19:18:03.351Z,1758395883.351 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.351Z,1758395883.351 [controlThread](INFO): Join timeout helper Thread ID is 4591 2025-09-20T19:18:03.416Z,1758395883.416 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2025-09-20T19:18:03.416Z,1758395883.416 [controlThread](DEBUG): Uninitializing ControlThread 2025-09-20T19:18:03.417Z,1758395883.417 [AHRS_M2](INFO): Powering down 2025-09-20T19:18:03.420Z,1758395883.420 [NAL9602](INFO): Powering down 2025-09-20T19:18:03.421Z,1758395883.421 [RDI_Pathfinder](INFO): Powering down 2025-09-20T19:18:03.422Z,1758395883.422 [Sonardyne_Nano](INFO): Powering down 2025-09-20T19:18:03.512Z,1758395883.512 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2025-09-20T19:18:03.513Z,1758395883.513 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2025-09-20T19:18:03.514Z,1758395883.514 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2025-09-20T19:18:03.514Z,1758395883.514 [MissionManager](INFO): Uninitializing Mission DefaultWithUndock 2025-09-20T19:18:03.514Z,1758395883.514 [DefaultWithUndock] Stopped 2025-09-20T19:18:03.514Z,1758395883.514 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock 2025-09-20T19:18:03.515Z,1758395883.515 [DefaultWithUndock:SurfaceDefault] Stopped 2025-09-20T19:18:03.515Z,1758395883.515 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault 2025-09-20T19:18:03.515Z,1758395883.515 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Stopped 2025-09-20T19:18:03.515Z,1758395883.515 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-09-20T19:18:03.515Z,1758395883.515 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped 2025-09-20T19:18:03.515Z,1758395883.515 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-09-20T19:18:03.515Z,1758395883.515 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped 2025-09-20T19:18:03.515Z,1758395883.515 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-09-20T19:18:03.524Z,1758395883.524 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2025-09-20T19:18:03.524Z,1758395883.524 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2025-09-20T19:18:03.525Z,1758395883.525 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2025-09-20T19:18:03.525Z,1758395883.525 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2025-09-20T19:18:03.525Z,1758395883.525 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-09-20T19:18:03.526Z,1758395883.526 [BuoyancyServo](INFO): Powering down 2025-09-20T19:18:03.540Z,1758395883.540 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-09-20T19:18:03.540Z,1758395883.540 [ElevatorServo](INFO): Powering down 2025-09-20T19:18:03.541Z,1758395883.541 [DockingStepper](DEBUG): Uninitialize Docking Stepper. 2025-09-20T19:18:03.541Z,1758395883.541 [DockingStepper](INFO): Powering down 2025-09-20T19:18:03.542Z,1758395883.542 [MassServo](DEBUG): Uninitialize Mass Servo. 2025-09-20T19:18:03.542Z,1758395883.542 [MassServo](INFO): Powering down 2025-09-20T19:18:03.543Z,1758395883.543 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-09-20T19:18:03.543Z,1758395883.543 [RudderServo](INFO): Powering down 2025-09-20T19:18:03.544Z,1758395883.544 [ThrusterHE](DEBUG): Uninitialize Thruster Servo. 2025-09-20T19:18:03.544Z,1758395883.544 [ThrusterHE](INFO): Powering down 2025-09-20T19:18:03.545Z,1758395883.545 [SBIT](DEBUG): Uninitialize SBIT Component. 2025-09-20T19:18:03.546Z,1758395883.546 [IBIT](DEBUG): Uninitialize IBIT Component. 2025-09-20T19:18:03.546Z,1758395883.546 [CBIT](DEBUG): Uninitialize CBIT Component. 2025-09-20T19:18:03.546Z,1758395883.546 [CBIT](DEBUG): Powering off loads. 2025-09-20T19:18:03.560Z,1758395883.560 [CBIT](DEBUG): Disabling WDT. 2025-09-20T19:18:03.572Z,1758395883.572 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-09-20T19:18:03.572Z,1758395883.572 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-09-20T19:18:03.574Z,1758395883.574 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.641Z,1758395883.641 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.644Z,1758395883.644 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.650Z,1758395883.650 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.658Z,1758395883.658 [DAT ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.704Z,1758395883.704 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.773Z,1758395883.773 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.906Z,1758395883.906 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:03.914Z,1758395883.914 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-09-20T19:18:03.915Z,1758395883.915 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-09-20T19:18:03.931Z,1758395883.931 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-09-20T19:18:04.014Z,1758395884.014 [logger ThreadHandler](INFO): Thread cancelled.