2025-08-27T20:21:19.286Z,1756326079.286 [OnDock:L.Execute](INFO): Executing command restart logs 2025-08-27T20:21:19.286Z,1756326079.286 [OnDock:L.Execute] Stopped 2025-08-27T20:21:19.287Z,1756326079.287 [OnDock:N.Docked] Running Loop=1 2025-08-27T20:21:19.287Z,1756326079.287 [OnDock:N.Docked](DEBUG): Initialize. 2025-08-27T20:21:19.287Z,1756326079.287 [OnDock:N.Docked](DEBUG): Initializing internal variables to default values. 2025-08-27T20:21:19.317Z,1756326079.317 [CommandExec](IMPORTANT): got command restart logs 2025-08-27T20:21:19.864Z,1756326079.864 [DAT](INFO): Requesting device enable set for address 50. 2025-08-27T20:21:20.117Z,1756326080.117 [DAT](INFO): DAT read: user:2075> 2025-08-27T20:21:20.118Z,1756326080.118 [DAT](INFO): DAT read: Tx time:20:21:17.9333 2025-08-27T20:21:20.118Z,1756326080.118 [DAT](INFO): Ping request sent. 2025-08-27T20:21:20.119Z,1756326080.119 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:21:20.119Z,1756326080.119 [DAT](INFO): publishing transmit ping time 2025-08-27T20:21:20.120Z,1756326080.120 [DAT](INFO): Requesting device enable set for address 50. 2025-08-27T20:21:20.368Z,1756326080.368 [DAT](INFO): Requesting device enable set for address 50. 2025-08-27T20:21:20.517Z,1756326080.517 [CTD_Seabird](ERROR): Failed to parse device response: 2025-08-27T20:21:20.524Z,1756326080.524 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-08-27T20:21:20.645Z,1756326080.645 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-08-27T20:21:22.384Z,1756326082.384 [DAT](INFO): DAT read: Rx Time:20:21:19.7914 2025-08-27T20:21:22.385Z,1756326082.385 [DAT](INFO): Rx dataTimestamp_ set to:1756326082.384375 2025-08-27T20:21:22.893Z,1756326082.893 [DAT](INFO): DAT read: 20:21:19.7914 LVL= 10384, 13233, 17634, 14627, AGC= 44, IDX= 437, 0.10, 0.229,-1.095,-1.850,-0.579, PHS= 0.895,-0.469,-1.275, RAW= 68.5, 9.0, CAL= 69.2, 13.4, ROT= 80.8, -13.4 2025-08-27T20:21:22.895Z,1756326082.895 [DAT](INFO): got valid direction response: 20:21:19.7914 LVL= 10384, 13233, 17634, 14627, AGC= 44, IDX= 437, 0.10, 0.229,-1.095,-1.850,-0.579, PHS= 0.895,-0.469,-1.275, RAW= 68.5, 9.0, CAL= 69.2, 13.4, ROT= 80.8, -13.4 2025-08-27T20:21:22.895Z,1756326082.895 [DAT](INFO): DAT read: OK 2025-08-27T20:21:22.896Z,1756326082.896 [DAT](INFO): unknown deviceResponse_: OK 2025-08-27T20:21:22.896Z,1756326082.896 [DAT](INFO): DAT read: user:2076> 2025-08-27T20:21:22.897Z,1756326082.897 [DAT](INFO): DAT read: Tx time:20:21:20.8833 2025-08-27T20:21:22.897Z,1756326082.897 [DAT](INFO): Ping request sent. 2025-08-27T20:21:22.897Z,1756326082.897 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:21:22.897Z,1756326082.897 [DAT](INFO): #Rx 5: Read direction message, but no range. 2025-08-27T20:21:22.898Z,1756326082.898 [DAT](INFO): direction in FSK: [0.155528,0.960262,0.231748] 2025-08-27T20:21:22.899Z,1756326082.899 [DAT](INFO): publishing transmit ping time 2025-08-27T20:21:22.902Z,1756326082.902 [DAT](INFO): publishing transmit ping time 2025-08-27T20:21:24.180Z,1756326084.180 [DockingStepper](INFO): Changing to mode: 1 2025-08-27T20:21:25.408Z,1756326085.408 [DAT](INFO): DAT read: Rx Time:20:21:22.7414 2025-08-27T20:21:25.409Z,1756326085.409 [DAT](INFO): Rx dataTimestamp_ set to:1756326085.408531 2025-08-27T20:21:25.919Z,1756326085.919 [DAT](INFO): DAT read: 20:21:22.7414 LVL= 10336, 12705, 17778, 15331, AGC= 44, IDX= 438,-0.21,-1.964, 3.086, 2.435,-2.658, PHS= 0.782,-0.492,-1.192, RAW= 69.5, 10.4, CAL= 70.2, 16.5, ROT= 79.8, -16.5 2025-08-27T20:21:25.921Z,1756326085.921 [DAT](INFO): got valid direction response: 20:21:22.7414 LVL= 10336, 12705, 17778, 15331, AGC= 44, IDX= 438,-0.21,-1.964, 3.086, 2.435,-2.658, PHS= 0.782,-0.492,-1.192, RAW= 69.5, 10.4, CAL= 70.2, 16.5, ROT= 79.8, -16.5 2025-08-27T20:21:25.921Z,1756326085.921 [DAT](INFO): DAT read: OK 2025-08-27T20:21:25.921Z,1756326085.921 [DAT](INFO): unknown deviceResponse_: OK 2025-08-27T20:21:25.922Z,1756326085.922 [DAT](INFO): DAT read: user:2077> 2025-08-27T20:21:25.923Z,1756326085.923 [DAT](INFO): DAT read: Tx time:20:21:23.8333 2025-08-27T20:21:25.930Z,1756326085.930 [DAT](INFO): Ping request sent. 2025-08-27T20:21:25.930Z,1756326085.930 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:21:25.930Z,1756326085.930 [DAT](INFO): #Rx 6: Read direction message, but no range. 2025-08-27T20:21:25.932Z,1756326085.932 [DAT](INFO): direction in FSK: [0.169792,0.943666,0.284015] 2025-08-27T20:21:25.932Z,1756326085.932 [DAT](INFO): publishing transmit ping time 2025-08-27T20:21:25.935Z,1756326085.935 [DAT](INFO): publishing transmit ping time 2025-08-27T20:21:28.432Z,1756326088.432 [DAT](INFO): DAT read: Rx Time:20:21:25.6915 2025-08-27T20:21:28.433Z,1756326088.433 [DAT](INFO): Rx dataTimestamp_ set to:1756326088.432309 2025-08-27T20:21:28.941Z,1756326088.941 [DAT](INFO): DAT read: 20:21:25.6916 LVL= 10096, 12737, 18082, 15619, AGC= 44, IDX= 438, 0.27,-0.413,-1.717,-2.373,-1.154, PHS= 0.829,-0.516,-1.222, RAW= 70.2, 10.1, CAL= 71.2, 15.8, ROT= 78.8, -15.8 2025-08-27T20:21:28.942Z,1756326088.942 [DAT](INFO): got valid direction response: 20:21:25.6916 LVL= 10096, 12737, 18082, 15619, AGC= 44, IDX= 438, 0.27,-0.413,-1.717,-2.373,-1.154, PHS= 0.829,-0.516,-1.222, RAW= 70.2, 10.1, CAL= 71.2, 15.8, ROT= 78.8, -15.8 2025-08-27T20:21:28.942Z,1756326088.942 [DAT](INFO): DAT read: OK 2025-08-27T20:21:28.942Z,1756326088.942 [DAT](INFO): unknown deviceResponse_: OK 2025-08-27T20:21:28.943Z,1756326088.943 [DAT](INFO): #Rx 7: Read direction message, but no range. 2025-08-27T20:21:28.976Z,1756326088.976 [DAT](INFO): direction in FSK: [0.186896,0.943893,0.272280] 2025-08-27T20:23:17.271Z,1756326197.271 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:23:17.408Z,1756326197.408 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:23:17.408Z,1756326197.408 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:23:17.661Z,1756326197.661 [DAT](INFO): DAT read: user:2078> 2025-08-27T20:23:17.662Z,1756326197.662 [DAT](INFO): DAT read: Tx time:20:23:15.4857 2025-08-27T20:23:17.663Z,1756326197.663 [DAT](INFO): Ping request sent. 2025-08-27T20:23:17.663Z,1756326197.663 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:23:17.663Z,1756326197.663 [DAT](INFO): publishing transmit ping time 2025-08-27T20:23:17.664Z,1756326197.664 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001139 2025-08-27T20:23:17.912Z,1756326197.912 [DAT](INFO): DAT read: TxSync time:20:23:15.4850 2025-08-27T20:23:17.913Z,1756326197.913 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250430 2025-08-27T20:23:18.164Z,1756326198.164 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501426 2025-08-27T20:23:18.417Z,1756326198.417 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754611 2025-08-27T20:23:18.669Z,1756326198.669 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006134 2025-08-27T20:23:18.920Z,1756326198.920 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.257410 2025-08-27T20:23:19.172Z,1756326199.172 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.509711 2025-08-27T20:23:19.424Z,1756326199.424 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761496 2025-08-27T20:23:19.676Z,1756326199.676 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.013502 2025-08-27T20:23:19.928Z,1756326199.928 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.265637 2025-08-27T20:23:20.180Z,1756326200.180 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.517445 2025-08-27T20:23:20.433Z,1756326200.433 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770661 2025-08-27T20:23:20.684Z,1756326200.684 [DAT](INFO): DAT read: Rx Time:20:23:17.8923 2025-08-27T20:23:20.685Z,1756326200.685 [DAT](INFO): Rx dataTimestamp_ set to:1756326200.684343 2025-08-27T20:23:20.685Z,1756326200.685 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022529 2025-08-27T20:23:20.936Z,1756326200.936 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.273575 2025-08-27T20:23:21.193Z,1756326201.193 [DAT](INFO): DAT read: 20:23:17.8923 LVL= 10720, 13345, 22754, 19955, AGC= 44, IDX= 416, 0.28, 2.769, 1.380, 0.761, 2.008, PHS= 0.849,-0.581,-1.250, RAW= 71.8, 10.6, CAL= 73.4, 16.8, ROT= 76.6, -16.8 2025-08-27T20:23:21.194Z,1756326201.194 [DAT](INFO): got valid direction response: 20:23:17.8923 LVL= 10720, 13345, 22754, 19955, AGC= 44, IDX= 416, 0.28, 2.769, 1.380, 0.761, 2.008, PHS= 0.849,-0.581,-1.250, RAW= 71.8, 10.6, CAL= 73.4, 16.8, ROT= 76.6, -16.8 2025-08-27T20:23:21.195Z,1756326201.195 [DAT](INFO): DAT read: Bearing 257.4, -27.0 (Local) 2025-08-27T20:23:21.196Z,1756326201.196 [DAT](INFO): Local bearing/azimuth received: Bearing 257.4, -27.0 (Local) 2025-08-27T20:23:21.197Z,1756326201.197 [DAT](INFO): DAT read: Range 10 to 50 : 1.8 m (Round-trip 2.4 ms) speed 0.0 m/s 2025-08-27T20:23:21.198Z,1756326201.198 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:23:21.199Z,1756326201.199 [DAT](INFO): direction in FSK: [0.221857,0.931257,0.289032] 2025-08-27T20:23:21.199Z,1756326201.199 [DAT](INFO): publishing direction and range info 2025-08-27T20:24:59.094Z,1756326299.094 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD-0.02, +0.33, -0.08, 8.13, 0.00 2025-08-27T20:25:17.289Z,1756326317.289 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:25:17.452Z,1756326317.452 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:25:17.452Z,1756326317.452 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:25:17.704Z,1756326317.704 [DAT](INFO): DAT read: user:2079> 2025-08-27T20:25:17.706Z,1756326317.706 [DAT](INFO): DAT read: Tx time:20:25:15.5373 2025-08-27T20:25:17.706Z,1756326317.706 [DAT](INFO): Ping request sent. 2025-08-27T20:25:17.706Z,1756326317.706 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:25:17.706Z,1756326317.706 [DAT](INFO): publishing transmit ping time 2025-08-27T20:25:17.708Z,1756326317.708 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001194 2025-08-27T20:25:17.956Z,1756326317.956 [DAT](INFO): DAT read: TxSync time:20:25:15.5365 2025-08-27T20:25:17.957Z,1756326317.957 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250887 2025-08-27T20:25:18.209Z,1756326318.209 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502286 2025-08-27T20:25:18.460Z,1756326318.460 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753819 2025-08-27T20:25:18.712Z,1756326318.712 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006019 2025-08-27T20:25:18.964Z,1756326318.964 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.257876 2025-08-27T20:25:19.216Z,1756326319.216 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.509734 2025-08-27T20:25:19.468Z,1756326319.468 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761763 2025-08-27T20:25:19.721Z,1756326319.721 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014704 2025-08-27T20:25:19.972Z,1756326319.972 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.265655 2025-08-27T20:25:20.224Z,1756326320.224 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518026 2025-08-27T20:25:20.476Z,1756326320.476 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.769883 2025-08-27T20:25:20.728Z,1756326320.728 [DAT](INFO): DAT read: Rx Time:20:25:17.9438 2025-08-27T20:25:20.729Z,1756326320.729 [DAT](INFO): Rx dataTimestamp_ set to:1756326320.728344 2025-08-27T20:25:20.729Z,1756326320.729 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022845 2025-08-27T20:25:20.980Z,1756326320.980 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274019 2025-08-27T20:25:21.237Z,1756326321.237 [DAT](INFO): DAT read: 20:25:17.9438 LVL= 9584, 12257, 18194, 15667, AGC= 43, IDX= 432,-0.09,-3.109, 1.800, 1.198, 2.408, PHS= 0.854,-0.561,-1.214, RAW= 72.0, 10.1, CAL= 73.8, 15.7, ROT= 76.2, -15.7 2025-08-27T20:25:21.238Z,1756326321.238 [DAT](INFO): got valid direction response: 20:25:17.9438 LVL= 9584, 12257, 18194, 15667, AGC= 43, IDX= 432,-0.09,-3.109, 1.800, 1.198, 2.408, PHS= 0.854,-0.561,-1.214, RAW= 72.0, 10.1, CAL= 73.8, 15.7, ROT= 76.2, -15.7 2025-08-27T20:25:21.240Z,1756326321.240 [DAT](INFO): DAT read: Bearing 257.1, -25.9 (Local) 2025-08-27T20:25:21.240Z,1756326321.240 [DAT](INFO): Local bearing/azimuth received: Bearing 257.1, -25.9 (Local) 2025-08-27T20:25:21.241Z,1756326321.241 [DAT](INFO): DAT read: Range 10 to 50 : 1.8 m (Round-trip 2.4 ms) speed 0.0 m/s 2025-08-27T20:25:21.242Z,1756326321.242 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:25:21.243Z,1756326321.243 [DAT](INFO): direction in FSK: [0.229634,0.934903,0.270600] 2025-08-27T20:25:21.243Z,1756326321.243 [DAT](INFO): publishing direction and range info 2025-08-27T20:27:17.654Z,1756326437.654 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:27:17.748Z,1756326437.748 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:27:17.748Z,1756326437.748 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:27:18.000Z,1756326438.000 [DAT](INFO): DAT read: user:2080> 2025-08-27T20:27:18.001Z,1756326438.001 [DAT](INFO): DAT read: Tx time:20:27:15.8386 2025-08-27T20:27:18.001Z,1756326438.001 [DAT](INFO): Ping request sent. 2025-08-27T20:27:18.001Z,1756326438.001 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:27:18.002Z,1756326438.002 [DAT](INFO): publishing transmit ping time 2025-08-27T20:27:18.002Z,1756326438.002 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000728 2025-08-27T20:27:18.252Z,1756326438.252 [DAT](INFO): DAT read: TxSync time:20:27:15.8378 2025-08-27T20:27:18.253Z,1756326438.253 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251653 2025-08-27T20:27:18.505Z,1756326438.505 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503159 2025-08-27T20:27:18.756Z,1756326438.756 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754925 2025-08-27T20:27:19.008Z,1756326439.008 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006798 2025-08-27T20:27:19.260Z,1756326439.260 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258723 2025-08-27T20:27:19.512Z,1756326439.512 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510699 2025-08-27T20:27:19.764Z,1756326439.764 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762864 2025-08-27T20:27:20.016Z,1756326440.016 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014674 2025-08-27T20:27:20.268Z,1756326440.268 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266942 2025-08-27T20:27:20.521Z,1756326440.521 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519501 2025-08-27T20:27:20.772Z,1756326440.772 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.770670 2025-08-27T20:27:21.024Z,1756326441.024 [DAT](INFO): DAT read: Rx Time:20:27:18.2452 2025-08-27T20:27:21.025Z,1756326441.025 [DAT](INFO): Rx dataTimestamp_ set to:1756326441.024312 2025-08-27T20:27:21.025Z,1756326441.025 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023715 2025-08-27T20:27:21.276Z,1756326441.276 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274781 2025-08-27T20:27:21.533Z,1756326441.533 [DAT](INFO): DAT read: 20:27:18.2452 LVL= 10448, 12497, 18530, 17283, AGC= 44, IDX= 432,-0.19,-1.816,-3.114, 2.557,-2.515, PHS= 0.787,-0.553,-1.215, RAW= 71.0, 11.1, CAL= 72.2, 17.9, ROT= 77.8, -17.9 2025-08-27T20:27:21.534Z,1756326441.534 [DAT](INFO): got valid direction response: 20:27:18.2452 LVL= 10448, 12497, 18530, 17283, AGC= 44, IDX= 432,-0.19,-1.816,-3.114, 2.557,-2.515, PHS= 0.787,-0.553,-1.215, RAW= 71.0, 11.1, CAL= 72.2, 17.9, ROT= 77.8, -17.9 2025-08-27T20:27:21.535Z,1756326441.535 [DAT](INFO): DAT read: Bearing 258.7, -28.2 (Local) 2025-08-27T20:27:21.536Z,1756326441.536 [DAT](INFO): Local bearing/azimuth received: Bearing 258.7, -28.2 (Local) 2025-08-27T20:27:21.537Z,1756326441.537 [DAT](INFO): DAT read: Range 10 to 50 : 1.7 m (Round-trip 2.3 ms) speed 0.0 m/s 2025-08-27T20:27:21.538Z,1756326441.538 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:27:21.539Z,1756326441.539 [DAT](INFO): direction in FSK: [0.201095,0.930103,0.307357] 2025-08-27T20:27:21.539Z,1756326441.539 [DAT](INFO): publishing direction and range info 2025-08-27T20:27:24.110Z,1756326444.110 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for beam range. Device response is::RA, 0.00, 88.28, 81.30 2025-08-27T20:28:34.075Z,1756326514.075 [RDI_Pathfinder](ERROR): only read 1 of 4 data items for bottom velocity. Device response is::BS, +2A 2025-08-27T20:29:17.700Z,1756326557.700 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:29:17.904Z,1756326557.904 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:29:17.904Z,1756326557.904 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:29:18.156Z,1756326558.156 [DAT](INFO): DAT read: user:2081> 2025-08-27T20:29:18.157Z,1756326558.157 [DAT](INFO): DAT read: Tx time:20:29:15.9902 2025-08-27T20:29:18.157Z,1756326558.157 [DAT](INFO): Ping request sent. 2025-08-27T20:29:18.157Z,1756326558.157 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:29:18.157Z,1756326558.157 [DAT](INFO): publishing transmit ping time 2025-08-27T20:29:18.158Z,1756326558.158 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000752 2025-08-27T20:29:18.408Z,1756326558.408 [DAT](INFO): DAT read: TxSync time:20:29:15.9894 2025-08-27T20:29:18.409Z,1756326558.409 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.252063 2025-08-27T20:29:18.664Z,1756326558.664 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.505640 2025-08-27T20:29:18.913Z,1756326558.913 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755384 2025-08-27T20:29:19.164Z,1756326559.164 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.007209 2025-08-27T20:29:19.416Z,1756326559.416 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258937 2025-08-27T20:29:19.671Z,1756326559.671 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.513377 2025-08-27T20:29:19.920Z,1756326559.920 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762926 2025-08-27T20:29:20.172Z,1756326560.172 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014926 2025-08-27T20:29:20.424Z,1756326560.424 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266889 2025-08-27T20:29:20.679Z,1756326560.679 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.520999 2025-08-27T20:29:20.929Z,1756326560.929 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771636 2025-08-27T20:29:21.180Z,1756326561.180 [DAT](INFO): DAT read: Rx Time:20:29:18.3967 2025-08-27T20:29:21.181Z,1756326561.181 [DAT](INFO): Rx dataTimestamp_ set to:1756326561.180239 2025-08-27T20:29:21.181Z,1756326561.181 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023878 2025-08-27T20:29:21.432Z,1756326561.432 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275165 2025-08-27T20:29:21.688Z,1756326561.688 [DAT](INFO): DAT read: Range 10 to 50 : 1.8 m (Round-trip 2.4 ms) speed 0.0 m/s 2025-08-27T20:29:21.691Z,1756326561.691 [DAT](ERROR): #Rx 1: Read range message, but no direction. 2025-08-27T20:29:30.151Z,1756326570.151 [RDI_Pathfinder](ERROR): DVL BIT error. See manual. Result code: -32768 Device respsone is::TS,25082712304234,35.0, +11.5, 0.0,2768,-32768,-32768,-32768,V 2025-08-27T20:29:49.164Z,1756326589.164 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,25082712310161,35.0, +11.5, 0.0,1495.3RA, 0.00, 81.98, 78.92, 80.28, 79.94 2025-08-27T20:31:18.041Z,1756326678.041 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:31:18.264Z,1756326678.264 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:31:18.264Z,1756326678.264 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:31:18.516Z,1756326678.516 [DAT](INFO): DAT read: user:2082> 2025-08-27T20:31:18.517Z,1756326678.517 [DAT](INFO): DAT read: Tx time:20:31:16.3416 2025-08-27T20:31:18.517Z,1756326678.517 [DAT](INFO): Ping request sent. 2025-08-27T20:31:18.518Z,1756326678.518 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:31:18.518Z,1756326678.518 [DAT](INFO): publishing transmit ping time 2025-08-27T20:31:18.518Z,1756326678.518 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000752 2025-08-27T20:31:18.768Z,1756326678.768 [DAT](INFO): DAT read: TxSync time:20:31:16.3408 2025-08-27T20:31:18.769Z,1756326678.769 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251403 2025-08-27T20:31:19.020Z,1756326679.020 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502420 2025-08-27T20:31:19.282Z,1756326679.282 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.763984 2025-08-27T20:31:19.533Z,1756326679.533 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.014968 2025-08-27T20:31:19.784Z,1756326679.784 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.266560 2025-08-27T20:31:20.036Z,1756326680.036 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.518870 2025-08-27T20:31:20.288Z,1756326680.288 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.770586 2025-08-27T20:31:20.540Z,1756326680.540 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.022630 2025-08-27T20:31:20.792Z,1756326680.792 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.274501 2025-08-27T20:31:21.044Z,1756326681.044 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.526558 2025-08-27T20:31:21.297Z,1756326681.297 [DAT](INFO): DAT read: Rx Time:20:31:18.7480 2025-08-27T20:31:21.298Z,1756326681.298 [DAT](INFO): Rx dataTimestamp_ set to:1756326681.297574 2025-08-27T20:31:21.299Z,1756326681.299 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.781134 2025-08-27T20:31:21.548Z,1756326681.548 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.030579 2025-08-27T20:31:21.803Z,1756326681.803 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.284838 2025-08-27T20:31:22.057Z,1756326682.057 [DAT](INFO): DAT read: 20:31:18.7480 LVL= 9296, 14561, 21234, 17139, AGC= 43, IDX= 432,-0.11, 0.896,-0.465,-0.987, 0.224, PHS= 0.761,-0.642,-1.214, RAW= 73.6, 12.4, CAL= 75.7, 20.3, ROT= 74.3, -20.3 2025-08-27T20:31:22.058Z,1756326682.058 [DAT](INFO): got valid direction response: 20:31:18.7480 LVL= 9296, 14561, 21234, 17139, AGC= 43, IDX= 432,-0.11, 0.896,-0.465,-0.987, 0.224, PHS= 0.761,-0.642,-1.214, RAW= 73.6, 12.4, CAL= 75.7, 20.3, ROT= 74.3, -20.3 2025-08-27T20:31:22.060Z,1756326682.060 [DAT](INFO): DAT read: Bearing 254.7, -30.4 (Local) 2025-08-27T20:31:22.061Z,1756326682.061 [DAT](INFO): Local bearing/azimuth received: Bearing 254.7, -30.4 (Local) 2025-08-27T20:31:22.062Z,1756326682.062 [DAT](INFO): DAT read: Range 10 to 50 : 1.7 m (Round-trip 2.3 ms) speed 0.0 m/s 2025-08-27T20:31:22.063Z,1756326682.063 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:31:22.064Z,1756326682.064 [DAT](INFO): direction in FSK: [0.253793,0.902898,0.346936] 2025-08-27T20:31:22.064Z,1756326682.064 [DAT](INFO): publishing direction and range info 2025-08-27T20:33:18.450Z,1756326798.450 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:33:18.588Z,1756326798.588 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:33:18.589Z,1756326798.589 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:33:18.836Z,1756326798.836 [DAT](INFO): DAT read: user:2083> 2025-08-27T20:33:18.837Z,1756326798.837 [DAT](INFO): DAT read: Tx time:20:33:16.6429 2025-08-27T20:33:18.837Z,1756326798.837 [DAT](INFO): Ping request sent. 2025-08-27T20:33:18.837Z,1756326798.837 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:33:18.838Z,1756326798.838 [DAT](INFO): DAT read: TxSync time:20:33:16.6421 2025-08-27T20:33:18.838Z,1756326798.838 [DAT](INFO): publishing transmit ping time 2025-08-27T20:33:18.839Z,1756326798.839 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001563 2025-08-27T20:33:19.088Z,1756326799.088 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250660 2025-08-27T20:33:19.340Z,1756326799.340 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503055 2025-08-27T20:33:19.592Z,1756326799.592 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754743 2025-08-27T20:33:19.844Z,1756326799.844 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006605 2025-08-27T20:33:20.098Z,1756326800.098 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.260400 2025-08-27T20:33:20.348Z,1756326800.348 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510754 2025-08-27T20:33:20.600Z,1756326800.600 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762709 2025-08-27T20:33:20.852Z,1756326800.852 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015089 2025-08-27T20:33:21.104Z,1756326801.104 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266751 2025-08-27T20:33:21.358Z,1756326801.358 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519904 2025-08-27T20:33:21.608Z,1756326801.608 [DAT](INFO): DAT read: Rx Time:20:33:19.0495 2025-08-27T20:33:21.609Z,1756326801.609 [DAT](INFO): Rx dataTimestamp_ set to:1756326801.608544 2025-08-27T20:33:21.609Z,1756326801.609 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771976 2025-08-27T20:33:21.860Z,1756326801.860 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022735 2025-08-27T20:33:22.116Z,1756326802.116 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.277435 2025-08-27T20:33:22.370Z,1756326802.370 [DAT](INFO): DAT read: 20:33:19.0495 LVL= 9888, 13361, 20466, 16627, AGC= 44, IDX= 433,-0.37, 2.305, 1.013, 0.417, 1.645, PHS= 0.748,-0.584,-1.231, RAW= 71.3, 12.2, CAL= 72.3, 20.1, ROT= 77.7, -20.1 2025-08-27T20:33:22.371Z,1756326802.371 [DAT](INFO): got valid direction response: 20:33:19.0495 LVL= 9888, 13361, 20466, 16627, AGC= 44, IDX= 433,-0.37, 2.305, 1.013, 0.417, 1.645, PHS= 0.748,-0.584,-1.231, RAW= 71.3, 12.2, CAL= 72.3, 20.1, ROT= 77.7, -20.1 2025-08-27T20:33:22.372Z,1756326802.372 [DAT](INFO): DAT read: Bearing 258.4, -30.4 (Local) 2025-08-27T20:33:22.372Z,1756326802.372 [DAT](INFO): Local bearing/azimuth received: Bearing 258.4, -30.4 (Local) 2025-08-27T20:33:22.374Z,1756326802.374 [DAT](INFO): DAT read: Range 10 to 50 : 1.8 m (Round-trip 2.4 ms) speed 0.0 m/s 2025-08-27T20:33:22.374Z,1756326802.374 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:33:22.375Z,1756326802.375 [DAT](INFO): direction in FSK: [0.200056,0.917538,0.343660] 2025-08-27T20:33:22.375Z,1756326802.375 [DAT](INFO): publishing direction and range info 2025-08-27T20:33:24.474Z,1756326804.474 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,25082712343679,35.0 0.0,1495.3, 0 0.00, 83.00, 78.92, 80.28, 80.96 2025-08-27T20:34:34.394Z,1756326874.394 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.00, 81.30, 79.60, 80.96, :W,-32768,-32768,-32768,V 2025-08-27T20:35:18.812Z,1756326918.812 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:35:18.880Z,1756326918.880 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:35:18.880Z,1756326918.880 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:35:19.132Z,1756326919.132 [DAT](INFO): DAT read: user:2084> 2025-08-27T20:35:19.134Z,1756326919.134 [DAT](INFO): DAT read: Tx time:20:35:16.9444 2025-08-27T20:35:19.135Z,1756326919.135 [DAT](INFO): Ping request sent. 2025-08-27T20:35:19.135Z,1756326919.135 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:35:19.136Z,1756326919.136 [DAT](INFO): publishing transmit ping time 2025-08-27T20:35:19.138Z,1756326919.138 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.002259 2025-08-27T20:35:19.384Z,1756326919.384 [DAT](INFO): DAT read: TxSync time:20:35:16.9436 2025-08-27T20:35:19.385Z,1756326919.385 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.249740 2025-08-27T20:35:19.637Z,1756326919.637 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501552 2025-08-27T20:35:19.888Z,1756326919.888 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.752942 2025-08-27T20:35:20.140Z,1756326920.140 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.004877 2025-08-27T20:35:20.392Z,1756326920.392 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.256751 2025-08-27T20:35:20.645Z,1756326920.645 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.509166 2025-08-27T20:35:20.896Z,1756326920.896 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.760911 2025-08-27T20:35:21.148Z,1756326921.148 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.012813 2025-08-27T20:35:21.400Z,1756326921.400 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.264782 2025-08-27T20:35:21.653Z,1756326921.653 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.517551 2025-08-27T20:35:21.904Z,1756326921.904 [DAT](INFO): DAT read: Rx Time:20:35:19.3509 2025-08-27T20:35:21.905Z,1756326921.905 [DAT](INFO): Rx dataTimestamp_ set to:1756326921.904324 2025-08-27T20:35:21.905Z,1756326921.905 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.769849 2025-08-27T20:35:22.156Z,1756326922.156 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.020909 2025-08-27T20:35:22.409Z,1756326922.409 [DAT](INFO): DAT read: Range 10 to 50 : 1.8 m (Round-trip 2.4 ms) speed 0.0 m/s 2025-08-27T20:35:22.410Z,1756326922.410 [DAT](ERROR): #Rx 1: Read range message, but no direction. 2025-08-27T20:35:44.693Z,1756326944.693 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS, +23, -6A 2025-08-27T20:37:18.845Z,1756327038.845 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:37:18.948Z,1756327038.948 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:37:18.948Z,1756327038.948 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:37:19.200Z,1756327039.200 [DAT](INFO): DAT read: user:2085> 2025-08-27T20:37:19.201Z,1756327039.201 [DAT](INFO): DAT read: Tx time:20:37:16.9957 2025-08-27T20:37:19.201Z,1756327039.201 [DAT](INFO): Ping request sent. 2025-08-27T20:37:19.201Z,1756327039.201 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:37:19.201Z,1756327039.201 [DAT](INFO): publishing transmit ping time 2025-08-27T20:37:19.202Z,1756327039.202 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000761 2025-08-27T20:37:19.452Z,1756327039.452 [DAT](INFO): DAT read: TxSync time:20:37:16.9949 2025-08-27T20:37:19.453Z,1756327039.453 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251785 2025-08-27T20:37:19.704Z,1756327039.704 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502878 2025-08-27T20:37:19.956Z,1756327039.956 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754845 2025-08-27T20:37:20.208Z,1756327040.208 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006914 2025-08-27T20:37:20.461Z,1756327040.461 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259709 2025-08-27T20:37:20.712Z,1756327040.712 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510841 2025-08-27T20:37:20.964Z,1756327040.964 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762885 2025-08-27T20:37:21.216Z,1756327041.216 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014988 2025-08-27T20:37:21.468Z,1756327041.468 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266842 2025-08-27T20:37:21.720Z,1756327041.720 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518987 2025-08-27T20:37:21.972Z,1756327041.972 [DAT](INFO): DAT read: Rx Time:20:37:19.4023 2025-08-27T20:37:21.973Z,1756327041.973 [DAT](INFO): Rx dataTimestamp_ set to:1756327041.972376 2025-08-27T20:37:21.973Z,1756327041.973 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771988 2025-08-27T20:37:22.224Z,1756327042.224 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022881 2025-08-27T20:37:22.478Z,1756327042.478 [DAT](INFO): DAT read: Range 10 to 50 : 1.8 m (Round-trip 2.4 ms) speed 0.0 m/s 2025-08-27T20:37:22.479Z,1756327042.479 [DAT](ERROR): #Rx 1: Read range message, but no direction. 2025-08-27T20:38:09.719Z,1756327089.719 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for beam range. Device response is::RA, 0.00, 79.98, 80.28 2025-08-27T20:39:19.212Z,1756327159.212 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:39:19.236Z,1756327159.236 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:39:19.237Z,1756327159.237 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:39:19.488Z,1756327159.488 [DAT](INFO): DAT read: user:2086> 2025-08-27T20:39:19.489Z,1756327159.489 [DAT](INFO): DAT read: Tx time:20:39:17.2970 2025-08-27T20:39:19.489Z,1756327159.489 [DAT](INFO): Ping request sent. 2025-08-27T20:39:19.490Z,1756327159.490 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:39:19.490Z,1756327159.490 [DAT](INFO): DAT read: TxSync time:20:39:17.2962 2025-08-27T20:39:19.491Z,1756327159.491 [DAT](INFO): publishing transmit ping time 2025-08-27T20:39:19.491Z,1756327159.491 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001702 2025-08-27T20:39:19.644Z,1756327159.644 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS, +0, -2, B, -2, -1,A 2025-08-27T20:39:19.740Z,1756327159.740 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250457 2025-08-27T20:39:19.992Z,1756327159.992 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502765 2025-08-27T20:39:20.244Z,1756327160.244 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754558 2025-08-27T20:39:20.496Z,1756327160.496 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006601 2025-08-27T20:39:20.748Z,1756327160.748 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258525 2025-08-27T20:39:21.000Z,1756327161.000 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510552 2025-08-27T20:39:21.253Z,1756327161.253 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763240 2025-08-27T20:39:21.504Z,1756327161.504 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014543 2025-08-27T20:39:21.756Z,1756327161.756 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266538 2025-08-27T20:39:22.008Z,1756327162.008 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518425 2025-08-27T20:39:22.260Z,1756327162.260 [DAT](INFO): DAT read: Rx Time:20:39:19.7037 2025-08-27T20:39:22.261Z,1756327162.261 [DAT](INFO): Rx dataTimestamp_ set to:1756327162.260591 2025-08-27T20:39:22.261Z,1756327162.261 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771843 2025-08-27T20:39:22.513Z,1756327162.513 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023062 2025-08-27T20:39:22.767Z,1756327162.767 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.276886 2025-08-27T20:39:23.021Z,1756327163.021 [DAT](INFO): DAT read: 20:39:19.7037 LVL= 10928, 13425, 20082, 16963, AGC= 44, IDX= 432, 0.02, 0.036,-1.301,-1.938,-0.695, PHS= 0.819,-0.559,-1.246, RAW= 70.9, 10.8, CAL= 72.1, 17.4, ROT= 77.9, -17.4 2025-08-27T20:39:23.022Z,1756327163.022 [DAT](INFO): got valid direction response: 20:39:19.7037 LVL= 10928, 13425, 20082, 16963, AGC= 44, IDX= 432, 0.02, 0.036,-1.301,-1.938,-0.695, PHS= 0.819,-0.559,-1.246, RAW= 70.9, 10.8, CAL= 72.1, 17.4, ROT= 77.9, -17.4 2025-08-27T20:39:23.024Z,1756327163.024 [DAT](INFO): DAT read: Bearing 258.8, -27.7 (Local) 2025-08-27T20:39:23.024Z,1756327163.024 [DAT](INFO): Local bearing/azimuth received: Bearing 258.8, -27.7 (Local) 2025-08-27T20:39:23.025Z,1756327163.025 [DAT](INFO): DAT read: Range 10 to 50 : 1.8 m (Round-trip 2.4 ms) speed 0.0 m/s 2025-08-27T20:39:23.026Z,1756327163.026 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:39:23.027Z,1756327163.027 [DAT](INFO): direction in FSK: [0.200026,0.933040,0.299041] 2025-08-27T20:39:23.028Z,1756327163.028 [DAT](INFO): publishing direction and range info 2025-08-27T20:41:19.612Z,1756327279.612 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:41:19.804Z,1756327279.804 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:41:19.804Z,1756327279.804 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:41:20.057Z,1756327280.057 [DAT](INFO): DAT read: user:2087> 2025-08-27T20:41:20.058Z,1756327280.058 [DAT](INFO): DAT read: Tx time:20:41:17.8985 2025-08-27T20:41:20.059Z,1756327280.059 [DAT](INFO): Ping request sent. 2025-08-27T20:41:20.059Z,1756327280.059 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:41:20.059Z,1756327280.059 [DAT](INFO): publishing transmit ping time 2025-08-27T20:41:20.060Z,1756327280.060 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000883 2025-08-27T20:41:20.311Z,1756327280.311 [DAT](INFO): DAT read: TxSync time:20:41:17.8977 2025-08-27T20:41:20.314Z,1756327280.314 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.254603 2025-08-27T20:41:20.560Z,1756327280.560 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.501526 2025-08-27T20:41:20.812Z,1756327280.812 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753516 2025-08-27T20:41:21.064Z,1756327281.064 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005350 2025-08-27T20:41:21.320Z,1756327281.320 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.260814 2025-08-27T20:41:21.568Z,1756327281.568 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.509438 2025-08-27T20:41:21.820Z,1756327281.820 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761711 2025-08-27T20:41:22.072Z,1756327282.072 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.013379 2025-08-27T20:41:22.324Z,1756327282.324 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.265392 2025-08-27T20:41:22.576Z,1756327282.576 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.517365 2025-08-27T20:41:22.829Z,1756327282.829 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.769763 2025-08-27T20:41:23.080Z,1756327283.080 [DAT](INFO): DAT read: Rx Time:20:41:20.3050 2025-08-27T20:41:23.081Z,1756327283.081 [DAT](INFO): Rx dataTimestamp_ set to:1756327283.080389 2025-08-27T20:41:23.081Z,1756327283.081 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022492 2025-08-27T20:41:23.337Z,1756327283.337 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.277192 2025-08-27T20:41:23.590Z,1756327283.590 [DAT](INFO): DAT read: 20:41:20.3050 LVL= 10608, 13857, 18226, 15411, AGC= 44, IDX= 432, 0.36, 1.777, 0.413,-0.224, 1.066, PHS= 0.799,-0.606,-1.292, RAW= 71.2, 11.9, CAL= 72.2, 19.6, ROT= 77.8, -19.6 2025-08-27T20:41:23.591Z,1756327283.591 [DAT](INFO): got valid direction response: 20:41:20.3050 LVL= 10608, 13857, 18226, 15411, AGC= 44, IDX= 432, 0.36, 1.777, 0.413,-0.224, 1.066, PHS= 0.799,-0.606,-1.292, RAW= 71.2, 11.9, CAL= 72.2, 19.6, ROT= 77.8, -19.6 2025-08-27T20:41:23.592Z,1756327283.592 [DAT](INFO): DAT read: Bearing 258.6, -29.8 (Local) 2025-08-27T20:41:23.592Z,1756327283.592 [DAT](INFO): Local bearing/azimuth received: Bearing 258.6, -29.8 (Local) 2025-08-27T20:41:23.593Z,1756327283.593 [DAT](INFO): DAT read: Range 10 to 50 : 1.8 m (Round-trip 2.4 ms) speed 0.0 m/s 2025-08-27T20:41:23.594Z,1756327283.594 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:41:23.595Z,1756327283.595 [DAT](INFO): direction in FSK: [0.199080,0.920782,0.335452] 2025-08-27T20:41:23.595Z,1756327283.595 [DAT](INFO): publishing direction and range info 2025-08-27T20:41:45.077Z,1756327305.077 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for water velocity. Device response is::WS,-32768,-32768,-327WE,-32768,-32768,-32768,V 2025-08-27T20:42:54.944Z,1756327374.944 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. Device response is::WD, +0.00, , +0.00,1977.10 2025-08-27T20:43:19.990Z,1756327399.990 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:43:20.098Z,1756327400.098 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:43:20.099Z,1756327400.099 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:43:20.348Z,1756327400.348 [DAT](INFO): DAT read: user:2088> 2025-08-27T20:43:20.349Z,1756327400.349 [DAT](INFO): DAT read: Tx time:20:43:18.1498 2025-08-27T20:43:20.349Z,1756327400.349 [DAT](INFO): Ping request sent. 2025-08-27T20:43:20.349Z,1756327400.349 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:43:20.350Z,1756327400.350 [DAT](INFO): DAT read: TxSync time:20:43:18.1490 2025-08-27T20:43:20.350Z,1756327400.350 [DAT](INFO): publishing transmit ping time 2025-08-27T20:43:20.351Z,1756327400.351 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001571 2025-08-27T20:43:20.600Z,1756327400.600 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250827 2025-08-27T20:43:20.859Z,1756327400.859 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.509696 2025-08-27T20:43:21.121Z,1756327401.121 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.765047 2025-08-27T20:43:21.364Z,1756327401.364 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.014889 2025-08-27T20:43:21.616Z,1756327401.616 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.266924 2025-08-27T20:43:21.868Z,1756327401.868 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.518842 2025-08-27T20:43:22.129Z,1756327402.129 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.777085 2025-08-27T20:43:22.376Z,1756327402.376 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.026759 2025-08-27T20:43:22.629Z,1756327402.629 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.279339 2025-08-27T20:43:22.880Z,1756327402.880 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.530975 2025-08-27T20:43:23.134Z,1756327403.134 [DAT](INFO): DAT read: Rx Time:20:43:20.5563 2025-08-27T20:43:23.152Z,1756327403.152 [DAT](INFO): Rx dataTimestamp_ set to:1756327403.151497 2025-08-27T20:43:23.154Z,1756327403.154 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.804444 2025-08-27T20:43:23.384Z,1756327403.384 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.035139 2025-08-27T20:43:23.643Z,1756327403.643 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.292935 2025-08-27T20:43:23.898Z,1756327403.898 [DAT](INFO): DAT read: 20:43:20.5563 LVL= 10272, 11665, 19298, 16275, AGC= 44, IDX= 432, 0.28, 1.912, 0.666,-0.033, 1.223, PHS= 0.777,-0.510,-1.259, RAW= 68.7, 11.1, CAL= 68.9, 17.9, ROT= 81.1, -17.9 2025-08-27T20:43:23.899Z,1756327403.899 [DAT](INFO): got valid direction response: 20:43:20.5563 LVL= 10272, 11665, 19298, 16275, AGC= 44, IDX= 432, 0.28, 1.912, 0.666,-0.033, 1.223, PHS= 0.777,-0.510,-1.259, RAW= 68.7, 11.1, CAL= 68.9, 17.9, ROT= 81.1, -17.9 2025-08-27T20:43:23.900Z,1756327403.900 [DAT](INFO): DAT read: Bearing 262.2, -28.4 (Local) 2025-08-27T20:43:23.900Z,1756327403.900 [DAT](INFO): Local bearing/azimuth received: Bearing 262.2, -28.4 (Local) 2025-08-27T20:43:23.902Z,1756327403.902 [DAT](INFO): DAT read: Range 10 to 50 : 1.8 m (Round-trip 2.4 ms) speed 0.0 m/s 2025-08-27T20:43:23.902Z,1756327403.902 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:43:23.904Z,1756327403.904 [DAT](INFO): direction in FSK: [0.147222,0.940137,0.307357] 2025-08-27T20:43:23.904Z,1756327403.904 [DAT](INFO): publishing direction and range info 2025-08-27T20:44:04.837Z,1756327444.837 [RDI_Pathfinder](ERROR): only read 1 of 4 data items for bottom velocity. Device response is::BS, +2, +E, -11, +2, +0,A 2025-08-27T20:44:10.085Z,1756327450.085 [RDI_Pathfinder](ERROR): only read 3 of 4 data items for beam range. Device response is::RA, 0.66, 79.26, 80.28, 80.96 2025-08-27T20:45:19.983Z,1756327519.983 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for water velocity. Device response is::WS,-32768,32768,V 2025-08-27T20:45:19.997Z,1756327519.997 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-08-27T20:45:20.240Z,1756327520.240 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:45:20.240Z,1756327520.240 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:45:20.492Z,1756327520.492 [DAT](INFO): DAT read: user:2089> 2025-08-27T20:45:20.493Z,1756327520.493 [DAT](INFO): DAT read: Tx time:20:45:18.3011 2025-08-27T20:45:20.493Z,1756327520.493 [DAT](INFO): Ping request sent. 2025-08-27T20:45:20.493Z,1756327520.493 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:45:20.494Z,1756327520.494 [DAT](INFO): DAT read: TxSync time:20:45:18.3003 2025-08-27T20:45:20.494Z,1756327520.494 [DAT](INFO): publishing transmit ping time 2025-08-27T20:45:20.495Z,1756327520.495 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001557 2025-08-27T20:45:20.744Z,1756327520.744 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250680 2025-08-27T20:45:20.996Z,1756327520.996 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502852 2025-08-27T20:45:21.249Z,1756327521.249 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755395 2025-08-27T20:45:21.500Z,1756327521.500 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006621 2025-08-27T20:45:21.752Z,1756327521.752 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258674 2025-08-27T20:45:22.004Z,1756327522.004 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510800 2025-08-27T20:45:22.256Z,1756327522.256 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762636 2025-08-27T20:45:22.508Z,1756327522.508 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014949 2025-08-27T20:45:22.760Z,1756327522.760 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266702 2025-08-27T20:45:23.012Z,1756327523.012 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518646 2025-08-27T20:45:23.278Z,1756327523.278 [DAT](INFO): DAT read: Rx Time:20:45:20.7078 2025-08-27T20:45:23.279Z,1756327523.279 [DAT](INFO): Rx dataTimestamp_ set to:1756327523.278425 2025-08-27T20:45:23.288Z,1756327523.288 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.793944 2025-08-27T20:45:23.516Z,1756327523.516 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022702 2025-08-27T20:45:23.771Z,1756327523.771 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.276935 2025-08-27T20:45:24.026Z,1756327524.026 [DAT](INFO): DAT read: 20:45:20.7078 LVL= 11184, 15649, 18466, 15955, AGC= 44, IDX= 432,-0.13, 2.006, 0.657, 0.020, 1.255, PHS= 0.839,-0.551,-1.238, RAW= 71.0, 10.4, CAL= 72.3, 16.4, ROT= 77.7, -16.4 2025-08-27T20:45:24.027Z,1756327524.027 [DAT](INFO): got valid direction response: 20:45:20.7078 LVL= 11184, 15649, 18466, 15955, AGC= 44, IDX= 432,-0.13, 2.006, 0.657, 0.020, 1.255, PHS= 0.839,-0.551,-1.238, RAW= 71.0, 10.4, CAL= 72.3, 16.4, ROT= 77.7, -16.4 2025-08-27T20:45:24.028Z,1756327524.028 [DAT](INFO): DAT read: Bearing 258.6, -26.7 (Local) 2025-08-27T20:45:24.028Z,1756327524.028 [DAT](INFO): Local bearing/azimuth received: Bearing 258.6, -26.7 (Local) 2025-08-27T20:45:24.030Z,1756327524.030 [DAT](INFO): DAT read: Range 10 to 50 : 1.8 m (Round-trip 2.4 ms) speed 0.0 m/s 2025-08-27T20:45:24.030Z,1756327524.030 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:45:24.031Z,1756327524.031 [DAT](INFO): direction in FSK: [0.204363,0.937293,0.282341] 2025-08-27T20:45:24.031Z,1756327524.031 [DAT](INFO): publishing direction and range info 2025-08-27T20:45:37.384Z,1756327537.384 [DAT](INFO): DAT read: user:2090>Rx Time:20:45:34.7825 2025-08-27T20:45:37.385Z,1756327537.385 [DAT](INFO): Rx dataTimestamp_ set to:1756327537.384629 2025-08-27T20:45:37.893Z,1756327537.893 [DAT](INFO): DAT read: 20:45:34.7825 LVL= 11088, 12241, 14034, 10819, AGC= 46, IDX= 204, 0.26, 1.889, 0.613,-0.125, 1.128, PHS= 0.849,-0.468,-1.256, RAW= 68.3, 9.5, CAL= 68.8, 14.6, ROT= 81.2, -14.6 2025-08-27T20:45:37.894Z,1756327537.894 [DAT](INFO): got valid direction response: 20:45:34.7825 LVL= 11088, 12241, 14034, 10819, AGC= 46, IDX= 204, 0.26, 1.889, 0.613,-0.125, 1.128, PHS= 0.849,-0.468,-1.256, RAW= 68.3, 9.5, CAL= 68.8, 14.6, ROT= 81.2, -14.6 2025-08-27T20:45:37.895Z,1756327537.895 [DAT](INFO): DAT read: 2025-08-27T20:45:37.896Z,1756327537.896 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-08-27T20:45:37.897Z,1756327537.897 [DAT](INFO): commRate: 600 2025-08-27T20:45:37.897Z,1756327537.897 [DAT](INFO): DAT read: Tx time:20:45:35.8501 2025-08-27T20:45:37.897Z,1756327537.897 [DAT](INFO): Ping request sent. 2025-08-27T20:45:37.898Z,1756327537.898 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:45:37.898Z,1756327537.898 [DAT](INFO): #Rx 2: Read direction message, but no range. 2025-08-27T20:45:37.899Z,1756327537.899 [DAT](INFO): direction in FSK: [0.148046,0.956318,0.252069] 2025-08-27T20:45:37.899Z,1756327537.899 [DAT](INFO): publishing transmit ping time 2025-08-27T20:45:37.902Z,1756327537.902 [DAT](INFO): publishing transmit ping time 2025-08-27T20:45:52.769Z,1756327552.769 [DAT](INFO): DAT read: Rx Time:20:45:50.1327 2025-08-27T20:45:52.770Z,1756327552.770 [DAT](INFO): Rx dataTimestamp_ set to:1756327552.769803 2025-08-27T20:45:53.530Z,1756327553.530 [DAT](INFO): DAT read: 20:45:50.1327 LVL= 10800, 12113, 18370, 16355, AGC= 44, IDX= 461, 0.07,-0.534,-1.786,-2.472,-1.258, PHS= 0.812,-0.481,-1.217, RAW= 69.0, 10.0, CAL= 69.7, 15.6, ROT= 80.3, -15.6 2025-08-27T20:45:53.531Z,1756327553.531 [DAT](INFO): got valid direction response: 20:45:50.1327 LVL= 10800, 12113, 18370, 16355, AGC= 44, IDX= 461, 0.07,-0.534,-1.786,-2.472,-1.258, PHS= 0.812,-0.481,-1.217, RAW= 69.0, 10.0, CAL= 69.7, 15.6, ROT= 80.3, -15.6 2025-08-27T20:45:53.547Z,1756327553.547 [DAT](INFO): DAT read: 2025-08-27T20:45:53.548Z,1756327553.548 [DAT](INFO): DAT read: DATA(0005):stop 2025-08-27T20:45:53.548Z,1756327553.548 [DAT](INFO): Got DATA 5 2025-08-27T20:45:53.548Z,1756327553.548 [DAT](INFO): DAT read: 2025-08-27T20:45:53.549Z,1756327553.549 [DAT](INFO): DAT read: Source:050 Destination:010 2025-08-27T20:45:53.549Z,1756327553.549 [DAT](INFO): Got Src/Dest after DATA 2025-08-27T20:45:53.550Z,1756327553.550 [DAT](INFO): DATA Src=50, Dst=10 2025-08-27T20:45:53.551Z,1756327553.551 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:17.7 AGC:43 SPD:-0.1 CCERR:013 2025-08-27T20:45:53.551Z,1756327553.551 [DAT](INFO): Got CRC:Pass 2025-08-27T20:45:53.551Z,1756327553.551 [DAT](INFO): Got CRC:Pass 2025-08-27T20:45:53.551Z,1756327553.551 [DAT](INFO): Incoming data is intended for us 2025-08-27T20:45:53.552Z,1756327553.552 [DAT](INFO): Received command: stop 2025-08-27T20:45:53.552Z,1756327553.552 [DAT](INFO): #Outgoing data=1 2025-08-27T20:45:53.552Z,1756327553.552 [DAT](INFO): Sending ack 2025-08-27T20:45:53.552Z,1756327553.552 [DAT](INFO): DAT read: 2025-08-27T20:45:53.553Z,1756327553.553 [DAT](INFO): DAT read: 2025-08-27T20:45:53.553Z,1756327553.553 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-08-27T20:45:53.553Z,1756327553.553 [DAT](INFO): #Rx 3: Read direction message, but no range. 2025-08-27T20:45:53.554Z,1756327553.554 [DAT](INFO): direction in FSK: [0.162283,0.949393,0.268920] 2025-08-27T20:45:53.645Z,1756327553.645 [CommandExec](IMPORTANT): got command stop 2025-08-27T20:45:53.645Z,1756327553.645 [CommandExec](IMPORTANT): Scheduling is paused 2025-08-27T20:45:53.645Z,1756327553.645 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2025-08-27T20:45:53.776Z,1756327553.776 [DAT](INFO): setting remote address to 50 2025-08-27T20:45:53.935Z,1756327553.935 [MissionManager](INFO): MissionManager is completed. 2025-08-27T20:45:53.935Z,1756327553.935 [MissionManager](INFO): Uninitializing Mission OnDock 2025-08-27T20:45:53.935Z,1756327553.935 [OnDock] Stopped 2025-08-27T20:45:53.935Z,1756327553.935 [OnDock](DEBUG): Aggregate::uninitialize OnDock 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:StandardEnvelopes] Stopped 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:StandardEnvelopes](DEBUG): Aggregate::uninitialize OnDock:StandardEnvelopes 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:BackseatDriver] Stopped 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:BackseatDriver](DEBUG): Aggregate::uninitialize OnDock:BackseatDriver 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:BackseatDriver:A.BackseatDriver] Stopped 2025-08-27T20:45:53.936Z,1756327553.936 [OnDock:PowerOnly] Stopped 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:PowerOnly](DEBUG): Aggregate::uninitialize OnDock:PowerOnly 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:PowerOnly:E.Wait] Stopped 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:dataRead] Stopped 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:dataRead](DEBUG): Aggregate::uninitialize OnDock:dataRead 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:dataRead:A] Stopped 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:J.] Stopped 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:J.](DEBUG): Uninitializing TrackAcousticContact. 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:PeriodicCheck] Stopped 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:PeriodicCheck](DEBUG): Aggregate::uninitialize OnDock:PeriodicCheck 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:PeriodicCheck:CheckIP] Stopped 2025-08-27T20:45:53.937Z,1756327553.937 [OnDock:PeriodicCheck:CheckIP](DEBUG): Aggregate::uninitialize OnDock:PeriodicCheck:CheckIP 2025-08-27T20:45:53.938Z,1756327553.938 [OnDock:PeriodicCheck:CheckIP:B.Wait] Stopped 2025-08-27T20:45:53.938Z,1756327553.938 [OnDock:PeriodicCheck:CheckIP:B.Wait](DEBUG): Uninitialize Wait Component. 2025-08-27T20:45:53.938Z,1756327553.938 [OnDock:N.Docked] Stopped 2025-08-27T20:45:54.028Z,1756327554.028 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:54.280Z,1756327554.280 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:54.340Z,1756327554.340 [MissionManager](IMPORTANT): Started mission DefaultWithUndock 2025-08-27T20:45:54.340Z,1756327554.340 [DefaultWithUndock] Running Loop=1 2025-08-27T20:45:54.340Z,1756327554.340 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock 2025-08-27T20:45:54.341Z,1756327554.341 [DefaultWithUndock:A.Wait] Running Loop=1 2025-08-27T20:45:54.342Z,1756327554.342 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component. 2025-08-27T20:45:54.532Z,1756327554.532 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:54.784Z,1756327554.784 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:55.036Z,1756327555.036 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:55.288Z,1756327555.288 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:55.540Z,1756327555.540 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:55.792Z,1756327555.792 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:56.044Z,1756327556.044 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:56.296Z,1756327556.296 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:56.548Z,1756327556.548 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:56.800Z,1756327556.800 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:57.052Z,1756327557.052 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:57.304Z,1756327557.304 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:57.599Z,1756327557.599 [DAT](DEBUG): checking for remote address setting acknowledgment 2025-08-27T20:45:57.808Z,1756327557.808 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:45:55.7003 2025-08-27T20:45:57.809Z,1756327557.809 [DAT](DEBUG): Re-entering command mode due to unexpected online mode. 2025-08-27T20:45:57.863Z,1756327557.863 [DAT](INFO): entering command mode 2025-08-27T20:45:57.863Z,1756327557.863 [DAT](ERROR): Failure setting remote address to 50 2025-08-27T20:45:58.060Z,1756327558.060 [DAT](INFO): DAT read: 2025-08-27T20:45:58.060Z,1756327558.060 [DAT](INFO): DAT read: user:2090> 2025-08-27T20:45:58.061Z,1756327558.061 [DAT](INFO): setting remote address to 50 2025-08-27T20:45:58.312Z,1756327558.312 [DAT](INFO): DAT read: user:2090> 2025-08-27T20:45:58.313Z,1756327558.313 [DAT](INFO): DAT read: RemoteAddr | 50 2025-08-27T20:45:58.314Z,1756327558.314 [DAT](INFO): set remote address to 50 2025-08-27T20:45:58.314Z,1756327558.314 [DAT](INFO): entering online mode 2025-08-27T20:45:58.564Z,1756327558.564 [DAT](INFO): DAT read: user:2091> 2025-08-27T20:45:58.565Z,1756327558.565 [DAT](INFO): DAT read: 2025-08-27T20:45:58.566Z,1756327558.566 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-08-27T20:45:58.566Z,1756327558.566 [DAT](INFO): commRate: 600 2025-08-27T20:45:58.566Z,1756327558.566 [DAT](INFO): online mode acknowledged 2025-08-27T20:45:58.566Z,1756327558.566 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-08-27T20:46:01.841Z,1756327561.841 [DAT](INFO): DAT read: Forwarding Delay UpTx time:20:45:59.7003 2025-08-27T20:46:01.841Z,1756327561.841 [DAT](DEBUG): In parseResponses, sent ack so set commsState_ = SENDING_VERIFIED 2025-08-27T20:46:01.841Z,1756327561.841 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-08-27T20:46:24.639Z,1756327584.639 [DefaultWithUndock:A.Wait](INFO): Done Waiting. 2025-08-27T20:46:24.639Z,1756327584.639 [DefaultWithUndock:A.Wait] Stopped 2025-08-27T20:46:24.639Z,1756327584.639 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component. 2025-08-27T20:46:24.640Z,1756327584.640 [DefaultWithUndock:LeaveDock] Running Loop=1 2025-08-27T20:46:24.640Z,1756327584.640 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock 2025-08-27T20:46:24.640Z,1756327584.640 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2025-08-27T20:46:24.640Z,1756327584.640 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact. 2025-08-27T20:46:24.640Z,1756327584.640 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1 2025-08-27T20:46:24.640Z,1756327584.640 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-08-27T20:46:24.640Z,1756327584.640 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-08-27T20:46:25.065Z,1756327585.065 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-08-27T20:46:25.065Z,1756327585.065 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-08-27T20:46:25.066Z,1756327585.066 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detaching from dock at depth 66.173424 m. 2025-08-27T20:46:25.067Z,1756327585.067 [DefaultWithUndock:LeaveDock:A.](ERROR): Failed to read sound speed 2025-08-27T20:46:25.914Z,1756327585.914 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-08-27T20:46:26.034Z,1756327586.034 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-08-27T20:46:27.956Z,1756327587.956 [CTD_Seabird](ERROR): Failed to parse device response: 2025-08-27T20:46:29.537Z,1756327589.537 [DockingStepper](INFO): Changing to mode: 3 2025-08-27T20:46:34.735Z,1756327594.735 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-27T20:46:34.880Z,1756327594.880 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:46:34.931Z,1756327594.931 [DAT](INFO): entering command mode 2025-08-27T20:46:35.132Z,1756327595.132 [DAT](INFO): DAT read: 2025-08-27T20:46:35.132Z,1756327595.132 [DAT](INFO): DAT read: user:2092> 2025-08-27T20:46:35.133Z,1756327595.133 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:46:35.133Z,1756327595.133 [DAT](INFO): setting remote address to 0 2025-08-27T20:46:35.384Z,1756327595.384 [DAT](INFO): DAT read: user:2092> 2025-08-27T20:46:35.385Z,1756327595.385 [DAT](INFO): DAT read: RemoteAddr | 0 2025-08-27T20:46:35.385Z,1756327595.385 [DAT](INFO): set remote address to 0 2025-08-27T20:46:35.386Z,1756327595.386 [DAT](DEBUG): Acoustic response timeout 2025-08-27T20:46:35.386Z,1756327595.386 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:46:35.559Z,1756327595.559 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-27T20:46:35.559Z,1756327595.559 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Engaging thruster for 10.0 seconds (max) to disengage. 2025-08-27T20:46:35.638Z,1756327595.638 [DAT](INFO): DAT read: user:2093> 2025-08-27T20:46:35.640Z,1756327595.640 [DAT](INFO): DAT read: Tx time:20:46:33.4535 2025-08-27T20:46:35.641Z,1756327595.641 [DAT](INFO): Ping request sent. 2025-08-27T20:46:35.641Z,1756327595.641 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:46:35.642Z,1756327595.642 [DAT](INFO): publishing transmit ping time 2025-08-27T20:46:35.643Z,1756327595.643 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001869 2025-08-27T20:46:35.888Z,1756327595.888 [DAT](INFO): DAT read: TxSync time:20:46:33.4527 2025-08-27T20:46:35.889Z,1756327595.889 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.248165 2025-08-27T20:46:36.014Z,1756327596.014 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-27T20:46:36.140Z,1756327596.140 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.499495 2025-08-27T20:46:36.364Z,1756327596.364 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-27T20:46:36.393Z,1756327596.393 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.751965 2025-08-27T20:46:36.645Z,1756327596.645 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.003510 2025-08-27T20:46:36.760Z,1756327596.760 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-27T20:46:36.896Z,1756327596.896 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.255223 2025-08-27T20:46:37.148Z,1756327597.148 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.507416 2025-08-27T20:46:37.190Z,1756327597.190 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-27T20:46:37.400Z,1756327597.400 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.759201 2025-08-27T20:46:37.555Z,1756327597.555 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-27T20:46:37.653Z,1756327597.653 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.012013 2025-08-27T20:46:37.904Z,1756327597.904 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.263360 2025-08-27T20:46:37.970Z,1756327597.970 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-27T20:46:38.156Z,1756327598.156 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.515238 2025-08-27T20:46:38.397Z,1756327598.397 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-27T20:46:38.409Z,1756327598.409 [DAT](INFO): DAT read: Rx Time:20:46:35.8599 2025-08-27T20:46:38.409Z,1756327598.409 [DAT](INFO): Rx dataTimestamp_ set to:1756327598.408729 2025-08-27T20:46:38.410Z,1756327598.410 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.768712 2025-08-27T20:46:38.660Z,1756327598.660 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.019351 2025-08-27T20:46:38.783Z,1756327598.783 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock 2025-08-27T20:46:38.915Z,1756327598.915 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274043 2025-08-27T20:46:39.169Z,1756327599.169 [DAT](INFO): DAT read: 20:46:35.8599 LVL= 13712, 15857, 9314, 21491, AGC= 49, IDX= 103, 0.21, 2.000, 0.705, 0.554, 2.587, PHS=-0.499,-1.835,-2.036, RAW= 83.1, 46.9, CAL= 82.3, 53.2, ROT= 67.7, -53.2 2025-08-27T20:46:39.170Z,1756327599.170 [DAT](INFO): got valid direction response: 20:46:35.8599 LVL= 13712, 15857, 9314, 21491, AGC= 49, IDX= 103, 0.21, 2.000, 0.705, 0.554, 2.587, PHS=-0.499,-1.835,-2.036, RAW= 83.1, 46.9, CAL= 82.3, 53.2, ROT= 67.7, -53.2 2025-08-27T20:46:39.171Z,1756327599.171 [DAT](INFO): DAT read: Bearing 242.0, -62.7 (Local) 2025-08-27T20:46:39.172Z,1756327599.172 [DAT](INFO): Local bearing/azimuth received: Bearing 242.0, -62.7 (Local) 2025-08-27T20:46:39.173Z,1756327599.173 [DAT](INFO): DAT read: Range 10 to 50 : 1.7 m (Round-trip 2.3 ms) speed 0.0 m/s 2025-08-27T20:46:39.174Z,1756327599.174 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:46:39.174Z,1756327599.174 [DAT](INFO): direction in FSK: [0.227303,0.554222,0.800731] 2025-08-27T20:46:39.175Z,1756327599.175 [DAT](INFO): publishing direction and range info 2025-08-27T20:46:44.860Z,1756327604.860 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-27T20:46:44.964Z,1756327604.964 [DAT](INFO): ****** received valid address query ****** 2025-08-27T20:46:44.964Z,1756327604.964 [DAT](INFO): ****** received valid ping request ****** 2025-08-27T20:46:44.964Z,1756327604.964 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:46:45.216Z,1756327605.216 [DAT](INFO): DAT read: user:2094> 2025-08-27T20:46:45.217Z,1756327605.217 [DAT](INFO): DAT read: Tx time:20:46:43.0520 2025-08-27T20:46:45.217Z,1756327605.217 [DAT](INFO): Ping request sent. 2025-08-27T20:46:45.217Z,1756327605.217 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:46:45.217Z,1756327605.217 [DAT](INFO): publishing transmit ping time 2025-08-27T20:46:45.218Z,1756327605.218 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000751 2025-08-27T20:46:45.468Z,1756327605.468 [DAT](INFO): DAT read: TxSync time:20:46:43.0512 2025-08-27T20:46:45.469Z,1756327605.469 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251929 2025-08-27T20:46:45.660Z,1756327605.660 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Thruster off. 2025-08-27T20:46:45.726Z,1756327605.726 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.508432 2025-08-27T20:46:45.976Z,1756327605.976 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.758967 2025-08-27T20:46:46.228Z,1756327606.228 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.011060 2025-08-27T20:46:46.480Z,1756327606.480 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.263022 2025-08-27T20:46:46.732Z,1756327606.732 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.514991 2025-08-27T20:46:46.984Z,1756327606.984 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.767169 2025-08-27T20:46:47.236Z,1756327607.236 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.018950 2025-08-27T20:46:47.488Z,1756327607.488 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.271195 2025-08-27T20:46:47.740Z,1756327607.740 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.523135 2025-08-27T20:46:47.992Z,1756327607.992 [DAT](INFO): DAT read: Rx Time:20:46:45.4598 2025-08-27T20:46:47.993Z,1756327607.993 [DAT](INFO): Rx dataTimestamp_ set to:1756327607.992672 2025-08-27T20:46:47.993Z,1756327607.993 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.776386 2025-08-27T20:46:48.244Z,1756327608.244 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.026942 2025-08-27T20:46:48.499Z,1756327608.499 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.280991 2025-08-27T20:46:48.753Z,1756327608.753 [DAT](INFO): DAT read: 20:46:45.4598 LVL= 17808, 22369, 13858, 22131, AGC= 45, IDX= 432, 0.16, 1.069,-0.586, 0.643, 1.262, PHS=-0.105,-1.801,-0.622, RAW= 132.7, 30.7, CAL= 147.5, 40.5, ROT= 2.5, -40.5 2025-08-27T20:46:48.754Z,1756327608.754 [DAT](INFO): got valid direction response: 20:46:45.4598 LVL= 17808, 22369, 13858, 22131, AGC= 45, IDX= 432, 0.16, 1.069,-0.586, 0.643, 1.262, PHS=-0.105,-1.801,-0.622, RAW= 132.7, 30.7, CAL= 147.5, 40.5, ROT= 2.5, -40.5 2025-08-27T20:46:48.756Z,1756327608.756 [DAT](INFO): DAT read: Bearing 175.4, -40.0 (Local) 2025-08-27T20:46:48.756Z,1756327608.756 [DAT](INFO): Local bearing/azimuth received: Bearing 175.4, -40.0 (Local) 2025-08-27T20:46:48.757Z,1756327608.757 [DAT](INFO): DAT read: Range 10 to 50 : 2.7 m (Round-trip 3.7 ms) speed -0.3 m/s 2025-08-27T20:46:48.758Z,1756327608.758 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:46:48.759Z,1756327608.759 [DAT](INFO): direction in FSK: [0.759682,0.033168,0.649448] 2025-08-27T20:46:48.759Z,1756327608.759 [DAT](INFO): publishing direction and range info 2025-08-27T20:46:54.961Z,1756327614.961 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-27T20:46:55.060Z,1756327615.060 [DAT](INFO): ****** received valid address query ****** 2025-08-27T20:46:55.060Z,1756327615.060 [DAT](INFO): ****** received valid ping request ****** 2025-08-27T20:46:55.060Z,1756327615.060 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:46:55.314Z,1756327615.314 [DAT](INFO): DAT read: user:2095> 2025-08-27T20:46:55.314Z,1756327615.314 [DAT](INFO): DAT read: Tx time:20:46:53.1521 2025-08-27T20:46:55.315Z,1756327615.315 [DAT](INFO): Ping request sent. 2025-08-27T20:46:55.315Z,1756327615.315 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:46:55.315Z,1756327615.315 [DAT](INFO): publishing transmit ping time 2025-08-27T20:46:55.316Z,1756327615.316 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000904 2025-08-27T20:46:55.564Z,1756327615.564 [DAT](INFO): DAT read: TxSync time:20:46:53.1513 2025-08-27T20:46:55.565Z,1756327615.565 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250057 2025-08-27T20:46:55.817Z,1756327615.817 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502150 2025-08-27T20:46:56.068Z,1756327616.068 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.753099 2025-08-27T20:46:56.320Z,1756327616.320 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.005170 2025-08-27T20:46:56.572Z,1756327616.572 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.257547 2025-08-27T20:46:56.826Z,1756327616.826 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510845 2025-08-27T20:46:57.076Z,1756327617.076 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.761150 2025-08-27T20:46:57.332Z,1756327617.332 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015782 2025-08-27T20:46:57.580Z,1756327617.580 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.265227 2025-08-27T20:46:57.832Z,1756327617.832 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.517187 2025-08-27T20:46:58.085Z,1756327618.085 [DAT](INFO): DAT read: Rx Time:20:46:55.5636 2025-08-27T20:46:58.085Z,1756327618.085 [DAT](INFO): Rx dataTimestamp_ set to:1756327618.085094 2025-08-27T20:46:58.086Z,1756327618.086 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771010 2025-08-27T20:46:58.339Z,1756327618.339 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023467 2025-08-27T20:46:58.588Z,1756327618.588 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.273254 2025-08-27T20:46:58.845Z,1756327618.845 [DAT](INFO): DAT read: 20:46:55.5636 LVL= 24128, 32753, 19650, 31603, AGC= 54, IDX= 456, 0.09, 2.381, 0.620, 2.273, 1.902, PHS= 0.566,-1.236, 0.367, RAW= 144.2, 3.6, CAL= 147.4, -5.0, ROT= 2.6, 5.0 2025-08-27T20:46:58.846Z,1756327618.846 [DAT](INFO): got valid direction response: 20:46:55.5636 LVL= 24128, 32753, 19650, 31603, AGC= 54, IDX= 456, 0.09, 2.381, 0.620, 2.273, 1.902, PHS= 0.566,-1.236, 0.367, RAW= 144.2, 3.6, CAL= 147.4, -5.0, ROT= 2.6, 5.0 2025-08-27T20:46:58.848Z,1756327618.848 [DAT](INFO): DAT read: Bearing 185.4, 4.5 (Local) 2025-08-27T20:46:58.848Z,1756327618.848 [DAT](INFO): Local bearing/azimuth received: Bearing 185.4, 4.5 (Local) 2025-08-27T20:46:58.849Z,1756327618.849 [DAT](INFO): DAT read: Range 10 to 50 : 5.5 m (Round-trip 7.4 ms) speed -0.3 m/s 2025-08-27T20:46:58.850Z,1756327618.850 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:46:58.851Z,1756327618.851 [DAT](INFO): direction in FSK: [0.995169,0.045190,-0.087156] 2025-08-27T20:46:58.851Z,1756327618.851 [DAT](INFO): publishing direction and range info 2025-08-27T20:47:05.059Z,1756327625.059 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-27T20:47:05.140Z,1756327625.140 [DAT](INFO): ****** received valid address query ****** 2025-08-27T20:47:05.140Z,1756327625.140 [DAT](INFO): ****** received valid ping request ****** 2025-08-27T20:47:05.140Z,1756327625.140 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:47:05.392Z,1756327625.392 [DAT](INFO): DAT read: user:2096> 2025-08-27T20:47:05.393Z,1756327625.393 [DAT](INFO): DAT read: Tx time:20:47:03.2022 2025-08-27T20:47:05.394Z,1756327625.394 [DAT](INFO): Ping request sent. 2025-08-27T20:47:05.394Z,1756327625.394 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:47:05.396Z,1756327625.396 [DAT](INFO): DAT read: TxSync time:20:47:03.2014 2025-08-27T20:47:05.398Z,1756327625.398 [DAT](INFO): publishing transmit ping time 2025-08-27T20:47:05.400Z,1756327625.400 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.005960 2025-08-27T20:47:05.646Z,1756327625.646 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251741 2025-08-27T20:47:05.898Z,1756327625.898 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503836 2025-08-27T20:47:06.148Z,1756327626.148 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754334 2025-08-27T20:47:06.404Z,1756327626.404 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.009528 2025-08-27T20:47:06.653Z,1756327626.653 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259135 2025-08-27T20:47:06.904Z,1756327626.904 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510324 2025-08-27T20:47:07.156Z,1756327627.156 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762364 2025-08-27T20:47:07.411Z,1756327627.411 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.016740 2025-08-27T20:47:07.660Z,1756327627.660 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266341 2025-08-27T20:47:07.912Z,1756327627.912 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518471 2025-08-27T20:47:08.164Z,1756327628.164 [DAT](INFO): DAT read: Rx Time:20:47:05.6170 2025-08-27T20:47:08.165Z,1756327628.165 [DAT](INFO): Rx dataTimestamp_ set to:1756327628.164417 2025-08-27T20:47:08.165Z,1756327628.165 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771507 2025-08-27T20:47:08.416Z,1756327628.416 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022341 2025-08-27T20:47:08.671Z,1756327628.671 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.276873 2025-08-27T20:47:08.925Z,1756327628.925 [DAT](INFO): DAT read: 20:47:05.6170 LVL= 29936, 32753, 23858, 32755, AGC= 58, IDX= 458,-0.10, 2.874, 1.252, 2.741, 2.600, PHS= 0.362,-1.301, 0.138, RAW= 142.9, 10.3, CAL= 145.5, 2.9, ROT= 4.5, -2.9 2025-08-27T20:47:08.926Z,1756327628.926 [DAT](INFO): got valid direction response: 20:47:05.6170 LVL= 29936, 32753, 23858, 32755, AGC= 58, IDX= 458,-0.10, 2.874, 1.252, 2.741, 2.600, PHS= 0.362,-1.301, 0.138, RAW= 142.9, 10.3, CAL= 145.5, 2.9, ROT= 4.5, -2.9 2025-08-27T20:47:08.928Z,1756327628.928 [DAT](INFO): DAT read: Bearing 185.8, -3.6 (Local) 2025-08-27T20:47:08.928Z,1756327628.928 [DAT](INFO): Local bearing/azimuth received: Bearing 185.8, -3.6 (Local) 2025-08-27T20:47:08.930Z,1756327628.930 [DAT](INFO): DAT read: Range 10 to 50 : 8.0 m (Round-trip 10.7 ms) speed -0.2 m/s 2025-08-27T20:47:08.930Z,1756327628.930 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:47:08.931Z,1756327628.931 [DAT](INFO): direction in FSK: [0.995641,0.078359,0.050593] 2025-08-27T20:47:08.931Z,1756327628.931 [DAT](INFO): publishing direction and range info 2025-08-27T20:47:09.073Z,1756327629.073 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2025-08-27T20:47:15.133Z,1756327635.133 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-27T20:47:15.224Z,1756327635.224 [DAT](INFO): ****** received valid address query ****** 2025-08-27T20:47:15.224Z,1756327635.224 [DAT](INFO): ****** received valid ping request ****** 2025-08-27T20:47:15.224Z,1756327635.224 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:47:15.476Z,1756327635.476 [DAT](INFO): DAT read: user:2097> 2025-08-27T20:47:15.477Z,1756327635.477 [DAT](INFO): DAT read: Tx time:20:47:13.3023 2025-08-27T20:47:15.477Z,1756327635.477 [DAT](INFO): Ping request sent. 2025-08-27T20:47:15.477Z,1756327635.477 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:47:15.477Z,1756327635.477 [DAT](INFO): publishing transmit ping time 2025-08-27T20:47:15.478Z,1756327635.478 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000765 2025-08-27T20:47:15.728Z,1756327635.728 [DAT](INFO): DAT read: TxSync time:20:47:13.3015 2025-08-27T20:47:15.729Z,1756327635.729 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251762 2025-08-27T20:47:15.982Z,1756327635.982 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.504154 2025-08-27T20:47:16.232Z,1756327636.232 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755018 2025-08-27T20:47:16.484Z,1756327636.484 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006881 2025-08-27T20:47:16.736Z,1756327636.736 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258915 2025-08-27T20:47:16.988Z,1756327636.988 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510826 2025-08-27T20:47:17.240Z,1756327637.240 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762894 2025-08-27T20:47:17.498Z,1756327637.498 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.020606 2025-08-27T20:47:17.746Z,1756327637.746 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.268260 2025-08-27T20:47:17.996Z,1756327637.996 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518917 2025-08-27T20:47:18.248Z,1756327638.248 [DAT](INFO): DAT read: Rx Time:20:47:15.7205 2025-08-27T20:47:18.249Z,1756327638.249 [DAT](INFO): Rx dataTimestamp_ set to:1756327638.248336 2025-08-27T20:47:18.249Z,1756327638.249 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771889 2025-08-27T20:47:18.500Z,1756327638.500 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023078 2025-08-27T20:47:18.752Z,1756327638.752 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274960 2025-08-27T20:47:19.009Z,1756327639.009 [DAT](INFO): DAT read: 20:47:15.7205 LVL= 26080, 32753, 20050, 32755, AGC= 58, IDX= 460,-0.19, 0.278,-1.171, 0.522, 0.132, PHS= 0.235,-1.256, 0.388, RAW= 154.8, 8.1, CAL= 155.0, -1.2, ROT= 355.0, 1.2 2025-08-27T20:47:19.010Z,1756327639.010 [DAT](INFO): got valid direction response: 20:47:15.7205 LVL= 26080, 32753, 20050, 32755, AGC= 58, IDX= 460,-0.19, 0.278,-1.171, 0.522, 0.132, PHS= 0.235,-1.256, 0.388, RAW= 154.8, 8.1, CAL= 155.0, -1.2, ROT= 355.0, 1.2 2025-08-27T20:47:19.011Z,1756327639.011 [DAT](INFO): DAT read: Bearing 177.2, 2.2 (Local) 2025-08-27T20:47:19.012Z,1756327639.012 [DAT](INFO): Local bearing/azimuth received: Bearing 177.2, 2.2 (Local) 2025-08-27T20:47:19.013Z,1756327639.013 [DAT](INFO): DAT read: Range 10 to 50 : 10.5 m (Round-trip 14.0 ms) speed -0.1 m/s 2025-08-27T20:47:19.014Z,1756327639.014 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:47:19.015Z,1756327639.015 [DAT](INFO): direction in FSK: [0.995976,-0.087136,-0.020942] 2025-08-27T20:47:19.015Z,1756327639.015 [DAT](INFO): publishing direction and range info 2025-08-27T20:47:25.254Z,1756327645.254 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-27T20:47:25.308Z,1756327645.308 [DAT](INFO): ****** received valid address query ****** 2025-08-27T20:47:25.308Z,1756327645.308 [DAT](INFO): ****** received valid ping request ****** 2025-08-27T20:47:25.309Z,1756327645.309 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:47:25.560Z,1756327645.560 [DAT](INFO): DAT read: user:2098> 2025-08-27T20:47:25.561Z,1756327645.561 [DAT](INFO): DAT read: Tx time:20:47:23.4024 2025-08-27T20:47:25.561Z,1756327645.561 [DAT](INFO): Ping request sent. 2025-08-27T20:47:25.561Z,1756327645.561 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:47:25.561Z,1756327645.561 [DAT](INFO): publishing transmit ping time 2025-08-27T20:47:25.562Z,1756327645.562 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000767 2025-08-27T20:47:25.812Z,1756327645.812 [DAT](INFO): DAT read: TxSync time:20:47:23.4016 2025-08-27T20:47:25.813Z,1756327645.813 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251729 2025-08-27T20:47:26.064Z,1756327646.064 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502734 2025-08-27T20:47:26.316Z,1756327646.316 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754836 2025-08-27T20:47:26.568Z,1756327646.568 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006790 2025-08-27T20:47:26.825Z,1756327646.825 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.263290 2025-08-27T20:47:27.076Z,1756327647.076 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.514847 2025-08-27T20:47:27.335Z,1756327647.335 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.773499 2025-08-27T20:47:27.588Z,1756327647.588 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.026822 2025-08-27T20:47:27.840Z,1756327647.840 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.278883 2025-08-27T20:47:28.105Z,1756327648.105 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.543907 2025-08-27T20:47:28.356Z,1756327648.356 [DAT](INFO): DAT read: Rx Time:20:47:25.8235 2025-08-27T20:47:28.357Z,1756327648.357 [DAT](INFO): Rx dataTimestamp_ set to:1756327648.356357 2025-08-27T20:47:28.357Z,1756327648.357 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.795916 2025-08-27T20:47:28.608Z,1756327648.608 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.046883 2025-08-27T20:47:28.860Z,1756327648.860 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.298876 2025-08-27T20:47:29.118Z,1756327649.118 [DAT](INFO): DAT read: 20:47:25.8235 LVL= 24496, 32753, 16818, 32755, AGC= 55, IDX= 458,-0.05, 2.410, 1.076, 2.957, 2.315, PHS= 0.183,-1.192, 0.639, RAW= 163.8, 4.5, CAL= 164.3, -4.6, ROT= 345.7, 4.6 2025-08-27T20:47:29.119Z,1756327649.119 [DAT](INFO): got valid direction response: 20:47:25.8235 LVL= 24496, 32753, 16818, 32755, AGC= 55, IDX= 458,-0.05, 2.410, 1.076, 2.957, 2.315, PHS= 0.183,-1.192, 0.639, RAW= 163.8, 4.5, CAL= 164.3, -4.6, ROT= 345.7, 4.6 2025-08-27T20:47:29.120Z,1756327649.120 [DAT](INFO): DAT read: Bearing 168.7, 7.3 (Local) 2025-08-27T20:47:29.120Z,1756327649.120 [DAT](INFO): Local bearing/azimuth received: Bearing 168.7, 7.3 (Local) 2025-08-27T20:47:29.121Z,1756327649.121 [DAT](INFO): DAT read: Range 10 to 50 : 12.6 m (Round-trip 16.9 ms) speed -0.3 m/s 2025-08-27T20:47:29.122Z,1756327649.122 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:47:29.123Z,1756327649.123 [DAT](INFO): direction in FSK: [0.965895,-0.246203,-0.080199] 2025-08-27T20:47:29.123Z,1756327649.123 [DAT](INFO): publishing direction and range info 2025-08-27T20:47:29.292Z,1756327649.292 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: 12.60 m. Transitioning docking module to standby. 2025-08-27T20:47:29.704Z,1756327649.704 [DockingStepper](INFO): Changing to mode: 1 2025-08-27T20:47:35.336Z,1756327655.336 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact *** 2025-08-27T20:47:35.416Z,1756327655.416 [DAT](INFO): ****** received valid address query ****** 2025-08-27T20:47:35.416Z,1756327655.416 [DAT](INFO): ****** received valid ping request ****** 2025-08-27T20:47:35.416Z,1756327655.416 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-08-27T20:47:35.668Z,1756327655.668 [DAT](INFO): DAT read: user:2099> 2025-08-27T20:47:35.669Z,1756327655.669 [DAT](INFO): DAT read: Tx time:20:47:33.5025 2025-08-27T20:47:35.669Z,1756327655.669 [DAT](INFO): Ping request sent. 2025-08-27T20:47:35.669Z,1756327655.669 [DAT](INFO): transmitted an acoustic signal 2025-08-27T20:47:35.669Z,1756327655.669 [DAT](INFO): publishing transmit ping time 2025-08-27T20:47:35.670Z,1756327655.670 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000772 2025-08-27T20:47:35.747Z,1756327655.747 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby. 2025-08-27T20:47:35.920Z,1756327655.920 [DAT](INFO): DAT read: TxSync time:20:47:33.5017 2025-08-27T20:47:35.921Z,1756327655.921 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.252130 2025-08-27T20:47:36.167Z,1756327656.167 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete. 2025-08-27T20:47:36.167Z,1756327656.167 [DefaultWithUndock:LeaveDock:B.Undock] Stopped 2025-08-27T20:47:36.168Z,1756327656.168 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock 2025-08-27T20:47:36.168Z,1756327656.168 [DefaultWithUndock:LeaveDock] Stopped 2025-08-27T20:47:36.168Z,1756327656.168 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock 2025-08-27T20:47:36.168Z,1756327656.168 [DefaultWithUndock:LeaveDock:A.] Stopped 2025-08-27T20:47:36.168Z,1756327656.168 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact. 2025-08-27T20:47:36.168Z,1756327656.168 [DefaultWithUndock:SurfaceDefault] Running Loop=1 2025-08-27T20:47:36.169Z,1756327656.169 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault 2025-08-27T20:47:36.169Z,1756327656.169 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1 2025-08-27T20:47:36.169Z,1756327656.169 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-27T20:47:36.169Z,1756327656.169 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-08-27T20:47:36.169Z,1756327656.169 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-08-27T20:47:36.170Z,1756327656.170 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-08-27T20:47:36.170Z,1756327656.170 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-08-27T20:47:36.170Z,1756327656.170 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-27T20:47:36.170Z,1756327656.170 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-27T20:47:36.172Z,1756327656.172 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503109 2025-08-27T20:47:36.424Z,1756327656.424 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755102 2025-08-27T20:47:36.676Z,1756327656.676 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.007237 2025-08-27T20:47:36.928Z,1756327656.928 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259090 2025-08-27T20:47:37.119Z,1756327657.119 [Radio_Surface](INFO): Powering up 2025-08-27T20:47:37.180Z,1756327657.180 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510923 2025-08-27T20:47:37.432Z,1756327657.432 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762970 2025-08-27T20:47:37.684Z,1756327657.684 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015030 2025-08-27T20:47:37.940Z,1756327657.940 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.269790 2025-08-27T20:47:38.188Z,1756327658.188 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519080 2025-08-27T20:47:38.440Z,1756327658.440 [DAT](INFO): DAT read: Rx Time:20:47:35.9261 2025-08-27T20:47:38.441Z,1756327658.441 [DAT](INFO): Rx dataTimestamp_ set to:1756327658.440410 2025-08-27T20:47:38.441Z,1756327658.441 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772094 2025-08-27T20:47:38.692Z,1756327658.692 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022929 2025-08-27T20:47:38.945Z,1756327658.945 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275666 2025-08-27T20:47:39.202Z,1756327659.202 [DAT](INFO): DAT read: 20:47:35.9261 LVL= 21888, 32753, 14450, 32755, AGC= 58, IDX= 452,-0.32, 3.078, 1.953,-2.545, 3.071, PHS= 0.095,-1.071, 0.665, RAW= 168.8, 4.1, CAL= 169.1, -4.9, ROT= 340.9, 4.9 2025-08-27T20:47:39.203Z,1756327659.203 [DAT](INFO): got valid direction response: 20:47:35.9261 LVL= 21888, 32753, 14450, 32755, AGC= 58, IDX= 452,-0.32, 3.078, 1.953,-2.545, 3.071, PHS= 0.095,-1.071, 0.665, RAW= 168.8, 4.1, CAL= 169.1, -4.9, ROT= 340.9, 4.9 2025-08-27T20:47:39.204Z,1756327659.204 [DAT](INFO): DAT read: Bearing 163.9, 8.4 (Local) 2025-08-27T20:47:39.205Z,1756327659.205 [DAT](INFO): Local bearing/azimuth received: Bearing 163.9, 8.4 (Local) 2025-08-27T20:47:39.206Z,1756327659.206 [DAT](INFO): DAT read: Range 10 to 50 : 14.6 m (Round-trip 19.5 ms) speed -0.2 m/s 2025-08-27T20:47:39.207Z,1756327659.207 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-08-27T20:47:39.208Z,1756327659.208 [DAT](INFO): direction in FSK: [0.941495,-0.326022,-0.085417] 2025-08-27T20:47:39.208Z,1756327659.208 [DAT](INFO): publishing direction and range info 2025-08-27T20:47:42.373Z,1756327662.373 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.10 2025-08-27T20:47:42.373Z,1756327662.373 [Radio_Surface](INFO): No local IP found 2025-08-27T20:47:45.066Z,1756327665.066 [RDI_Pathfinder](ERROR): only read 1 of 4 data items for beam range. Device response is::RA, 76.87, 84.02 2025-08-27T20:49:47.445Z,1756327787.445 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1 2025-08-27T20:49:47.445Z,1756327787.445 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-08-27T20:49:47.445Z,1756327787.445 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1 2025-08-27T20:50:20.151Z,1756327820.151 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-27T20:50:20.235Z,1756327820.235 [NAL9602](ERROR): received: +CSQ:0 OK669, 2, 0, 0, 0 OK 2025-08-27T20:50:46.203Z,1756327846.203 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:50:47.207Z,1756327847.207 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-27T20:50:47.207Z,1756327847.207 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:50:52.066Z,1756327852.066 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-27T20:51:00.957Z,1756327860.957 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205100.00,A,3646.74301,N,12151.53056,W,0.350,199.50,270825,,,A*77 2025-08-27T20:51:00.959Z,1756327860.959 [NAL9602](INFO): GPS fix at 20250827T205100: (36.779050, -121.858843) 2025-08-27T20:51:00.972Z,1756327860.972 [UniversalFixResidualReporter](INFO): Fix residual: 2.5 %DT, over the last 3430.5 m. Residual distance 86.5 m at bearing 47.6 degrees. Fix at (36.7790, -121.8588) with 287.0 m made good. 2025-08-27T20:51:00.973Z,1756327860.973 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped 2025-08-27T20:51:00.973Z,1756327860.973 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1 2025-08-27T20:51:17.339Z,1756327877.339 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:51:18.343Z,1756327878.343 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:51:31.658Z,1756327891.658 [NAL9602](ERROR): Queried for signal strength and failed to receive proper response. 2025-08-27T20:51:31.735Z,1756327891.735 [NAL9602](ERROR): received: +CSQ:0 OK669, 2, 0, 0, 0 OK 2025-08-27T20:51:36.333Z,1756327896.333 [DataOverHttps](IMPORTANT): SBD MTMSN=20250827T205135 2025-08-27T20:51:36.337Z,1756327896.337 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004087 2025-08-27T20:51:45.760Z,1756327905.760 [DataOverHttps](INFO): Sending 202 bytes from file Logs/20250827T173616/Courier0012.lzma 2025-08-27T20:51:45.763Z,1756327905.763 [DataOverHttps](INFO): Received command: load Transport/transit.tl;set transit.MissionTimeout 120 min;set transit.NeedCommsTime 20 min;set transit.Latitude 36.806966 degree;set transit.Longitude -121.824326 degree;set transit.Depth 7 m;set transit.Speed 1.2 m/s;run 2025-08-27T20:51:45.849Z,1756327905.849 [CommandExec](IMPORTANT): got command load ./Missions/Transport/transit.tl 2025-08-27T20:51:45.849Z,1756327905.849 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/transit.tl 2025-08-27T20:51:45.850Z,1756327905.850 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/transit.tl 2025-08-27T20:51:45.862Z,1756327905.862 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/transit.tl 2025-08-27T20:51:46.895Z,1756327906.895 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/transit.tl translated into: 60 30 NaN NaN 0 0 10 1 20 1 7 1 2025-08-27T20:51:46.909Z,1756327906.909 [MissionManager](INFO): DefineArg transit.MissionTimeout = 60.000000 min 2025-08-27T20:51:46.917Z,1756327906.917 [MissionManager](INFO): DefineArg transit.NeedCommsTime = 30.000000 min 2025-08-27T20:51:46.924Z,1756327906.924 [MissionManager](INFO): DefineArg transit.Latitude = nan arcdeg 2025-08-27T20:51:46.947Z,1756327906.947 [MissionManager](INFO): DefineArg transit.Longitude = nan arcdeg 2025-08-27T20:51:46.950Z,1756327906.950 [MissionManager](INFO): DefineArg transit.Northings = 0.000000 m 2025-08-27T20:51:46.961Z,1756327906.961 [MissionManager](INFO): DefineArg transit.Eastings = 0.000000 m 2025-08-27T20:51:46.969Z,1756327906.969 [MissionManager](INFO): DefineArg transit.Depth = 10.000000 m 2025-08-27T20:51:46.984Z,1756327906.984 [MissionManager](INFO): DefineArg transit.Speed = 1.000000 m/s 2025-08-27T20:51:46.996Z,1756327906.996 [MissionManager](INFO): DefineArg transit.MaxDepth = 20.000000 m 2025-08-27T20:51:46.999Z,1756327906.999 [MissionManager](INFO): DefineArg transit.MinOffshore = 1.000000 km 2025-08-27T20:51:47.030Z,1756327907.030 [MissionManager](INFO): DefineArg transit.MinAltitude = 7.000000 m 2025-08-27T20:51:47.061Z,1756327907.061 [MissionManager](INFO): DefineArg transit.MassHold = 1 bool 2025-08-27T20:51:47.080Z,1756327907.080 [MissionManager](INFO): DefineArg transit.BuoyancyHold = 1 bool 2025-08-27T20:51:47.080Z,1756327907.080 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl 2025-08-27T20:51:47.080Z,1756327907.080 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl 2025-08-27T20:51:47.084Z,1756327907.084 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl 2025-08-27T20:51:47.509Z,1756327907.509 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/NeedComms.tl translated into: 1 10 20 NaN 1 1000 7 30 0 last time_fix was: first GPS update timeout Comms timed out after minutes second GPS update timeout 2025-08-27T20:51:47.516Z,1756327907.516 [MissionManager](INFO): DefineArg transit:NeedComms.DiveInterval = 1.000000 h 2025-08-27T20:51:47.527Z,1756327907.527 [MissionManager](INFO): DefineArg transit:NeedComms.WaitForPitchUp = 10.000000 min 2025-08-27T20:51:47.531Z,1756327907.531 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacePitch = 20.000000 arcdeg 2025-08-27T20:51:47.534Z,1756327907.534 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceDepthRate = nan m/s 2025-08-27T20:51:47.549Z,1756327907.549 [MissionManager](INFO): DefineArg transit:NeedComms.SurfaceSpeed = 1.000000 m/s 2025-08-27T20:51:47.554Z,1756327907.554 [MissionManager](INFO): DefineArg transit:NeedComms.SurfacingTimeout = 1000.000000 s 2025-08-27T20:51:47.570Z,1756327907.570 [MissionManager](INFO): DefineArg transit:NeedComms.GPSTimeout = 7.000000 min 2025-08-27T20:51:47.577Z,1756327907.577 [MissionManager](INFO): DefineArg transit:NeedComms.CommsTimeout = 30.000000 min 2025-08-27T20:51:47.590Z,1756327907.590 [transit:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface. 2025-08-27T20:51:47.661Z,1756327907.661 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl 2025-08-27T20:51:47.662Z,1756327907.662 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl 2025-08-27T20:51:47.663Z,1756327907.663 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl 2025-08-27T20:51:47.794Z,1756327907.794 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into: 5 1.5 200 2000 2025-08-27T20:51:47.799Z,1756327907.799 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinAltitude = 5.000000 m 2025-08-27T20:51:47.802Z,1756327907.802 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepthIgnore = 1.500000 m 2025-08-27T20:51:47.806Z,1756327907.806 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MaxDepth = 200.000000 m 2025-08-27T20:51:47.809Z,1756327907.809 [MissionManager](INFO): DefineArg transit:StandardEnvelopes.MinOffshore = 2000.000000 m 2025-08-27T20:51:47.810Z,1756327907.810 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2025-08-27T20:51:47.861Z,1756327907.861 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2025-08-27T20:51:47.894Z,1756327907.894 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2025-08-27T20:51:47.923Z,1756327907.923 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-08-27T20:51:47.940Z,1756327907.940 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-08-27T20:51:47.948Z,1756327907.948 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-08-27T20:51:48.023Z,1756327908.023 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-08-27T20:51:48.035Z,1756327908.035 [MissionManager](INFO): DefineArg transit:BackseatDriver.EnableBackseat = 0 bool 2025-08-27T20:51:48.038Z,1756327908.038 [transit:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-08-27T20:51:48.041Z,1756327908.041 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-08-27T20:51:48.041Z,1756327908.041 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-08-27T20:51:48.042Z,1756327908.042 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-08-27T20:51:48.325Z,1756327908.325 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-08-27T20:51:48.362Z,1756327908.362 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleAll = 0 bool 2025-08-27T20:51:48.376Z,1756327908.376 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad1 = 0 bool 2025-08-27T20:51:48.383Z,1756327908.383 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad2 = 0 bool 2025-08-27T20:51:48.386Z,1756327908.386 [MissionManager](INFO): DefineArg transit:PowerOnly.SampleLoad3 = 0 bool 2025-08-27T20:51:48.398Z,1756327908.398 [MissionManager](INFO): DefineArg transit:PowerOnly.EnabledPowerOnly = 0 bool 2025-08-27T20:51:48.415Z,1756327908.415 [transit:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-08-27T20:51:48.421Z,1756327908.421 [transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy. 2025-08-27T20:51:48.430Z,1756327908.430 [transit:MassHold.Pitch](DEBUG): Construct. 2025-08-27T20:51:48.446Z,1756327908.446 [transit:Transit:A.Pitch](DEBUG): Construct. 2025-08-27T20:51:48.460Z,1756327908.460 [transit:Transit:B.SetSpeed](DEBUG): Construct. 2025-08-27T20:51:48.468Z,1756327908.468 [transit:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2025-08-27T20:51:48.510Z,1756327908.510 [MissionManager](DEBUG): # Copyright (c) 2024 MBARI # MBARI Proprietary Information. Confidential. All Rights Reserved # Unauthorized copying or distribution of this file via any medium is strictly # prohibited. # # WARNING - This file contains information whose export is restricted by the # Export Administration Act of 1979 (Title 50, U.S.C., App. 2401 et seq.), as # amended. Violations of these export laws are subject to severe civil and/or # criminal penalties. mission transit { """ Vehicle dives immediately with no comms/GPS and transits to desired waypoint and can be commanded to use/hold mass or buoyancy. """ arguments { MissionTimeout = 60 minute """ Maximum duration of mission """ NeedCommsTime = 30 minute """ How often to surface for commumications """ Latitude = NaN degree """ Latitude of waypoint to seek. If set to NaN, uses latitude at mission initialization. """ Longitude = NaN degree """ Longitude of waypoint to seek. If set to NaN, uses longitude at mission initialization. """ Northings = 0 meter """ Northward distance of the waypoint to seek. If combined with Latitude and/or Longitude, this is an offset from the specified Latitude and/or Longitude. """ Eastings = 0 meter """ Eastward distance of the waypoint to seek. If combined with Latitude and/or Longitude, this is an offset from the specified Latitude and/or Longitude. """ Depth = 10 meter """ Depth of flat and level flight during the mission. """ Speed = 1 meter_per_second """ Speed of vehicle (relative to water) during the mission. """ MaxDepth = 20 meter """ Maximum depth for the entire mission. """ MinOffshore = 1 kilometer """ Minimum distance offshore for the entire mission. """ MinAltitude = 7 meter """ Minimum height above the sea floor for the entire mission. """ MassHold = true """ Set to True in order to hold mass at default position, False to allow mass to run on its own. """ BuoyancyHold = true """ Set to True in order to hold buoyancy at neutral position, False to allow buoyancy to run on its own. """ } timeout duration=MissionTimeout insert id="NeedComms" Insert/NeedComms.tl assign in sequence NeedComms:DiveInterval = NeedCommsTime assign in sequence NeedComms:WaitForPitchUp = 1 second insert Insert/StandardEnvelopes.tl assign in sequence StandardEnvelopes:MinAltitude = MinAltitude assign in sequence StandardEnvelopes:MaxDepth = MaxDepth assign in sequence StandardEnvelopes:MinOffshore = MinOffshore insert Insert/BackseatDriver.tl insert Insert/PowerOnly.tl behavior Guidance:Buoyancy id="BuoyancyHold" { run while ( BuoyancyHold ) set position = Control:VerticalControl.buoyancyNeutral } behavior Guidance:Pitch id="MassHold" { run while ( MassHold ) set massPosition = Control:VerticalControl.massDefault } aggregate Transit { run in sequence behavior Guidance:Pitch { run in parallel set depth = Depth } behavior Guidance:SetSpeed { run in parallel set speed = Speed } behavior Guidance:Waypoint id="Wpt1" { run in sequence set latitude = Latitude set longitude = Longitude set northingsDelta = Northings set eastingsDelta = Eastings } call id="PhoneHome" priorityHere=false refId="NeedComms" } } 2025-08-27T20:51:48.516Z,1756327908.516 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/transit.tl id=transit 2025-08-27T20:51:57.306Z,1756327917.306 [DataOverHttps](INFO): Moved sent file to Logs/20250827T173616/Courier0012.lzma.bak 2025-08-27T20:51:57.306Z,1756327917.306 [DataOverHttps](INFO): SBD MOMSN=25906521 2025-08-27T20:52:02.048Z,1756327922.048 [NAL9602](INFO): SBD MO Status=2, MOMSN=49669, MT Status=2, MTMSN=0 2025-08-27T20:52:02.048Z,1756327922.048 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-27T20:52:21.195Z,1756327941.195 [CommandExec](IMPORTANT): got command set transit.MissionTimeout 120 minute 2025-08-27T20:52:21.196Z,1756327941.196 [CommandExec](IMPORTANT): got command set transit.NeedCommsTime 20 minute 2025-08-27T20:52:21.197Z,1756327941.197 [CommandExec](IMPORTANT): got command set transit.Latitude 36.806966 degree 2025-08-27T20:52:21.198Z,1756327941.198 [CommandExec](IMPORTANT): got command set transit.Longitude -121.824326 degree 2025-08-27T20:52:21.198Z,1756327941.198 [CommandExec](IMPORTANT): got command set transit.Depth 7 meter 2025-08-27T20:52:21.199Z,1756327941.199 [CommandExec](IMPORTANT): got command set transit.Speed 1.2 meter_per_second 2025-08-27T20:52:21.200Z,1756327941.200 [CommandExec](IMPORTANT): got command run 2025-08-27T20:52:21.202Z,1756327941.202 [CommandExec](IMPORTANT): Running 2025-08-27T20:52:21.403Z,1756327941.403 [DefaultWithUndock] Stopped 2025-08-27T20:52:21.403Z,1756327941.403 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock 2025-08-27T20:52:21.404Z,1756327941.404 [DefaultWithUndock:SurfaceDefault] Stopped 2025-08-27T20:52:21.404Z,1756327941.404 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault 2025-08-27T20:52:21.404Z,1756327941.404 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Stopped 2025-08-27T20:52:21.404Z,1756327941.404 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-27T20:52:21.404Z,1756327941.404 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped 2025-08-27T20:52:21.404Z,1756327941.404 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-08-27T20:52:21.404Z,1756327941.404 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped 2025-08-27T20:52:21.404Z,1756327941.404 [MissionManager](IMPORTANT): Started mission transit 2025-08-27T20:52:21.404Z,1756327941.404 [transit] Running Loop=1 2025-08-27T20:52:21.405Z,1756327941.405 [transit](DEBUG): Aggregate::initialize transit 2025-08-27T20:52:21.405Z,1756327941.405 [transit:StandardEnvelopes] Running Loop=1 2025-08-27T20:52:21.405Z,1756327941.405 [transit:StandardEnvelopes](DEBUG): Aggregate::initialize transit:StandardEnvelopes 2025-08-27T20:52:21.405Z,1756327941.405 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-08-27T20:52:21.405Z,1756327941.405 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2025-08-27T20:52:21.405Z,1756327941.405 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-08-27T20:52:21.405Z,1756327941.405 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2025-08-27T20:52:21.405Z,1756327941.405 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-08-27T20:52:21.405Z,1756327941.405 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2025-08-27T20:52:21.405Z,1756327941.405 [transit:BackseatDriver] Running Loop=1 2025-08-27T20:52:21.406Z,1756327941.406 [transit:BackseatDriver](DEBUG): Aggregate::initialize transit:BackseatDriver 2025-08-27T20:52:21.406Z,1756327941.406 [transit:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-08-27T20:52:21.406Z,1756327941.406 [transit:PowerOnly] Running Loop=1 2025-08-27T20:52:21.406Z,1756327941.406 [transit:PowerOnly](DEBUG): Aggregate::initialize transit:PowerOnly 2025-08-27T20:52:21.406Z,1756327941.406 [transit:PowerOnly:A] Running Loop=1 2025-08-27T20:52:21.406Z,1756327941.406 [transit:PowerOnly:B] Running Loop=1 2025-08-27T20:52:21.406Z,1756327941.406 [transit:PowerOnly:C] Running Loop=1 2025-08-27T20:52:21.406Z,1756327941.406 [transit:PowerOnly:D] Running Loop=1 2025-08-27T20:52:21.406Z,1756327941.406 [transit:PowerOnly:E.Wait] Running Loop=1 2025-08-27T20:52:21.406Z,1756327941.406 [transit:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2025-08-27T20:52:21.406Z,1756327941.406 [transit:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-27T20:52:21.407Z,1756327941.407 [transit:BuoyancyHold.Buoyancy](DEBUG): Initialize Buoyancy Component. 2025-08-27T20:52:21.407Z,1756327941.407 [transit:MassHold.Pitch] Running Loop=1 2025-08-27T20:52:21.407Z,1756327941.407 [transit:MassHold.Pitch](DEBUG): Initialize. 2025-08-27T20:52:21.417Z,1756327941.417 [transit:B] Running Loop=1 2025-08-27T20:52:21.418Z,1756327941.418 [transit:MassHold.Pitch] Running Loop=1 2025-08-27T20:52:21.418Z,1756327941.418 [transit:BuoyancyHold.Buoyancy] Running Loop=1 2025-08-27T20:52:21.418Z,1756327941.418 [transit:PowerOnly] Running Loop=1 2025-08-27T20:52:21.419Z,1756327941.419 [transit:PowerOnly:D] Stopped 2025-08-27T20:52:21.419Z,1756327941.419 [transit:PowerOnly:C] Stopped 2025-08-27T20:52:21.419Z,1756327941.419 [transit:PowerOnly:B] Stopped 2025-08-27T20:52:21.419Z,1756327941.419 [transit:PowerOnly:A] Stopped 2025-08-27T20:52:21.419Z,1756327941.419 [transit:BackseatDriver] Running Loop=1 2025-08-27T20:52:21.419Z,1756327941.419 [transit:StandardEnvelopes] Running Loop=1 2025-08-27T20:52:21.419Z,1756327941.419 [transit:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-08-27T20:52:21.420Z,1756327941.420 [transit:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-08-27T20:52:21.420Z,1756327941.420 [transit:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-08-27T20:52:21.421Z,1756327941.421 [transit:B] Stopped 2025-08-27T20:52:21.421Z,1756327941.421 [transit:C] Running Loop=1 2025-08-27T20:52:21.832Z,1756327941.832 [transit:C] Stopped 2025-08-27T20:52:21.832Z,1756327941.832 [transit:E] Running Loop=1 2025-08-27T20:52:22.246Z,1756327942.246 [transit:E] Stopped 2025-08-27T20:52:22.247Z,1756327942.247 [transit:F] Running Loop=1 2025-08-27T20:52:22.613Z,1756327942.613 [transit:F] Stopped 2025-08-27T20:52:22.614Z,1756327942.614 [transit:G] Running Loop=1 2025-08-27T20:52:23.040Z,1756327943.040 [transit:G] Stopped 2025-08-27T20:52:23.040Z,1756327943.040 [transit:Transit] Running Loop=1 2025-08-27T20:52:23.040Z,1756327943.040 [transit:Transit](DEBUG): Aggregate::initialize transit:Transit 2025-08-27T20:52:23.040Z,1756327943.040 [transit:Transit:A.Pitch] Running Loop=1 2025-08-27T20:52:23.040Z,1756327943.040 [transit:Transit:A.Pitch](DEBUG): Initialize. 2025-08-27T20:52:23.040Z,1756327943.040 [transit:Transit:B.SetSpeed] Running Loop=1 2025-08-27T20:52:23.040Z,1756327943.040 [transit:Transit:B.SetSpeed](DEBUG): Initialize. 2025-08-27T20:52:23.041Z,1756327943.041 [transit:Transit:Wpt1.Waypoint] Running Loop=1 2025-08-27T20:52:23.041Z,1756327943.041 [transit:Transit:Wpt1.Waypoint](DEBUG): Initialize WaypointComponent. 2025-08-27T20:52:23.042Z,1756327943.042 [transit:Transit:Wpt1.Waypoint](IMPORTANT): Navigating to waypoint: 36.806965,-121.824326 2025-08-27T20:52:23.445Z,1756327943.445 [transit:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326 2025-08-27T20:52:23.446Z,1756327943.446 [transit:Transit:B.SetSpeed] Running Loop=1 2025-08-27T20:52:23.446Z,1756327943.446 [transit:Transit:A.Pitch] Running Loop=1 2025-08-27T20:52:23.470Z,1756327943.470 [HorizontalControl](DEBUG): kpHeading = 0.400000 2025-08-27T20:52:23.470Z,1756327943.470 [HorizontalControl](DEBUG): kiHeading = 0.001000 2025-08-27T20:52:32.823Z,1756327952.823 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-27T20:52:35.208Z,1756327955.208 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250827T180804/Courier0000.lzma 2025-08-27T20:52:53.276Z,1756327973.276 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-08-27T20:52:54.279Z,1756327974.279 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:53:22.418Z,1756328002.418 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.929161 2025-08-27T20:53:23.419Z,1756328003.419 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:53:53.540Z,1756328033.540 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:53:54.543Z,1756328034.543 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:54:24.664Z,1756328064.664 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:54:25.667Z,1756328065.667 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:54:32.555Z,1756328072.555 [Radio_Surface](INFO): Powering down 2025-08-27T20:54:55.788Z,1756328095.788 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:54:56.793Z,1756328096.793 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-27T20:54:56.793Z,1756328096.793 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:55:26.924Z,1756328126.924 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:55:27.927Z,1756328127.927 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:55:58.064Z,1756328158.064 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:55:59.067Z,1756328159.067 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:56:29.196Z,1756328189.196 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:56:30.200Z,1756328190.200 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:57:00.320Z,1756328220.320 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:57:01.323Z,1756328221.323 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:57:31.443Z,1756328251.443 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:57:32.448Z,1756328252.448 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:58:02.567Z,1756328282.567 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:58:03.571Z,1756328283.571 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:58:33.692Z,1756328313.692 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:58:34.695Z,1756328314.695 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:59:04.832Z,1756328344.832 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:59:05.835Z,1756328345.835 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T20:59:35.965Z,1756328375.965 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T20:59:36.967Z,1756328376.967 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:00:07.091Z,1756328407.092 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:00:08.096Z,1756328408.096 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:00:38.215Z,1756328438.215 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:00:39.219Z,1756328439.219 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:01:09.351Z,1756328469.351 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:01:10.364Z,1756328470.364 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:01:40.491Z,1756328500.491 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:01:41.495Z,1756328501.495 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:02:11.619Z,1756328531.619 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:02:12.623Z,1756328532.623 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:02:42.751Z,1756328562.751 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:02:43.756Z,1756328563.756 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:03:13.884Z,1756328593.884 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:03:14.887Z,1756328594.887 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:03:45.007Z,1756328625.007 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:03:46.011Z,1756328626.011 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:04:16.133Z,1756328656.133 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:04:17.135Z,1756328657.135 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:04:47.264Z,1756328687.264 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:04:48.267Z,1756328688.267 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:05:18.403Z,1756328718.403 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:05:19.407Z,1756328719.407 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:05:49.528Z,1756328749.528 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:05:50.531Z,1756328750.531 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:06:20.659Z,1756328780.659 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:06:21.663Z,1756328781.663 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:06:51.789Z,1756328811.789 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:06:52.791Z,1756328812.791 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:06:56.109Z,1756328816.109 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,25082713080834,35.0, +0.0,1503.8, 0 2025-08-27T21:07:06.209Z,1756328826.209 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,25082713081834,35.0 0.0,1503.8, 0 2025-08-27T21:07:16.303Z,1756328836.303 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for beam range. Device response is::RA, 0.00,1182.61,1242.39 2025-08-27T21:07:22.911Z,1756328842.911 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:07:23.915Z,1756328843.915 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:07:26.026Z,1756328846.026 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for beam range. Device response is::RA, 0.00,1212.38,1107.92, 2025-08-27T21:07:46.223Z,1756328866.223 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. Device response is::WD11.23, +1046.22, -3.17, 20.00, 0.00 2025-08-27T21:07:54.036Z,1756328874.036 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:07:55.039Z,1756328875.039 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:07:56.306Z,1756328876.306 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS, -12, -13,A 2025-08-27T21:08:06.045Z,1756328886.045 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS, +7, +1026, 2025-08-27T21:08:16.109Z,1756328896.109 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS, -26, -115,A 2025-08-27T21:08:25.159Z,1756328905.159 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:08:26.163Z,1756328906.163 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:08:56.284Z,1756328936.284 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:08:57.287Z,1756328937.287 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:09:27.419Z,1756328967.419 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:09:28.423Z,1756328968.423 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:09:58.559Z,1756328998.559 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:09:59.565Z,1756328999.565 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:10:29.695Z,1756329029.695 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:10:30.699Z,1756329030.699 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:11:00.827Z,1756329060.827 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:11:01.358Z,1756329061.358 [transit:NeedComms] Running Loop=1 2025-08-27T21:11:01.358Z,1756329061.358 [transit:NeedComms](DEBUG): Aggregate::initialize transit:NeedComms 2025-08-27T21:11:01.358Z,1756329061.358 [transit:NeedComms:B.GoToSurface] Running Loop=1 2025-08-27T21:11:01.358Z,1756329061.358 [transit:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-27T21:11:01.359Z,1756329061.359 [transit:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-27T21:11:01.359Z,1756329061.359 [transit:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-27T21:11:01.360Z,1756329061.360 [transit:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-27T21:11:01.360Z,1756329061.360 [transit:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-27T21:11:01.360Z,1756329061.360 [transit:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-27T21:11:01.361Z,1756329061.361 [transit:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-27T21:11:01.361Z,1756329061.361 [transit:NeedComms:A] Running Loop=1 2025-08-27T21:11:01.363Z,1756329061.363 [transit:NeedComms:A](INFO): last time_fix was: 1756327860.000000 second since 1970/01/01T00:00:00Z 2025-08-27T21:11:01.363Z,1756329061.363 [transit:NeedComms:A] Stopped 2025-08-27T21:11:01.832Z,1756329061.832 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:11:27.786Z,1756329087.786 [transit:NeedComms:C] Running Loop=1 2025-08-27T21:11:28.215Z,1756329088.215 [transit:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-08-27T21:11:28.248Z,1756329088.248 [Radio_Surface](INFO): Powering up 2025-08-27T21:11:31.965Z,1756329091.965 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:11:32.967Z,1756329092.967 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:11:33.505Z,1756329093.505 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.10 2025-08-27T21:11:33.505Z,1756329093.505 [Radio_Surface](INFO): Found local IP address 10.89.10.2 for eth0 2025-08-27T21:12:03.091Z,1756329123.091 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:12:04.095Z,1756329124.095 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-27T21:12:04.096Z,1756329124.096 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:12:32.008Z,1756329152.008 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-27T21:12:34.216Z,1756329154.216 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:12:35.220Z,1756329155.220 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:12:40.890Z,1756329160.890 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211240.00,A,3647.18346,N,12151.07751,W,0.583,67.63,270825,,,D*41 2025-08-27T21:12:40.892Z,1756329160.892 [NAL9602](INFO): GPS fix at 20250827T211240: (36.786391, -121.851292) 2025-08-27T21:12:40.925Z,1756329160.925 [UniversalFixResidualReporter](INFO): Fix residual: 8.8 %DT, over the last 1135.8 m. Residual distance 100.1 m at bearing 131.0 degrees. Fix at (36.7864, -121.8513) with 1057.6 m made good. 2025-08-27T21:12:40.926Z,1756329160.926 [transit:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326 2025-08-27T21:12:40.934Z,1756329160.934 [transit:NeedComms:C] Stopped 2025-08-27T21:12:40.934Z,1756329160.934 [transit:NeedComms:D] Running Loop=1 2025-08-27T21:12:41.336Z,1756329161.336 [transit:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications 2025-08-27T21:13:05.339Z,1756329185.339 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:13:06.343Z,1756329186.343 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:13:11.608Z,1756329191.608 [NAL9602](ERROR): Queried for signal strength and failed to receive proper response. 2025-08-27T21:13:11.692Z,1756329191.692 [NAL9602](ERROR): received: +CSQ:0 OK669, 2, 0, 0, 0 OK 2025-08-27T21:13:36.476Z,1756329216.476 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:13:37.479Z,1756329217.479 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:14:07.608Z,1756329247.608 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:14:08.612Z,1756329248.612 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:14:38.732Z,1756329278.732 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:14:39.735Z,1756329279.735 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:14:52.774Z,1756329292.774 [NAL9602](INFO): SBD MO Status=2, MOMSN=49669, MT Status=2, MTMSN=0 2025-08-27T21:14:52.774Z,1756329292.774 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-27T21:15:09.857Z,1756329309.857 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:15:10.859Z,1756329310.859 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:15:29.627Z,1756329329.627 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002903 2025-08-27T21:15:38.919Z,1756329338.919 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20250827T180804/Courier0000.lzma 2025-08-27T21:15:51.974Z,1756329351.974 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0000.lzma.bak 2025-08-27T21:15:51.974Z,1756329351.974 [DataOverHttps](INFO): SBD MOMSN=25906525 2025-08-27T21:16:00.524Z,1756329360.524 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-27T21:16:26.644Z,1756329386.644 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0003.lzma 2025-08-27T21:16:37.681Z,1756329397.681 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0003.lzma.bak 2025-08-27T21:16:37.681Z,1756329397.681 [DataOverHttps](INFO): SBD MOMSN=25906769 2025-08-27T21:17:05.583Z,1756329425.583 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0006.lzma 2025-08-27T21:17:16.625Z,1756329436.625 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0006.lzma.bak 2025-08-27T21:17:16.625Z,1756329436.625 [DataOverHttps](INFO): SBD MOMSN=25906771 2025-08-27T21:17:45.279Z,1756329465.279 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0009.lzma 2025-08-27T21:17:56.321Z,1756329476.321 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0009.lzma.bak 2025-08-27T21:17:56.321Z,1756329476.321 [DataOverHttps](INFO): SBD MOMSN=25906779 2025-08-27T21:18:18.009Z,1756329498.009 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-08-27T21:18:28.135Z,1756329508.135 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0012.lzma 2025-08-27T21:18:31.400Z,1756329511.400 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-08-27T21:18:39.177Z,1756329519.177 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0012.lzma.bak 2025-08-27T21:18:39.177Z,1756329519.177 [DataOverHttps](INFO): SBD MOMSN=25906793 2025-08-27T21:18:44.720Z,1756329524.720 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-08-27T21:18:58.215Z,1756329538.215 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-08-27T21:19:07.951Z,1756329547.951 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0015.lzma 2025-08-27T21:19:11.143Z,1756329551.143 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-08-27T21:19:18.986Z,1756329558.986 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0015.lzma.bak 2025-08-27T21:19:18.986Z,1756329558.986 [DataOverHttps](INFO): SBD MOMSN=25906802 2025-08-27T21:19:24.479Z,1756329564.479 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-08-27T21:19:37.453Z,1756329577.453 [BPC1](ERROR): BPC1A got IPBS message with 6 sticks (min is 7). 2025-08-27T21:19:48.107Z,1756329588.107 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0018.lzma 2025-08-27T21:19:59.149Z,1756329599.149 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0018.lzma.bak 2025-08-27T21:19:59.149Z,1756329599.149 [DataOverHttps](INFO): SBD MOMSN=25906804 2025-08-27T21:20:33.621Z,1756329633.621 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20250827T180804/Courier0021.lzma 2025-08-27T21:20:44.661Z,1756329644.661 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0021.lzma.bak 2025-08-27T21:20:44.661Z,1756329644.661 [DataOverHttps](INFO): SBD MOMSN=25906806 2025-08-27T21:21:14.883Z,1756329674.883 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0024.lzma 2025-08-27T21:21:27.456Z,1756329687.456 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0024.lzma.bak 2025-08-27T21:21:27.456Z,1756329687.456 [DataOverHttps](INFO): SBD MOMSN=25906808 2025-08-27T21:21:28.453Z,1756329688.453 [GFScanner](IMPORTANT): Beginning ground fault scan 2025-08-27T21:21:32.806Z,1756329692.806 [GFScanner](IMPORTANT): Ground fault detected mA: CHAN A0 (Batt): 0.061576 CHAN A1 (24V): 0.081438 CHAN A2 (12V): 0.040254 CHAN A3 (5V): 0.012244 CHAN B0 (3.3V): 0.008586 CHAN B1 (3.15aV): 0.007774 CHAN B2 (3.15bV): 0.009003 CHAN B3 (GND): -0.002372 OPEN: 0.008255 Full Scale: +/- 1 mA 2025-08-27T21:21:55.759Z,1756329715.759 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0027.lzma 2025-08-27T21:21:56.531Z,1756329716.531 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging 2025-08-27T21:22:06.808Z,1756329726.808 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0027.lzma.bak 2025-08-27T21:22:06.808Z,1756329726.808 [DataOverHttps](INFO): SBD MOMSN=25906810 2025-08-27T21:22:38.071Z,1756329758.071 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0030.lzma 2025-08-27T21:22:50.117Z,1756329770.117 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0030.lzma.bak 2025-08-27T21:22:50.117Z,1756329770.117 [DataOverHttps](INFO): SBD MOMSN=25906812 2025-08-27T21:23:22.295Z,1756329802.295 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0033.lzma 2025-08-27T21:23:32.519Z,1756329812.519 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0033.lzma.bak 2025-08-27T21:23:32.519Z,1756329812.519 [DataOverHttps](INFO): SBD MOMSN=25906814 2025-08-27T21:24:01.471Z,1756329841.471 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0036.lzma 2025-08-27T21:24:12.513Z,1756329852.513 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0036.lzma.bak 2025-08-27T21:24:12.513Z,1756329852.513 [DataOverHttps](INFO): SBD MOMSN=25906816 2025-08-27T21:24:39.469Z,1756329879.469 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5. 2025-08-27T21:24:39.472Z,1756329879.472 [BPC1](INFO): Received data from all battery sticks. 2025-08-27T21:24:45.075Z,1756329885.075 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20250827T180804/Courier0039.lzma 2025-08-27T21:24:59.129Z,1756329899.129 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0039.lzma.bak 2025-08-27T21:24:59.129Z,1756329899.129 [DataOverHttps](INFO): SBD MOMSN=25906818 2025-08-27T21:25:28.747Z,1756329928.747 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0042.lzma 2025-08-27T21:25:39.789Z,1756329939.789 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0042.lzma.bak 2025-08-27T21:25:39.789Z,1756329939.789 [DataOverHttps](INFO): SBD MOMSN=25906820 2025-08-27T21:26:08.163Z,1756329968.163 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T180804/Courier0045.lzma 2025-08-27T21:26:19.209Z,1756329979.209 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Courier0045.lzma.bak 2025-08-27T21:26:19.209Z,1756329979.209 [DataOverHttps](INFO): SBD MOMSN=25906822 2025-08-27T21:26:53.540Z,1756330013.540 [DataOverHttps](INFO): Sending 324 bytes from file Logs/20250827T202119/Courier0000.lzma 2025-08-27T21:27:04.581Z,1756330024.581 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Courier0000.lzma.bak 2025-08-27T21:27:04.581Z,1756330024.581 [DataOverHttps](INFO): SBD MOMSN=25906826 2025-08-27T21:27:32.113Z,1756330052.113 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,25082713284440,35.0, +17.1, 0., 0 2025-08-27T21:27:32.843Z,1756330052.843 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T202119/Courier0003.lzma 2025-08-27T21:27:42.230Z,1756330062.230 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,2508271328544+17.1, 0.0,1513.1, 0 2025-08-27T21:27:43.894Z,1756330063.894 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Courier0003.lzma.bak 2025-08-27T21:27:43.894Z,1756330063.894 [DataOverHttps](INFO): SBD MOMSN=25906837 2025-08-27T21:28:14.183Z,1756330094.183 [DataOverHttps](INFO): Sending 81 bytes from file Logs/20250827T202119/Courier0006.lzma 2025-08-27T21:28:25.225Z,1756330105.225 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Courier0006.lzma.bak 2025-08-27T21:28:25.225Z,1756330105.225 [DataOverHttps](INFO): SBD MOMSN=25906845 2025-08-27T21:28:59.070Z,1756330139.070 [DataOverHttps](INFO): Sending 929 bytes from file Logs/20250827T173616/Express0013.lzma 2025-08-27T21:29:12.592Z,1756330152.592 [DataOverHttps](INFO): Moved sent file to Logs/20250827T173616/Express0013.lzma.bak 2025-08-27T21:29:12.593Z,1756330152.593 [DataOverHttps](INFO): SBD MOMSN=25906856 2025-08-27T21:29:42.482Z,1756330182.482 [DataOverHttps](INFO): Sending 729 bytes from file Logs/20250827T180804/Express0001.lzma 2025-08-27T21:29:54.380Z,1756330194.380 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0001.lzma.bak 2025-08-27T21:29:54.380Z,1756330194.380 [DataOverHttps](INFO): SBD MOMSN=25906883 2025-08-27T21:30:26.412Z,1756330226.412 [DataOverHttps](INFO): Sending 499 bytes from file Logs/20250827T180804/Express0004.lzma 2025-08-27T21:30:37.453Z,1756330237.453 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0004.lzma.bak 2025-08-27T21:30:37.453Z,1756330237.453 [DataOverHttps](INFO): SBD MOMSN=25906887 2025-08-27T21:31:06.847Z,1756330266.847 [DataOverHttps](INFO): Sending 216 bytes from file Logs/20250827T180804/Express0007.lzma 2025-08-27T21:31:21.906Z,1756330281.906 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0007.lzma.bak 2025-08-27T21:31:21.906Z,1756330281.906 [DataOverHttps](INFO): SBD MOMSN=25906893 2025-08-27T21:31:53.294Z,1756330313.294 [DataOverHttps](INFO): Sending 234 bytes from file Logs/20250827T180804/Express0010.lzma 2025-08-27T21:32:04.361Z,1756330324.361 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0010.lzma.bak 2025-08-27T21:32:04.361Z,1756330324.361 [DataOverHttps](INFO): SBD MOMSN=25906896 2025-08-27T21:32:18.075Z,1756330338.075 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,25082713333040,35.0, +17.1, 0., 0 2025-08-27T21:32:34.671Z,1756330354.671 [DataOverHttps](INFO): Sending 245 bytes from file Logs/20250827T180804/Express0013.lzma 2025-08-27T21:32:47.737Z,1756330367.737 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0013.lzma.bak 2025-08-27T21:32:47.737Z,1756330367.737 [DataOverHttps](INFO): SBD MOMSN=25906899 2025-08-27T21:33:18.531Z,1756330398.531 [DataOverHttps](INFO): Sending 193 bytes from file Logs/20250827T180804/Express0016.lzma 2025-08-27T21:33:33.589Z,1756330413.589 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0016.lzma.bak 2025-08-27T21:33:33.589Z,1756330413.589 [DataOverHttps](INFO): SBD MOMSN=25906903 2025-08-27T21:34:03.927Z,1756330443.927 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20250827T180804/Express0019.lzma 2025-08-27T21:34:14.969Z,1756330454.969 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0019.lzma.bak 2025-08-27T21:34:14.969Z,1756330454.969 [DataOverHttps](INFO): SBD MOMSN=25906906 2025-08-27T21:34:49.671Z,1756330489.671 [DataOverHttps](INFO): Sending 157 bytes from file Logs/20250827T180804/Express0022.lzma 2025-08-27T21:35:02.729Z,1756330502.729 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0022.lzma.bak 2025-08-27T21:35:02.729Z,1756330502.729 [DataOverHttps](INFO): SBD MOMSN=25906908 2025-08-27T21:35:33.823Z,1756330533.823 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20250827T180804/Express0025.lzma 2025-08-27T21:35:44.866Z,1756330544.866 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0025.lzma.bak 2025-08-27T21:35:44.866Z,1756330544.866 [DataOverHttps](INFO): SBD MOMSN=25906910 2025-08-27T21:36:14.443Z,1756330574.443 [DataOverHttps](INFO): Sending 173 bytes from file Logs/20250827T180804/Express0028.lzma 2025-08-27T21:36:25.501Z,1756330585.501 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0028.lzma.bak 2025-08-27T21:36:25.501Z,1756330585.501 [DataOverHttps](INFO): SBD MOMSN=25906913 2025-08-27T21:36:58.927Z,1756330618.927 [DataOverHttps](INFO): Sending 131 bytes from file Logs/20250827T180804/Express0031.lzma 2025-08-27T21:37:09.979Z,1756330629.979 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0031.lzma.bak 2025-08-27T21:37:09.979Z,1756330629.979 [DataOverHttps](INFO): SBD MOMSN=25906916 2025-08-27T21:37:42.187Z,1756330662.187 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20250827T180804/Express0034.lzma 2025-08-27T21:37:53.229Z,1756330673.229 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0034.lzma.bak 2025-08-27T21:37:53.229Z,1756330673.229 [DataOverHttps](INFO): SBD MOMSN=25906918 2025-08-27T21:38:27.290Z,1756330707.290 [DataOverHttps](INFO): Sending 418 bytes from file Logs/20250827T180804/Express0037.lzma 2025-08-27T21:38:38.605Z,1756330718.605 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0037.lzma.bak 2025-08-27T21:38:38.605Z,1756330718.605 [DataOverHttps](INFO): SBD MOMSN=25906928 2025-08-27T21:39:10.519Z,1756330750.519 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20250827T180804/Express0040.lzma 2025-08-27T21:39:21.561Z,1756330761.561 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0040.lzma.bak 2025-08-27T21:39:21.561Z,1756330761.561 [DataOverHttps](INFO): SBD MOMSN=25906946 2025-08-27T21:39:50.880Z,1756330790.880 [DataOverHttps](INFO): Sending 233 bytes from file Logs/20250827T180804/Express0043.lzma 2025-08-27T21:40:01.921Z,1756330801.921 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0043.lzma.bak 2025-08-27T21:40:01.921Z,1756330801.921 [DataOverHttps](INFO): SBD MOMSN=25906963 2025-08-27T21:40:36.536Z,1756330836.536 [DataOverHttps](INFO): Sending 474 bytes from file Logs/20250827T180804/Express0046.lzma 2025-08-27T21:40:47.577Z,1756330847.577 [DataOverHttps](INFO): Moved sent file to Logs/20250827T180804/Express0046.lzma.bak 2025-08-27T21:40:47.577Z,1756330847.577 [DataOverHttps](INFO): SBD MOMSN=25906968 2025-08-27T21:41:16.911Z,1756330876.911 [DataOverHttps](INFO): Sending 767 bytes from file Logs/20250827T202119/Express0001.lzma 2025-08-27T21:41:27.952Z,1756330887.952 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Express0001.lzma.bak 2025-08-27T21:41:27.952Z,1756330887.952 [DataOverHttps](INFO): SBD MOMSN=25906973 2025-08-27T21:41:57.259Z,1756330917.259 [DataOverHttps](INFO): Sending 180 bytes from file Logs/20250827T202119/Express0004.lzma 2025-08-27T21:42:08.301Z,1756330928.301 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Express0004.lzma.bak 2025-08-27T21:42:08.301Z,1756330928.301 [DataOverHttps](INFO): SBD MOMSN=25906981 2025-08-27T21:42:38.728Z,1756330958.728 [DataOverHttps](INFO): Sending 519 bytes from file Logs/20250827T202119/Express0007.lzma 2025-08-27T21:42:41.150Z,1756330961.150 [transit:NeedComms:D](INFO): Timed out from 2025-08-27T21:12:40.9Z 2025-08-27T21:42:41.150Z,1756330961.150 [transit:NeedComms:D:A_Timeout] Running Loop=1 2025-08-27T21:42:41.150Z,1756330961.150 [transit:NeedComms:D:A_Timeout](DEBUG): Aggregate::initialize transit:NeedComms:D:A_Timeout 2025-08-27T21:42:41.150Z,1756330961.150 [transit:NeedComms:D:A_Timeout:A] Running Loop=1 2025-08-27T21:42:41.151Z,1756330961.151 [transit:NeedComms:D:A_Timeout:A](IMPORTANT): Comms timed out after 30.000000 min minutes 2025-08-27T21:42:41.151Z,1756330961.151 [transit:NeedComms:D:A_Timeout:A] Stopped 2025-08-27T21:42:41.151Z,1756330961.151 [transit:NeedComms:D:A_Timeout](INFO): Completed transit:NeedComms:D:A_Timeout 2025-08-27T21:42:41.151Z,1756330961.151 [transit:NeedComms:D] Stopped 2025-08-27T21:42:41.152Z,1756330961.152 [transit:NeedComms:E] Running Loop=1 2025-08-27T21:42:41.560Z,1756330961.560 [transit:NeedComms:E](DEBUG): Initialize ReadDataComponent to sense time_fix 2025-08-27T21:42:43.158Z,1756330963.158 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214242.00,A,3647.05836,N,12151.01900,W,0.272,214.09,270825,,,D*79 2025-08-27T21:42:43.161Z,1756330963.161 [NAL9602](INFO): GPS fix at 20250827T214242: (36.784306, -121.850317) 2025-08-27T21:42:43.186Z,1756330963.186 [transit:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326 2025-08-27T21:42:43.193Z,1756330963.193 [transit:NeedComms:E] Stopped 2025-08-27T21:42:43.194Z,1756330963.194 [transit:NeedComms](INFO): Completed transit:NeedComms 2025-08-27T21:42:43.194Z,1756330963.194 [transit:NeedComms] Stopped 2025-08-27T21:42:43.194Z,1756330963.194 [transit:NeedComms](DEBUG): Aggregate::uninitialize transit:NeedComms 2025-08-27T21:42:43.194Z,1756330963.194 [transit:NeedComms:B.GoToSurface] Stopped 2025-08-27T21:42:43.194Z,1756330963.194 [transit:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-27T21:42:44.022Z,1756330964.022 [ElevatorOffsetCalculator](INFO): Removing expired estimator for commanded vars: speed 1.00 m/s, pitch 30.00 deg, mass-position -22.00 mm. 2025-08-27T21:42:49.769Z,1756330969.769 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Express0007.lzma.bak 2025-08-27T21:42:49.769Z,1756330969.769 [DataOverHttps](INFO): SBD MOMSN=25906985 2025-08-27T21:43:10.055Z,1756330990.055 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:43:26.945Z,1756331006.945 [ElevatorOffsetCalculator](INFO): New estimator for commanded vars: speed 1.20 m/s, pitch 20.00 deg, mass-position 19.54 mm (2 active estimators). 2025-08-27T21:43:40.748Z,1756331020.748 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-08-27T21:43:41.751Z,1756331021.751 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:43:45.529Z,1756331025.529 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-27T21:44:09.872Z,1756331049.872 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.819351 2025-08-27T21:44:10.875Z,1756331050.875 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:44:16.225Z,1756331056.225 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-27T21:44:27.343Z,1756331067.343 [Radio_Surface](INFO): Powering down 2025-08-27T21:44:41.023Z,1756331081.023 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:44:42.029Z,1756331082.029 [DataOverHttps](INFO): Radio surface powered OFF, will not connect. 2025-08-27T21:44:42.029Z,1756331082.029 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:45:12.171Z,1756331112.171 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:45:13.175Z,1756331113.175 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:45:43.304Z,1756331143.304 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:45:44.307Z,1756331144.307 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:46:08.167Z,1756331168.167 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. Device response is::WD, , +1632.40, +101.09, 20.00, 0.00 2025-08-27T21:46:14.443Z,1756331174.443 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:46:15.448Z,1756331175.448 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:46:18.264Z,1756331178.264 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error. Device response is::TS,25082713473040,35.0, +14.6, 0.0,150 2025-08-27T21:46:38.067Z,1756331198.067 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. Device response is::WD, +387.50, +1662 +101.09, 20.0 2025-08-27T21:46:45.567Z,1756331205.567 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:46:46.571Z,1756331206.571 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:46:58.264Z,1756331218.264 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS, -93, +1023, 2025-08-27T21:47:08.368Z,1756331228.368 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS, 904, +112,A 2025-08-27T21:47:16.691Z,1756331236.691 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:47:17.696Z,1756331237.696 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:47:18.081Z,1756331238.081 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for altitude. Device response is::BD, +0.45, +1 +14.94, 132.86, 0.00 2025-08-27T21:47:47.819Z,1756331267.819 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:47:48.824Z,1756331268.824 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:48:18.959Z,1756331298.959 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:48:19.964Z,1756331299.964 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:48:50.084Z,1756331330.084 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:48:51.087Z,1756331331.087 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:49:21.223Z,1756331361.223 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:49:22.227Z,1756331362.227 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:49:52.360Z,1756331392.360 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:49:53.363Z,1756331393.363 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:50:23.483Z,1756331423.483 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:50:24.489Z,1756331424.489 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:50:54.608Z,1756331454.608 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:50:55.611Z,1756331455.611 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:51:25.731Z,1756331485.731 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:51:26.735Z,1756331486.735 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:51:56.872Z,1756331516.872 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:51:57.875Z,1756331517.875 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:52:28.005Z,1756331548.005 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:52:29.007Z,1756331549.007 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:52:59.144Z,1756331579.144 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:53:00.147Z,1756331580.147 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:53:30.268Z,1756331610.268 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:53:31.271Z,1756331611.271 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:54:01.392Z,1756331641.392 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:54:02.395Z,1756331642.395 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:54:32.516Z,1756331672.516 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:54:33.519Z,1756331673.519 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:55:03.664Z,1756331703.664 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:55:04.667Z,1756331704.667 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:55:34.819Z,1756331734.819 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:55:35.823Z,1756331735.823 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:56:05.951Z,1756331765.951 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:56:06.955Z,1756331766.955 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:56:37.091Z,1756331797.091 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:56:38.096Z,1756331798.096 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:57:08.216Z,1756331828.216 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:57:09.220Z,1756331829.220 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:57:39.339Z,1756331859.339 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:57:40.344Z,1756331860.344 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:58:10.464Z,1756331890.464 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:58:11.467Z,1756331891.467 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:58:41.588Z,1756331921.588 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:58:42.591Z,1756331922.591 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:59:12.720Z,1756331952.720 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:59:13.727Z,1756331953.727 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T21:59:43.847Z,1756331983.847 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T21:59:44.851Z,1756331984.851 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:00:14.976Z,1756332014.976 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:00:15.980Z,1756332015.980 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:00:46.119Z,1756332046.119 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:00:47.123Z,1756332047.123 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:01:17.247Z,1756332077.247 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:01:18.251Z,1756332078.251 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:01:48.388Z,1756332108.388 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:01:49.391Z,1756332109.391 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:02:19.520Z,1756332139.520 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:02:20.523Z,1756332140.523 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:02:43.345Z,1756332163.345 [transit:NeedComms] Running Loop=1 2025-08-27T22:02:43.345Z,1756332163.345 [transit:NeedComms](DEBUG): Aggregate::initialize transit:NeedComms 2025-08-27T22:02:43.345Z,1756332163.345 [transit:NeedComms:B.GoToSurface] Running Loop=1 2025-08-27T22:02:43.345Z,1756332163.345 [transit:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-27T22:02:43.346Z,1756332163.346 [transit:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s. 2025-08-27T22:02:43.346Z,1756332163.346 [transit:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees. 2025-08-27T22:02:43.346Z,1756332163.346 [transit:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s. 2025-08-27T22:02:43.347Z,1756332163.347 [transit:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds. 2025-08-27T22:02:43.347Z,1756332163.347 [transit:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-27T22:02:43.348Z,1756332163.348 [transit:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-27T22:02:43.349Z,1756332163.349 [transit:NeedComms:A] Running Loop=1 2025-08-27T22:02:43.353Z,1756332163.353 [transit:NeedComms:A](INFO): last time_fix was: 1756330962.000000 second since 1970/01/01T00:00:00Z 2025-08-27T22:02:43.353Z,1756332163.353 [transit:NeedComms:A] Stopped 2025-08-27T22:02:50.643Z,1756332170.643 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:02:51.647Z,1756332171.647 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:02:59.116Z,1756332179.116 [transit:StandardEnvelopes:A.AltitudeEnvelope](IMPORTANT): Altitude envelope ACTIVE. Altitude:1.610000m. At depth:4.272917m. 2025-08-27T22:03:01.146Z,1756332181.146 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.39 2025-08-27T22:03:01.524Z,1756332181.524 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.39 2025-08-27T22:03:01.623Z,1756332181.623 [Radio_Surface](INFO): Powering up 2025-08-27T22:03:01.979Z,1756332181.979 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.39 2025-08-27T22:03:02.361Z,1756332182.361 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.46 2025-08-27T22:03:02.740Z,1756332182.740 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.46 2025-08-27T22:03:04.091Z,1756332184.091 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.35 2025-08-27T22:03:04.449Z,1756332184.449 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.35 2025-08-27T22:03:04.894Z,1756332184.894 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.35 2025-08-27T22:03:05.337Z,1756332185.337 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.42 2025-08-27T22:03:05.691Z,1756332185.691 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.42 2025-08-27T22:03:06.122Z,1756332186.122 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.23 2025-08-27T22:03:06.499Z,1756332186.499 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.23 2025-08-27T22:03:06.875Z,1756332186.875 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.10 2025-08-27T22:03:06.876Z,1756332186.876 [Radio_Surface](INFO): Found local IP address 10.89.10.2 for eth0 2025-08-27T22:03:06.912Z,1756332186.912 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.23 2025-08-27T22:03:07.331Z,1756332187.331 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.47 2025-08-27T22:03:07.712Z,1756332187.712 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.47 2025-08-27T22:03:11.472Z,1756332191.472 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.30 2025-08-27T22:03:11.843Z,1756332191.843 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.30 2025-08-27T22:03:12.303Z,1756332192.303 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.44 2025-08-27T22:03:12.667Z,1756332192.667 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.44 2025-08-27T22:03:13.080Z,1756332193.080 [transit:NeedComms:B.GoToSurface](ERROR): Altitude too low: 1.44 2025-08-27T22:03:14.338Z,1756332194.338 [transit:NeedComms:C] Running Loop=1 2025-08-27T22:03:21.768Z,1756332201.768 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:03:22.771Z,1756332202.771 [DataOverHttps](INFO): Radio surface powered ON. 2025-08-27T22:03:22.772Z,1756332202.772 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:03:47.133Z,1756332227.133 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check. 2025-08-27T22:03:47.207Z,1756332227.207 [NAL9602](ERROR): received: +CSQ:0 OK669, 2, 0, 0, 0 OK 2025-08-27T22:03:52.902Z,1756332232.902 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:03:53.903Z,1756332233.903 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:04:24.024Z,1756332264.024 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:04:25.027Z,1756332265.027 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:04:26.718Z,1756332266.718 [NAL9602](INFO): SBD MO Status=2, MOMSN=49669, MT Status=2, MTMSN=0 2025-08-27T22:04:26.718Z,1756332266.718 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-27T22:04:27.124Z,1756332267.124 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-27T22:04:28.344Z,1756332268.344 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220427.00,A,3647.57293,N,12150.55145,W,0.272,0.00,270825,,,D*7E 2025-08-27T22:04:28.346Z,1756332268.346 [NAL9602](INFO): GPS fix at 20250827T220427: (36.792882, -121.842524) 2025-08-27T22:04:28.359Z,1756332268.359 [UniversalFixResidualReporter](INFO): Fix residual: 10.7 %DT, over the last 1243.1 m. Residual distance 132.8 m at bearing 133.1 degrees. Fix at (36.7929, -121.8425) with 1179.4 m made good. 2025-08-27T22:04:28.361Z,1756332268.361 [transit:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326 2025-08-27T22:04:28.364Z,1756332268.364 [transit:NeedComms:C] Stopped 2025-08-27T22:04:28.365Z,1756332268.365 [transit:NeedComms:D] Running Loop=1 2025-08-27T22:04:46.124Z,1756332286.124 [NAL9602](INFO): SBD MO Status=2, MOMSN=49669, MT Status=2, MTMSN=0 2025-08-27T22:04:46.125Z,1756332286.125 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-27T22:04:55.151Z,1756332295.151 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:04:56.155Z,1756332296.155 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:05:26.276Z,1756332326.276 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:05:27.279Z,1756332327.279 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:05:36.780Z,1756332336.780 [NAL9602](INFO): SBD MO Status=2, MOMSN=49669, MT Status=2, MTMSN=0 2025-08-27T22:05:36.780Z,1756332336.780 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-27T22:05:57.401Z,1756332357.401 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:05:58.403Z,1756332358.403 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:06:22.495Z,1756332382.495 [NAL9602](INFO): SBD MO Status=2, MOMSN=49669, MT Status=2, MTMSN=0 2025-08-27T22:06:22.495Z,1756332382.495 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2 2025-08-27T22:06:28.523Z,1756332388.523 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:06:29.528Z,1756332389.528 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:06:59.647Z,1756332419.647 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting. 2025-08-27T22:07:00.651Z,1756332420.651 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:07:19.419Z,1756332439.419 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003124 2025-08-27T22:07:31.402Z,1756332451.402 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20250827T202119/Courier0009.lzma 2025-08-27T22:07:42.457Z,1756332462.457 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Courier0009.lzma.bak 2025-08-27T22:07:42.458Z,1756332462.458 [DataOverHttps](INFO): SBD MOMSN=25907104 2025-08-27T22:07:50.334Z,1756332470.334 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-27T22:08:15.045Z,1756332495.045 [DataOverHttps](INFO): Sending 664 bytes from file Logs/20250827T202119/Express0010.lzma 2025-08-27T22:08:26.085Z,1756332506.085 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Express0010.lzma.bak 2025-08-27T22:08:26.085Z,1756332506.085 [DataOverHttps](INFO): SBD MOMSN=25907107 2025-08-27T22:08:29.582Z,1756332509.582 [transit:NeedComms:D] Stopped 2025-08-27T22:08:29.582Z,1756332509.582 [transit:NeedComms:E] Running Loop=1 2025-08-27T22:08:31.550Z,1756332511.550 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220831.00,A,3647.56342,N,12150.54920,W,0.253,290.17,270825,,,D*7D 2025-08-27T22:08:31.553Z,1756332511.553 [NAL9602](INFO): GPS fix at 20250827T220831: (36.792724, -121.842487) 2025-08-27T22:08:31.573Z,1756332511.573 [transit:Transit:Wpt1.Waypoint](INFO): Navigating to waypoint: 36.806965,-121.824326 2025-08-27T22:08:31.581Z,1756332511.581 [transit:NeedComms:E] Stopped 2025-08-27T22:08:31.581Z,1756332511.581 [transit:NeedComms](INFO): Completed transit:NeedComms 2025-08-27T22:08:31.582Z,1756332511.582 [transit:NeedComms] Stopped 2025-08-27T22:08:31.582Z,1756332511.582 [transit:NeedComms](DEBUG): Aggregate::uninitialize transit:NeedComms 2025-08-27T22:08:31.582Z,1756332511.582 [transit:NeedComms:B.GoToSurface] Stopped 2025-08-27T22:08:31.582Z,1756332511.582 [transit:NeedComms:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-27T22:08:49.441Z,1756332529.441 [DataOverHttps](IMPORTANT): SBD MTMSN=20250827T220848 2025-08-27T22:08:58.195Z,1756332538.195 [DataOverHttps](INFO): Received command: stop 2025-08-27T22:08:58.228Z,1756332538.228 [CommandExec](IMPORTANT): got command stop 2025-08-27T22:08:58.228Z,1756332538.228 [Supervisor](INFO): Stop Mission called by CommandExec::commandStop 2025-08-27T22:08:58.395Z,1756332538.395 [MissionManager](INFO): MissionManager is completed. 2025-08-27T22:08:58.395Z,1756332538.395 [MissionManager](INFO): Uninitializing Mission transit 2025-08-27T22:08:58.395Z,1756332538.395 [transit] Stopped 2025-08-27T22:08:58.395Z,1756332538.395 [transit](DEBUG): Aggregate::uninitialize transit 2025-08-27T22:08:58.395Z,1756332538.395 [transit:StandardEnvelopes] Stopped 2025-08-27T22:08:58.395Z,1756332538.395 [transit:StandardEnvelopes](DEBUG): Aggregate::uninitialize transit:StandardEnvelopes 2025-08-27T22:08:58.396Z,1756332538.396 [transit:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-08-27T22:08:58.396Z,1756332538.396 [transit:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-08-27T22:08:58.396Z,1756332538.396 [transit:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-08-27T22:08:58.396Z,1756332538.396 [transit:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-08-27T22:08:58.396Z,1756332538.396 [transit:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-08-27T22:08:58.396Z,1756332538.396 [transit:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-08-27T22:08:58.396Z,1756332538.396 [transit:BackseatDriver] Stopped 2025-08-27T22:08:58.396Z,1756332538.396 [transit:BackseatDriver](DEBUG): Aggregate::uninitialize transit:BackseatDriver 2025-08-27T22:08:58.396Z,1756332538.396 [transit:BackseatDriver:A.BackseatDriver] Stopped 2025-08-27T22:08:58.396Z,1756332538.396 [transit:PowerOnly] Stopped 2025-08-27T22:08:58.396Z,1756332538.396 [transit:PowerOnly](DEBUG): Aggregate::uninitialize transit:PowerOnly 2025-08-27T22:08:58.396Z,1756332538.396 [transit:PowerOnly:E.Wait] Stopped 2025-08-27T22:08:58.396Z,1756332538.396 [transit:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-08-27T22:08:58.397Z,1756332538.397 [transit:BuoyancyHold.Buoyancy] Stopped 2025-08-27T22:08:58.397Z,1756332538.397 [transit:BuoyancyHold.Buoyancy](DEBUG): Uninitialize Buoyancy Component. 2025-08-27T22:08:58.397Z,1756332538.397 [transit:MassHold.Pitch] Stopped 2025-08-27T22:08:58.397Z,1756332538.397 [transit:Transit] Stopped 2025-08-27T22:08:58.397Z,1756332538.397 [transit:Transit](DEBUG): Aggregate::uninitialize transit:Transit 2025-08-27T22:08:58.397Z,1756332538.397 [transit:Transit:A.Pitch] Stopped 2025-08-27T22:08:58.397Z,1756332538.397 [transit:Transit:B.SetSpeed] Stopped 2025-08-27T22:08:58.397Z,1756332538.397 [transit:Transit:B.SetSpeed](DEBUG): Uninitialize. 2025-08-27T22:08:58.397Z,1756332538.397 [transit:Transit:Wpt1.Waypoint] Stopped 2025-08-27T22:08:58.397Z,1756332538.397 [transit:Transit:Wpt1.Waypoint](DEBUG): Uninitialize WaypointComponent. 2025-08-27T22:08:58.845Z,1756332538.845 [MissionManager](IMPORTANT): Started mission DefaultWithUndock 2025-08-27T22:08:58.845Z,1756332538.845 [DefaultWithUndock] Running Loop=1 2025-08-27T22:08:58.845Z,1756332538.845 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock 2025-08-27T22:08:58.845Z,1756332538.845 [DefaultWithUndock:A.Wait] Running Loop=1 2025-08-27T22:08:58.845Z,1756332538.845 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component. 2025-08-27T22:09:21.284Z,1756332561.284 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting. 2025-08-27T22:09:22.287Z,1756332562.287 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:09:29.099Z,1756332569.099 [DefaultWithUndock:A.Wait](INFO): Done Waiting. 2025-08-27T22:09:29.100Z,1756332569.100 [DefaultWithUndock:A.Wait] Stopped 2025-08-27T22:09:29.100Z,1756332569.100 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component. 2025-08-27T22:09:29.100Z,1756332569.100 [DefaultWithUndock:LeaveDock] Running Loop=1 2025-08-27T22:09:29.100Z,1756332569.100 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock 2025-08-27T22:09:29.100Z,1756332569.100 [DefaultWithUndock:LeaveDock:A.] Running Loop=1 2025-08-27T22:09:29.100Z,1756332569.100 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact. 2025-08-27T22:09:29.100Z,1756332569.100 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1 2025-08-27T22:09:29.101Z,1756332569.101 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-08-27T22:09:29.101Z,1756332569.101 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-08-27T22:09:29.501Z,1756332569.501 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize. 2025-08-27T22:09:29.501Z,1756332569.501 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values. 2025-08-27T22:09:29.501Z,1756332569.501 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached from dock at depth 0.559226 m. 2025-08-27T22:09:29.502Z,1756332569.502 [DefaultWithUndock:LeaveDock:A.] Stopped 2025-08-27T22:09:29.502Z,1756332569.502 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact. 2025-08-27T22:09:29.916Z,1756332569.916 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer. 2025-08-27T22:09:30.341Z,1756332570.341 [DockingStepper](DEBUG): Initializing EZServoServo. 2025-08-27T22:09:30.462Z,1756332570.462 [DockingStepper](DEBUG): Initializing DockingStepper. 2025-08-27T22:09:33.992Z,1756332573.992 [DockingStepper](INFO): Changing to mode: 1 2025-08-27T22:09:34.338Z,1756332574.338 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session. 2025-08-27T22:09:50.112Z,1756332590.112 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: 14.60 m. Transitioning docking module to standby. 2025-08-27T22:09:50.545Z,1756332590.545 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby. 2025-08-27T22:09:50.913Z,1756332590.913 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete. 2025-08-27T22:09:50.913Z,1756332590.913 [DefaultWithUndock:LeaveDock:B.Undock] Stopped 2025-08-27T22:09:50.913Z,1756332590.913 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock 2025-08-27T22:09:50.913Z,1756332590.913 [DefaultWithUndock:LeaveDock] Stopped 2025-08-27T22:09:50.913Z,1756332590.913 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock 2025-08-27T22:09:50.913Z,1756332590.913 [DefaultWithUndock:SurfaceDefault] Running Loop=1 2025-08-27T22:09:50.913Z,1756332590.913 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault 2025-08-27T22:09:50.914Z,1756332590.914 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1 2025-08-27T22:09:50.914Z,1756332590.914 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent. 2025-08-27T22:09:50.914Z,1756332590.914 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s. 2025-08-27T22:09:50.914Z,1756332590.914 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees. 2025-08-27T22:09:50.914Z,1756332590.914 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s. 2025-08-27T22:09:50.915Z,1756332590.915 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds. 2025-08-27T22:09:50.915Z,1756332590.915 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds. 2025-08-27T22:09:50.916Z,1756332590.916 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds. 2025-08-27T22:09:51.318Z,1756332591.318 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1 2025-08-27T22:09:51.318Z,1756332591.318 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-08-27T22:09:51.318Z,1756332591.318 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1 2025-08-27T22:09:51.351Z,1756332591.351 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:09:53.330Z,1756332593.330 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220952.00,A,3647.57501,N,12150.55171,W,0.214,271.95,270825,,,D*72 2025-08-27T22:09:53.342Z,1756332593.342 [NAL9602](INFO): GPS fix at 20250827T220952: (36.792917, -121.842529) 2025-08-27T22:09:53.353Z,1756332593.353 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped 2025-08-27T22:09:53.354Z,1756332593.354 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1 2025-08-27T22:09:59.006Z,1756332599.006 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20250827T202119/Courier0012.lzma 2025-08-27T22:10:11.069Z,1756332611.069 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Courier0012.lzma.bak 2025-08-27T22:10:11.069Z,1756332611.069 [DataOverHttps](INFO): SBD MOMSN=25907119 2025-08-27T22:10:25.456Z,1756332625.456 [NAL9602](INFO): Not Powering down - fast GPS 2025-08-27T22:10:40.379Z,1756332640.379 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250827T202119/Courier0015.lzma 2025-08-27T22:10:51.421Z,1756332651.421 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Courier0015.lzma.bak 2025-08-27T22:10:51.421Z,1756332651.421 [DataOverHttps](INFO): SBD MOMSN=25907125 2025-08-27T22:11:20.772Z,1756332680.772 [DataOverHttps](INFO): Sending 321 bytes from file Logs/20250827T202119/Express0013.lzma 2025-08-27T22:11:31.813Z,1756332691.813 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Express0013.lzma.bak 2025-08-27T22:11:31.813Z,1756332691.813 [DataOverHttps](INFO): SBD MOMSN=25907143 2025-08-27T22:12:00.735Z,1756332720.735 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20250827T202119/Express0016.lzma 2025-08-27T22:12:11.777Z,1756332731.777 [DataOverHttps](INFO): Moved sent file to Logs/20250827T202119/Express0016.lzma.bak 2025-08-27T22:12:11.777Z,1756332731.777 [DataOverHttps](INFO): SBD MOMSN=25907176 2025-08-27T22:12:15.185Z,1756332735.185 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped 2025-08-27T22:12:15.185Z,1756332735.185 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Running Loop=1 2025-08-27T22:12:15.185Z,1756332735.185 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Initialize Wait Component. 2025-08-27T22:12:58.399Z,1756332778.399 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:13:17.299Z,1756332797.299 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:13:36.096Z,1756332816.096 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off 2025-08-27T22:13:53.733Z,1756332833.733 [DataOverHttps](IMPORTANT): SBD MTMSN=20250827T221353 2025-08-27T22:14:01.415Z,1756332841.415 [DataOverHttps](INFO): Received command: configSet ESPComponent.loadAtStartup 1 bool persist;configSet ESPComponent.simulateHardware 1 bool persist;restart app 2025-08-27T22:14:02.412Z,1756332842.412 [CommandExec](IMPORTANT): got command configSet ESPComponent.loadAtStartup 1 bool persist 2025-08-27T22:14:02.412Z,1756332842.412 [CommandExec](IMPORTANT): configSet ESPComponent.loadAtStartup requires a restart to take effect. 2025-08-27T22:14:02.433Z,1756332842.433 [CommandExec](IMPORTANT): got command configSet ESPComponent.simulateHardware 1 bool persist 2025-08-27T22:14:02.436Z,1756332842.436 [CommandExec](IMPORTANT): got command restart application 2025-08-27T22:14:03.439Z,1756332843.439 [CommandExec ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:03.439Z,1756332843.439 [CommandExec](INFO): Uninitializing the command executive. 2025-08-27T22:14:03.440Z,1756332843.440 [CommandExec](INFO): Uninitializing the command scheduler. 2025-08-27T22:14:03.440Z,1756332843.440 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:03.491Z,1756332843.491 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye! 2025-08-27T22:14:03.491Z,1756332843.491 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler 2025-08-27T22:14:03.492Z,1756332843.492 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:03.492Z,1756332843.492 [NavChartDb](INFO): Join timeout helper Thread ID is 7270 2025-08-27T22:14:03.520Z,1756332843.520 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:03.521Z,1756332843.521 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:03.536Z,1756332843.536 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler 2025-08-27T22:14:03.536Z,1756332843.536 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:03.537Z,1756332843.537 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 7271 2025-08-27T22:14:03.647Z,1756332843.647 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:03.648Z,1756332843.648 [WetLabsUBAT](INFO): Powering down 2025-08-27T22:14:03.648Z,1756332843.648 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:03.651Z,1756332843.651 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler 2025-08-27T22:14:03.651Z,1756332843.651 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:03.652Z,1756332843.652 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 7272 2025-08-27T22:14:03.724Z,1756332843.724 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:03.724Z,1756332843.724 [WetLabsBB2FL](INFO): Powering down 2025-08-27T22:14:03.725Z,1756332843.725 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:03.735Z,1756332843.735 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler 2025-08-27T22:14:03.735Z,1756332843.735 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:03.736Z,1756332843.736 [CTD_Seabird](INFO): Join timeout helper Thread ID is 7273 2025-08-27T22:14:04.287Z,1756332844.287 [CTD_Seabird](INFO): Powering down 2025-08-27T22:14:04.299Z,1756332844.299 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:04.300Z,1756332844.300 [CTD_Seabird](INFO): Powering down 2025-08-27T22:14:04.311Z,1756332844.311 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:04.327Z,1756332844.327 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler 2025-08-27T22:14:04.327Z,1756332844.327 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:04.328Z,1756332844.328 [Radio_Surface](INFO): Join timeout helper Thread ID is 7274 2025-08-27T22:14:04.439Z,1756332844.439 [Radio_Surface](INFO): Powering down 2025-08-27T22:14:04.440Z,1756332844.440 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:04.440Z,1756332844.440 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:04.460Z,1756332844.460 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler 2025-08-27T22:14:04.460Z,1756332844.460 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:04.460Z,1756332844.460 [Onboard](INFO): Join timeout helper Thread ID is 7275 2025-08-27T22:14:09.395Z,1756332849.395 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:09.396Z,1756332849.396 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.408Z,1756332849.408 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler 2025-08-27T22:14:09.408Z,1756332849.408 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.408Z,1756332849.408 [DataOverHttps](INFO): Join timeout helper Thread ID is 7276 2025-08-27T22:14:09.455Z,1756332849.455 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:09.459Z,1756332849.459 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.468Z,1756332849.468 [ComponentRegistry](INFO): Shutting down DAT ThreadHandler 2025-08-27T22:14:09.468Z,1756332849.468 [DAT ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.468Z,1756332849.468 [DAT](INFO): Join timeout helper Thread ID is 7277 2025-08-27T22:14:09.613Z,1756332849.613 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,-32768,-327681.09 2025-08-27T22:14:09.615Z,1756332849.615 [DAT](INFO): Powering down 2025-08-27T22:14:09.616Z,1756332849.616 [DAT ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:09.617Z,1756332849.617 [DAT](INFO): Powering down 2025-08-27T22:14:09.617Z,1756332849.617 [DAT ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.636Z,1756332849.636 [ComponentRegistry](INFO): Shutting down BackseatComponent ThreadHandler 2025-08-27T22:14:09.637Z,1756332849.637 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.637Z,1756332849.637 [BackseatComponent](INFO): Join timeout helper Thread ID is 7278 2025-08-27T22:14:09.819Z,1756332849.819 [BackseatComponent ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:09.820Z,1756332849.820 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.843Z,1756332849.843 [ComponentRegistry](INFO): Shutting down logger ThreadHandler 2025-08-27T22:14:09.843Z,1756332849.843 [logger ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.843Z,1756332849.843 [logger](INFO): Join timeout helper Thread ID is 7279 2025-08-27T22:14:09.856Z,1756332849.856 [logger ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:09.856Z,1756332849.856 [logger ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.858Z,1756332849.858 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler 2025-08-27T22:14:09.858Z,1756332849.858 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.858Z,1756332849.858 [CommandLine](INFO): Join timeout helper Thread ID is 7280 2025-08-27T22:14:09.955Z,1756332849.955 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:09.956Z,1756332849.956 [CommandLine ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.957Z,1756332849.957 [ComponentRegistry](INFO): Shutting down CommandExec ThreadHandler 2025-08-27T22:14:09.957Z,1756332849.957 [CommandExec ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.958Z,1756332849.958 [CommandExec](INFO): Join timeout helper Thread ID is 7281 2025-08-27T22:14:09.960Z,1756332849.960 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler 2025-08-27T22:14:09.960Z,1756332849.960 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:09.961Z,1756332849.961 [controlThread](INFO): Join timeout helper Thread ID is 7282 2025-08-27T22:14:09.979Z,1756332849.979 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread. 2025-08-27T22:14:09.980Z,1756332849.980 [controlThread](DEBUG): Uninitializing ControlThread 2025-08-27T22:14:09.980Z,1756332849.980 [AHRS_M2](INFO): Powering down 2025-08-27T22:14:10.037Z,1756332850.037 [NAL9602](INFO): Powering down 2025-08-27T22:14:10.040Z,1756332850.040 [RDI_Pathfinder](INFO): Powering down 2025-08-27T22:14:10.041Z,1756332850.041 [Sonardyne_Nano](INFO): Powering down 2025-08-27T22:14:10.043Z,1756332850.043 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator. 2025-08-27T22:14:10.044Z,1756332850.044 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator. 2025-08-27T22:14:10.044Z,1756332850.044 [NavChart](DEBUG): Uninitialize NavChart Navigation. 2025-08-27T22:14:10.045Z,1756332850.045 [MissionManager](INFO): Uninitializing Mission DefaultWithUndock 2025-08-27T22:14:10.045Z,1756332850.045 [DefaultWithUndock] Stopped 2025-08-27T22:14:10.045Z,1756332850.045 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock 2025-08-27T22:14:10.045Z,1756332850.045 [DefaultWithUndock:SurfaceDefault] Stopped 2025-08-27T22:14:10.045Z,1756332850.045 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault 2025-08-27T22:14:10.045Z,1756332850.045 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Stopped 2025-08-27T22:14:10.045Z,1756332850.045 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent. 2025-08-27T22:14:10.045Z,1756332850.045 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped 2025-08-27T22:14:10.045Z,1756332850.045 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn 2025-08-27T22:14:10.045Z,1756332850.045 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait] Stopped 2025-08-27T22:14:10.045Z,1756332850.045 [DefaultWithUndock:SurfaceDefault:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component. 2025-08-27T22:14:10.054Z,1756332850.054 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent. 2025-08-27T22:14:10.054Z,1756332850.054 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent. 2025-08-27T22:14:10.054Z,1756332850.054 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent. 2025-08-27T22:14:10.054Z,1756332850.054 [LoopControl](DEBUG): Uninitialize LoopControlComponent. 2025-08-27T22:14:10.055Z,1756332850.055 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo. 2025-08-27T22:14:10.055Z,1756332850.055 [BuoyancyServo](INFO): Powering down 2025-08-27T22:14:10.067Z,1756332850.067 [ElevatorServo](DEBUG): Uninitialize Elevator Servo. 2025-08-27T22:14:10.067Z,1756332850.067 [ElevatorServo](INFO): Powering down 2025-08-27T22:14:10.068Z,1756332850.068 [DockingStepper](DEBUG): Uninitialize Docking Stepper. 2025-08-27T22:14:10.068Z,1756332850.068 [DockingStepper](INFO): Powering down 2025-08-27T22:14:10.069Z,1756332850.069 [MassServo](DEBUG): Uninitialize Mass Servo. 2025-08-27T22:14:10.069Z,1756332850.069 [MassServo](INFO): Powering down 2025-08-27T22:14:10.070Z,1756332850.070 [RudderServo](DEBUG): Uninitialize Rudder Servo. 2025-08-27T22:14:10.070Z,1756332850.070 [RudderServo](INFO): Powering down 2025-08-27T22:14:10.071Z,1756332850.071 [ThrusterServo](DEBUG): Uninitialize Thruster Servo. 2025-08-27T22:14:10.071Z,1756332850.071 [ThrusterServo](INFO): Powering down 2025-08-27T22:14:10.072Z,1756332850.072 [SBIT](DEBUG): Uninitialize SBIT Component. 2025-08-27T22:14:10.072Z,1756332850.072 [IBIT](DEBUG): Uninitialize IBIT Component. 2025-08-27T22:14:10.073Z,1756332850.073 [CBIT](DEBUG): Uninitialize CBIT Component. 2025-08-27T22:14:10.073Z,1756332850.073 [CBIT](DEBUG): Powering off loads. 2025-08-27T22:14:10.083Z,1756332850.083 [CBIT](DEBUG): Disabling WDT. 2025-08-27T22:14:10.095Z,1756332850.095 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-08-27T22:14:10.095Z,1756332850.095 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-08-27T22:14:10.096Z,1756332850.096 [controlThread ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:10.154Z,1756332850.154 [Radio_Surface ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:10.157Z,1756332850.157 [Onboard ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:10.163Z,1756332850.163 [DataOverHttps ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:10.169Z,1756332850.169 [DAT ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:10.212Z,1756332850.212 [BackseatComponent ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:10.261Z,1756332850.261 [GFScanner](DEBUG): Uninitialize GFScanner component. 2025-08-27T22:14:10.261Z,1756332850.261 [GFScanner](DEBUG): Opening all GF detection circuits. 2025-08-27T22:14:10.291Z,1756332850.291 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:10.293Z,1756332850.293 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:10.297Z,1756332850.297 [CTD_Seabird ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:10.306Z,1756332850.306 [NavChartDb ThreadHandler](INFO): Thread cancelled. 2025-08-27T22:14:10.384Z,1756332850.384 [logger ThreadHandler](INFO): Thread cancelled.