2025-06-09T01:23:48.394Z,1749432228.394 [OnDock:N.Docked](DEBUG): Initializing internal variables to default values. 2025-06-09T01:23:48.434Z,1749432228.434 [CommandExec](IMPORTANT): got command restart logs 2025-06-09T01:23:49.032Z,1749432229.032 [DAT](INFO): entering command mode 2025-06-09T01:23:49.181Z,1749432229.181 [CTD_Seabird](ERROR): Failed to parse device response: 2025-06-09T01:23:49.229Z,1749432229.229 [DAT](INFO): DAT read: 2025-06-09T01:23:49.229Z,1749432229.229 [DAT](INFO): DAT read: user:1109> 2025-06-09T01:23:49.230Z,1749432229.230 [DAT](INFO): Requesting device enable set for address 50. 2025-06-09T01:23:49.481Z,1749432229.481 [DAT](INFO): DAT read: user:1109> 2025-06-09T01:23:49.482Z,1749432229.482 [DAT](INFO): DAT read: Tx time:01:23:50.0384 2025-06-09T01:23:49.482Z,1749432229.482 [DAT](INFO): Ping request sent. 2025-06-09T01:23:49.482Z,1749432229.482 [DAT](INFO): transmitted an acoustic signal 2025-06-09T01:23:49.482Z,1749432229.482 [DAT](INFO): publishing transmit ping time 2025-06-09T01:23:49.483Z,1749432229.483 [DAT](INFO): Requesting device enable set for address 50. 2025-06-09T01:23:49.733Z,1749432229.733 [DAT](INFO): Requesting device enable set for address 50. 2025-06-09T01:23:51.749Z,1749432231.749 [DAT](INFO): DAT read: Rx Time:01:23:51.9247 2025-06-09T01:23:51.749Z,1749432231.749 [DAT](INFO): Rx dataTimestamp_ set to:1749432231.749002 2025-06-09T01:23:52.259Z,1749432232.259 [DAT](INFO): DAT read: 01:23:51.9247 LVL= 9936, 20145, 16690, 15507, AGC= 45, IDX= 443,-0.46, 3.014,-2.382, 2.980,-1.926, PHS=-1.255,-0.409,-1.380, RAW= 336.8, 49.6, CAL= 336.4, 49.5, ROT= 173.6, -49.5 2025-06-09T01:23:52.260Z,1749432232.260 [DAT](INFO): got valid direction response: 01:23:51.9247 LVL= 9936, 20145, 16690, 15507, AGC= 45, IDX= 443,-0.46, 3.014,-2.382, 2.980,-1.926, PHS=-1.255,-0.409,-1.380, RAW= 336.8, 49.6, CAL= 336.4, 49.5, ROT= 173.6, -49.5 2025-06-09T01:23:52.260Z,1749432232.260 [DAT](INFO): DAT read: OK 2025-06-09T01:23:52.261Z,1749432232.261 [DAT](INFO): unknown deviceResponse_: OK 2025-06-09T01:23:52.261Z,1749432232.261 [DAT](INFO): DAT read: user:1110> 2025-06-09T01:23:52.262Z,1749432232.262 [DAT](INFO): #Rx 6: Read direction message, but no range. 2025-06-09T01:23:52.263Z,1749432232.263 [DAT](INFO): direction in FSK: [-0.645401,0.072393,0.760406] 2025-06-09T01:23:52.505Z,1749432232.505 [DAT](INFO): DAT read: Tx time:01:23:53.0384 2025-06-09T01:23:52.505Z,1749432232.505 [DAT](INFO): Ping request sent. 2025-06-09T01:23:52.505Z,1749432232.505 [DAT](INFO): transmitted an acoustic signal 2025-06-09T01:23:52.505Z,1749432232.505 [DAT](INFO): publishing transmit ping time 2025-06-09T01:23:54.773Z,1749432234.773 [DAT](INFO): DAT read: Rx Time:01:23:54.9247 2025-06-09T01:23:54.773Z,1749432234.773 [DAT](INFO): Rx dataTimestamp_ set to:1749432234.772980 2025-06-09T01:23:55.282Z,1749432235.282 [DAT](INFO): DAT read: 01:23:54.9247 LVL= 9568, 17025, 14962, 14771, AGC= 45, IDX= 443,-0.01, 2.863,-1.574,-2.457,-1.091, PHS=-2.241,-0.436,-1.369, RAW= 301.1, 42.5, CAL= 309.5, 42.7, ROT= 200.5, -42.7 2025-06-09T01:23:55.283Z,1749432235.283 [DAT](INFO): got valid direction response: 01:23:54.9247 LVL= 9568, 17025, 14962, 14771, AGC= 45, IDX= 443,-0.01, 2.863,-1.574,-2.457,-1.091, PHS=-2.241,-0.436,-1.369, RAW= 301.1, 42.5, CAL= 309.5, 42.7, ROT= 200.5, -42.7 2025-06-09T01:23:55.283Z,1749432235.283 [DAT](INFO): DAT read: OK 2025-06-09T01:23:55.283Z,1749432235.283 [DAT](INFO): unknown deviceResponse_: OK 2025-06-09T01:23:55.284Z,1749432235.284 [DAT](INFO): DAT read: user:1111> 2025-06-09T01:23:55.285Z,1749432235.285 [DAT](INFO): DAT read: Tx time:01:23:56.0384 2025-06-09T01:23:55.285Z,1749432235.285 [DAT](INFO): Ping request sent. 2025-06-09T01:23:55.285Z,1749432235.285 [DAT](INFO): transmitted an acoustic signal 2025-06-09T01:23:55.286Z,1749432235.286 [DAT](INFO): #Rx 7: Read direction message, but no range. 2025-06-09T01:23:55.287Z,1749432235.287 [DAT](INFO): direction in FSK: [-0.688374,-0.257372,0.678160] 2025-06-09T01:23:55.287Z,1749432235.287 [DAT](INFO): publishing transmit ping time 2025-06-09T01:23:55.290Z,1749432235.290 [DAT](INFO): publishing transmit ping time 2025-06-09T01:23:56.788Z,1749432236.788 [DAT](FAULT): Buffer send receipt timeout failure. 2025-06-09T01:23:56.789Z,1749432236.789 [DAT](DEBUG): In sendingTransmitVerify, timeout so go online and set commsState_ = SENDING_FILL_BUFFER 2025-06-09T01:23:57.043Z,1749432237.043 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-06-09T01:23:57.293Z,1749432237.293 [DAT](INFO): entering online mode 2025-06-09T01:23:57.544Z,1749432237.545 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:23:57.797Z,1749432237.797 [DAT](INFO): DAT read: Rx Time:01:23:57.9249 2025-06-09T01:23:57.797Z,1749432237.797 [DAT](INFO): Rx dataTimestamp_ set to:1749432237.797070 2025-06-09T01:23:57.798Z,1749432237.798 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:23:58.049Z,1749432238.049 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:23:58.306Z,1749432238.306 [DAT](INFO): DAT read: 01:23:57.9249 LVL= 10432, 18033, 14802, 17891, AGC= 45, IDX= 444,-0.36, 2.190,-2.693, 2.549,-2.331, PHS=-1.674,-0.315,-1.406, RAW= 319.3, 43.9, CAL= 323.4, 43.4, ROT= 186.6, -43.4 2025-06-09T01:23:58.307Z,1749432238.307 [DAT](INFO): got valid direction response: 01:23:57.9249 LVL= 10432, 18033, 14802, 17891, AGC= 45, IDX= 444,-0.36, 2.190,-2.693, 2.549,-2.331, PHS=-1.674,-0.315,-1.406, RAW= 319.3, 43.9, CAL= 323.4, 43.4, ROT= 186.6, -43.4 2025-06-09T01:23:58.307Z,1749432238.307 [DAT](INFO): DAT read: OK 2025-06-09T01:23:58.307Z,1749432238.307 [DAT](INFO): unknown deviceResponse_: OK 2025-06-09T01:23:58.308Z,1749432238.308 [DAT](INFO): DAT read: user:1112> 2025-06-09T01:23:58.309Z,1749432238.309 [DAT](INFO): DAT read: 2025-06-09T01:23:58.310Z,1749432238.310 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-06-09T01:23:58.310Z,1749432238.310 [DAT](INFO): commRate: 600 2025-06-09T01:23:58.310Z,1749432238.310 [DAT](INFO): online mode acknowledged 2025-06-09T01:23:58.311Z,1749432238.311 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-06-09T01:23:58.311Z,1749432238.311 [DAT](INFO): #Rx 8: Read direction message, but no range. 2025-06-09T01:23:58.312Z,1749432238.312 [DAT](INFO): direction in FSK: [-0.721759,-0.083510,0.687088] 2025-06-09T01:24:01.577Z,1749432241.577 [DAT](INFO): DAT read: Forwarding Delay UpTx time:01:24:02.2383 2025-06-09T01:24:01.578Z,1749432241.578 [DAT](DEBUG): In parseResponses, sent ack so set commsState_ = SENDING_VERIFIED 2025-06-09T01:24:01.578Z,1749432241.578 [DAT](DEBUG): In sendingVerified, data done so set commsState_ = SENDING_FILL_BUFFER 2025-06-09T01:25:26.566Z,1749432326.566 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for water velocity. Device response is::WS,-32768,-3278,V 2025-06-09T01:25:30.877Z,1749432330.877 [DAT](INFO): DAT read: Rx Time:01:25:31.0278 2025-06-09T01:25:30.877Z,1749432330.877 [DAT](INFO): Rx dataTimestamp_ set to:1749432330.877027 2025-06-09T01:25:31.642Z,1749432331.642 [DAT](INFO): DAT read: 01:25:31.0278 LVL= 10272, 19313, 15570, 16211, AGC= 45, IDX= 460,-0.08, 2.959,-1.371,-2.324,-0.996, PHS=-2.241,-0.329,-1.331, RAW= 301.6, 39.8, CAL= 310.2, 40.0, ROT= 199.8, -40.0 2025-06-09T01:25:31.643Z,1749432331.643 [DAT](INFO): got valid direction response: 01:25:31.0278 LVL= 10272, 19313, 15570, 16211, AGC= 45, IDX= 460,-0.08, 2.959,-1.371,-2.324,-0.996, PHS=-2.241,-0.329,-1.331, RAW= 301.6, 39.8, CAL= 310.2, 40.0, ROT= 199.8, -40.0 2025-06-09T01:25:31.643Z,1749432331.643 [DAT](INFO): DAT read: 2025-06-09T01:25:31.644Z,1749432331.644 [DAT](INFO): DAT read: DATA(0009):dock arm 2025-06-09T01:25:31.645Z,1749432331.645 [DAT](INFO): Got DATA 9 2025-06-09T01:25:31.645Z,1749432331.645 [DAT](INFO): DAT read: 2025-06-09T01:25:31.646Z,1749432331.646 [DAT](INFO): DAT read: Source:050 Destination:010 2025-06-09T01:25:31.646Z,1749432331.646 [DAT](INFO): Got Src/Dest after DATA 2025-06-09T01:25:31.646Z,1749432331.646 [DAT](INFO): DATA Src=50, Dst=10 2025-06-09T01:25:31.647Z,1749432331.647 [DAT](INFO): DAT read: CRC:Pass MPD:03.3 PSNR:15.2 AGC:49 SPD:+0.0 CCERR:011 2025-06-09T01:25:31.647Z,1749432331.647 [DAT](INFO): Got CRC:Pass 2025-06-09T01:25:31.648Z,1749432331.648 [DAT](INFO): Got CRC:Pass 2025-06-09T01:25:31.648Z,1749432331.648 [DAT](INFO): Incoming data is intended for us 2025-06-09T01:25:31.648Z,1749432331.648 [DAT](INFO): Received command: dock arm 2025-06-09T01:25:31.649Z,1749432331.649 [DAT](INFO): Sending ack 2025-06-09T01:25:31.649Z,1749432331.649 [DAT](INFO): DAT read: 2025-06-09T01:25:31.649Z,1749432331.649 [DAT](INFO): DAT read: 2025-06-09T01:25:31.650Z,1749432331.650 [DAT](INFO): #Rx 9: Read direction message, but no range. 2025-06-09T01:25:31.651Z,1749432331.651 [DAT](INFO): direction in FSK: [-0.720756,-0.259488,0.642788] 2025-06-09T01:25:31.721Z,1749432331.721 [CommandExec](IMPORTANT): got command docking arm 2025-06-09T01:25:31.721Z,1749432331.721 [CommandExec](IMPORTANT): Switching docking module to ARM. 2025-06-09T01:25:34.909Z,1749432334.909 [DAT](INFO): DAT read: Forwarding Delay UpTx time:01:25:35.5394 2025-06-09T01:25:46.374Z,1749432346.374 [OnDock:J.](INFO): *** querying acoustic contact *** 2025-06-09T01:25:46.501Z,1749432346.501 [DAT](DEBUG): Acoustic response timeout 2025-06-09T01:25:46.552Z,1749432346.552 [DAT](INFO): entering command mode 2025-06-09T01:25:46.753Z,1749432346.753 [DAT](INFO): DAT read: 2025-06-09T01:25:46.753Z,1749432346.753 [DAT](INFO): DAT read: user:1113> 2025-06-09T01:25:46.754Z,1749432346.754 [DAT](DEBUG): Acoustic response timeout 2025-06-09T01:25:46.754Z,1749432346.754 [DAT](INFO): setting remote address to 0 2025-06-09T01:25:47.005Z,1749432347.005 [DAT](INFO): DAT read: user:1113> 2025-06-09T01:25:47.006Z,1749432347.006 [DAT](INFO): DAT read: RemoteAddr | 0 2025-06-09T01:25:47.006Z,1749432347.006 [DAT](INFO): set remote address to 0 2025-06-09T01:25:47.006Z,1749432347.006 [DAT](DEBUG): Acoustic response timeout 2025-06-09T01:25:47.006Z,1749432347.006 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode. 2025-06-09T01:25:47.257Z,1749432347.257 [DAT](INFO): DAT read: user:1114> 2025-06-09T01:25:47.257Z,1749432347.257 [DAT](INFO): DAT read: Tx time:01:25:47.8408 2025-06-09T01:25:47.258Z,1749432347.258 [DAT](INFO): Ping request sent. 2025-06-09T01:25:47.258Z,1749432347.258 [DAT](INFO): transmitted an acoustic signal 2025-06-09T01:25:47.258Z,1749432347.258 [DAT](INFO): publishing transmit ping time 2025-06-09T01:25:47.259Z,1749432347.259 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000729 2025-06-09T01:25:47.509Z,1749432347.509 [DAT](INFO): DAT read: TxSync time:01:25:47.8400 2025-06-09T01:25:47.510Z,1749432347.510 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251833 2025-06-09T01:25:47.761Z,1749432347.761 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503317 2025-06-09T01:25:48.013Z,1749432348.013 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754952 2025-06-09T01:25:48.265Z,1749432348.265 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006892 2025-06-09T01:25:48.517Z,1749432348.517 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258876 2025-06-09T01:25:48.769Z,1749432348.769 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511128 2025-06-09T01:25:49.021Z,1749432349.021 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762916 2025-06-09T01:25:49.273Z,1749432349.273 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015300 2025-06-09T01:25:49.525Z,1749432349.525 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266891 2025-06-09T01:25:49.779Z,1749432349.779 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.520815 2025-06-09T01:25:50.030Z,1749432350.030 [DAT](INFO): DAT read: Rx Time:01:25:50.2480 2025-06-09T01:25:50.031Z,1749432350.031 [DAT](INFO): Rx dataTimestamp_ set to:1749432350.030291 2025-06-09T01:25:50.031Z,1749432350.031 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.773252 2025-06-09T01:25:50.281Z,1749432350.281 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022875 2025-06-09T01:25:50.533Z,1749432350.533 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274934 2025-06-09T01:25:50.790Z,1749432350.790 [DAT](INFO): DAT read: 01:25:50.2480 LVL= 8688, 17553, 15458, 14883, AGC= 46, IDX= 220, 0.07, 0.291, 1.868, 0.820, 2.188, PHS=-1.809,-0.274,-1.371, RAW= 313.9, 41.7, CAL= 319.8, 41.2, ROT= 190.2, -41.2 2025-06-09T01:25:50.791Z,1749432350.791 [DAT](INFO): got valid direction response: 01:25:50.2480 LVL= 8688, 17553, 15458, 14883, AGC= 46, IDX= 220, 0.07, 0.291, 1.868, 0.820, 2.188, PHS=-1.809,-0.274,-1.371, RAW= 313.9, 41.7, CAL= 319.8, 41.2, ROT= 190.2, -41.2 2025-06-09T01:25:50.797Z,1749432350.797 [DAT](INFO): DAT read: Bearing 190.2, -41.2 (Local) 2025-06-09T01:25:50.797Z,1749432350.797 [DAT](INFO): Local bearing/azimuth received: Bearing 190.2, -41.2 (Local) 2025-06-09T01:25:50.798Z,1749432350.798 [DAT](INFO): DAT read: Range 10 to 50 : 2.3 m (Round-trip 3.1 ms) speed 0.0 m/s 2025-06-09T01:25:50.799Z,1749432350.799 [DAT](INFO): #Rx 1: Read range and direction messages. 2025-06-09T01:25:50.812Z,1749432350.812 [DAT](INFO): direction in FSK: [-0.740523,-0.133241,0.658689] 2025-06-09T01:25:50.813Z,1749432350.813 [DAT](INFO): publishing direction and range info 2025-06-09T01:26:33.410Z,1749432393.410 [DAT](INFO): DAT read: user:1115>Rx Time:01:26:33.5791 2025-06-09T01:26:33.410Z,1749432393.410 [DAT](INFO): Rx dataTimestamp_ set to:1749432393.409926 2025-06-09T01:26:34.443Z,1749432394.443 [DAT](INFO): DAT read: 01:26:33.5791 LVL= 11184, 18017, 14322, 15427, AGC= 47, IDX= 278, 0.41,-2.347,-0.683,-1.616,-0.257, PHS=-2.002,-0.378,-1.361, RAW= 306.9, 43.0, CAL= 314.1, 43.0, ROT= 195.9, -43.0 2025-06-09T01:26:34.452Z,1749432394.452 [DAT](INFO): got valid direction response: 01:26:33.5791 LVL= 11184, 18017, 14322, 15427, AGC= 47, IDX= 278, 0.41,-2.347,-0.683,-1.616,-0.257, PHS=-2.002,-0.378,-1.361, RAW= 306.9, 43.0, CAL= 314.1, 43.0, ROT= 195.9, -43.0 2025-06-09T01:26:34.453Z,1749432394.453 [DAT](INFO): DAT read: 2025-06-09T01:26:34.454Z,1749432394.454 [DAT](INFO): DAT read: DATA(0026):run Engineering/undock.tl 2025-06-09T01:26:34.454Z,1749432394.454 [DAT](INFO): Got DATA 26 2025-06-09T01:26:34.454Z,1749432394.454 [DAT](INFO): DAT read: 2025-06-09T01:26:34.455Z,1749432394.455 [DAT](INFO): DAT read: Source:050 Destination:010 2025-06-09T01:26:34.455Z,1749432394.455 [DAT](INFO): Got Src/Dest after DATA 2025-06-09T01:26:34.460Z,1749432394.460 [DAT](INFO): DATA Src=50, Dst=10 2025-06-09T01:26:34.461Z,1749432394.461 [DAT](INFO): DAT read: CRC:Pass MPD:03.8 PSNR:14.8 AGC:50 SPD:-0.1 CCERR:011 2025-06-09T01:26:34.461Z,1749432394.461 [DAT](INFO): Got CRC:Pass 2025-06-09T01:26:34.461Z,1749432394.461 [DAT](INFO): Got CRC:Pass 2025-06-09T01:26:34.462Z,1749432394.462 [DAT](INFO): Incoming data is intended for us 2025-06-09T01:26:34.462Z,1749432394.462 [DAT](INFO): Received command: run Engineering/undock.tl 2025-06-09T01:26:34.462Z,1749432394.462 [DAT](INFO): #Outgoing data=1 2025-06-09T01:26:34.462Z,1749432394.462 [DAT](INFO): Sending ack 2025-06-09T01:26:34.462Z,1749432394.462 [DAT](INFO): DAT read: 2025-06-09T01:26:34.463Z,1749432394.463 [DAT](INFO): DAT read: 2025-06-09T01:26:34.465Z,1749432394.465 [DAT](DEBUG): In sendingFillBuffer, set commsState_ = SENDING_TRANSMIT 2025-06-09T01:26:34.465Z,1749432394.465 [DAT](INFO): #Rx 2: Read direction message, but no range. 2025-06-09T01:26:34.466Z,1749432394.466 [DAT](INFO): direction in FSK: [-0.703373,-0.200361,0.681998] 2025-06-09T01:26:34.549Z,1749432394.549 [CommandExec](IMPORTANT): got command run ./Missions/Engineering/undock.tl 2025-06-09T01:26:34.549Z,1749432394.549 [MissionManager](INFO): Uninitializing Mission OnDock 2025-06-09T01:26:34.549Z,1749432394.549 [OnDock] Stopped 2025-06-09T01:26:34.549Z,1749432394.549 [OnDock](DEBUG): Aggregate::uninitialize OnDock 2025-06-09T01:26:34.549Z,1749432394.549 [OnDock:StandardEnvelopes] Stopped 2025-06-09T01:26:34.549Z,1749432394.549 [OnDock:StandardEnvelopes](DEBUG): Aggregate::uninitialize OnDock:StandardEnvelopes 2025-06-09T01:26:34.549Z,1749432394.549 [OnDock:StandardEnvelopes:A.AltitudeEnvelope] Stopped 2025-06-09T01:26:34.549Z,1749432394.549 [OnDock:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent. 2025-06-09T01:26:34.549Z,1749432394.549 [OnDock:StandardEnvelopes:B.DepthEnvelope] Stopped 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize. 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:StandardEnvelopes:C.OffshoreEnvelope] Stopped 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent. 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:BackseatDriver] Stopped 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:BackseatDriver](DEBUG): Aggregate::uninitialize OnDock:BackseatDriver 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:BackseatDriver:A.BackseatDriver] Stopped 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:PowerOnly] Stopped 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:PowerOnly](DEBUG): Aggregate::uninitialize OnDock:PowerOnly 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:PowerOnly:E.Wait] Stopped 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component. 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:dataRead] Stopped 2025-06-09T01:26:34.550Z,1749432394.550 [OnDock:dataRead](DEBUG): Aggregate::uninitialize OnDock:dataRead 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:dataRead:B.Wait] Stopped 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:dataRead:B.Wait](DEBUG): Uninitialize Wait Component. 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:J.] Stopped 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:J.](DEBUG): Uninitializing TrackAcousticContact. 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:PeriodicCheck] Stopped 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:PeriodicCheck](DEBUG): Aggregate::uninitialize OnDock:PeriodicCheck 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:PeriodicCheck:CheckIP] Stopped 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:PeriodicCheck:CheckIP](DEBUG): Aggregate::uninitialize OnDock:PeriodicCheck:CheckIP 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:PeriodicCheck:CheckIP:B.Wait] Stopped 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:PeriodicCheck:CheckIP:B.Wait](DEBUG): Uninitialize Wait Component. 2025-06-09T01:26:34.551Z,1749432394.551 [OnDock:N.Docked] Stopped 2025-06-09T01:26:34.673Z,1749432394.673 [DAT](INFO): setting remote address to 50 2025-06-09T01:26:34.803Z,1749432394.803 [MissionManager](INFO): Loading Mission from file: ./Missions/Engineering/undock.tl 2025-06-09T01:26:34.803Z,1749432394.803 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Engineering/undock.tl 2025-06-09T01:26:34.847Z,1749432394.847 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Engineering/undock.tl 2025-06-09T01:26:34.925Z,1749432394.925 [DAT](INFO): DAT read: 2025-06-09T01:26:34.926Z,1749432394.926 [DAT](INFO): DAT read: RemoteAddr | 50 2025-06-09T01:26:34.927Z,1749432394.927 [DAT](INFO): set remote address to 50 2025-06-09T01:26:34.927Z,1749432394.927 [DAT](INFO): DAT read: user:1116> 2025-06-09T01:26:34.928Z,1749432394.928 [DAT](INFO): DAT read: Tx time:01:26:35.5403 2025-06-09T01:26:34.929Z,1749432394.929 [DAT](INFO): Ping request sent. 2025-06-09T01:26:34.929Z,1749432394.929 [DAT](INFO): transmitted an acoustic signal 2025-06-09T01:26:34.929Z,1749432394.929 [DAT](INFO): entering online mode 2025-06-09T01:26:35.177Z,1749432395.177 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:35.430Z,1749432395.430 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:35.680Z,1749432395.680 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:35.893Z,1749432395.893 [MissionManager](DEBUG): TethyslAPI: ./Missions/Engineering/undock.tl translated into: 20 10 2 NaN NaN 1 10 1 5 2 NaN Restarting logs restart logs Undocking at range and depth . Undock timed out, stopping mission Docked depth above surface threshold, skipping transit. 2025-06-09T01:26:35.901Z,1749432395.901 [MissionManager](INFO): DefineArg undock.MissionTimeout = 20.000000 min 2025-06-09T01:26:35.904Z,1749432395.904 [MissionManager](INFO): DefineArg undock.UndockTimeout = 10.000000 min 2025-06-09T01:26:35.907Z,1749432395.907 [MissionManager](INFO): DefineArg undock.DriftTimeout = 2.000000 min 2025-06-09T01:26:35.910Z,1749432395.910 [MissionManager](INFO): DefineArg undock.TransitLat = nan arcdeg 2025-06-09T01:26:35.913Z,1749432395.913 [MissionManager](INFO): DefineArg undock.TransitLon = nan arcdeg 2025-06-09T01:26:35.916Z,1749432395.916 [MissionManager](INFO): DefineArg undock.TransitSpeed = 1.000000 m/s 2025-06-09T01:26:35.919Z,1749432395.919 [MissionManager](INFO): DefineArg undock.TrackingUpdatePeriod = 10.000000 s 2025-06-09T01:26:35.923Z,1749432395.923 [MissionManager](INFO): DefineArg undock.NumberOfPings = 1.000000 count 2025-06-09T01:26:35.926Z,1749432395.926 [MissionManager](INFO): DefineArg undock.TransponderCode = 50 count 2025-06-09T01:26:35.930Z,1749432395.930 [MissionManager](INFO): DefineArg undock.MaxDepth = 215.000000 m 2025-06-09T01:26:35.936Z,1749432395.936 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:35.953Z,1749432395.953 [MissionManager](INFO): DefineArg undock.MinAltitude = 5.000000 m 2025-06-09T01:26:35.964Z,1749432395.964 [MissionManager](INFO): DefineArg undock.MinOffshore = 2.000000 km 2025-06-09T01:26:35.982Z,1749432395.982 [MissionManager](INFO): DefineOutput undock.DockedDepth = nan m 2025-06-09T01:26:35.998Z,1749432395.998 [MissionManager](INFO): DefineOutput undock.SkipTransit = 0 bool 2025-06-09T01:26:35.998Z,1749432395.998 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl 2025-06-09T01:26:35.998Z,1749432395.998 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl 2025-06-09T01:26:35.999Z,1749432395.999 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl 2025-06-09T01:26:36.189Z,1749432396.189 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:36.211Z,1749432396.211 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into: 5 1.5 200 2000 2025-06-09T01:26:36.228Z,1749432396.228 [MissionManager](INFO): DefineArg undock:StandardEnvelopes.MinAltitude = 5.000000 m 2025-06-09T01:26:36.231Z,1749432396.231 [MissionManager](INFO): DefineArg undock:StandardEnvelopes.MaxDepthIgnore = 1.500000 m 2025-06-09T01:26:36.239Z,1749432396.239 [MissionManager](INFO): DefineArg undock:StandardEnvelopes.MaxDepth = 200.000000 m 2025-06-09T01:26:36.246Z,1749432396.246 [MissionManager](INFO): DefineArg undock:StandardEnvelopes.MinOffshore = 2000.000000 m 2025-06-09T01:26:36.247Z,1749432396.247 [undock:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope. 2025-06-09T01:26:36.267Z,1749432396.267 [undock:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope. 2025-06-09T01:26:36.286Z,1749432396.286 [undock:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope. 2025-06-09T01:26:36.314Z,1749432396.314 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl 2025-06-09T01:26:36.314Z,1749432396.314 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl 2025-06-09T01:26:36.315Z,1749432396.315 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl 2025-06-09T01:26:36.355Z,1749432396.355 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into: 2025-06-09T01:26:36.374Z,1749432396.374 [MissionManager](INFO): DefineArg undock:BackseatDriver.EnableBackseat = 0 bool 2025-06-09T01:26:36.383Z,1749432396.383 [undock:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver. 2025-06-09T01:26:36.403Z,1749432396.403 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl 2025-06-09T01:26:36.411Z,1749432396.411 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl 2025-06-09T01:26:36.442Z,1749432396.442 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:36.485Z,1749432396.485 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl 2025-06-09T01:26:36.692Z,1749432396.692 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:36.765Z,1749432396.765 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into: 99999 2025-06-09T01:26:36.788Z,1749432396.788 [MissionManager](INFO): DefineArg undock:PowerOnly.SampleAll = 0 bool 2025-06-09T01:26:36.790Z,1749432396.790 [MissionManager](INFO): DefineArg undock:PowerOnly.SampleLoad1 = 0 bool 2025-06-09T01:26:36.794Z,1749432396.794 [MissionManager](INFO): DefineArg undock:PowerOnly.SampleLoad2 = 0 bool 2025-06-09T01:26:36.804Z,1749432396.804 [MissionManager](INFO): DefineArg undock:PowerOnly.SampleLoad3 = 0 bool 2025-06-09T01:26:36.812Z,1749432396.812 [MissionManager](INFO): DefineArg undock:PowerOnly.EnabledPowerOnly = 0 bool 2025-06-09T01:26:36.823Z,1749432396.823 [undock:PowerOnly:E.Wait](DEBUG): Construct Wait. 2025-06-09T01:26:36.866Z,1749432396.866 [undock:I.Execute](DEBUG): Construct Execute. 2025-06-09T01:26:36.945Z,1749432396.945 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:36.959Z,1749432396.959 [undock:Detach:D.Undock](DEBUG): Construct. 2025-06-09T01:26:36.959Z,1749432396.959 [undock:Detach:D.Undock](DEBUG): Initializing internal variables to default values. 2025-06-09T01:26:37.007Z,1749432397.007 [undock:Transit:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy. 2025-06-09T01:26:37.022Z,1749432397.022 [undock:Transit:MassHold.Pitch](DEBUG): Construct. 2025-06-09T01:26:37.033Z,1749432397.033 [undock:Transit:C.Pitch](DEBUG): Construct. 2025-06-09T01:26:37.047Z,1749432397.047 [undock:Transit:D.SetSpeed](DEBUG): Construct. 2025-06-09T01:26:37.051Z,1749432397.051 [undock:Transit:Wpt1.Waypoint](DEBUG): Construct Waypoint. 2025-06-09T01:26:37.087Z,1749432397.087 [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 { """ Leave dock and transit to waypoint at dock depth """ arguments { MissionTimeout = 20 minute """ Maximum duration of mission. """ UndockTimeout = 10 minute """ Maximum time to wait for successful undocking before ending mission. """ DriftTimeout = 2 minute """ Time to wait before retrying undock manuever if previous undock unsuccessful. """ TransitLat = NaN degree """ Latitude of waypoint to seek. Skipped if NaN. """ TransitLon = NaN degree """ Longitude of waypoint to seek. Skipped if NaN. """ TransitSpeed = 1 meter_per_second """ Speed at which to transit. """ TrackingUpdatePeriod = 10 second """ How long to wait between acoustic queries. """ NumberOfPings = 1 count """ Number of pings requested each time. """ TransponderCode = Dock:Dock.transponderCode """ Transponder Address. """ MaxDepth = BIT:CBIT.stopDepth """ Maximum depth while docked. """ MinAltitude = 5 meter """ Minimum altitude. """ MinOffshore = 2 km """ Minimum offshore. """ } output { DockedDepth = NaN meter SkipTransit = false } timeout duration=MissionTimeout 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 # Send data when connection exists (it shouldn't) readData { while ( Sensor:DataOverHttps.connectionStatus == true ) Universal:platform_communications } syslog important "Restarting logs" behavior Guidance:Execute { run in sequence set command = "restart logs" } # Undock cleanly, instead of relying on DefaultWithUndock to come next aggregate Detach { run in sequence behavior Estimation:TrackAcousticContact { run in parallel set contactLabelSetting = TransponderCode set numberOfSamplesSetting = NumberOfPings set updatePeriodSetting = TrackingUpdatePeriod } syslog important "Undocking at range " + Estimation:TrackAcousticContact.range_to_contact~meter + "and depth " + Universal:depth~meter + "." assign in sequence DockedDepth = Universal:depth behavior Dock:Undock { run in sequence timeout duration=UndockTimeout { assign in sequence SkipTransit = true syslog critical "Undock timed out, stopping mission" } set driftTimeout = DriftTimeout } aggregate SurfaceCheck { run when ( DockedDepth <= Control:VerticalControl.surfaceThreshold ) syslog important "Docked depth " + DockedDepth~meter + "above surface threshold, skipping transit." assign in sequence SkipTransit = true } } # And get away from the dock aggregate Transit { run in sequence break if ( SkipTransit or isNaN ( TransitLat ) or isNaN ( TransitLon ) or isNaN ( DockedDepth ) ) behavior Guidance:Buoyancy id="BuoyancyHold" { run in parallel set position = Control:VerticalControl.buoyancyNeutral } behavior Guidance:Pitch id="MassHold" { run in parallel set massPosition = Control:VerticalControl.massDefault } behavior Guidance:Pitch { run in parallel set depth = DockedDepth } behavior Guidance:SetSpeed { run in parallel set speed = TransitSpeed } behavior Guidance:Waypoint id="Wpt1" { run in sequence set latitude = TransitLat set longitude = TransitLon } } } 2025-06-09T01:26:37.093Z,1749432397.093 [CommandExec](IMPORTANT): Running ./Missions/Engineering/undock.tl 2025-06-09T01:26:37.197Z,1749432397.197 [DAT](INFO): DAT read: Rx Time:01:26:37.4296 2025-06-09T01:26:37.198Z,1749432397.198 [DAT](INFO): Rx dataTimestamp_ set to:1749432397.197538 2025-06-09T01:26:37.198Z,1749432397.198 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:37.285Z,1749432397.285 [MissionManager](IMPORTANT): Started mission undock 2025-06-09T01:26:37.285Z,1749432397.285 [undock] Running Loop=1 2025-06-09T01:26:37.285Z,1749432397.285 [undock](DEBUG): Aggregate::initialize undock 2025-06-09T01:26:37.285Z,1749432397.285 [undock:StandardEnvelopes] Running Loop=1 2025-06-09T01:26:37.285Z,1749432397.285 [undock:StandardEnvelopes](DEBUG): Aggregate::initialize undock:StandardEnvelopes 2025-06-09T01:26:37.285Z,1749432397.285 [undock:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-06-09T01:26:37.286Z,1749432397.286 [undock:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent. 2025-06-09T01:26:37.286Z,1749432397.286 [undock:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-06-09T01:26:37.286Z,1749432397.286 [undock:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent. 2025-06-09T01:26:37.286Z,1749432397.286 [undock:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-06-09T01:26:37.286Z,1749432397.286 [undock:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent. 2025-06-09T01:26:37.286Z,1749432397.286 [undock:BackseatDriver] Running Loop=1 2025-06-09T01:26:37.286Z,1749432397.286 [undock:BackseatDriver](DEBUG): Aggregate::initialize undock:BackseatDriver 2025-06-09T01:26:37.286Z,1749432397.286 [undock:BackseatDriver:A.BackseatDriver] Running Loop=1 2025-06-09T01:26:37.286Z,1749432397.286 [undock:PowerOnly] Running Loop=1 2025-06-09T01:26:37.287Z,1749432397.287 [undock:PowerOnly](DEBUG): Aggregate::initialize undock:PowerOnly 2025-06-09T01:26:37.287Z,1749432397.287 [undock:PowerOnly:A] Running Loop=1 2025-06-09T01:26:37.287Z,1749432397.287 [undock:PowerOnly:B] Running Loop=1 2025-06-09T01:26:37.287Z,1749432397.287 [undock:PowerOnly:C] Running Loop=1 2025-06-09T01:26:37.287Z,1749432397.287 [undock:PowerOnly:D] Running Loop=1 2025-06-09T01:26:37.287Z,1749432397.287 [undock:PowerOnly:E.Wait] Running Loop=1 2025-06-09T01:26:37.287Z,1749432397.287 [undock:PowerOnly:E.Wait](DEBUG): Initialize Wait Component. 2025-06-09T01:26:37.287Z,1749432397.287 [undock:G] Running Loop=1 2025-06-09T01:26:37.287Z,1749432397.287 [undock:B] Running Loop=1 2025-06-09T01:26:37.287Z,1749432397.287 [undock:G] Stopped 2025-06-09T01:26:37.292Z,1749432397.292 [undock:PowerOnly] Running Loop=1 2025-06-09T01:26:37.292Z,1749432397.292 [undock:PowerOnly:D] Stopped 2025-06-09T01:26:37.292Z,1749432397.292 [undock:PowerOnly:C] Stopped 2025-06-09T01:26:37.292Z,1749432397.292 [undock:PowerOnly:B] Stopped 2025-06-09T01:26:37.292Z,1749432397.292 [undock:PowerOnly:A] Stopped 2025-06-09T01:26:37.292Z,1749432397.292 [undock:BackseatDriver] Running Loop=1 2025-06-09T01:26:37.293Z,1749432397.293 [undock:B] Stopped 2025-06-09T01:26:37.293Z,1749432397.293 [undock:C] Running Loop=1 2025-06-09T01:26:37.293Z,1749432397.293 [undock:StandardEnvelopes] Running Loop=1 2025-06-09T01:26:37.293Z,1749432397.293 [undock:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1 2025-06-09T01:26:37.293Z,1749432397.293 [undock:StandardEnvelopes:B.DepthEnvelope] Running Loop=1 2025-06-09T01:26:37.294Z,1749432397.294 [undock:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1 2025-06-09T01:26:37.451Z,1749432397.451 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:37.700Z,1749432397.700 [DAT](DEBUG): checking for online mode acknowledgment 2025-06-09T01:26:37.702Z,1749432397.702 [undock:C] Stopped 2025-06-09T01:26:37.702Z,1749432397.702 [undock:D] Running Loop=1 2025-06-09T01:26:37.958Z,1749432397.958 [DAT](INFO): DAT read: 01:26:37.4296 LVL= 12320, 11377, 13874, 16275, AGC= 49, IDX= 55, 0.08,-2.488,-0.717,-1.663,-0.305, PHS=-2.095,-0.365,-1.361, RAW= 305.0, 41.9, CAL= 312.7, 41.9, ROT= 197.3, -41.9 2025-06-09T01:26:37.959Z,1749432397.959 [DAT](INFO): got valid direction response: 01:26:37.4296 LVL= 12320, 11377, 13874, 16275, AGC= 49, IDX= 55, 0.08,-2.488,-0.717,-1.663,-0.305, PHS=-2.095,-0.365,-1.361, RAW= 305.0, 41.9, CAL= 312.7, 41.9, ROT= 197.3, -41.9 2025-06-09T01:26:37.959Z,1749432397.959 [DAT](INFO): DAT read: OK 2025-06-09T01:26:37.959Z,1749432397.959 [DAT](INFO): unknown deviceResponse_: OK 2025-06-09T01:26:37.960Z,1749432397.960 [DAT](INFO): DAT read: user:1117> 2025-06-09T01:26:37.960Z,1749432397.960 [DAT](INFO): DAT read: 2025-06-09T01:26:37.961Z,1749432397.961 [DAT](INFO): DAT read: CONNECT 00600 bits/sec 1 of 4, Rate 1/2 CC 25.00ms MGP 2025-06-09T01:26:37.962Z,1749432397.962 [DAT](INFO): commRate: 600 2025-06-09T01:26:37.962Z,1749432397.962 [DAT](INFO): online mode acknowledged 2025-06-09T01:26:37.962Z,1749432397.962 [DAT](DEBUG): In sendingTransmit, set commsState_ = SENDING_TRANSMIT_VERIFY 2025-06-09T01:26:37.962Z,1749432397.962 [DAT](INFO): #Rx 3: Read direction message, but no range. 2025-06-09T01:26:37.963Z,1749432397.963 [DAT](INFO): direction in FSK: [-0.710639,-0.221340,0.667833] 2025-06-09T01:26:38.097Z,1749432398.097 [undock:D] Stopped 2025-06-09T01:26:38.097Z,1749432398.097 [undock:H] Running Loop=1 2025-06-09T01:26:38.539Z,1749432398.539 [undock:H](IMPORTANT): Restarting logs 2025-06-09T01:26:38.539Z,1749432398.539 [undock:H] Stopped 2025-06-09T01:26:38.539Z,1749432398.539 [undock:I.Execute] Running Loop=1 2025-06-09T01:26:38.892Z,1749432398.892 [undock:I.Execute](INFO): Executing command restart logs 2025-06-09T01:26:38.892Z,1749432398.892 [undock:I.Execute] Stopped 2025-06-09T01:26:38.892Z,1749432398.892 [undock:Detach] Running Loop=1 2025-06-09T01:26:38.892Z,1749432398.892 [undock:Detach](DEBUG): Aggregate::initialize undock:Detach 2025-06-09T01:26:38.892Z,1749432398.892 [undock:Detach:A.] Running Loop=1 2025-06-09T01:26:38.892Z,1749432398.892 [undock:Detach:A.](INFO): Initializing TrackAcousticContact. 2025-06-09T01:26:38.893Z,1749432398.893 [undock:Detach:B] Running Loop=1