2025-09-11T07:30:04.376Z,1757575804.376 [undock:I.Execute](INFO): Executing command restart logs 2025-09-11T07:30:04.376Z,1757575804.376 [undock:I.Execute] Stopped 2025-09-11T07:30:04.377Z,1757575804.377 [undock:Detach] Running Loop=1 2025-09-11T07:30:04.377Z,1757575804.377 [undock:Detach](DEBUG): Aggregate::initialize undock:Detach 2025-09-11T07:30:04.377Z,1757575804.377 [undock:Detach:A.] Running Loop=1 2025-09-11T07:30:04.377Z,1757575804.377 [undock:Detach:A.](INFO): Initializing TrackAcousticContact. 2025-09-11T07:30:04.377Z,1757575804.377 [undock:Detach:B] Running Loop=1 2025-09-11T07:30:04.420Z,1757575804.420 [CommandExec](IMPORTANT): got command restart logs 2025-09-11T07:30:04.809Z,1757575804.809 [undock:Detach:B](IMPORTANT): Undocking at range 1.300000 m and depth 66.297966 m . 2025-09-11T07:30:04.809Z,1757575804.809 [undock:Detach:B] Stopped 2025-09-11T07:30:04.809Z,1757575804.809 [undock:Detach:C] Running Loop=1 2025-09-11T07:30:04.809Z,1757575804.809 [undock:Detach:A.] Running Loop=1 2025-09-11T07:30:04.809Z,1757575804.809 [undock:Detach:A.](ERROR): Failed to read sound speed 2025-09-11T07:30:05.229Z,1757575805.229 [undock:Detach:C] Stopped 2025-09-11T07:30:05.229Z,1757575805.229 [undock:Detach:D.Undock] Running Loop=1 2025-09-11T07:30:05.229Z,1757575805.229 [undock:Detach:D.Undock](DEBUG): Initialize. 2025-09-11T07:30:05.230Z,1757575805.230 [undock:Detach:D.Undock](DEBUG): Initializing internal variables to default values. 2025-09-11T07:30:05.604Z,1757575805.604 [undock:Detach:D.Undock](DEBUG): Initialize. 2025-09-11T07:30:05.604Z,1757575805.604 [undock:Detach:D.Undock](DEBUG): Initializing internal variables to default values. 2025-09-11T07:30:05.605Z,1757575805.605 [undock:Detach:D.Undock](INFO): Detaching from dock at depth 66.342468 m. 2025-09-11T07:30:05.904Z,1757575805.904 [DAT](INFO): DAT read: Rx Time:07:30:09.9719 2025-09-11T07:30:05.904Z,1757575805.904 [DAT](INFO): Rx dataTimestamp_ set to:1757575805.904121 2025-09-11T07:30:06.407Z,1757575806.407 [DAT](INFO): DAT read: OK 2025-09-11T07:30:06.408Z,1757575806.408 [DAT](INFO): unknown deviceResponse_: OK 2025-09-11T07:30:06.408Z,1757575806.408 [DAT](INFO): DAT read: user:6803> 2025-09-11T07:30:06.409Z,1757575806.409 [DAT](INFO): DAT read: Tx time:07:30:11.0573 2025-09-11T07:30:06.409Z,1757575806.409 [DAT](INFO): Ping request sent. 2025-09-11T07:30:06.409Z,1757575806.409 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:30:06.409Z,1757575806.409 [DAT](INFO): publishing transmit ping time 2025-09-11T07:30:06.439Z,1757575806.439 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-09-11T07:30:06.560Z,1757575806.560 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-09-11T07:30:08.256Z,1757575808.256 [CTD_Seabird](ERROR): Failed to parse device response: 2025-09-11T07:30:08.928Z,1757575808.928 [DAT](INFO): DAT read: Rx Time:07:30:12.9220 2025-09-11T07:30:08.928Z,1757575808.928 [DAT](INFO): Rx dataTimestamp_ set to:1757575808.927874 2025-09-11T07:30:09.431Z,1757575809.431 [DAT](INFO): DAT read: OK 2025-09-11T07:30:09.432Z,1757575809.432 [DAT](INFO): unknown deviceResponse_: OK 2025-09-11T07:30:10.144Z,1757575810.144 [DockingStepper](INFO): Changing to mode: 3 2025-09-11T07:30:14.493Z,1757575814.493 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, -0.17, ,+0.04, 7.77, 0.00 2025-09-11T07:30:14.517Z,1757575814.517 [undock:Detach:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:30:14.727Z,1757575814.727 [DAT](INFO): ****** received valid address query ****** 2025-09-11T07:30:14.728Z,1757575814.728 [DAT](INFO): ****** received valid ping request ****** 2025-09-11T07:30:14.728Z,1757575814.728 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:30:14.980Z,1757575814.980 [DAT](INFO): DAT read: user:6804> 2025-09-11T07:30:14.981Z,1757575814.981 [DAT](INFO): DAT read: Tx time:07:30:19.5082 2025-09-11T07:30:14.981Z,1757575814.981 [DAT](INFO): Ping request sent. 2025-09-11T07:30:14.981Z,1757575814.981 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:30:14.982Z,1757575814.982 [DAT](INFO): publishing transmit ping time 2025-09-11T07:30:14.982Z,1757575814.982 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000753 2025-09-11T07:30:15.232Z,1757575815.232 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250327 2025-09-11T07:30:15.484Z,1757575815.484 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502298 2025-09-11T07:30:15.737Z,1757575815.737 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755696 2025-09-11T07:30:15.988Z,1757575815.988 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006426 2025-09-11T07:30:16.152Z,1757575816.152 [undock:Detach:D.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-09-11T07:30:16.153Z,1757575816.153 [undock:Detach:D.Undock](INFO): Engaging thruster for 10.0 seconds (max) to disengage. 2025-09-11T07:30:16.240Z,1757575816.240 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258306 2025-09-11T07:30:16.492Z,1757575816.492 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510586 2025-09-11T07:30:16.607Z,1757575816.607 [ElevatorOffsetCalculator](INFO): Removing expired estimator for commanded vars: speed 0.80 m/s, pitch 20.00 deg, mass-position -1.82 mm. 2025-09-11T07:30:16.623Z,1757575816.623 [undock:Detach:D.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-09-11T07:30:16.744Z,1757575816.744 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762367 2025-09-11T07:30:16.912Z,1757575816.912 [undock:Detach:D.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-09-11T07:30:16.996Z,1757575816.996 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014310 2025-09-11T07:30:17.248Z,1757575817.248 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266228 2025-09-11T07:30:17.349Z,1757575817.349 [undock:Detach:D.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-09-11T07:30:17.500Z,1757575817.500 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518271 2025-09-11T07:30:17.720Z,1757575817.720 [undock:Detach:D.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-09-11T07:30:17.752Z,1757575817.752 [DAT](INFO): DAT read: Rx Time:07:30:21.9140 2025-09-11T07:30:17.753Z,1757575817.753 [DAT](INFO): Rx dataTimestamp_ set to:1757575817.752274 2025-09-11T07:30:17.754Z,1757575817.754 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772071 2025-09-11T07:30:18.004Z,1757575818.004 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022354 2025-09-11T07:30:18.157Z,1757575818.157 [undock:Detach:D.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-09-11T07:30:18.259Z,1757575818.259 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.276674 2025-09-11T07:30:18.513Z,1757575818.513 [DAT](INFO): DAT read: 07:30:21.9140 LVL= 9632, 12449, 18690, 13427, AGC= 41, IDX= 350,-0.11, 0.997,-0.074,-0.418, 1.547, PHS=-0.448,-1.576,-2.009, RAW= 74.4, 45.6, CAL= 70.8, 51.8, ROT= 79.2, -51.8 2025-09-11T07:30:18.514Z,1757575818.514 [DAT](INFO): got valid direction response: 07:30:21.9140 LVL= 9632, 12449, 18690, 13427, AGC= 41, IDX= 350,-0.11, 0.997,-0.074,-0.418, 1.547, PHS=-0.448,-1.576,-2.009, RAW= 74.4, 45.6, CAL= 70.8, 51.8, ROT= 79.2, -51.8 2025-09-11T07:30:18.515Z,1757575818.515 [DAT](INFO): DAT read: Range 11 to 50 : 1.2 m (Round-trip 1.7 ms) speed 0.0 m/s 2025-09-11T07:30:18.516Z,1757575818.516 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-09-11T07:30:18.517Z,1757575818.517 [DAT](INFO): direction in FSK: [0.115878,0.607455,0.785857] 2025-09-11T07:30:18.517Z,1757575818.517 [DAT](INFO): publishing direction and range info 2025-09-11T07:30:24.649Z,1757575824.649 [undock:Detach:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:30:24.807Z,1757575824.807 [DAT](INFO): ****** received valid address query ****** 2025-09-11T07:30:24.807Z,1757575824.807 [DAT](INFO): ****** received valid ping request ****** 2025-09-11T07:30:24.808Z,1757575824.808 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:30:25.060Z,1757575825.060 [DAT](INFO): DAT read: user:6805> 2025-09-11T07:30:25.060Z,1757575825.060 [DAT](INFO): DAT read: Tx time:07:30:29.6082 2025-09-11T07:30:25.061Z,1757575825.061 [DAT](INFO): Ping request sent. 2025-09-11T07:30:25.061Z,1757575825.061 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:30:25.061Z,1757575825.061 [DAT](INFO): publishing transmit ping time 2025-09-11T07:30:25.062Z,1757575825.062 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000758 2025-09-11T07:30:25.312Z,1757575825.312 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250764 2025-09-11T07:30:25.565Z,1757575825.565 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503811 2025-09-11T07:30:25.816Z,1757575825.816 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754914 2025-09-11T07:30:26.068Z,1757575826.068 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006787 2025-09-11T07:30:26.212Z,1757575826.212 [undock:Detach:D.Undock](INFO): Thruster off. 2025-09-11T07:30:26.320Z,1757575826.320 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259547 2025-09-11T07:30:26.573Z,1757575826.573 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511374 2025-09-11T07:30:26.824Z,1757575826.824 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762881 2025-09-11T07:30:27.076Z,1757575827.076 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015215 2025-09-11T07:30:27.328Z,1757575827.328 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266885 2025-09-11T07:30:27.580Z,1757575827.580 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519393 2025-09-11T07:30:27.832Z,1757575827.832 [DAT](INFO): DAT read: Rx Time:07:30:32.0146 2025-09-11T07:30:27.832Z,1757575827.832 [DAT](INFO): Rx dataTimestamp_ set to:1757575827.832021 2025-09-11T07:30:27.833Z,1757575827.833 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772006 2025-09-11T07:30:28.084Z,1757575828.084 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022956 2025-09-11T07:30:28.341Z,1757575828.341 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.279126 2025-09-11T07:30:28.593Z,1757575828.593 [DAT](INFO): DAT read: Range 11 to 50 : 1.7 m (Round-trip 2.3 ms) speed -0.2 m/s 2025-09-11T07:30:28.594Z,1757575828.594 [DAT](ERROR): #Rx 1: Read range message, but no direction. 2025-09-11T07:30:34.713Z,1757575834.713 [undock:Detach:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:30:34.895Z,1757575834.895 [DAT](INFO): ****** received valid address query ****** 2025-09-11T07:30:34.895Z,1757575834.895 [DAT](INFO): ****** received valid ping request ****** 2025-09-11T07:30:34.896Z,1757575834.896 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:30:35.148Z,1757575835.148 [DAT](INFO): DAT read: user:6806> 2025-09-11T07:30:35.149Z,1757575835.149 [DAT](INFO): DAT read: Tx time:07:30:39.7082 2025-09-11T07:30:35.149Z,1757575835.149 [DAT](INFO): Ping request sent. 2025-09-11T07:30:35.149Z,1757575835.149 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:30:35.150Z,1757575835.150 [DAT](INFO): publishing transmit ping time 2025-09-11T07:30:35.151Z,1757575835.151 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001179 2025-09-11T07:30:35.403Z,1757575835.403 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.252525 2025-09-11T07:30:35.652Z,1757575835.652 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502090 2025-09-11T07:30:35.904Z,1757575835.904 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754095 2025-09-11T07:30:36.156Z,1757575836.156 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006320 2025-09-11T07:30:36.410Z,1757575836.410 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.260187 2025-09-11T07:30:36.660Z,1757575836.660 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510028 2025-09-11T07:30:36.912Z,1757575836.912 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762023 2025-09-11T07:30:37.165Z,1757575837.165 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014679 2025-09-11T07:30:37.418Z,1757575837.418 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.268001 2025-09-11T07:30:37.668Z,1757575837.668 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518003 2025-09-11T07:30:37.922Z,1757575837.922 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771437 2025-09-11T07:30:38.172Z,1757575838.172 [DAT](INFO): DAT read: Rx Time:07:30:42.1171 2025-09-11T07:30:38.172Z,1757575838.172 [DAT](INFO): Rx dataTimestamp_ set to:1757575838.171784 2025-09-11T07:30:38.173Z,1757575838.173 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023095 2025-09-11T07:30:38.424Z,1757575838.424 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274061 2025-09-11T07:30:38.681Z,1757575838.681 [DAT](INFO): DAT read: 07:30:42.1171 LVL= 17680, 25313, 18578, 32755, AGC= 44, IDX= 446,-0.46, 2.079, 0.496, 2.449, 2.037, PHS= 0.144,-1.496, 0.367, RAW= 156.3, 11.2, CAL= 156.4, 12.3, ROT= 353.6, -12.3 2025-09-11T07:30:38.682Z,1757575838.682 [DAT](INFO): got valid direction response: 07:30:42.1171 LVL= 17680, 25313, 18578, 32755, AGC= 44, IDX= 446,-0.46, 2.079, 0.496, 2.449, 2.037, PHS= 0.144,-1.496, 0.367, RAW= 156.3, 11.2, CAL= 156.4, 12.3, ROT= 353.6, -12.3 2025-09-11T07:30:38.683Z,1757575838.683 [DAT](INFO): DAT read: Bearing 175.3, -6.1 (Local) 2025-09-11T07:30:38.684Z,1757575838.684 [DAT](INFO): Local bearing/azimuth received: Bearing 175.3, -6.1 (Local) 2025-09-11T07:30:38.685Z,1757575838.685 [DAT](INFO): DAT read: Range 11 to 50 : 3.6 m (Round-trip 4.8 ms) speed -0.2 m/s 2025-09-11T07:30:38.685Z,1757575838.685 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-09-11T07:30:38.687Z,1757575838.687 [DAT](INFO): direction in FSK: [0.970957,-0.108910,0.213030] 2025-09-11T07:30:38.687Z,1757575838.687 [DAT](INFO): publishing direction and range info 2025-09-11T07:30:44.808Z,1757575844.808 [undock:Detach:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:30:44.983Z,1757575844.983 [DAT](INFO): ****** received valid address query ****** 2025-09-11T07:30:44.983Z,1757575844.983 [DAT](INFO): ****** received valid ping request ****** 2025-09-11T07:30:44.984Z,1757575844.984 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:30:45.236Z,1757575845.236 [DAT](INFO): DAT read: user:6807> 2025-09-11T07:30:45.237Z,1757575845.237 [DAT](INFO): DAT read: Tx time:07:30:49.7582 2025-09-11T07:30:45.237Z,1757575845.237 [DAT](INFO): Ping request sent. 2025-09-11T07:30:45.237Z,1757575845.237 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:30:45.238Z,1757575845.238 [DAT](INFO): publishing transmit ping time 2025-09-11T07:30:45.239Z,1757575845.239 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001054 2025-09-11T07:30:45.488Z,1757575845.488 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250385 2025-09-11T07:30:45.740Z,1757575845.740 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502377 2025-09-11T07:30:45.992Z,1757575845.992 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754681 2025-09-11T07:30:46.244Z,1757575846.244 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006374 2025-09-11T07:30:46.496Z,1757575846.496 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258247 2025-09-11T07:30:46.748Z,1757575846.748 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510647 2025-09-11T07:30:46.000Z,1757575847.000 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762511 2025-09-11T07:30:47.252Z,1757575847.252 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014800 2025-09-11T07:30:47.504Z,1757575847.504 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266328 2025-09-11T07:30:47.756Z,1757575847.756 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518411 2025-09-11T07:30:48.008Z,1757575848.008 [DAT](INFO): DAT read: Rx Time:07:30:52.1701 2025-09-11T07:30:48.008Z,1757575848.008 [DAT](INFO): Rx dataTimestamp_ set to:1757575848.007731 2025-09-11T07:30:48.009Z,1757575848.009 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771283 2025-09-11T07:30:48.260Z,1757575848.260 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022604 2025-09-11T07:30:48.515Z,1757575848.515 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.276877 2025-09-11T07:30:48.774Z,1757575848.774 [DAT](INFO): DAT read: 07:30:52.1701 LVL= 25056, 24545, 19378, 28147, AGC= 47, IDX= 461,-0.22,-2.842, 1.646,-2.718,-2.930, PHS= 0.189,-1.662, 0.168, RAW= 149.4, 14.1, CAL= 149.5, 15.6, ROT= 0.5, -15.6 2025-09-11T07:30:48.776Z,1757575848.776 [DAT](INFO): got valid direction response: 07:30:52.1701 LVL= 25056, 24545, 19378, 28147, AGC= 47, IDX= 461,-0.22,-2.842, 1.646,-2.718,-2.930, PHS= 0.189,-1.662, 0.168, RAW= 149.4, 14.1, CAL= 149.5, 15.6, ROT= 0.5, -15.6 2025-09-11T07:30:48.776Z,1757575848.776 [DAT](INFO): DAT read: Bearing 180.9, 1.0 (Local) 2025-09-11T07:30:48.777Z,1757575848.777 [DAT](INFO): Local bearing/azimuth received: Bearing 180.9, 1.0 (Local) 2025-09-11T07:30:48.778Z,1757575848.778 [DAT](INFO): DAT read: Range 11 to 50 : 5.8 m (Round-trip 7.8 ms) speed -0.2 m/s 2025-09-11T07:30:48.788Z,1757575848.788 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-09-11T07:30:48.788Z,1757575848.788 [DAT](INFO): direction in FSK: [0.963126,0.008405,0.268920] 2025-09-11T07:30:48.789Z,1757575848.789 [DAT](INFO): publishing direction and range info 2025-09-11T07:30:54.908Z,1757575854.908 [undock:Detach:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:30:55.067Z,1757575855.067 [DAT](INFO): ****** received valid address query ****** 2025-09-11T07:30:55.067Z,1757575855.067 [DAT](INFO): ****** received valid ping request ****** 2025-09-11T07:30:55.068Z,1757575855.068 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:30:55.319Z,1757575855.319 [DAT](INFO): DAT read: user:6808> 2025-09-11T07:30:55.320Z,1757575855.320 [DAT](INFO): DAT read: Tx time:07:30:59.8582 2025-09-11T07:30:55.321Z,1757575855.321 [DAT](INFO): Ping request sent. 2025-09-11T07:30:55.321Z,1757575855.321 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:30:55.321Z,1757575855.321 [DAT](INFO): publishing transmit ping time 2025-09-11T07:30:55.321Z,1757575855.321 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000736 2025-09-11T07:30:55.572Z,1757575855.572 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251352 2025-09-11T07:30:55.824Z,1757575855.824 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502964 2025-09-11T07:30:56.076Z,1757575856.076 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754926 2025-09-11T07:30:56.328Z,1757575856.328 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006907 2025-09-11T07:30:56.580Z,1757575856.580 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259742 2025-09-11T07:30:56.832Z,1757575856.832 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510942 2025-09-11T07:30:57.084Z,1757575857.084 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763146 2025-09-11T07:30:57.336Z,1757575857.336 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014982 2025-09-11T07:30:57.588Z,1757575857.588 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266946 2025-09-11T07:30:57.843Z,1757575857.843 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.521987 2025-09-11T07:30:58.092Z,1757575858.092 [DAT](INFO): DAT read: Rx Time:07:31:02.2730 2025-09-11T07:30:58.092Z,1757575858.092 [DAT](INFO): Rx dataTimestamp_ set to:1757575858.091859 2025-09-11T07:30:58.093Z,1757575858.093 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772040 2025-09-11T07:30:58.344Z,1757575858.344 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022923 2025-09-11T07:30:58.615Z,1757575858.615 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.293598 2025-09-11T07:30:58.869Z,1757575858.869 [DAT](INFO): DAT read: 07:31:02.2730 LVL= 26448, 31601, 27442, 32755, AGC= 49, IDX= 459,-0.17,-1.467,-3.136,-1.254,-1.518, PHS= 0.153,-1.573, 0.219, RAW= 151.9, 13.6, CAL= 152.0, 15.1, ROT= 358.0, -15.1 2025-09-11T07:30:58.870Z,1757575858.870 [DAT](INFO): got valid direction response: 07:31:02.2730 LVL= 26448, 31601, 27442, 32755, AGC= 49, IDX= 459,-0.17,-1.467,-3.136,-1.254,-1.518, PHS= 0.153,-1.573, 0.219, RAW= 151.9, 13.6, CAL= 152.0, 15.1, ROT= 358.0, -15.1 2025-09-11T07:30:58.871Z,1757575858.871 [DAT](INFO): DAT read: Bearing 181.7, -1.6 (Local) 2025-09-11T07:30:58.871Z,1757575858.871 [DAT](INFO): Local bearing/azimuth received: Bearing 181.7, -1.6 (Local) 2025-09-11T07:30:58.872Z,1757575858.872 [DAT](INFO): DAT read: Range 11 to 50 : 8.0 m (Round-trip 10.7 ms) speed -0.2 m/s 2025-09-11T07:30:58.873Z,1757575858.873 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-09-11T07:30:58.874Z,1757575858.874 [DAT](INFO): direction in FSK: [0.964884,-0.033695,0.260505] 2025-09-11T07:30:58.874Z,1757575858.874 [DAT](INFO): publishing direction and range info 2025-09-11T07:30:58.999Z,1757575858.999 [undock:Detach:D.Undock](INFO): Detected possible detachment. Starting timer. 2025-09-11T07:31:05.045Z,1757575865.045 [undock:Detach:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:31:05.187Z,1757575865.187 [DAT](INFO): ****** received valid address query ****** 2025-09-11T07:31:05.187Z,1757575865.187 [DAT](INFO): ****** received valid ping request ****** 2025-09-11T07:31:05.188Z,1757575865.188 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:31:05.440Z,1757575865.440 [DAT](INFO): DAT read: user:6809> 2025-09-11T07:31:05.441Z,1757575865.441 [DAT](INFO): DAT read: Tx time:07:31:10.0082 2025-09-11T07:31:05.442Z,1757575865.442 [DAT](INFO): Ping request sent. 2025-09-11T07:31:05.442Z,1757575865.442 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:31:05.442Z,1757575865.442 [DAT](INFO): publishing transmit ping time 2025-09-11T07:31:05.451Z,1757575865.451 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.009271 2025-09-11T07:31:05.692Z,1757575865.692 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.249634 2025-09-11T07:31:05.944Z,1757575865.944 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501671 2025-09-11T07:31:06.193Z,1757575866.193 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.00, 79.52, 81.22, 81.90 2025-09-11T07:31:06.196Z,1757575866.196 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753784 2025-09-11T07:31:06.448Z,1757575866.448 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005629 2025-09-11T07:31:06.701Z,1757575866.701 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258628 2025-09-11T07:31:06.952Z,1757575866.952 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.509727 2025-09-11T07:31:07.204Z,1757575867.204 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761643 2025-09-11T07:31:07.456Z,1757575867.456 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014412 2025-09-11T07:31:07.708Z,1757575867.708 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.265746 2025-09-11T07:31:07.960Z,1757575867.960 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.517635 2025-09-11T07:31:08.217Z,1757575868.217 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.774802 2025-09-11T07:31:08.468Z,1757575868.468 [DAT](INFO): DAT read: Rx Time:07:31:12.4260 2025-09-11T07:31:08.468Z,1757575868.468 [DAT](INFO): Rx dataTimestamp_ set to:1757575868.467826 2025-09-11T07:31:08.469Z,1757575868.469 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.026758 2025-09-11T07:31:08.720Z,1757575868.720 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.277805 2025-09-11T07:31:08.977Z,1757575868.977 [DAT](INFO): DAT read: 07:31:12.4260 LVL= 19792, 25201, 23282, 29939, AGC= 50, IDX= 457,-0.18, 0.584,-1.039, 0.844, 0.523, PHS= 0.163,-1.517, 0.277, RAW= 153.3, 12.4, CAL= 153.4, 13.7, ROT= 356.6, -13.7 2025-09-11T07:31:08.978Z,1757575868.978 [DAT](INFO): got valid direction response: 07:31:12.4260 LVL= 19792, 25201, 23282, 29939, AGC= 50, IDX= 457,-0.18, 0.584,-1.039, 0.844, 0.523, PHS= 0.163,-1.517, 0.277, RAW= 153.3, 12.4, CAL= 153.4, 13.7, ROT= 356.6, -13.7 2025-09-11T07:31:08.979Z,1757575868.979 [DAT](INFO): DAT read: Bearing 179.7, -2.6 (Local) 2025-09-11T07:31:08.979Z,1757575868.979 [DAT](INFO): Local bearing/azimuth received: Bearing 179.7, -2.6 (Local) 2025-09-11T07:31:08.980Z,1757575868.980 [DAT](INFO): DAT read: Range 11 to 50 : 10.2 m (Round-trip 13.7 ms) speed -0.3 m/s 2025-09-11T07:31:08.981Z,1757575868.981 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-09-11T07:31:08.982Z,1757575868.982 [DAT](INFO): direction in FSK: [0.969839,-0.057619,0.236838] 2025-09-11T07:31:08.983Z,1757575868.983 [DAT](INFO): publishing direction and range info 2025-09-11T07:31:15.105Z,1757575875.105 [undock:Detach:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:31:15.287Z,1757575875.287 [DAT](INFO): ****** received valid address query ****** 2025-09-11T07:31:15.287Z,1757575875.287 [DAT](INFO): ****** received valid ping request ****** 2025-09-11T07:31:15.288Z,1757575875.288 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:31:15.540Z,1757575875.540 [DAT](INFO): DAT read: user:6810> 2025-09-11T07:31:15.541Z,1757575875.541 [DAT](INFO): DAT read: Tx time:07:31:20.1082 2025-09-11T07:31:15.542Z,1757575875.542 [DAT](INFO): Ping request sent. 2025-09-11T07:31:15.542Z,1757575875.542 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:31:15.551Z,1757575875.551 [DAT](INFO): publishing transmit ping time 2025-09-11T07:31:15.552Z,1757575875.552 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.009430 2025-09-11T07:31:15.792Z,1757575875.792 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.249661 2025-09-11T07:31:16.044Z,1757575876.044 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501692 2025-09-11T07:31:16.296Z,1757575876.296 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753741 2025-09-11T07:31:16.548Z,1757575876.548 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006178 2025-09-11T07:31:16.800Z,1757575876.800 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.257714 2025-09-11T07:31:17.054Z,1757575877.054 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511236 2025-09-11T07:31:17.304Z,1757575877.304 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761630 2025-09-11T07:31:17.556Z,1757575877.556 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014415 2025-09-11T07:31:17.808Z,1757575877.808 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.265631 2025-09-11T07:31:18.062Z,1757575878.062 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519780 2025-09-11T07:31:18.316Z,1757575878.316 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.774075 2025-09-11T07:31:18.564Z,1757575878.564 [DAT](INFO): DAT read: Rx Time:07:31:22.5290 2025-09-11T07:31:18.565Z,1757575878.565 [DAT](INFO): Rx dataTimestamp_ set to:1757575878.564428 2025-09-11T07:31:18.566Z,1757575878.566 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023659 2025-09-11T07:31:18.816Z,1757575878.816 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274233 2025-09-11T07:31:19.087Z,1757575879.087 [DAT](INFO): DAT read: 07:31:22.5290 LVL= 18912, 26417, 21362, 27827, AGC= 53, IDX= 455,-0.09, 2.522, 0.799, 2.587, 2.366, PHS= 0.258,-1.522, 0.177, RAW= 147.7, 12.4, CAL= 147.5, 13.7, ROT= 2.5, -13.7 2025-09-11T07:31:19.091Z,1757575879.091 [DAT](INFO): got valid direction response: 07:31:22.5290 LVL= 18912, 26417, 21362, 27827, AGC= 53, IDX= 455,-0.09, 2.522, 0.799, 2.587, 2.366, PHS= 0.258,-1.522, 0.177, RAW= 147.7, 12.4, CAL= 147.5, 13.7, ROT= 2.5, -13.7 2025-09-11T07:31:19.092Z,1757575879.092 [DAT](INFO): DAT read: Bearing 178.0, 3.0 (Local) 2025-09-11T07:31:19.093Z,1757575879.093 [DAT](INFO): Local bearing/azimuth received: Bearing 178.0, 3.0 (Local) 2025-09-11T07:31:19.094Z,1757575879.094 [DAT](INFO): DAT read: Range 11 to 50 : 12.4 m (Round-trip 16.6 ms) speed -0.2 m/s 2025-09-11T07:31:19.123Z,1757575879.123 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-09-11T07:31:19.124Z,1757575879.124 [DAT](INFO): direction in FSK: [0.970624,0.042378,0.236838] 2025-09-11T07:31:19.124Z,1757575879.124 [DAT](INFO): publishing direction and range info 2025-09-11T07:31:19.247Z,1757575879.247 [undock:Detach:D.Undock](INFO): Detached at range: 12.40 m. Transitioning docking module to standby. 2025-09-11T07:31:19.575Z,1757575879.575 [DockingStepper](INFO): Changing to mode: 1 2025-09-11T07:31:25.236Z,1757575885.236 [undock:Detach:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:31:25.371Z,1757575885.371 [DAT](INFO): ****** received valid address query ****** 2025-09-11T07:31:25.371Z,1757575885.371 [DAT](INFO): ****** received valid ping request ****** 2025-09-11T07:31:25.372Z,1757575885.372 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:31:25.604Z,1757575885.604 [undock:Detach:D.Undock](INFO): Docking module at standby. 2025-09-11T07:31:25.624Z,1757575885.624 [DAT](INFO): DAT read: user:6811> 2025-09-11T07:31:25.624Z,1757575885.624 [DAT](INFO): DAT read: Tx time:07:31:30.1582 2025-09-11T07:31:25.625Z,1757575885.625 [DAT](INFO): Ping request sent. 2025-09-11T07:31:25.625Z,1757575885.625 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:31:25.625Z,1757575885.625 [DAT](INFO): publishing transmit ping time 2025-09-11T07:31:25.626Z,1757575885.626 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000782 2025-09-11T07:31:25.876Z,1757575885.876 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250895 2025-09-11T07:31:25.995Z,1757575885.995 [undock:Detach:D.Undock](IMPORTANT): Undocking sequence complete. 2025-09-11T07:31:25.995Z,1757575885.995 [undock:Detach:D.Undock] Stopped 2025-09-11T07:31:25.996Z,1757575885.996 [undock:Detach](INFO): Completed undock:Detach 2025-09-11T07:31:25.996Z,1757575885.996 [undock:Detach] Stopped 2025-09-11T07:31:25.996Z,1757575885.996 [undock:Detach](DEBUG): Aggregate::uninitialize undock:Detach 2025-09-11T07:31:25.996Z,1757575885.996 [undock:Detach:A.] Stopped 2025-09-11T07:31:25.996Z,1757575885.996 [undock:Detach:A.](DEBUG): Uninitializing TrackAcousticContact. 2025-09-11T07:31:25.997Z,1757575885.997 [undock:Transit] Running Loop=1 2025-09-11T07:31:25.997Z,1757575885.997 [undock:Transit](DEBUG): Aggregate::initialize undock:Transit 2025-09-11T07:31:25.997Z,1757575885.997 [undock:Transit:BuoyancyHold.Buoyancy] Running Loop=1 2025-09-11T07:31:25.997Z,1757575885.997 [undock:Transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-09-11T07:31:25.997Z,1757575885.997 [undock:Transit:MassHold.Pitch] Running Loop=1 2025-09-11T07:31:25.997Z,1757575885.997 [undock:Transit:MassHold.Pitch](DEBUG): Initialize. 2025-09-11T07:31:25.997Z,1757575885.997 [undock:Transit:C.Pitch] Running Loop=1 2025-09-11T07:31:25.997Z,1757575885.997 [undock:Transit:C.Pitch](DEBUG): Initialize. 2025-09-11T07:31:25.997Z,1757575885.997 [undock:Transit:D.SetSpeed] Running Loop=1 2025-09-11T07:31:25.997Z,1757575885.997 [undock:Transit:D.SetSpeed](DEBUG): Initialize. 2025-09-11T07:31:25.998Z,1757575885.998 [undock:Transit:Wpt1.Waypoint] Running Loop=1 2025-09-11T07:31:25.998Z,1757575885.998 [undock:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2025-09-11T07:31:26.130Z,1757575886.130 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.505019 2025-09-11T07:31:26.380Z,1757575886.380 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754834 2025-09-11T07:31:26.441Z,1757575886.441 [undock:Transit] Stopped 2025-09-11T07:31:26.441Z,1757575886.441 [undock:Transit](DEBUG): Aggregate::uninitialize undock:Transit 2025-09-11T07:31:26.441Z,1757575886.441 [undock:Transit:BuoyancyHold.Buoyancy] Stopped 2025-09-11T07:31:26.441Z,1757575886.441 [undock:Transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-09-11T07:31:26.441Z,1757575886.441 [undock:Transit:MassHold.Pitch] Stopped 2025-09-11T07:31:26.441Z,1757575886.441 [undock:Transit:C.Pitch] Stopped 2025-09-11T07:31:26.441Z,1757575886.441 [undock:Transit:D.SetSpeed] Stopped 2025-09-11T07:31:26.442Z,1757575886.442 [undock:Transit:D.SetSpeed](DEBUG): Uninitialize. 2025-09-11T07:31:26.442Z,1757575886.442 [undock:Transit:Wpt1.Waypoint] Stopped 2025-09-11T07:31:26.442Z,1757575886.442 [undock:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2025-09-11T07:31:26.447Z,1757575886.447 [undock](INFO): Completed undock 2025-09-11T07:31:26.448Z,1757575886.448 [MissionManager](INFO): undock is completed. 2025-09-11T07:31:26.448Z,1757575886.448 [MissionManager](INFO): Uninitializing Mission undock 2025-09-11T07:31:26.448Z,1757575886.448 [undock] Stopped 2025-09-11T07:31:26.448Z,1757575886.448 [undock](DEBUG): Aggregate::uninitialize undock 2025-09-11T07:31:26.448Z,1757575886.448 [undock:StandardEnvelopes] Stopped 2025-09-11T07:31:26.448Z,1757575886.448 [undock:StandardEnvelopes](DEBUG): Aggregate::uninitialize undock:StandardEnvelopes 2025-09-11T07:31:26.448Z,1757575886.448 [undock:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-09-11T07:31:26.448Z,1757575886.448 [undock:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-09-11T07:31:26.448Z,1757575886.448 [undock:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-09-11T07:31:26.448Z,1757575886.448 [undock:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-09-11T07:31:26.449Z,1757575886.449 [undock:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-09-11T07:31:26.449Z,1757575886.449 [undock:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-09-11T07:31:26.449Z,1757575886.449 [undock:BackseatDriver] Stopped 2025-09-11T07:31:26.449Z,1757575886.449 [undock:BackseatDriver](DEBUG): Aggregate::uninitialize undock:BackseatDriver 2025-09-11T07:31:26.449Z,1757575886.449 [undock:BackseatDriver:A.BackseatDriver] Stopped 2025-09-11T07:31:26.449Z,1757575886.449 [undock:PowerOnly] Stopped 2025-09-11T07:31:26.449Z,1757575886.449 [undock:PowerOnly](DEBUG): Aggregate::uninitialize undock:PowerOnly 2025-09-11T07:31:26.449Z,1757575886.449 [undock:PowerOnly:E.Wait] Stopped 2025-09-11T07:31:26.449Z,1757575886.449 [undock:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-09-11T07:31:26.632Z,1757575886.632 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006820 2025-09-11T07:31:26.806Z,1757575886.806 [MissionManager](IMPORTANT): Started mission DefaultWithUndock 2025-09-11T07:31:26.807Z,1757575886.807 [DefaultWithUndock] Running Loop=1 2025-09-11T07:31:26.807Z,1757575886.807 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock 2025-09-11T07:31:26.807Z,1757575886.807 [DefaultWithUndock:A.Wait] Running Loop=1 2025-09-11T07:31:26.807Z,1757575886.807 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component. 2025-09-11T07:31:26.884Z,1757575886.884 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258882 2025-09-11T07:31:27.136Z,1757575887.136 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510998 2025-09-11T07:31:27.388Z,1757575887.388 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762775 2025-09-11T07:31:27.640Z,1757575887.640 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014867 2025-09-11T07:31:27.892Z,1757575887.892 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266779 2025-09-11T07:31:28.144Z,1757575888.144 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518818 2025-09-11T07:31:28.396Z,1757575888.396 [DAT](INFO): DAT read: Rx Time:07:31:32.5820 2025-09-11T07:31:28.396Z,1757575888.396 [DAT](INFO): Rx dataTimestamp_ set to:1757575888.396127 2025-09-11T07:31:28.397Z,1757575888.397 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772166 2025-09-11T07:31:28.651Z,1757575888.651 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.026244 2025-09-11T07:31:28.902Z,1757575888.902 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.276824 2025-09-11T07:31:29.157Z,1757575889.157 [DAT](INFO): DAT read: 07:31:32.5820 LVL= 21584, 26513, 23314, 32371, AGC= 53, IDX= 454,-0.00,-0.347,-2.201,-0.437,-0.634, PHS= 0.389,-1.522, 0.153, RAW= 143.5, 10.9, CAL= 143.0, 11.8, ROT= 7.0, -11.8 2025-09-11T07:31:29.158Z,1757575889.158 [DAT](INFO): got valid direction response: 07:31:32.5820 LVL= 21584, 26513, 23314, 32371, AGC= 53, IDX= 454,-0.00,-0.347,-2.201,-0.437,-0.634, PHS= 0.389,-1.522, 0.153, RAW= 143.5, 10.9, CAL= 143.0, 11.8, ROT= 7.0, -11.8 2025-09-11T07:31:29.162Z,1757575889.162 [DAT](INFO): DAT read: Bearing 174.3, 7.3 (Local) 2025-09-11T07:31:29.164Z,1757575889.164 [DAT](INFO): Local bearing/azimuth received: Bearing 174.3, 7.3 (Local) 2025-09-11T07:31:29.165Z,1757575889.165 [DAT](INFO): DAT read: Range 11 to 50 : 14.7 m (Round-trip 19.7 ms) speed -0.2 m/s 2025-09-11T07:31:29.166Z,1757575889.166 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-09-11T07:31:29.167Z,1757575889.167 [DAT](INFO): direction in FSK: [0.971571,0.119294,0.204496] 2025-09-11T07:31:29.167Z,1757575889.167 [DAT](INFO): publishing direction and range info 2025-09-11T07:31:57.111Z,1757575917.111 [DefaultWithUndock:A.Wait](INFO): Done Waiting. 2025-09-11T07:31:57.111Z,1757575917.111 [DefaultWithUndock:A.Wait] Stopped 2025-09-11T07:31:57.111Z,1757575917.111 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component. 2025-09-11T07:31:57.111Z,1757575917.111 [DefaultWithUndock:LeaveDock] Running Loop=1 2025-09-11T07:31:57.111Z,1757575917.111 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock 2025-09-11T07:31:57.111Z,1757575917.111 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2025-09-11T07:31:57.111Z,1757575917.111 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact. 2025-09-11T07:31:57.112Z,1757575917.112 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1 2025-09-11T07:31:57.112Z,1757575917.112 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-09-11T07:31:57.112Z,1757575917.112 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-09-11T07:31:57.509Z,1757575917.509 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-09-11T07:31:57.509Z,1757575917.509 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-09-11T07:31:57.510Z,1757575917.510 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached from dock at depth 64.746902 m. 2025-09-11T07:31:57.511Z,1757575917.511 [DefaultWithUndock:LeaveDock:A.](ERROR): Failed to read sound speed 2025-09-11T07:31:58.340Z,1757575918.340 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-09-11T07:31:58.460Z,1757575918.460 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-09-11T07:32:00.708Z,1757575920.708 [CTD_Seabird](ERROR): Failed to parse device response: 2025-09-11T07:32:02.064Z,1757575922.064 [DockingStepper](INFO): Changing to mode: 3 2025-09-11T07:32:07.200Z,1757575927.200 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:32:07.250Z,1757575927.250 [DAT](DEBUG): Acoustic response timeout 2025-09-11T07:32:07.251Z,1757575927.251 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:32:07.503Z,1757575927.503 [DAT](INFO): DAT read: user:6812> 2025-09-11T07:32:07.504Z,1757575927.504 [DAT](INFO): DAT read: Tx time:07:32:12.0581 2025-09-11T07:32:07.504Z,1757575927.504 [DAT](INFO): Ping request sent. 2025-09-11T07:32:07.505Z,1757575927.505 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:32:07.505Z,1757575927.505 [DAT](INFO): publishing transmit ping time 2025-09-11T07:32:07.505Z,1757575927.505 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000743 2025-09-11T07:32:07.758Z,1757575927.758 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.252734 2025-09-11T07:32:08.008Z,1757575928.008 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503074 2025-09-11T07:32:08.045Z,1757575928.045 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2025-09-11T07:32:08.260Z,1757575928.260 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754951 2025-09-11T07:32:08.512Z,1757575928.512 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006934 2025-09-11T07:32:08.766Z,1757575928.766 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.260746 2025-09-11T07:32:09.016Z,1757575929.016 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510892 2025-09-11T07:32:09.268Z,1757575929.268 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763177 2025-09-11T07:32:09.520Z,1757575929.520 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014964 2025-09-11T07:32:09.772Z,1757575929.772 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266934 2025-09-11T07:32:10.024Z,1757575930.024 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519141 2025-09-11T07:32:10.278Z,1757575930.278 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.773358 2025-09-11T07:32:10.528Z,1757575930.528 [DAT](INFO): DAT read: Rx Time:07:32:14.4940 2025-09-11T07:32:10.528Z,1757575930.528 [DAT](INFO): Rx dataTimestamp_ set to:1757575930.527776 2025-09-11T07:32:10.529Z,1757575930.529 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023974 2025-09-11T07:32:10.783Z,1757575930.783 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.277795 2025-09-11T07:32:11.037Z,1757575931.037 [DAT](INFO): DAT read: 07:32:14.4940 LVL= 26400, 31393, 29426, 32755, AGC= 61, IDX= 34, 0.47, 0.357,-1.639, 0.043,-0.067, PHS= 0.526,-1.527, 0.066, RAW= 137.7, 10.0, CAL= 137.3, 11.0, ROT= 12.7, -11.0 2025-09-11T07:32:11.038Z,1757575931.038 [DAT](INFO): got valid direction response: 07:32:14.4940 LVL= 26400, 31393, 29426, 32755, AGC= 61, IDX= 34, 0.47, 0.357,-1.639, 0.043,-0.067, PHS= 0.526,-1.527, 0.066, RAW= 137.7, 10.0, CAL= 137.3, 11.0, ROT= 12.7, -11.0 2025-09-11T07:32:11.039Z,1757575931.039 [DAT](INFO): DAT read: Bearing 170.4, 15.9 (Local) 2025-09-11T07:32:11.039Z,1757575931.039 [DAT](INFO): Local bearing/azimuth received: Bearing 170.4, 15.9 (Local) 2025-09-11T07:32:11.040Z,1757575931.040 [DAT](INFO): DAT read: Range 11 to 50 : 23.8 m (Round-trip 31.8 ms) speed -0.2 m/s 2025-09-11T07:32:11.041Z,1757575931.041 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-09-11T07:32:11.042Z,1757575931.042 [DAT](INFO): direction in FSK: [0.957611,0.215807,0.190809] 2025-09-11T07:32:11.042Z,1757575931.042 [DAT](INFO): publishing direction and range info 2025-09-11T07:32:17.319Z,1757575937.319 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:32:17.348Z,1757575937.348 [DAT](INFO): ****** received valid address query ****** 2025-09-11T07:32:17.348Z,1757575937.348 [DAT](INFO): ****** received valid ping request ****** 2025-09-11T07:32:17.349Z,1757575937.349 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:32:17.600Z,1757575937.600 [DAT](INFO): DAT read: user:6813> 2025-09-11T07:32:17.600Z,1757575937.600 [DAT](INFO): DAT read: Tx time:07:32:22.1596 2025-09-11T07:32:17.601Z,1757575937.601 [DAT](INFO): Ping request sent. 2025-09-11T07:32:17.601Z,1757575937.601 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:32:17.601Z,1757575937.601 [DAT](INFO): publishing transmit ping time 2025-09-11T07:32:17.601Z,1757575937.601 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000737 2025-09-11T07:32:17.852Z,1757575937.852 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250910 2025-09-11T07:32:18.104Z,1757575938.104 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502928 2025-09-11T07:32:18.356Z,1757575938.356 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755032 2025-09-11T07:32:18.608Z,1757575938.608 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006879 2025-09-11T07:32:18.860Z,1757575938.860 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258890 2025-09-11T07:32:19.112Z,1757575939.112 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510910 2025-09-11T07:32:19.373Z,1757575939.373 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.771966 2025-09-11T07:32:19.624Z,1757575939.624 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.022819 2025-09-11T07:32:19.876Z,1757575939.876 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.274837 2025-09-11T07:32:20.128Z,1757575940.128 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.527012 2025-09-11T07:32:20.380Z,1757575940.380 [DAT](INFO): DAT read: Rx Time:07:32:24.5986 2025-09-11T07:32:20.380Z,1757575940.380 [DAT](INFO): Rx dataTimestamp_ set to:1757575940.379812 2025-09-11T07:32:20.381Z,1757575940.381 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.779951 2025-09-11T07:32:20.632Z,1757575940.632 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.030877 2025-09-11T07:32:20.884Z,1757575940.884 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.282948 2025-09-11T07:32:21.141Z,1757575941.141 [DAT](INFO): DAT read: 07:32:24.5986 LVL= 23968, 29633, 25266, 32755, AGC= 59, IDX= 450,-0.27, 2.923, 1.011, 2.709, 2.620, PHS= 0.405,-1.564, 0.046, RAW= 140.1, 12.2, CAL= 139.5, 13.2, ROT= 10.5, -13.2 2025-09-11T07:32:21.142Z,1757575941.142 [DAT](INFO): got valid direction response: 07:32:24.5986 LVL= 23968, 29633, 25266, 32755, AGC= 59, IDX= 450,-0.27, 2.923, 1.011, 2.709, 2.620, PHS= 0.405,-1.564, 0.046, RAW= 140.1, 12.2, CAL= 139.5, 13.2, ROT= 10.5, -13.2 2025-09-11T07:32:21.143Z,1757575941.143 [DAT](INFO): DAT read: Bearing 173.6, 8.5 (Local) 2025-09-11T07:32:21.143Z,1757575941.143 [DAT](INFO): Local bearing/azimuth received: Bearing 173.6, 8.5 (Local) 2025-09-11T07:32:21.144Z,1757575941.144 [DAT](INFO): DAT read: Range 11 to 50 : 26.1 m (Round-trip 34.8 ms) speed -0.2 m/s 2025-09-11T07:32:21.145Z,1757575941.145 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-09-11T07:32:21.146Z,1757575941.146 [DAT](INFO): direction in FSK: [0.957276,0.177421,0.228351] 2025-09-11T07:32:21.146Z,1757575941.146 [DAT](INFO): publishing direction and range info 2025-09-11T07:32:27.426Z,1757575947.426 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-09-11T07:32:27.448Z,1757575947.448 [DAT](INFO): ****** received valid address query ****** 2025-09-11T07:32:27.448Z,1757575947.448 [DAT](INFO): ****** received valid ping request ****** 2025-09-11T07:32:27.449Z,1757575947.449 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-09-11T07:32:27.699Z,1757575947.699 [DAT](INFO): DAT read: user:6814> 2025-09-11T07:32:27.700Z,1757575947.700 [DAT](INFO): DAT read: Tx time:07:32:32.2581 2025-09-11T07:32:27.701Z,1757575947.701 [DAT](INFO): Ping request sent. 2025-09-11T07:32:27.701Z,1757575947.701 [DAT](INFO): transmitted an acoustic signal 2025-09-11T07:32:27.701Z,1757575947.701 [DAT](INFO): publishing transmit ping time 2025-09-11T07:32:27.701Z,1757575947.701 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000745 2025-09-11T07:32:27.952Z,1757575947.952 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250891 2025-09-11T07:32:28.204Z,1757575948.204 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503274 2025-09-11T07:32:28.245Z,1757575948.245 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: 26.10 m. Transitioning docking module to standby. 2025-09-11T07:32:28.456Z,1757575948.456 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754959 2025-09-11T07:32:28.619Z,1757575948.619 [DockingStepper](INFO): Changing to mode: 1 2025-09-11T07:32:28.711Z,1757575948.711 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.010017 2025-09-11T07:32:28.960Z,1757575948.960 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259232 2025-09-11T07:32:29.212Z,1757575949.212 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510990 2025-09-11T07:32:29.464Z,1757575949.464 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762968 2025-09-11T07:32:29.716Z,1757575949.716 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014932 2025-09-11T07:32:29.968Z,1757575949.968 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266966 2025-09-11T07:32:30.220Z,1757575950.220 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518961 2025-09-11T07:32:30.474Z,1757575950.474 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.773378 2025-09-11T07:32:30.724Z,1757575950.724 [DAT](INFO): DAT read: Rx Time:07:32:34.7000 2025-09-11T07:32:30.725Z,1757575950.725 [DAT](INFO): Rx dataTimestamp_ set to:1757575950.724429 2025-09-11T07:32:30.726Z,1757575950.726 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.024933 2025-09-11T07:32:30.976Z,1757575950.976 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274897 2025-09-11T07:32:31.234Z,1757575951.234 [DAT](INFO): DAT read: 07:32:34.7000 LVL= 19488, 25025, 19938, 23747, AGC= 57, IDX= 463, 0.24, 1.124,-0.704, 1.202, 0.841, PHS= 0.385,-1.500, 0.317, RAW= 148.2, 8.7, CAL= 147.7, 9.4, ROT= 2.3, -9.4 2025-09-11T07:32:31.236Z,1757575951.236 [DAT](INFO): got valid direction response: 07:32:34.7000 LVL= 19488, 25025, 19938, 23747, AGC= 57, IDX= 463, 0.24, 1.124,-0.704, 1.202, 0.841, PHS= 0.385,-1.500, 0.317, RAW= 148.2, 8.7, CAL= 147.7, 9.4, ROT= 2.3, -9.4 2025-09-11T07:32:31.237Z,1757575951.237 [DAT](INFO): DAT read: Bearing 172.0, 2.8 (Local) 2025-09-11T07:32:31.237Z,1757575951.237 [DAT](INFO): Local bearing/azimuth received: Bearing 172.0, 2.8 (Local) 2025-09-11T07:32:31.239Z,1757575951.239 [DAT](INFO): DAT read: Range 11 to 50 : 28.2 m (Round-trip 37.7 ms) speed -0.2 m/s 2025-09-11T07:32:31.239Z,1757575951.239 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-09-11T07:32:31.240Z,1757575951.240 [DAT](INFO): direction in FSK: [0.985777,0.039593,0.163326] 2025-09-11T07:32:31.241Z,1757575951.241 [DAT](INFO): publishing direction and range info 2025-09-11T07:32:34.678Z,1757575954.678 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby. 2025-09-11T07:32:35.077Z,1757575955.077 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete. 2025-09-11T07:32:35.077Z,1757575955.077 [DefaultWithUndock:LeaveDock:B.Undock] Stopped 2025-09-11T07:32:35.079Z,1757575955.079 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock 2025-09-11T07:32:35.079Z,1757575955.079 [DefaultWithUndock:LeaveDock] Stopped 2025-09-11T07:32:35.079Z,1757575955.079 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock 2025-09-11T07:32:35.081Z,1757575955.081 [DefaultWithUndock:LeaveDock:A.] Stopped 2025-09-11T07:32:35.081Z,1757575955.081 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact. 2025-09-11T07:32:35.081Z,1757575955.081 [DefaultWithUndock:SurfaceDefault] Running Loop=1 2025-09-11T07:32:35.090Z,1757575955.090 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault 2025-09-11T07:32:35.090Z,1757575955.090 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1 2025-09-11T07:32:35.090Z,1757575955.090 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-09-11T07:32:35.093Z,1757575955.093 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-09-11T07:32:35.093Z,1757575955.093 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-09-11T07:32:35.093Z,1757575955.093 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-09-11T07:32:35.094Z,1757575955.094 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-09-11T07:32:35.094Z,1757575955.094 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-09-11T07:32:35.095Z,1757575955.095 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-09-11T07:32:35.890Z,1757575955.890 [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-11T07:32:36.095Z,1757575956.095 [Radio_Surface](INFO): Powering up 2025-09-11T07:32:41.347Z,1757575961.347 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.11 2025-09-11T07:32:41.347Z,1757575961.347 [Radio_Surface](INFO): No local IP found 2025-09-11T07:34:54.455Z,1757576094.455 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00031811223178,3.1, 0.0,1494.0, 0 2025-09-11T07:34:58.947Z,1757576098.947 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-09-11T07:34:59.952Z,1757576099.952 [DataOverHttps](INFO): Radio surface powered ON. 2025-09-11T07:34:59.952Z,1757576099.952 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-11T07:35:04.568Z,1757576104.568 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,00031811224178,35.0, +1.0,1494.2, 0 2025-09-11T07:35:09.809Z,1757576109.809 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1 2025-09-11T07:35:09.809Z,1757576109.809 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-09-11T07:35:09.809Z,1757576109.809 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1 2025-09-11T07:35:14.655Z,1757576114.655 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for water velocity. Device response is::WS, 68, +354,A 2025-09-11T07:35:24.759Z,1757576124.759 [RDI_Pathfinder](ERROR): only read 0 of 4 data items for water velocity. Device response is::WS +470, -60,A 2025-09-11T07:35:30.072Z,1757576130.072 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-09-11T07:35:31.076Z,1757576131.076 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-11T07:35:53.029Z,1757576153.029 [NAL9602](INFO): SBD MO Status=2, MOMSN=1535, MT Status=2, MTMSN=0 2025-09-11T07:35:53.029Z,1757576153.029 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-09-11T07:36:01.195Z,1757576161.195 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-09-11T07:36:02.200Z,1757576162.200 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-09-11T07:36:04.760Z,1757576164.760 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS, -306, +36, 2025-09-11T07:36:14.479Z,1757576174.479 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, -29.97, ,15.97, 72.64, 0.00 2025-09-11T07:36:29.964Z,1757576189.964 [DataOverHttps](IMPORTANT): SBD MTMSN=20250911T073629 2025-09-11T07:36:29.968Z,1757576189.968 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003577 2025-09-11T07:36:30.597Z,1757576190.597 [NAL9602](INFO): SBD MO Status=0, MOMSN=1535, MT Status=0, MTMSN=0 2025-09-11T07:36:30.598Z,1757576190.598 [NAL9602](INFO): No messages in MT queue 2025-09-11T07:36:31.817Z,1757576191.817 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,073631.00,A,3646.79821,N,12151.58144,W,1.380,252.80,110925,,,A*7D 2025-09-11T07:36:31.820Z,1757576191.820 [NAL9602](INFO): GPS fix at 20250911T073631: (36.779970, -121.859691) 2025-09-11T07:36:31.857Z,1757576191.857 [UniversalFixResidualReporter](INFO): Fix residual: 0.7 %DT, over the last 7226.5 m. Residual distance 47.8 m at bearing -36.0 degrees. Fix at (36.7800, -121.8597) with 489.6 m made good. 2025-09-11T07:36:31.858Z,1757576191.858 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped 2025-09-11T07:36:31.859Z,1757576191.859 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1 2025-09-11T07:36:40.644Z,1757576200.644 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20250910T093246/Courier0060.lzma 2025-09-11T07:36:40.646Z,1757576200.646 [DataOverHttps](INFO): Received command: restart logs