2025-08-22T21:53:53.807Z,1755899633.807 [CommandExec](IMPORTANT): got command restart logs 2025-08-22T21:53:54.114Z,1755899634.114 [DAT](INFO): Requesting device enable set for address 50. 2025-08-22T21:53:54.366Z,1755899634.366 [DAT](INFO): DAT read: user:2545> 2025-08-22T21:53:54.367Z,1755899634.367 [DAT](INFO): DAT read: Tx time:21:53:55.3807 2025-08-22T21:53:54.368Z,1755899634.368 [DAT](INFO): Ping request sent. 2025-08-22T21:53:54.368Z,1755899634.368 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:53:54.368Z,1755899634.368 [DAT](INFO): publishing transmit ping time 2025-08-22T21:53:54.368Z,1755899634.368 [DAT](INFO): Requesting device enable set for address 50. 2025-08-22T21:53:54.507Z,1755899634.507 [CTD_Seabird](ERROR): Failed to parse device response: 2025-08-22T21:53:54.621Z,1755899634.621 [DAT](INFO): Requesting device enable set for address 50. 2025-08-22T21:53:56.887Z,1755899636.887 [DAT](INFO): DAT read: Rx Time:21:53:57.2781 2025-08-22T21:53:56.887Z,1755899636.887 [DAT](INFO): Rx dataTimestamp_ set to:1755899636.886714 2025-08-22T21:53:57.395Z,1755899637.395 [DAT](INFO): DAT read: 21:53:57.2781 LVL= 31824, 12913, 20546, 22259, AGC= 36, IDX= 479,-0.24,-2.990,-1.733,-2.278,-1.413, PHS=-1.476,-0.275,-0.909, RAW= 301.9, 42.1, CAL= 303.8, 46.9, ROT= 206.2, -46.9 2025-08-22T21:53:57.396Z,1755899637.396 [DAT](INFO): got valid direction response: 21:53:57.2781 LVL= 31824, 12913, 20546, 22259, AGC= 36, IDX= 479,-0.24,-2.990,-1.733,-2.278,-1.413, PHS=-1.476,-0.275,-0.909, RAW= 301.9, 42.1, CAL= 303.8, 46.9, ROT= 206.2, -46.9 2025-08-22T21:53:57.397Z,1755899637.397 [DAT](INFO): DAT read: OK 2025-08-22T21:53:57.397Z,1755899637.397 [DAT](INFO): unknown deviceResponse_: OK 2025-08-22T21:53:57.398Z,1755899637.398 [DAT](INFO): DAT read: user:2546> 2025-08-22T21:53:57.398Z,1755899637.398 [DAT](INFO): DAT read: Tx time:21:53:58.3807 2025-08-22T21:53:57.399Z,1755899637.399 [DAT](INFO): Ping request sent. 2025-08-22T21:53:57.399Z,1755899637.399 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:53:57.399Z,1755899637.399 [DAT](INFO): #Rx 5: Read direction message, but no range. 2025-08-22T21:53:57.400Z,1755899637.400 [DAT](INFO): direction in FSK: [-0.613073,-0.301669,0.730162] 2025-08-22T21:53:57.400Z,1755899637.400 [DAT](INFO): publishing transmit ping time 2025-08-22T21:53:57.403Z,1755899637.403 [DAT](INFO): publishing transmit ping time 2025-08-22T21:53:59.661Z,1755899639.661 [DAT](INFO): DAT read: Rx Time:21:54:00.2782 2025-08-22T21:53:59.663Z,1755899639.663 [DAT](INFO): Rx dataTimestamp_ set to:1755899639.661742 2025-08-22T21:54:00.419Z,1755899640.419 [DAT](INFO): DAT read: 21:54:00.2782 LVL= 24896, 25201, 28914, 27859, AGC= 36, IDX= 445, 0.34, 1.406, 2.168, 0.628, 2.511, PHS=-1.003,-0.298,-1.927, RAW= 4.4, 38.9, CAL= 2.8, 44.1, ROT= 147.2, -44.1 2025-08-22T21:54:00.420Z,1755899640.420 [DAT](INFO): got valid direction response: 21:54:00.2782 LVL= 24896, 25201, 28914, 27859, AGC= 36, IDX= 445, 0.34, 1.406, 2.168, 0.628, 2.511, PHS=-1.003,-0.298,-1.927, RAW= 4.4, 38.9, CAL= 2.8, 44.1, ROT= 147.2, -44.1 2025-08-22T21:54:00.420Z,1755899640.420 [DAT](INFO): DAT read: OK 2025-08-22T21:54:00.420Z,1755899640.420 [DAT](INFO): unknown deviceResponse_: OK 2025-08-22T21:54:00.421Z,1755899640.421 [DAT](INFO): DAT read: user:2547> 2025-08-22T21:54:00.422Z,1755899640.422 [DAT](INFO): DAT read: Tx time:21:54:01.3807 2025-08-22T21:54:00.422Z,1755899640.422 [DAT](INFO): Ping request sent. 2025-08-22T21:54:00.422Z,1755899640.422 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:54:00.423Z,1755899640.423 [DAT](INFO): #Rx 6: Read direction message, but no range. 2025-08-22T21:54:00.423Z,1755899640.423 [DAT](INFO): direction in FSK: [-0.603633,0.389015,0.695913] 2025-08-22T21:54:00.424Z,1755899640.424 [DAT](INFO): publishing transmit ping time 2025-08-22T21:54:00.427Z,1755899640.427 [DAT](INFO): publishing transmit ping time 2025-08-22T21:54:02.683Z,1755899642.683 [DAT](INFO): DAT read: Rx Time:21:54:03.2782 2025-08-22T21:54:02.684Z,1755899642.684 [DAT](INFO): Rx dataTimestamp_ set to:1755899642.683679 2025-08-22T21:54:03.192Z,1755899643.192 [DAT](INFO): DAT read: 21:54:03.2782 LVL= 26576, 24849, 28498, 32403, AGC= 35, IDX= 447,-0.35,-1.521,-0.919,-2.448,-0.575, PHS=-0.845,-0.299,-1.917, RAW= 10.6, 37.2, CAL= 9.0, 42.8, ROT= 141.0, -42.8 2025-08-22T21:54:03.193Z,1755899643.193 [DAT](INFO): got valid direction response: 21:54:03.2782 LVL= 26576, 24849, 28498, 32403, AGC= 35, IDX= 447,-0.35,-1.521,-0.919,-2.448,-0.575, PHS=-0.845,-0.299,-1.917, RAW= 10.6, 37.2, CAL= 9.0, 42.8, ROT= 141.0, -42.8 2025-08-22T21:54:03.194Z,1755899643.194 [DAT](INFO): DAT read: OK 2025-08-22T21:54:03.194Z,1755899643.194 [DAT](INFO): unknown deviceResponse_: OK 2025-08-22T21:54:03.194Z,1755899643.194 [DAT](INFO): #Rx 7: Read direction message, but no range. 2025-08-22T21:54:03.195Z,1755899643.195 [DAT](INFO): direction in FSK: [-0.570215,0.461751,0.679441] 2025-08-22T21:55:12.901Z,1755899712.901 [OnDock:StandardEnvelopes:A.AltitudeEnvelope](IMPORTANT): Altitude envelope ACTIVE. Altitude:4.980000m. At depth:68.853951m. 2025-08-22T21:55:51.679Z,1755899751.679 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-22T21:55:51.890Z,1755899751.890 [DAT](DEBUG): Acoustic response timeout 2025-08-22T21:55:51.890Z,1755899751.890 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-22T21:55:52.143Z,1755899752.143 [DAT](INFO): DAT read: user:2548> 2025-08-22T21:55:52.144Z,1755899752.144 [DAT](INFO): DAT read: Tx time:21:55:53.1310 2025-08-22T21:55:52.144Z,1755899752.144 [DAT](INFO): Ping request sent. 2025-08-22T21:55:52.144Z,1755899752.144 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:55:52.145Z,1755899752.145 [DAT](INFO): publishing transmit ping time 2025-08-22T21:55:52.146Z,1755899752.146 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001128 2025-08-22T21:55:52.395Z,1755899752.395 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250117 2025-08-22T21:55:52.647Z,1755899752.647 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502188 2025-08-22T21:55:52.899Z,1755899752.899 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754677 2025-08-22T21:55:53.150Z,1755899753.150 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006055 2025-08-22T21:55:53.403Z,1755899753.403 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258125 2025-08-22T21:55:53.657Z,1755899753.657 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.512167 2025-08-22T21:55:53.911Z,1755899753.911 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.766573 2025-08-22T21:55:54.163Z,1755899754.163 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.018807 2025-08-22T21:55:54.417Z,1755899754.417 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.272273 2025-08-22T21:55:54.667Z,1755899754.667 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.522208 2025-08-22T21:55:54.918Z,1755899754.918 [DAT](INFO): DAT read: Rx Time:21:55:55.5493 2025-08-22T21:55:54.919Z,1755899754.919 [DAT](INFO): Rx dataTimestamp_ set to:1755899754.918949 2025-08-22T21:55:54.920Z,1755899754.920 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.775396 2025-08-22T21:55:55.171Z,1755899755.171 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.026300 2025-08-22T21:55:55.443Z,1755899755.443 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.298064 2025-08-22T21:55:55.700Z,1755899755.700 [DAT](INFO): DAT read: 21:55:55.5493 LVL= 28496, 32753, 31410, 32755, AGC= 46, IDX= 142, 0.25, 0.691,-1.045, 0.622, 0.051, PHS= 0.742,-1.051, 0.526, RAW= 143.7, -2.6, CAL= 143.5, -3.0, ROT= 6.5, 3.0 2025-08-22T21:55:55.701Z,1755899755.701 [DAT](INFO): got valid direction response: 21:55:55.5493 LVL= 28496, 32753, 31410, 32755, AGC= 46, IDX= 142, 0.25, 0.691,-1.045, 0.622, 0.051, PHS= 0.742,-1.051, 0.526, RAW= 143.7, -2.6, CAL= 143.5, -3.0, ROT= 6.5, 3.0 2025-08-22T21:55:55.702Z,1755899755.702 [DAT](INFO): DAT read: Bearing 300.2, 10.1 (Local) 2025-08-22T21:55:55.702Z,1755899755.702 [DAT](INFO): Local bearing/azimuth received: Bearing 300.2, 10.1 (Local) 2025-08-22T21:55:55.703Z,1755899755.703 [DAT](INFO): DAT read: Range 11 to 50 : 10.6 m (Round-trip 14.2 ms) speed -0.1 m/s 2025-08-22T21:55:55.704Z,1755899755.704 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-22T21:55:55.705Z,1755899755.705 [DAT](INFO): direction in FSK: [0.992210,0.113048,-0.052336] 2025-08-22T21:55:55.705Z,1755899755.705 [DAT](INFO): publishing direction and range info 2025-08-22T21:55:55.814Z,1755899755.814 [OnDock:N.Docked](FAULT): Off dock, range to dock 10.600000 exceeded threshold. 2025-08-22T21:55:55.814Z,1755899755.814 [OnDock:N.Docked](IMPORTANT): State switched to DETACHED. Waiting for state timeout to act... 2025-08-22T21:56:07.833Z,1755899767.833 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.00, 41.76, 45.83, 42.10 2025-08-22T21:56:21.959Z,1755899781.959 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.00, 43.80, 49.23, 49.57, 2025-08-22T21:56:26.017Z,1755899786.017 [OnDock:N.Docked](IMPORTANT): VEHICLE DETACHED FROM DOCK. 2025-08-22T21:56:26.033Z,1755899786.033 [OnDock:N.Docked] Stopped 2025-08-22T21:56:26.034Z,1755899786.034 [OnDock:Detach] Running Loop=1 2025-08-22T21:56:26.034Z,1755899786.034 [OnDock:Detach](DEBUG): Aggregate::initialize OnDock:Detach 2025-08-22T21:56:26.034Z,1755899786.034 [OnDock:Detach:A] Running Loop=1 2025-08-22T21:56:26.183Z,1755899786.183 [DockingStepper](INFO): Changing to mode: 2 2025-08-22T21:56:26.405Z,1755899786.405 [OnDock:Detach:A](IMPORTANT): Mission ending, breaking off. Range: 10.600000 m . 2025-08-22T21:56:26.405Z,1755899786.405 [OnDock:Detach:A] Stopped 2025-08-22T21:56:26.405Z,1755899786.405 [OnDock:Detach:B.Undock] Running Loop=1 2025-08-22T21:56:26.405Z,1755899786.405 [OnDock:Detach:B.Undock](DEBUG): Initialize. 2025-08-22T21:56:26.405Z,1755899786.405 [OnDock:Detach:B.Undock](DEBUG): Initializing internal variables to default values. 2025-08-22T21:56:26.467Z,1755899786.467 [DAT](INFO): DAT read: user:2549> 2025-08-22T21:56:26.467Z,1755899786.467 [DAT](INFO): DAT read: Tx time:21:56:27.4798 2025-08-22T21:56:26.468Z,1755899786.468 [DAT](INFO): Ping request sent. 2025-08-22T21:56:26.468Z,1755899786.468 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:56:26.468Z,1755899786.468 [DAT](INFO): publishing transmit ping time 2025-08-22T21:56:26.823Z,1755899786.823 [OnDock:Detach:B.Undock](DEBUG): Initialize. 2025-08-22T21:56:26.823Z,1755899786.823 [OnDock:Detach:B.Undock](DEBUG): Initializing internal variables to default values. 2025-08-22T21:56:26.824Z,1755899786.824 [OnDock:Detach:B.Undock](INFO): Detached from dock at depth 68.975784 m. 2025-08-22T21:56:27.407Z,1755899787.407 [DockingStepper](INFO): Changing to mode: 3 2025-08-22T21:56:28.987Z,1755899788.987 [DAT](INFO): DAT read: Rx Time:21:56:29.3922 2025-08-22T21:56:28.988Z,1755899788.988 [DAT](INFO): Rx dataTimestamp_ set to:1755899788.987521 2025-08-22T21:56:29.495Z,1755899789.495 [DAT](INFO): DAT read: 21:56:29.3922 LVL= 27216, 29329, 29554, 32755, AGC= 50, IDX= 375, 0.27,-2.279, 2.183,-2.413,-2.858, PHS= 0.681,-1.198, 0.401, RAW= 142.1, 1.3, CAL= 141.8, 1.7, ROT= 8.2, -1.7 2025-08-22T21:56:29.496Z,1755899789.496 [DAT](INFO): got valid direction response: 21:56:29.3922 LVL= 27216, 29329, 29554, 32755, AGC= 50, IDX= 375, 0.27,-2.279, 2.183,-2.413,-2.858, PHS= 0.681,-1.198, 0.401, RAW= 142.1, 1.3, CAL= 141.8, 1.7, ROT= 8.2, -1.7 2025-08-22T21:56:29.496Z,1755899789.496 [DAT](INFO): DAT read: OK 2025-08-22T21:56:29.496Z,1755899789.496 [DAT](INFO): unknown deviceResponse_: OK 2025-08-22T21:56:29.497Z,1755899789.497 [DAT](INFO): DAT read: user:2550> 2025-08-22T21:56:29.498Z,1755899789.498 [DAT](INFO): DAT read: Tx time:21:56:30.4806 2025-08-22T21:56:29.498Z,1755899789.498 [DAT](INFO): Ping request sent. 2025-08-22T21:56:29.498Z,1755899789.498 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:56:29.498Z,1755899789.498 [DAT](INFO): #Rx 2: Read direction message, but no range. 2025-08-22T21:56:29.499Z,1755899789.499 [DAT](INFO): direction in FSK: [0.989341,0.142566,0.029666] 2025-08-22T21:56:29.500Z,1755899789.500 [DAT](INFO): publishing transmit ping time 2025-08-22T21:56:29.503Z,1755899789.503 [DAT](INFO): publishing transmit ping time 2025-08-22T21:56:31.759Z,1755899791.759 [DAT](INFO): DAT read: Rx Time:21:56:32.3926 2025-08-22T21:56:31.760Z,1755899791.760 [DAT](INFO): Rx dataTimestamp_ set to:1755899791.759232 2025-08-22T21:56:32.094Z,1755899792.094 [OnDock:Detach:B.Undock](INFO): Detected possible detachment. Starting timer. 2025-08-22T21:56:32.519Z,1755899792.519 [DAT](INFO): DAT read: 21:56:32.3926 LVL= 26672, 32753, 32066, 32755, AGC= 47, IDX= 427, 0.25,-2.776, 1.705,-2.939, 2.947, PHS= 0.662,-1.197, 0.353, RAW= 141.1, 2.1, CAL= 140.9, 2.6, ROT= 9.1, -2.6 2025-08-22T21:56:32.520Z,1755899792.520 [DAT](INFO): got valid direction response: 21:56:32.3926 LVL= 26672, 32753, 32066, 32755, AGC= 47, IDX= 427, 0.25,-2.776, 1.705,-2.939, 2.947, PHS= 0.662,-1.197, 0.353, RAW= 141.1, 2.1, CAL= 140.9, 2.6, ROT= 9.1, -2.6 2025-08-22T21:56:32.520Z,1755899792.520 [DAT](INFO): DAT read: OK 2025-08-22T21:56:32.521Z,1755899792.521 [DAT](INFO): unknown deviceResponse_: OK 2025-08-22T21:56:32.521Z,1755899792.521 [DAT](INFO): DAT read: user:2551> 2025-08-22T21:56:32.522Z,1755899792.522 [DAT](INFO): DAT read: Tx time:21:56:33.4798 2025-08-22T21:56:32.523Z,1755899792.523 [DAT](INFO): Ping request sent. 2025-08-22T21:56:32.523Z,1755899792.523 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:56:32.523Z,1755899792.523 [DAT](INFO): #Rx 3: Read direction message, but no range. 2025-08-22T21:56:32.524Z,1755899792.524 [DAT](INFO): direction in FSK: [0.986397,0.157995,0.045363] 2025-08-22T21:56:32.524Z,1755899792.524 [DAT](INFO): publishing transmit ping time 2025-08-22T21:56:32.531Z,1755899792.531 [DAT](INFO): publishing transmit ping time 2025-08-22T21:56:34.783Z,1755899794.783 [DAT](INFO): DAT read: Rx Time:21:56:35.3930 2025-08-22T21:56:34.783Z,1755899794.783 [DAT](INFO): Rx dataTimestamp_ set to:1755899794.782756 2025-08-22T21:56:35.292Z,1755899795.292 [DAT](INFO): DAT read: 21:56:35.3930 LVL= 25968, 30305, 29858, 32755, AGC= 48, IDX= 431, 0.39,-3.065, 1.395, 3.069, 2.665, PHS= 0.655,-1.225, 0.360, RAW= 141.6, 2.4, CAL= 141.4, 2.9, ROT= 8.6, -2.9 2025-08-22T21:56:35.293Z,1755899795.293 [DAT](INFO): got valid direction response: 21:56:35.3930 LVL= 25968, 30305, 29858, 32755, AGC= 48, IDX= 431, 0.39,-3.065, 1.395, 3.069, 2.665, PHS= 0.655,-1.225, 0.360, RAW= 141.6, 2.4, CAL= 141.4, 2.9, ROT= 8.6, -2.9 2025-08-22T21:56:35.294Z,1755899795.294 [DAT](INFO): DAT read: OK 2025-08-22T21:56:35.294Z,1755899795.294 [DAT](INFO): unknown deviceResponse_: OK 2025-08-22T21:56:35.294Z,1755899795.294 [DAT](INFO): #Rx 4: Read direction message, but no range. 2025-08-22T21:56:35.295Z,1755899795.295 [DAT](INFO): direction in FSK: [0.987490,0.149344,0.050593] 2025-08-22T21:56:52.318Z,1755899812.318 [OnDock:Detach:B.Undock](INFO): Detached at range: 10.60 m. Transitioning docking module to standby. 2025-08-22T21:56:52.690Z,1755899812.690 [DockingStepper](INFO): Changing to mode: 1 2025-08-22T21:56:58.722Z,1755899818.722 [OnDock:Detach:B.Undock](INFO): Docking module at standby. 2025-08-22T21:56:59.126Z,1755899819.126 [OnDock:Detach:B.Undock](IMPORTANT): Undocking sequence complete. 2025-08-22T21:56:59.126Z,1755899819.126 [OnDock:Detach:B.Undock] Stopped 2025-08-22T21:56:59.126Z,1755899819.126 [OnDock:Detach](INFO): Completed OnDock:Detach 2025-08-22T21:56:59.126Z,1755899819.126 [OnDock:Detach] Stopped 2025-08-22T21:56:59.126Z,1755899819.126 [OnDock:Detach](DEBUG): Aggregate::uninitialize OnDock:Detach 2025-08-22T21:56:59.128Z,1755899819.128 [OnDock](INFO): Completed OnDock 2025-08-22T21:56:59.128Z,1755899819.128 [MissionManager](INFO): OnDock is completed. 2025-08-22T21:56:59.129Z,1755899819.129 [MissionManager](INFO): Uninitializing Mission OnDock 2025-08-22T21:56:59.129Z,1755899819.129 [OnDock] Stopped 2025-08-22T21:56:59.129Z,1755899819.129 [OnDock](DEBUG): Aggregate::uninitialize OnDock 2025-08-22T21:56:59.129Z,1755899819.129 [OnDock:StandardEnvelopes] Stopped 2025-08-22T21:56:59.129Z,1755899819.129 [OnDock:StandardEnvelopes](DEBUG): Aggregate::uninitialize OnDock:StandardEnvelopes 2025-08-22T21:56:59.129Z,1755899819.129 [OnDock:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-08-22T21:56:59.129Z,1755899819.129 [OnDock:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-08-22T21:56:59.129Z,1755899819.129 [OnDock:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-08-22T21:56:59.129Z,1755899819.129 [OnDock:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-08-22T21:56:59.129Z,1755899819.129 [OnDock:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:BackseatDriver] Stopped 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:BackseatDriver](DEBUG): Aggregate::uninitialize OnDock:BackseatDriver 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:BackseatDriver:A.BackseatDriver] Stopped 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:PowerOnly] Stopped 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:PowerOnly](DEBUG): Aggregate::uninitialize OnDock:PowerOnly 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:PowerOnly:E.Wait] Stopped 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:dataRead] Stopped 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:dataRead](DEBUG): Aggregate::uninitialize OnDock:dataRead 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:dataRead:A] Stopped 2025-08-22T21:56:59.130Z,1755899819.130 [OnDock:J.] Stopped 2025-08-22T21:56:59.131Z,1755899819.131 [OnDock:J.](DEBUG): Uninitializing TrackAcousticContact. 2025-08-22T21:56:59.131Z,1755899819.131 [OnDock:PeriodicCheck] Stopped 2025-08-22T21:56:59.131Z,1755899819.131 [OnDock:PeriodicCheck](DEBUG): Aggregate::uninitialize OnDock:PeriodicCheck 2025-08-22T21:56:59.131Z,1755899819.131 [OnDock:PeriodicCheck:CheckIP] Stopped 2025-08-22T21:56:59.131Z,1755899819.131 [OnDock:PeriodicCheck:CheckIP](DEBUG): Aggregate::uninitialize OnDock:PeriodicCheck:CheckIP 2025-08-22T21:56:59.131Z,1755899819.131 [OnDock:PeriodicCheck:CheckIP:B.Wait] Stopped 2025-08-22T21:56:59.131Z,1755899819.131 [OnDock:PeriodicCheck:CheckIP:B.Wait](DEBUG): Uninitialize Wait Component. 2025-08-22T21:56:59.559Z,1755899819.559 [MissionManager](IMPORTANT): Started mission DefaultWithUndock 2025-08-22T21:56:59.559Z,1755899819.559 [DefaultWithUndock] Running Loop=1 2025-08-22T21:56:59.559Z,1755899819.559 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock 2025-08-22T21:56:59.559Z,1755899819.559 [DefaultWithUndock:A.Wait] Running Loop=1 2025-08-22T21:56:59.559Z,1755899819.559 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component. 2025-08-22T21:57:29.869Z,1755899849.869 [DefaultWithUndock:A.Wait](INFO): Done Waiting. 2025-08-22T21:57:29.869Z,1755899849.869 [DefaultWithUndock:A.Wait] Stopped 2025-08-22T21:57:29.869Z,1755899849.869 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component. 2025-08-22T21:57:29.869Z,1755899849.869 [DefaultWithUndock:LeaveDock] Running Loop=1 2025-08-22T21:57:29.869Z,1755899849.869 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock 2025-08-22T21:57:29.869Z,1755899849.869 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2025-08-22T21:57:29.869Z,1755899849.869 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact. 2025-08-22T21:57:29.870Z,1755899849.870 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1 2025-08-22T21:57:29.870Z,1755899849.870 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-08-22T21:57:29.870Z,1755899849.870 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-08-22T21:57:30.235Z,1755899850.235 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-08-22T21:57:30.235Z,1755899850.235 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-08-22T21:57:30.236Z,1755899850.236 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock at depth 68.457764 m. 2025-08-22T21:57:30.237Z,1755899850.237 [DefaultWithUndock:LeaveDock:A.](ERROR): Failed to read sound speed 2025-08-22T21:57:30.687Z,1755899850.687 [DockingStepper](INFO): Changing to mode: 3 2025-08-22T21:57:33.435Z,1755899853.435 [CTD_Seabird](ERROR): Failed to parse device response: 2025-08-22T21:57:36.294Z,1755899856.294 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:36.295Z,1755899856.295 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Engaging thruster for 10.0 seconds (max) to disengage. 2025-08-22T21:57:36.699Z,1755899856.699 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:37.113Z,1755899857.113 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,0002280144569+10.3, 0.0,1491.1, 0 2025-08-22T21:57:37.124Z,1755899857.124 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:37.506Z,1755899857.506 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:37.982Z,1755899857.982 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:38.321Z,1755899858.321 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:38.718Z,1755899858.718 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:39.160Z,1755899859.160 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:39.535Z,1755899859.535 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:39.992Z,1755899859.992 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:39.993Z,1755899859.993 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-22T21:57:40.082Z,1755899860.082 [DAT](DEBUG): Acoustic response timeout 2025-08-22T21:57:40.083Z,1755899860.083 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-22T21:57:40.334Z,1755899860.334 [DAT](INFO): DAT read: user:2552> 2025-08-22T21:57:40.335Z,1755899860.335 [DAT](INFO): DAT read: Tx time:21:57:41.3305 2025-08-22T21:57:40.336Z,1755899860.336 [DAT](INFO): Ping request sent. 2025-08-22T21:57:40.336Z,1755899860.336 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:57:40.336Z,1755899860.336 [DAT](INFO): publishing transmit ping time 2025-08-22T21:57:40.336Z,1755899860.336 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000729 2025-08-22T21:57:40.396Z,1755899860.396 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:40.587Z,1755899860.587 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250946 2025-08-22T21:57:40.741Z,1755899860.741 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:40.840Z,1755899860.840 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.504047 2025-08-22T21:57:41.091Z,1755899861.091 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754858 2025-08-22T21:57:41.183Z,1755899861.183 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:41.343Z,1755899861.343 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006957 2025-08-22T21:57:41.549Z,1755899861.549 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:41.595Z,1755899861.595 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259569 2025-08-22T21:57:41.847Z,1755899861.847 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510929 2025-08-22T21:57:42.010Z,1755899862.010 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:42.099Z,1755899862.099 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762929 2025-08-22T21:57:42.351Z,1755899862.351 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014891 2025-08-22T21:57:42.376Z,1755899862.376 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:42.603Z,1755899862.603 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266930 2025-08-22T21:57:42.772Z,1755899862.772 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:42.855Z,1755899862.855 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519184 2025-08-22T21:57:43.107Z,1755899863.107 [DAT](INFO): DAT read: Rx Time:21:57:43.7729 2025-08-22T21:57:43.107Z,1755899863.107 [DAT](INFO): Rx dataTimestamp_ set to:1755899863.106721 2025-08-22T21:57:43.108Z,1755899863.108 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771912 2025-08-22T21:57:43.200Z,1755899863.200 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:43.359Z,1755899863.359 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022874 2025-08-22T21:57:43.566Z,1755899863.566 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-22T21:57:43.611Z,1755899863.611 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275461 2025-08-22T21:57:43.868Z,1755899863.868 [DAT](INFO): DAT read: 21:57:43.7729 LVL= 25840, 31441, 28914, 32755, AGC= 57, IDX= 212,-0.06,-0.313,-2.204,-0.501,-0.752, PHS= 0.541,-1.407, 0.207, RAW= 140.8, 7.4, CAL= 140.4, 8.1, ROT= 9.6, -8.1 2025-08-22T21:57:43.869Z,1755899863.869 [DAT](INFO): got valid direction response: 21:57:43.7729 LVL= 25840, 31441, 28914, 32755, AGC= 57, IDX= 212,-0.06,-0.313,-2.204,-0.501,-0.752, PHS= 0.541,-1.407, 0.207, RAW= 140.8, 7.4, CAL= 140.4, 8.1, ROT= 9.6, -8.1 2025-08-22T21:57:43.870Z,1755899863.870 [DAT](INFO): DAT read: Bearing 308.9, 13.4 (Local) 2025-08-22T21:57:43.870Z,1755899863.870 [DAT](INFO): Local bearing/azimuth received: Bearing 308.9, 13.4 (Local) 2025-08-22T21:57:43.871Z,1755899863.871 [DAT](INFO): DAT read: Range 11 to 50 : 28.6 m (Round-trip 38.2 ms) speed -0.3 m/s 2025-08-22T21:57:43.872Z,1755899863.872 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-22T21:57:43.873Z,1755899863.873 [DAT](INFO): direction in FSK: [0.976159,0.165105,0.140901] 2025-08-22T21:57:43.873Z,1755899863.873 [DAT](INFO): publishing direction and range info 2025-08-22T21:57:43.995Z,1755899863.995 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Thruster off. 2025-08-22T21:57:44.394Z,1755899864.394 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2025-08-22T21:57:50.031Z,1755899870.031 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-22T21:57:50.171Z,1755899870.171 [DAT](INFO): ****** received valid address query ****** 2025-08-22T21:57:50.171Z,1755899870.171 [DAT](INFO): ****** received valid ping request ****** 2025-08-22T21:57:50.171Z,1755899870.171 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-22T21:57:50.423Z,1755899870.423 [DAT](INFO): DAT read: user:2553> 2025-08-22T21:57:50.423Z,1755899870.423 [DAT](INFO): DAT read: Tx time:21:57:51.4304 2025-08-22T21:57:50.424Z,1755899870.424 [DAT](INFO): Ping request sent. 2025-08-22T21:57:50.424Z,1755899870.424 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:57:50.424Z,1755899870.424 [DAT](INFO): publishing transmit ping time 2025-08-22T21:57:50.424Z,1755899870.424 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000727 2025-08-22T21:57:50.674Z,1755899870.674 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250674 2025-08-22T21:57:50.927Z,1755899870.927 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502877 2025-08-22T21:57:51.179Z,1755899871.179 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755198 2025-08-22T21:57:51.430Z,1755899871.430 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006717 2025-08-22T21:57:51.696Z,1755899871.696 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.271792 2025-08-22T21:57:51.947Z,1755899871.947 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.522786 2025-08-22T21:57:52.199Z,1755899872.199 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.774770 2025-08-22T21:57:52.451Z,1755899872.451 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.027335 2025-08-22T21:57:52.703Z,1755899872.703 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.278803 2025-08-22T21:57:52.954Z,1755899872.954 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.530753 2025-08-22T21:57:53.207Z,1755899873.207 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.783599 2025-08-22T21:57:53.459Z,1755899873.459 [DAT](INFO): DAT read: Rx Time:21:57:53.8767 2025-08-22T21:57:53.459Z,1755899873.459 [DAT](INFO): Rx dataTimestamp_ set to:1755899873.458774 2025-08-22T21:57:53.460Z,1755899873.460 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.035869 2025-08-22T21:57:53.711Z,1755899873.711 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.287270 2025-08-22T21:57:53.968Z,1755899873.968 [DAT](INFO): DAT read: 21:57:53.8767 LVL= 32752, 32753, 32754, 32755, AGC= 58, IDX= 460, 0.15,-3.038, 1.298, 3.068, 2.929, PHS= 0.418,-1.586, 0.095, RAW= 141.4, 11.5, CAL= 140.8, 12.5, ROT= 9.2, -12.5 2025-08-22T21:57:53.969Z,1755899873.969 [DAT](INFO): got valid direction response: 21:57:53.8767 LVL= 32752, 32753, 32754, 32755, AGC= 58, IDX= 460, 0.15,-3.038, 1.298, 3.068, 2.929, PHS= 0.418,-1.586, 0.095, RAW= 141.4, 11.5, CAL= 140.8, 12.5, ROT= 9.2, -12.5 2025-08-22T21:57:53.970Z,1755899873.970 [DAT](INFO): DAT read: Bearing 312.8, 7.9 (Local) 2025-08-22T21:57:53.970Z,1755899873.970 [DAT](INFO): Local bearing/azimuth received: Bearing 312.8, 7.9 (Local) 2025-08-22T21:57:53.971Z,1755899873.971 [DAT](INFO): DAT read: Range 11 to 50 : 31.5 m (Round-trip 42.1 ms) speed -0.3 m/s 2025-08-22T21:57:53.972Z,1755899873.972 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-22T21:57:53.973Z,1755899873.973 [DAT](INFO): direction in FSK: [0.963737,0.156091,0.216440] 2025-08-22T21:57:53.974Z,1755899873.974 [DAT](INFO): publishing direction and range info 2025-08-22T21:58:00.132Z,1755899880.132 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-22T21:58:00.264Z,1755899880.264 [DAT](INFO): ****** received valid address query ****** 2025-08-22T21:58:00.264Z,1755899880.264 [DAT](INFO): ****** received valid ping request ****** 2025-08-22T21:58:00.266Z,1755899880.266 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-22T21:58:00.518Z,1755899880.518 [DAT](INFO): DAT read: user:2554> 2025-08-22T21:58:00.519Z,1755899880.519 [DAT](INFO): DAT read: Tx time:21:58:01.5304 2025-08-22T21:58:00.519Z,1755899880.519 [DAT](INFO): Ping request sent. 2025-08-22T21:58:00.520Z,1755899880.520 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:58:00.520Z,1755899880.520 [DAT](INFO): publishing transmit ping time 2025-08-22T21:58:00.520Z,1755899880.520 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000752 2025-08-22T21:58:00.771Z,1755899880.771 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250911 2025-08-22T21:58:01.023Z,1755899881.023 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502956 2025-08-22T21:58:01.278Z,1755899881.278 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.757352 2025-08-22T21:58:01.527Z,1755899881.527 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006908 2025-08-22T21:58:01.779Z,1755899881.779 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259213 2025-08-22T21:58:02.031Z,1755899882.031 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511048 2025-08-22T21:58:02.285Z,1755899882.285 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.765220 2025-08-22T21:58:02.542Z,1755899882.542 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.022842 2025-08-22T21:58:02.794Z,1755899882.794 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.274875 2025-08-22T21:58:03.047Z,1755899883.047 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.527065 2025-08-22T21:58:03.301Z,1755899883.301 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.780637 2025-08-22T21:58:03.550Z,1755899883.550 [DAT](INFO): DAT read: Rx Time:21:58:03.9805 2025-08-22T21:58:03.551Z,1755899883.551 [DAT](INFO): Rx dataTimestamp_ set to:1755899883.550639 2025-08-22T21:58:03.551Z,1755899883.551 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.031885 2025-08-22T21:58:03.803Z,1755899883.803 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.283431 2025-08-22T21:58:04.064Z,1755899884.064 [DAT](INFO): DAT read: 21:58:03.9805 LVL= 32192, 32753, 32754, 32755, AGC= 57, IDX= 468, 0.29,-1.294, 3.069,-1.483,-1.664, PHS= 0.472,-1.505, 0.137, RAW= 140.9, 9.8, CAL= 140.4, 10.7, ROT= 9.6, -10.7 2025-08-22T21:58:04.065Z,1755899884.065 [DAT](INFO): got valid direction response: 21:58:03.9805 LVL= 32192, 32753, 32754, 32755, AGC= 57, IDX= 468, 0.29,-1.294, 3.069,-1.483,-1.664, PHS= 0.472,-1.505, 0.137, RAW= 140.9, 9.8, CAL= 140.4, 10.7, ROT= 9.6, -10.7 2025-08-22T21:58:04.066Z,1755899884.066 [DAT](INFO): DAT read: Bearing 310.3, 10.2 (Local) 2025-08-22T21:58:04.067Z,1755899884.067 [DAT](INFO): Local bearing/azimuth received: Bearing 310.3, 10.2 (Local) 2025-08-22T21:58:04.068Z,1755899884.068 [DAT](INFO): DAT read: Range 11 to 50 : 34.5 m (Round-trip 46.0 ms) speed -0.3 m/s 2025-08-22T21:58:04.068Z,1755899884.068 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-22T21:58:04.070Z,1755899884.070 [DAT](INFO): direction in FSK: [0.968852,0.163869,0.185667] 2025-08-22T21:58:04.070Z,1755899884.070 [DAT](INFO): publishing direction and range info 2025-08-22T21:58:04.618Z,1755899884.618 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: 34.50 m. Transitioning docking module to standby. 2025-08-22T21:58:04.989Z,1755899884.989 [DockingStepper](INFO): Changing to mode: 1 2025-08-22T21:58:10.235Z,1755899890.235 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-22T21:58:10.358Z,1755899890.358 [DAT](INFO): ****** received valid address query ****** 2025-08-22T21:58:10.358Z,1755899890.358 [DAT](INFO): ****** received valid ping request ****** 2025-08-22T21:58:10.359Z,1755899890.359 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-22T21:58:10.614Z,1755899890.614 [DAT](INFO): DAT read: user:2555> 2025-08-22T21:58:10.615Z,1755899890.615 [DAT](INFO): DAT read: Tx time:21:58:11.6303 2025-08-22T21:58:10.615Z,1755899890.615 [DAT](INFO): Ping request sent. 2025-08-22T21:58:10.616Z,1755899890.616 [DAT](INFO): transmitted an acoustic signal 2025-08-22T21:58:10.616Z,1755899890.616 [DAT](INFO): publishing transmit ping time 2025-08-22T21:58:10.616Z,1755899890.616 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000737 2025-08-22T21:58:10.867Z,1755899890.867 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251783 2025-08-22T21:58:11.043Z,1755899891.043 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby. 2025-08-22T21:58:11.119Z,1755899891.119 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502954 2025-08-22T21:58:11.373Z,1755899891.373 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.757208 2025-08-22T21:58:11.477Z,1755899891.477 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete. 2025-08-22T21:58:11.477Z,1755899891.477 [DefaultWithUndock:LeaveDock:B.Undock] Stopped 2025-08-22T21:58:11.478Z,1755899891.478 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock 2025-08-22T21:58:11.478Z,1755899891.478 [DefaultWithUndock:LeaveDock] Stopped 2025-08-22T21:58:11.478Z,1755899891.478 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock 2025-08-22T21:58:11.478Z,1755899891.478 [DefaultWithUndock:LeaveDock:A.] Stopped 2025-08-22T21:58:11.478Z,1755899891.478 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact. 2025-08-22T21:58:11.478Z,1755899891.478 [DefaultWithUndock:SurfaceDefault] Running Loop=1 2025-08-22T21:58:11.479Z,1755899891.479 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault 2025-08-22T21:58:11.479Z,1755899891.479 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1 2025-08-22T21:58:11.479Z,1755899891.479 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-22T21:58:11.479Z,1755899891.479 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-08-22T21:58:11.479Z,1755899891.479 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-08-22T21:58:11.479Z,1755899891.479 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-08-22T21:58:11.480Z,1755899891.480 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-08-22T21:58:11.480Z,1755899891.480 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-22T21:58:11.480Z,1755899891.480 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-22T21:58:11.623Z,1755899891.623 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006976 2025-08-22T21:58:11.875Z,1755899891.875 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259002 2025-08-22T21:58:12.127Z,1755899892.127 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510956 2025-08-22T21:58:12.370Z,1755899892.370 [Radio_Surface](INFO): Powering up 2025-08-22T21:58:12.381Z,1755899892.381 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.765628 2025-08-22T21:58:12.630Z,1755899892.630 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014854 2025-08-22T21:58:12.883Z,1755899892.883 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266945 2025-08-22T21:58:13.135Z,1755899893.135 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519029 2025-08-22T21:58:13.387Z,1755899893.387 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770941 2025-08-22T21:58:13.639Z,1755899893.639 [DAT](INFO): DAT read: Rx Time:21:58:14.0842 2025-08-22T21:58:13.640Z,1755899893.640 [DAT](INFO): Rx dataTimestamp_ set to:1755899893.639832 2025-08-22T21:58:13.641Z,1755899893.641 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.025113 2025-08-22T21:58:13.891Z,1755899893.891 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275116 2025-08-22T21:58:14.148Z,1755899894.148 [DAT](INFO): DAT read: 21:58:14.0842 LVL= 30192, 32753, 32754, 32755, AGC= 57, IDX= 459,-0.45,-0.293,-2.202,-0.505,-0.696, PHS= 0.504,-1.461, 0.147, RAW= 140.2, 9.0, CAL= 139.7, 9.9, ROT= 10.3, -9.9 2025-08-22T21:58:14.149Z,1755899894.149 [DAT](INFO): got valid direction response: 21:58:14.0842 LVL= 30192, 32753, 32754, 32755, AGC= 57, IDX= 459,-0.45,-0.293,-2.202,-0.505,-0.696, PHS= 0.504,-1.461, 0.147, RAW= 140.2, 9.0, CAL= 139.7, 9.9, ROT= 10.3, -9.9 2025-08-22T21:58:14.150Z,1755899894.150 [DAT](INFO): DAT read: Bearing 309.0, 12.8 (Local) 2025-08-22T21:58:14.150Z,1755899894.150 [DAT](INFO): Local bearing/azimuth received: Bearing 309.0, 12.8 (Local) 2025-08-22T21:58:14.151Z,1755899894.151 [DAT](INFO): DAT read: Range 11 to 50 : 37.3 m (Round-trip 49.8 ms) speed -0.3 m/s 2025-08-22T21:58:14.152Z,1755899894.152 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-22T21:58:14.153Z,1755899894.153 [DAT](INFO): direction in FSK: [0.969234,0.176140,0.171929] 2025-08-22T21:58:14.153Z,1755899894.153 [DAT](INFO): publishing direction and range info 2025-08-22T21:58:17.625Z,1755899897.625 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.11 2025-08-22T21:58:17.626Z,1755899897.626 [Radio_Surface](INFO): No local IP found 2025-08-22T21:58:41.919Z,1755899921.919 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, -3.20, . -1.91, 10.90, 0.00 2025-08-22T22:00:22.470Z,1755900022.470 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T22:00:23.475Z,1755900023.475 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-22T22:00:23.475Z,1755900023.475 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:00:46.416Z,1755900046.416 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1 2025-08-22T22:00:46.416Z,1755900046.416 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-08-22T22:00:46.416Z,1755900046.416 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1 2025-08-22T22:00:53.610Z,1755900053.610 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T22:00:54.614Z,1755900054.614 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:01:24.750Z,1755900084.750 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T22:01:25.755Z,1755900085.755 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:01:37.776Z,1755900097.776 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-08-22T22:01:55.883Z,1755900115.883 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-22T22:01:56.886Z,1755900116.886 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:02:12.458Z,1755900132.458 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003003 2025-08-22T22:02:13.458Z,1755900133.458 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:02:29.462Z,1755900149.462 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:02:40.326Z,1755900160.326 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:02:53.206Z,1755900173.206 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:03:03.166Z,1755900183.166 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:03:12.006Z,1755900192.006 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:03:20.770Z,1755900200.770 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:03:29.755Z,1755900209.755 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:03:40.606Z,1755900220.606 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-22T22:03:49.466Z,1755900229.466 [NAL9602](INFO): SBD MO Status=1, MOMSN=990, MT Status=0, MTMSN=0 2025-08-22T22:03:49.466Z,1755900229.466 [NAL9602](INFO): No messages in MT queue 2025-08-22T22:03:50.676Z,1755900230.676 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220349.00,A,3646.73663,N,12151.57740,W,0.641,58.74,220825,,,A*47 2025-08-22T22:03:50.679Z,1755900230.679 [NAL9602](INFO): GPS fix at 20250822T220349: (36.778944, -121.859623) 2025-08-22T22:03:50.711Z,1755900230.711 [UniversalFixResidualReporter](INFO): Fix residual: 0.2 %DT, over the last 1122.7 m. Residual distance 2.5 m at bearing -120.6 degrees. Fix at (36.7789, -121.8596) with 452.2 m made good. 2025-08-22T22:03:50.711Z,1755900230.711 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped 2025-08-22T22:03:50.712Z,1755900230.712 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1 2025-08-22T22:03:58.321Z,1755900238.321 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250822T210616/Courier0012.lzma 2025-08-22T22:03:59.323Z,1755900239.323 [DataOverHttps](INFO): Moved sent file to Logs/20250822T210616/Courier0012.lzma.bak 2025-08-22T22:03:59.324Z,1755900239.324 [DataOverHttps](INFO): SBD MOMSN=25883059 2025-08-22T22:04:23.422Z,1755900263.422 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-22T22:04:26.929Z,1755900266.929 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250822T211808/Courier0000.lzma 2025-08-22T22:04:27.931Z,1755900267.931 [DataOverHttps](INFO): Moved sent file to Logs/20250822T211808/Courier0000.lzma.bak 2025-08-22T22:04:27.932Z,1755900267.932 [DataOverHttps](INFO): SBD MOMSN=25883070 2025-08-22T22:04:50.613Z,1755900290.613 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250822T211808/Courier0003.lzma 2025-08-22T22:04:51.616Z,1755900291.616 [DataOverHttps](INFO): Moved sent file to Logs/20250822T211808/Courier0003.lzma.bak 2025-08-22T22:04:51.616Z,1755900291.616 [DataOverHttps](INFO): SBD MOMSN=25883075 2025-08-22T22:05:13.445Z,1755900313.445 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250822T211808/Courier0006.lzma 2025-08-22T22:05:14.447Z,1755900314.447 [DataOverHttps](INFO): Moved sent file to Logs/20250822T211808/Courier0006.lzma.bak 2025-08-22T22:05:14.448Z,1755900314.448 [DataOverHttps](INFO): SBD MOMSN=25883077 2025-08-22T22:05:34.185Z,1755900334.185 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250822T211808/Courier0009.lzma 2025-08-22T22:05:35.187Z,1755900335.187 [DataOverHttps](INFO): Moved sent file to Logs/20250822T211808/Courier0009.lzma.bak 2025-08-22T22:05:35.188Z,1755900335.188 [DataOverHttps](INFO): SBD MOMSN=25883079 2025-08-22T22:05:51.862Z,1755900351.862 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250822T211808/Courier0012.lzma 2025-08-22T22:05:53.011Z,1755900353.011 [DataOverHttps](INFO): Moved sent file to Logs/20250822T211808/Courier0012.lzma.bak 2025-08-22T22:05:53.011Z,1755900353.011 [DataOverHttps](INFO): SBD MOMSN=25883081 2025-08-22T22:06:09.649Z,1755900369.649 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250822T211808/Courier0015.lzma 2025-08-22T22:06:10.652Z,1755900370.652 [DataOverHttps](INFO): Moved sent file to Logs/20250822T211808/Courier0015.lzma.bak 2025-08-22T22:06:10.652Z,1755900370.652 [DataOverHttps](INFO): SBD MOMSN=25883083 2025-08-22T22:06:27.374Z,1755900387.374 [DataOverHttps](INFO): Sending 323 bytes from file Logs/20250822T215353/Courier0000.lzma 2025-08-22T22:06:28.376Z,1755900388.376 [DataOverHttps](INFO): Moved sent file to Logs/20250822T215353/Courier0000.lzma.bak 2025-08-22T22:06:28.376Z,1755900388.376 [DataOverHttps](IMPORTANT): SBD MOMSN=25883086, MTMSN=20250822T220627 2025-08-22T22:06:38.237Z,1755900398.237 [DataOverHttps](INFO): Received command: schedule clear;schedule resume;restart logs