2025-06-22T03:12:24.470Z,1750561944.470 [CommandExec](IMPORTANT): got command restart logs
2025-06-22T03:12:24.965Z,1750561944.965 [DockingStepper](INFO): Starting
2025-06-22T03:12:24.971Z,1750561944.971 [DAT](INFO): Requesting device enable set for address 50.
2025-06-22T03:12:25.221Z,1750561945.221 [DAT](INFO): DAT read: user:3696>
2025-06-22T03:12:25.222Z,1750561945.222 [DAT](INFO): DAT read: Tx time:03:12:29.3674
2025-06-22T03:12:25.222Z,1750561945.222 [DAT](INFO): Ping request sent.
2025-06-22T03:12:25.222Z,1750561945.222 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:12:25.222Z,1750561945.222 [DAT](INFO): publishing transmit ping time
2025-06-22T03:12:25.223Z,1750561945.223 [DAT](INFO): Requesting device enable set for address 50.
2025-06-22T03:12:25.377Z,1750561945.377 [DockingStepper](INFO): Changing to mode: 1
2025-06-22T03:12:25.377Z,1750561945.377 [DockingStepper](INFO): Standby mode.
2025-06-22T03:12:25.380Z,1750561945.380 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:12:25.440Z,1750561945.440 [DockingStepper](INFO): Commanding positive:17547
2025-06-22T03:12:25.473Z,1750561945.473 [DAT](INFO): Requesting device enable set for address 50.
2025-06-22T03:12:26.094Z,1750561946.094 [CTD_Seabird](ERROR): Failed to parse device response:
2025-06-22T03:12:27.336Z,1750561947.336 [DockingStepper](INFO): Commanding positive:17436
2025-06-22T03:12:27.489Z,1750561947.489 [DAT](INFO): DAT read: Rx Time:03:12:31.2256
2025-06-22T03:12:27.489Z,1750561947.489 [DAT](INFO): Rx dataTimestamp_ set to:1750561947.489105
2025-06-22T03:12:28.249Z,1750561948.249 [DAT](INFO): DAT read: 03:12:31.2256 LVL= 20048, 15521, 19154, 17267, AGC= 37, IDX= 441, 0.08, 3.035,-1.749,-1.765,-1.165, PHS=-1.995,-0.537,-0.604, RAW= 272.3, 37.9, CAL= 285.6, 41.5, ROT= 224.4, -41.5
2025-06-22T03:12:28.251Z,1750561948.251 [DAT](INFO): got valid direction response:
03:12:31.2256 LVL= 20048, 15521, 19154, 17267, AGC= 37, IDX= 441, 0.08, 3.035,-1.749,-1.765,-1.165, PHS=-1.995,-0.537,-0.604, RAW= 272.3, 37.9, CAL= 285.6, 41.5, ROT= 224.4, -41.5
2025-06-22T03:12:28.251Z,1750561948.251 [DAT](INFO): DAT read: OK
2025-06-22T03:12:28.251Z,1750561948.251 [DAT](INFO): unknown deviceResponse_: OK
2025-06-22T03:12:28.252Z,1750561948.252 [DAT](INFO): DAT read: user:3697>
2025-06-22T03:12:28.253Z,1750561948.253 [DAT](INFO): DAT read: Tx time:03:12:32.3174
2025-06-22T03:12:28.253Z,1750561948.253 [DAT](INFO): Ping request sent.
2025-06-22T03:12:28.253Z,1750561948.253 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:12:28.253Z,1750561948.253 [DAT](INFO): #Rx 6: Read direction message, but no range.
2025-06-22T03:12:28.254Z,1750561948.254 [DAT](INFO): direction in FSK: [-0.535108,-0.524017,0.662620]
2025-06-22T03:12:28.255Z,1750561948.255 [DAT](INFO): publishing transmit ping time
2025-06-22T03:12:28.258Z,1750561948.258 [DAT](INFO): publishing transmit ping time
2025-06-22T03:12:29.372Z,1750561949.372 [DockingStepper](INFO): Commanding positive:17436
2025-06-22T03:12:30.514Z,1750561950.514 [DAT](INFO): DAT read: Rx Time:03:12:34.1756
2025-06-22T03:12:30.515Z,1750561950.515 [DAT](INFO): Rx dataTimestamp_ set to:1750561950.514234
2025-06-22T03:12:31.017Z,1750561951.017 [DAT](INFO): DAT read: OK
2025-06-22T03:12:31.017Z,1750561951.017 [DAT](INFO): unknown deviceResponse_: OK
2025-06-22T03:12:31.017Z,1750561951.017 [DAT](INFO): DAT read: user:3698>
2025-06-22T03:12:31.018Z,1750561951.018 [DAT](INFO): DAT read: Tx time:03:12:35.2674
2025-06-22T03:12:31.018Z,1750561951.018 [DAT](INFO): Ping request sent.
2025-06-22T03:12:31.019Z,1750561951.019 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:12:31.019Z,1750561951.019 [DAT](INFO): publishing transmit ping time
2025-06-22T03:12:31.372Z,1750561951.372 [DockingStepper](INFO): Commanding positive:17362
2025-06-22T03:12:33.392Z,1750561953.392 [DockingStepper](INFO): Commanding positive:17553
2025-06-22T03:12:33.537Z,1750561953.537 [DAT](INFO): DAT read: Rx Time:03:12:37.1257
2025-06-22T03:12:33.537Z,1750561953.537 [DAT](INFO): Rx dataTimestamp_ set to:1750561953.537062
2025-06-22T03:12:34.041Z,1750561954.041 [DAT](INFO): DAT read: OK
2025-06-22T03:12:34.041Z,1750561954.041 [DAT](INFO): unknown deviceResponse_: OK
2025-06-22T03:12:35.420Z,1750561955.420 [DockingStepper](INFO): Commanding positive:17553
2025-06-22T03:12:35.445Z,1750561955.445 [DockingStepper](FAULT): Timed out moving from: 13599 to: 16450 response: ÿ
2025-06-22T03:12:35.445Z,1750561955.445 [DockingStepper] Hardware Fault, FailCount= 3
2025-06-22T03:12:35.445Z,1750561955.445 [DockingStepper](ERROR): Hardware Fault
2025-06-22T03:12:35.449Z,1750561955.449 [CBIT](ERROR): Hardware Fault in component: DockingStepper
2025-06-22T03:12:35.737Z,1750561955.737 [DockingStepper](INFO): Stop
2025-06-22T03:12:35.737Z,1750561955.737 [DockingStepper](DEBUG): Uninitialize Docking Stepper.
2025-06-22T03:12:35.737Z,1750561955.737 [DockingStepper](INFO): Powering down
2025-06-22T03:12:36.185Z,1750561956.185 [DockingStepper](INFO): Stopping
2025-06-22T03:12:36.529Z,1750561956.529 [DockingStepper](INFO): Stopping
2025-06-22T03:12:37.169Z,1750561957.169 [DockingStepper](INFO): Stopping
2025-06-22T03:12:37.349Z,1750561957.349 [DockingStepper](INFO): Stopping
2025-06-22T03:12:37.757Z,1750561957.757 [DockingStepper](INFO): Stopping
2025-06-22T03:12:38.249Z,1750561958.249 [DockingStepper](INFO): Stopping
2025-06-22T03:12:38.545Z,1750561958.545 [DockingStepper](INFO): Stopping
2025-06-22T03:12:38.957Z,1750561958.957 [DockingStepper](INFO): Stopping
2025-06-22T03:12:39.393Z,1750561959.393 [DockingStepper](INFO): Stopping
2025-06-22T03:12:39.765Z,1750561959.765 [DockingStepper](INFO): Stopping
2025-06-22T03:12:40.257Z,1750561960.257 [DockingStepper](INFO): Stopping
2025-06-22T03:12:40.569Z,1750561960.569 [DockingStepper](INFO): Stopping
2025-06-22T03:12:40.977Z,1750561960.977 [DockingStepper](INFO): Stopping
2025-06-22T03:12:41.449Z,1750561961.449 [DockingStepper](INFO): Stopping
2025-06-22T03:12:41.801Z,1750561961.801 [DockingStepper](INFO): Stopping
2025-06-22T03:12:42.282Z,1750561962.282 [DockingStepper](INFO): Stopping
2025-06-22T03:12:42.597Z,1750561962.597 [DockingStepper](INFO): Stopping
2025-06-22T03:12:42.997Z,1750561962.997 [DockingStepper](INFO): Stopping
2025-06-22T03:12:43.429Z,1750561963.429 [DockingStepper](INFO): Stopping
2025-06-22T03:12:43.793Z,1750561963.793 [DockingStepper](INFO): Stopping
2025-06-22T03:12:44.297Z,1750561964.297 [DockingStepper](INFO): Stopping
2025-06-22T03:12:44.631Z,1750561964.631 [DockingStepper](INFO): Stopping
2025-06-22T03:12:44.997Z,1750561964.997 [DockingStepper](INFO): Stopping
2025-06-22T03:12:45.429Z,1750561965.429 [DockingStepper](INFO): Stopping
2025-06-22T03:12:45.821Z,1750561965.821 [DockingStepper](INFO): Stopping
2025-06-22T03:12:46.305Z,1750561966.305 [DockingStepper](INFO): Stopping
2025-06-22T03:12:46.617Z,1750561966.617 [DockingStepper](INFO): Stopping
2025-06-22T03:12:47.033Z,1750561967.033 [DockingStepper](INFO): Stopping
2025-06-22T03:12:47.461Z,1750561967.461 [DockingStepper](INFO): Stopping
2025-06-22T03:12:47.829Z,1750561967.829 [DockingStepper](INFO): Stopping
2025-06-22T03:12:48.349Z,1750561968.349 [DockingStepper](INFO): Stopping
2025-06-22T03:12:48.650Z,1750561968.650 [DockingStepper](INFO): Stopping
2025-06-22T03:12:49.061Z,1750561969.061 [DockingStepper](INFO): Stopping
2025-06-22T03:12:49.489Z,1750561969.489 [DockingStepper](INFO): Stopping
2025-06-22T03:12:49.857Z,1750561969.857 [DockingStepper](INFO): Stopping
2025-06-22T03:12:50.357Z,1750561970.357 [DockingStepper](INFO): Stopping
2025-06-22T03:12:50.729Z,1750561970.729 [DockingStepper](INFO): Stopping
2025-06-22T03:12:51.079Z,1750561971.079 [DockingStepper](INFO): Stopping
2025-06-22T03:12:51.514Z,1750561971.514 [DockingStepper](INFO): Stopping
2025-06-22T03:12:51.885Z,1750561971.885 [DockingStepper](INFO): Stopping
2025-06-22T03:12:52.346Z,1750561972.346 [DockingStepper](INFO): Stopping
2025-06-22T03:12:52.732Z,1750561972.732 [DockingStepper](INFO): Stopping
2025-06-22T03:12:53.094Z,1750561973.094 [DockingStepper](INFO): Stopping
2025-06-22T03:12:53.521Z,1750561973.521 [DockingStepper](INFO): Stopping
2025-06-22T03:12:53.917Z,1750561973.917 [DockingStepper](INFO): Stopping
2025-06-22T03:12:54.401Z,1750561974.401 [DockingStepper](INFO): Stopping
2025-06-22T03:12:54.757Z,1750561974.757 [DockingStepper](INFO): Stopping
2025-06-22T03:12:55.121Z,1750561975.121 [DockingStepper](INFO): Stopping
2025-06-22T03:12:55.541Z,1750561975.541 [DockingStepper](INFO): Stopping
2025-06-22T03:12:55.917Z,1750561975.917 [DockingStepper](INFO): Stopping
2025-06-22T03:12:56.445Z,1750561976.445 [DockingStepper](INFO): Stopped
2025-06-22T03:12:56.449Z,1750561976.449 [CBIT](INFO): Clearing failed state for component DockingStepper
2025-06-22T03:12:56.449Z,1750561976.449 [DockingStepper] No Fault, FailCount= 3
2025-06-22T03:12:56.500Z,1750561976.500 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:12:56.757Z,1750561976.757 [DockingStepper](INFO): Start
2025-06-22T03:12:56.757Z,1750561976.757 [DockingStepper](DEBUG): Initializing EZServoServo.
2025-06-22T03:12:56.877Z,1750561976.877 [DockingStepper](DEBUG): Initializing DockingStepper.
2025-06-22T03:12:57.133Z,1750561977.133 [DockingStepper](INFO): Starting
2025-06-22T03:12:57.549Z,1750561977.549 [DockingStepper](INFO): Starting
2025-06-22T03:12:57.953Z,1750561977.953 [DockingStepper](INFO): Starting
2025-06-22T03:12:58.004Z,1750561978.004 [DockingStepper](INFO): Init string: /1z13616aE13561N3m50
2025-06-22T03:12:58.366Z,1750561978.366 [DockingStepper](INFO): Starting
2025-06-22T03:12:58.793Z,1750561978.793 [DockingStepper](INFO): Starting
2025-06-22T03:12:59.161Z,1750561979.161 [DockingStepper](INFO): Starting
2025-06-22T03:12:59.573Z,1750561979.573 [DockingStepper](INFO): Starting
2025-06-22T03:12:59.596Z,1750561979.596 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@
2025-06-22T03:12:59.989Z,1750561979.989 [DockingStepper](INFO): Starting
2025-06-22T03:13:00.365Z,1750561980.365 [DockingStepper](INFO): Changing to mode: 1
2025-06-22T03:13:00.366Z,1750561980.366 [DockingStepper](INFO): Standby mode.
2025-06-22T03:13:00.428Z,1750561980.428 [DockingStepper](INFO): Commanding positive:17454
2025-06-22T03:13:02.238Z,1750561982.238 [CTD_Seabird](ERROR): Failed to parse device response: 28,8079.23
2025-06-22T03:13:02.460Z,1750561982.460 [DockingStepper](INFO): Commanding positive:17553
2025-06-22T03:13:04.544Z,1750561984.544 [DockingStepper](INFO): Commanding positive:17454
2025-06-22T03:13:06.528Z,1750561986.528 [DockingStepper](INFO): Commanding positive:17565
2025-06-22T03:13:08.518Z,1750561988.518 [DockingStepper](INFO): Commanding positive:17547
2025-06-22T03:13:08.865Z,1750561988.865 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003657
2025-06-22T03:13:10.362Z,1750561990.362 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:13:10.548Z,1750561990.548 [DockingStepper](INFO): Commanding positive:17639
2025-06-22T03:13:10.576Z,1750561990.576 [DockingStepper](FAULT): Timed out moving from: 13585 to: 16450 response: ÿ
2025-06-22T03:13:10.576Z,1750561990.576 [DockingStepper] Hardware Fault, FailCount= 4
2025-06-22T03:13:10.576Z,1750561990.576 [DockingStepper](ERROR): Hardware Fault
2025-06-22T03:13:10.581Z,1750561990.581 [CBIT](ERROR): Hardware Fault in component: DockingStepper
2025-06-22T03:13:10.905Z,1750561990.905 [DockingStepper](INFO): Stop
2025-06-22T03:13:10.905Z,1750561990.905 [DockingStepper](DEBUG): Uninitialize Docking Stepper.
2025-06-22T03:13:10.905Z,1750561990.905 [DockingStepper](INFO): Powering down
2025-06-22T03:13:11.265Z,1750561991.265 [DockingStepper](INFO): Stopping
2025-06-22T03:13:11.729Z,1750561991.729 [DockingStepper](INFO): Stopping
2025-06-22T03:13:12.089Z,1750561992.089 [DockingStepper](INFO): Stopping
2025-06-22T03:13:12.490Z,1750561992.490 [DockingStepper](INFO): Stopping
2025-06-22T03:13:12.929Z,1750561992.929 [DockingStepper](INFO): Stopping
2025-06-22T03:13:13.293Z,1750561993.293 [DockingStepper](INFO): Stopping
2025-06-22T03:13:13.769Z,1750561993.769 [DockingStepper](INFO): Stopping
2025-06-22T03:13:14.089Z,1750561994.089 [DockingStepper](INFO): Stopping
2025-06-22T03:13:14.497Z,1750561994.497 [DockingStepper](INFO): Stopping
2025-06-22T03:13:14.929Z,1750561994.929 [DockingStepper](INFO): Stopping
2025-06-22T03:13:15.325Z,1750561995.325 [DockingStepper](INFO): Stopping
2025-06-22T03:13:15.745Z,1750561995.745 [DockingStepper](INFO): Stopping
2025-06-22T03:13:16.129Z,1750561996.129 [DockingStepper](INFO): Stopping
2025-06-22T03:13:16.585Z,1750561996.585 [DockingStepper](INFO): Stopping
2025-06-22T03:13:17.181Z,1750561997.181 [DockingStepper](INFO): Stopping
2025-06-22T03:13:17.341Z,1750561997.341 [DockingStepper](INFO): Stopping
2025-06-22T03:13:17.893Z,1750561997.893 [DockingStepper](INFO): Stopping
2025-06-22T03:13:18.205Z,1750561998.205 [DockingStepper](INFO): Stopping
2025-06-22T03:13:18.642Z,1750561998.642 [DockingStepper](INFO): Stopping
2025-06-22T03:13:19.302Z,1750561999.302 [DockingStepper](INFO): Stopping
2025-06-22T03:13:19.429Z,1750561999.429 [DockingStepper](INFO): Stopping
2025-06-22T03:13:19.833Z,1750561999.833 [DockingStepper](INFO): Stopping
2025-06-22T03:13:20.209Z,1750562000.209 [DockingStepper](INFO): Stopping
2025-06-22T03:13:20.613Z,1750562000.613 [DockingStepper](INFO): Stopping
2025-06-22T03:13:21.041Z,1750562001.041 [DockingStepper](INFO): Stopping
2025-06-22T03:13:21.433Z,1750562001.433 [DockingStepper](INFO): Stopping
2025-06-22T03:13:21.853Z,1750562001.853 [DockingStepper](INFO): Stopping
2025-06-22T03:13:22.229Z,1750562002.229 [DockingStepper](INFO): Stopping
2025-06-22T03:13:22.637Z,1750562002.637 [DockingStepper](INFO): Stopping
2025-06-22T03:13:23.085Z,1750562003.085 [DockingStepper](INFO): Stopping
2025-06-22T03:13:23.438Z,1750562003.438 [DockingStepper](INFO): Stopping
2025-06-22T03:13:23.925Z,1750562003.925 [DockingStepper](INFO): Stopping
2025-06-22T03:13:24.270Z,1750562004.270 [DockingStepper](INFO): Stopping
2025-06-22T03:13:24.689Z,1750562004.689 [DockingStepper](INFO): Stopping
2025-06-22T03:13:25.109Z,1750562005.109 [DockingStepper](INFO): Stopping
2025-06-22T03:13:25.484Z,1750562005.484 [DockingStepper](INFO): Stopping
2025-06-22T03:13:25.889Z,1750562005.889 [DockingStepper](INFO): Stopping
2025-06-22T03:13:26.265Z,1750562006.265 [DockingStepper](INFO): Stopping
2025-06-22T03:13:26.673Z,1750562006.673 [DockingStepper](INFO): Stopping
2025-06-22T03:13:27.089Z,1750562007.089 [DockingStepper](INFO): Stopping
2025-06-22T03:13:27.503Z,1750562007.503 [DockingStepper](INFO): Stopping
2025-06-22T03:13:27.905Z,1750562007.905 [DockingStepper](INFO): Stopping
2025-06-22T03:13:28.289Z,1750562008.289 [DockingStepper](INFO): Stopping
2025-06-22T03:13:28.705Z,1750562008.705 [DockingStepper](INFO): Stopping
2025-06-22T03:13:29.141Z,1750562009.141 [DockingStepper](INFO): Stopping
2025-06-22T03:13:29.501Z,1750562009.501 [DockingStepper](INFO): Stopping
2025-06-22T03:13:29.923Z,1750562009.923 [DockingStepper](INFO): Stopping
2025-06-22T03:13:30.321Z,1750562010.321 [DockingStepper](INFO): Stopping
2025-06-22T03:13:30.737Z,1750562010.737 [DockingStepper](INFO): Stopping
2025-06-22T03:13:31.157Z,1750562011.157 [DockingStepper](INFO): Stopping
2025-06-22T03:13:31.517Z,1750562011.517 [DockingStepper](INFO): Stopped
2025-06-22T03:13:31.521Z,1750562011.521 [CBIT](INFO): Clearing failed state for component DockingStepper
2025-06-22T03:13:31.521Z,1750562011.521 [DockingStepper] No Fault, FailCount= 4
2025-06-22T03:13:31.949Z,1750562011.949 [DockingStepper](INFO): Start
2025-06-22T03:13:31.949Z,1750562011.949 [DockingStepper](DEBUG): Initializing EZServoServo.
2025-06-22T03:13:32.069Z,1750562012.069 [DockingStepper](DEBUG): Initializing DockingStepper.
2025-06-22T03:13:32.337Z,1750562012.337 [DockingStepper](INFO): Starting
2025-06-22T03:13:32.721Z,1750562012.721 [DockingStepper](INFO): Starting
2025-06-22T03:13:33.149Z,1750562013.149 [DockingStepper](INFO): Starting
2025-06-22T03:13:33.196Z,1750562013.196 [DockingStepper](INFO): Init string: /1z13599aE13561N3m50
2025-06-22T03:13:33.549Z,1750562013.549 [DockingStepper](INFO): Starting
2025-06-22T03:13:33.969Z,1750562013.969 [DockingStepper](INFO): Starting
2025-06-22T03:13:34.401Z,1750562014.401 [DockingStepper](INFO): Starting
2025-06-22T03:13:34.753Z,1750562014.753 [DockingStepper](INFO): Starting
2025-06-22T03:13:34.786Z,1750562014.786 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@
2025-06-22T03:13:35.185Z,1750562015.185 [DockingStepper](INFO): Starting
2025-06-22T03:13:35.549Z,1750562015.549 [DockingStepper](INFO): Changing to mode: 1
2025-06-22T03:13:35.549Z,1750562015.549 [DockingStepper](INFO): Standby mode.
2025-06-22T03:13:35.612Z,1750562015.612 [DockingStepper](INFO): Commanding positive:17547
2025-06-22T03:13:37.724Z,1750562017.724 [DockingStepper](INFO): Commanding positive:17454
2025-06-22T03:13:39.648Z,1750562019.648 [DockingStepper](INFO): Commanding positive:17454
2025-06-22T03:13:41.708Z,1750562021.708 [DockingStepper](INFO): Commanding positive:17565
2025-06-22T03:13:41.994Z,1750562021.994 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:13:43.728Z,1750562023.728 [DockingStepper](INFO): Commanding positive:17547
2025-06-22T03:13:45.760Z,1750562025.760 [DockingStepper](INFO): Commanding positive:17448
2025-06-22T03:13:45.784Z,1750562025.784 [DockingStepper](FAULT): Timed out moving from: 13616 to: 16450 response: ÿ
2025-06-22T03:13:45.785Z,1750562025.785 [DockingStepper] Hardware Fault, FailCount= 5
2025-06-22T03:13:45.785Z,1750562025.785 [DockingStepper](ERROR): Hardware Fault
2025-06-22T03:13:45.805Z,1750562025.805 [CBIT](ERROR): Hardware Fault in component: DockingStepper
2025-06-22T03:13:45.805Z,1750562025.805 [CBIT](CRITICAL): Hardware Fault in component: DockingStepper
2025-06-22T03:13:46.157Z,1750562026.157 [DockingStepper](INFO): Stop
2025-06-22T03:13:46.157Z,1750562026.157 [DockingStepper](DEBUG): Uninitialize Docking Stepper.
2025-06-22T03:13:46.157Z,1750562026.157 [DockingStepper](INFO): Powering down
2025-06-22T03:13:46.160Z,1750562026.160 [CommandExec](FAULT): Scheduling is paused for 7 commands
2025-06-22T03:13:46.160Z,1750562026.160 [CBIT](INFO): Critical error at 20250622T031345
2025-06-22T03:13:46.160Z,1750562026.160 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2025-06-22T03:13:46.496Z,1750562026.496 [MissionManager](INFO): MissionManager is completed.
2025-06-22T03:13:46.497Z,1750562026.497 [MissionManager](INFO): Uninitializing Mission OnDock
2025-06-22T03:13:46.497Z,1750562026.497 [OnDock] Stopped
2025-06-22T03:13:46.497Z,1750562026.497 [OnDock](DEBUG): Aggregate::uninitialize OnDock
2025-06-22T03:13:46.497Z,1750562026.497 [OnDock:StandardEnvelopes] Stopped
2025-06-22T03:13:46.497Z,1750562026.497 [OnDock:StandardEnvelopes](DEBUG): Aggregate::uninitialize OnDock:StandardEnvelopes
2025-06-22T03:13:46.497Z,1750562026.497 [OnDock:StandardEnvelopes:A.AltitudeEnvelope] Stopped
2025-06-22T03:13:46.497Z,1750562026.497 [OnDock:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Uninitialize AltitudeEnvelopeComponent.
2025-06-22T03:13:46.497Z,1750562026.497 [OnDock:StandardEnvelopes:B.DepthEnvelope] Stopped
2025-06-22T03:13:46.497Z,1750562026.497 [OnDock:StandardEnvelopes:B.DepthEnvelope](DEBUG): Uninitialize.
2025-06-22T03:13:46.497Z,1750562026.497 [OnDock:StandardEnvelopes:C.OffshoreEnvelope] Stopped
2025-06-22T03:13:46.497Z,1750562026.497 [OnDock:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Uninitialize OffshoreEnvelopeComponent.
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:BackseatDriver] Stopped
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:BackseatDriver](DEBUG): Aggregate::uninitialize OnDock:BackseatDriver
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:BackseatDriver:A.BackseatDriver] Stopped
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:PowerOnly] Stopped
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:PowerOnly](DEBUG): Aggregate::uninitialize OnDock:PowerOnly
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:PowerOnly:E.Wait] Stopped
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:PowerOnly:E.Wait](DEBUG): Uninitialize Wait Component.
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:dataRead] Stopped
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:dataRead](DEBUG): Aggregate::uninitialize OnDock:dataRead
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:dataRead:A] Stopped
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:J.] Stopped
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:J.](DEBUG): Uninitializing TrackAcousticContact.
2025-06-22T03:13:46.498Z,1750562026.498 [OnDock:PeriodicCheck] Stopped
2025-06-22T03:13:46.499Z,1750562026.499 [OnDock:PeriodicCheck](DEBUG): Aggregate::uninitialize OnDock:PeriodicCheck
2025-06-22T03:13:46.499Z,1750562026.499 [OnDock:PeriodicCheck:CheckIP] Stopped
2025-06-22T03:13:46.499Z,1750562026.499 [OnDock:PeriodicCheck:CheckIP](DEBUG): Aggregate::uninitialize OnDock:PeriodicCheck:CheckIP
2025-06-22T03:13:46.499Z,1750562026.499 [OnDock:PeriodicCheck:CheckIP:B.Wait] Stopped
2025-06-22T03:13:46.499Z,1750562026.499 [OnDock:PeriodicCheck:CheckIP:B.Wait](DEBUG): Uninitialize Wait Component.
2025-06-22T03:13:46.499Z,1750562026.499 [OnDock:N.Docked] Stopped
2025-06-22T03:13:46.809Z,1750562026.809 [DockingStepper](INFO): Stopping
2025-06-22T03:13:46.875Z,1750562026.875 [MissionManager](IMPORTANT): Started mission DefaultWithUndock
2025-06-22T03:13:46.885Z,1750562026.885 [DAT](INFO): DAT read: user:3699>
2025-06-22T03:13:46.885Z,1750562026.885 [DAT](INFO): DAT read: Tx time:03:13:51.0181
2025-06-22T03:13:46.886Z,1750562026.886 [DAT](INFO): Ping request sent.
2025-06-22T03:13:46.886Z,1750562026.886 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:13:46.886Z,1750562026.886 [DAT](INFO): publishing transmit ping time
2025-06-22T03:13:46.896Z,1750562026.896 [DefaultWithUndock] Running Loop=1
2025-06-22T03:13:46.896Z,1750562026.896 [DefaultWithUndock](DEBUG): Aggregate::initialize DefaultWithUndock
2025-06-22T03:13:46.896Z,1750562026.896 [DefaultWithUndock:A.Wait] Running Loop=1
2025-06-22T03:13:46.896Z,1750562026.896 [DefaultWithUndock:A.Wait](DEBUG): Initialize Wait Component.
2025-06-22T03:13:46.937Z,1750562026.937 [DockingStepper](INFO): Stopping
2025-06-22T03:13:47.353Z,1750562027.353 [DockingStepper](INFO): Stopping
2025-06-22T03:13:47.717Z,1750562027.717 [DockingStepper](INFO): Stopping
2025-06-22T03:13:48.177Z,1750562028.177 [DockingStepper](INFO): Stopping
2025-06-22T03:13:48.561Z,1750562028.561 [DockingStepper](INFO): Stopping
2025-06-22T03:13:48.913Z,1750562028.913 [DockingStepper](INFO): Stopping
2025-06-22T03:13:49.153Z,1750562029.153 [DAT](INFO): DAT read: Rx Time:03:13:52.8780
2025-06-22T03:13:49.153Z,1750562029.153 [DAT](INFO): Rx dataTimestamp_ set to:1750562029.153009
2025-06-22T03:13:49.336Z,1750562029.336 [DockingStepper](INFO): Stopping
2025-06-22T03:13:49.666Z,1750562029.666 [DAT](INFO): DAT read: 03:13:52.8780 LVL= 18096, 15793, 16866, 15155, AGC= 36, IDX= 457,-0.33, 0.294, 2.524, 1.800, 2.671, PHS=-2.290,-0.101,-0.874, RAW= 290.4, 31.0, CAL= 300.0, 34.2, ROT= 210.0, -34.2
2025-06-22T03:13:49.667Z,1750562029.667 [DAT](INFO): got valid direction response:
03:13:52.8780 LVL= 18096, 15793, 16866, 15155, AGC= 36, IDX= 457,-0.33, 0.294, 2.524, 1.800, 2.671, PHS=-2.290,-0.101,-0.874, RAW= 290.4, 31.0, CAL= 300.0, 34.2, ROT= 210.0, -34.2
2025-06-22T03:13:49.668Z,1750562029.668 [DAT](INFO): DAT read: OK
2025-06-22T03:13:49.671Z,1750562029.671 [DAT](INFO): unknown deviceResponse_: OK
2025-06-22T03:13:49.671Z,1750562029.671 [DAT](INFO): DAT read: user:3700>
2025-06-22T03:13:49.678Z,1750562029.678 [DAT](INFO): DAT read: Tx time:03:13:53.9682
2025-06-22T03:13:49.678Z,1750562029.678 [DAT](INFO): Ping request sent.
2025-06-22T03:13:49.678Z,1750562029.678 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:13:49.679Z,1750562029.679 [DAT](INFO): #Rx 7: Read direction message, but no range.
2025-06-22T03:13:49.692Z,1750562029.692 [DAT](INFO): direction in FSK: [-0.716273,-0.413540,0.562083]
2025-06-22T03:13:49.692Z,1750562029.692 [DAT](INFO): publishing transmit ping time
2025-06-22T03:13:49.695Z,1750562029.695 [DAT](INFO): publishing transmit ping time
2025-06-22T03:13:49.801Z,1750562029.801 [DockingStepper](INFO): Stopping
2025-06-22T03:13:50.181Z,1750562030.181 [DockingStepper](INFO): Stopping
2025-06-22T03:13:50.545Z,1750562030.545 [DockingStepper](INFO): Stopping
2025-06-22T03:13:51.012Z,1750562031.012 [DockingStepper](INFO): Stopping
2025-06-22T03:13:51.378Z,1750562031.378 [DockingStepper](INFO): Stopping
2025-06-22T03:13:51.761Z,1750562031.761 [DockingStepper](INFO): Stopping
2025-06-22T03:13:52.177Z,1750562032.177 [DAT](INFO): DAT read: Rx Time:03:13:55.8280
2025-06-22T03:13:52.177Z,1750562032.177 [DAT](INFO): Rx dataTimestamp_ set to:1750562032.177108
2025-06-22T03:13:52.213Z,1750562032.213 [DockingStepper](INFO): Stopping
2025-06-22T03:13:52.566Z,1750562032.566 [DockingStepper](INFO): Stopping
2025-06-22T03:13:52.681Z,1750562032.681 [DAT](INFO): DAT read: OK
2025-06-22T03:13:52.681Z,1750562032.681 [DAT](INFO): unknown deviceResponse_: OK
2025-06-22T03:13:52.681Z,1750562032.681 [DAT](INFO): DAT read: user:3701>
2025-06-22T03:13:52.682Z,1750562032.682 [DAT](INFO): DAT read: Tx time:03:13:56.9182
2025-06-22T03:13:52.682Z,1750562032.682 [DAT](INFO): Ping request sent.
2025-06-22T03:13:52.682Z,1750562032.682 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:13:52.683Z,1750562032.683 [DAT](INFO): publishing transmit ping time
2025-06-22T03:13:52.962Z,1750562032.962 [DockingStepper](INFO): Stopping
2025-06-22T03:13:53.517Z,1750562033.517 [DockingStepper](INFO): Stopping
2025-06-22T03:13:53.759Z,1750562033.759 [DockingStepper](INFO): Stopping
2025-06-22T03:13:54.213Z,1750562034.213 [DockingStepper](INFO): Stopping
2025-06-22T03:13:54.589Z,1750562034.589 [DockingStepper](INFO): Stopping
2025-06-22T03:13:54.965Z,1750562034.965 [DockingStepper](INFO): Stopping
2025-06-22T03:13:55.208Z,1750562035.208 [DAT](INFO): DAT read: Rx Time:03:13:58.7781
2025-06-22T03:13:55.210Z,1750562035.210 [DAT](INFO): Rx dataTimestamp_ set to:1750562035.208709
2025-06-22T03:13:55.397Z,1750562035.397 [DockingStepper](INFO): Stopping
2025-06-22T03:13:55.717Z,1750562035.717 [DAT](INFO): DAT read: OK
2025-06-22T03:13:55.717Z,1750562035.717 [DAT](INFO): unknown deviceResponse_: OK
2025-06-22T03:13:55.802Z,1750562035.802 [DockingStepper](INFO): Stopping
2025-06-22T03:13:56.208Z,1750562036.208 [DockingStepper](INFO): Stopping
2025-06-22T03:13:56.620Z,1750562036.620 [DockingStepper](INFO): Stopping
2025-06-22T03:13:57.005Z,1750562037.005 [DockingStepper](INFO): Stopping
2025-06-22T03:13:57.421Z,1750562037.421 [DockingStepper](INFO): Stopping
2025-06-22T03:13:57.817Z,1750562037.817 [DockingStepper](INFO): Stopping
2025-06-22T03:13:58.248Z,1750562038.248 [DockingStepper](INFO): Stopping
2025-06-22T03:13:58.633Z,1750562038.633 [DockingStepper](INFO): Stopping
2025-06-22T03:13:59.013Z,1750562039.013 [DockingStepper](INFO): Stopping
2025-06-22T03:13:59.433Z,1750562039.433 [DockingStepper](INFO): Stopping
2025-06-22T03:13:59.833Z,1750562039.833 [DockingStepper](INFO): Stopping
2025-06-22T03:14:00.213Z,1750562040.213 [DockingStepper](INFO): Stopping
2025-06-22T03:14:00.665Z,1750562040.665 [DockingStepper](INFO): Stopping
2025-06-22T03:14:01.057Z,1750562041.057 [DockingStepper](INFO): Stopping
2025-06-22T03:14:01.461Z,1750562041.461 [DockingStepper](INFO): Stopping
2025-06-22T03:14:01.841Z,1750562041.841 [DockingStepper](INFO): Stopping
2025-06-22T03:14:02.241Z,1750562042.241 [DockingStepper](INFO): Stopping
2025-06-22T03:14:02.671Z,1750562042.671 [DockingStepper](INFO): Stopping
2025-06-22T03:14:03.045Z,1750562043.045 [DockingStepper](INFO): Stopping
2025-06-22T03:14:03.461Z,1750562043.461 [DockingStepper](INFO): Stopping
2025-06-22T03:14:03.857Z,1750562043.857 [DockingStepper](INFO): Stopping
2025-06-22T03:14:04.253Z,1750562044.253 [DockingStepper](INFO): Stopping
2025-06-22T03:14:04.761Z,1750562044.761 [DockingStepper](INFO): Stopping
2025-06-22T03:14:05.077Z,1750562045.077 [DockingStepper](INFO): Stopping
2025-06-22T03:14:05.499Z,1750562045.499 [DockingStepper](INFO): Stopping
2025-06-22T03:14:05.905Z,1750562045.905 [DockingStepper](INFO): Stopping
2025-06-22T03:14:06.273Z,1750562046.273 [DockingStepper](INFO): Stopping
2025-06-22T03:14:06.697Z,1750562046.697 [DockingStepper](INFO): Stopped
2025-06-22T03:14:09.851Z,1750562049.851 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.989677
2025-06-22T03:14:10.852Z,1750562050.852 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:14:15.985Z,1750562055.985 [CBIT](INFO): Clearing failed state for component DockingStepper
2025-06-22T03:14:15.985Z,1750562055.985 [DockingStepper] No Fault, FailCount= 5
2025-06-22T03:14:16.394Z,1750562056.394 [DockingStepper](INFO): Start
2025-06-22T03:14:16.394Z,1750562056.394 [DockingStepper](DEBUG): Initializing EZServoServo.
2025-06-22T03:14:16.510Z,1750562056.510 [DockingStepper](DEBUG): Initializing DockingStepper.
2025-06-22T03:14:16.825Z,1750562056.825 [DockingStepper](INFO): Starting
2025-06-22T03:14:17.149Z,1750562057.149 [DefaultWithUndock:A.Wait](INFO): Done Waiting.
2025-06-22T03:14:17.149Z,1750562057.149 [DefaultWithUndock:A.Wait] Stopped
2025-06-22T03:14:17.149Z,1750562057.149 [DefaultWithUndock:A.Wait](DEBUG): Uninitialize Wait Component.
2025-06-22T03:14:17.149Z,1750562057.149 [DefaultWithUndock:LeaveDock] Running Loop=1
2025-06-22T03:14:17.149Z,1750562057.149 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::initialize DefaultWithUndock:LeaveDock
2025-06-22T03:14:17.150Z,1750562057.150 [DefaultWithUndock:LeaveDock:A.] Running Loop=1
2025-06-22T03:14:17.150Z,1750562057.150 [DefaultWithUndock:LeaveDock:A.](INFO): Initializing TrackAcousticContact.
2025-06-22T03:14:17.150Z,1750562057.150 [DefaultWithUndock:LeaveDock:B.Undock] Running Loop=1
2025-06-22T03:14:17.150Z,1750562057.150 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2025-06-22T03:14:17.150Z,1750562057.150 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2025-06-22T03:14:17.181Z,1750562057.181 [DockingStepper](INFO): Starting
2025-06-22T03:14:17.618Z,1750562057.618 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initialize.
2025-06-22T03:14:17.619Z,1750562057.619 [DefaultWithUndock:LeaveDock:B.Undock](DEBUG): Initializing internal variables to default values.
2025-06-22T03:14:17.619Z,1750562057.619 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached from dock at depth 64.299820 m.
2025-06-22T03:14:17.625Z,1750562057.625 [DefaultWithUndock:LeaveDock:A.](ERROR): Failed to read sound speed
2025-06-22T03:14:17.769Z,1750562057.769 [DockingStepper](INFO): Starting
2025-06-22T03:14:17.820Z,1750562057.820 [DockingStepper](INFO): Init string: /1z13602aE13561N3m50
2025-06-22T03:14:18.025Z,1750562058.025 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2025-06-22T03:14:18.061Z,1750562058.061 [DockingStepper](INFO): Starting
2025-06-22T03:14:18.369Z,1750562058.369 [DockingStepper](INFO): Starting
2025-06-22T03:14:18.827Z,1750562058.827 [DockingStepper](INFO): Starting
2025-06-22T03:14:19.264Z,1750562059.264 [DockingStepper](INFO): Starting
2025-06-22T03:14:19.629Z,1750562059.629 [DockingStepper](INFO): Starting
2025-06-22T03:14:19.660Z,1750562059.660 [DockingStepper](INFO): Sent speed cmd:/1V10000 Response:ÿ/0@
2025-06-22T03:14:19.981Z,1750562059.981 [DockingStepper](INFO): Starting
2025-06-22T03:14:20.390Z,1750562060.390 [DockingStepper](INFO): Changing to mode: 3
2025-06-22T03:14:20.390Z,1750562060.390 [DockingStepper](INFO): Detach mode.
2025-06-22T03:14:20.448Z,1750562060.448 [DockingStepper](INFO): Commanding negative:37556
2025-06-22T03:14:20.553Z,1750562060.553 [CTD_Seabird](ERROR): Failed to parse device response:
2025-06-22T03:14:24.516Z,1750562064.516 [DockingStepper](INFO): Failure count cleared after critical for DockingStepper
2025-06-22T03:14:24.858Z,1750562064.858 [DefaultWithUndock:LeaveDock:B.Undock](FAULT): Drifted too long without detachment, restarting undock sequence
2025-06-22T03:14:25.226Z,1750562065.226 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:25.226Z,1750562065.226 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Engaging thruster for 10.0 seconds (max) to disengage.
2025-06-22T03:14:25.710Z,1750562065.710 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:26.033Z,1750562066.033 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:26.436Z,1750562066.436 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:26.859Z,1750562066.859 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:27.259Z,1750562067.259 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:27.260Z,1750562067.260 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-06-22T03:14:27.485Z,1750562067.485 [DAT](DEBUG): Acoustic response timeout
2025-06-22T03:14:27.485Z,1750562067.485 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-06-22T03:14:27.721Z,1750562067.721 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:27.737Z,1750562067.737 [DAT](INFO): DAT read: user:3702>
2025-06-22T03:14:27.738Z,1750562067.738 [DAT](INFO): DAT read: Tx time:03:14:31.8695
2025-06-22T03:14:27.738Z,1750562067.738 [DAT](INFO): Ping request sent.
2025-06-22T03:14:27.738Z,1750562067.738 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:14:27.739Z,1750562067.739 [DAT](INFO): publishing transmit ping time
2025-06-22T03:14:27.739Z,1750562067.739 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000727
2025-06-22T03:14:27.989Z,1750562067.989 [DAT](INFO): DAT read: TxSync time:03:14:31.8687
2025-06-22T03:14:27.990Z,1750562067.990 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251279
2025-06-22T03:14:28.099Z,1750562068.099 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:28.241Z,1750562068.241 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502442
2025-06-22T03:14:28.461Z,1750562068.461 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:28.493Z,1750562068.493 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754592
2025-06-22T03:14:28.745Z,1750562068.745 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006616
2025-06-22T03:14:28.889Z,1750562068.889 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:28.997Z,1750562068.997 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258403
2025-06-22T03:14:29.249Z,1750562069.249 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510314
2025-06-22T03:14:29.271Z,1750562069.271 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:29.501Z,1750562069.501 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762352
2025-06-22T03:14:29.741Z,1750562069.741 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:29.753Z,1750562069.753 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014537
2025-06-22T03:14:30.005Z,1750562070.005 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266313
2025-06-22T03:14:30.103Z,1750562070.103 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:30.257Z,1750562070.257 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518300
2025-06-22T03:14:30.476Z,1750562070.476 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:30.511Z,1750562070.511 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772391
2025-06-22T03:14:30.761Z,1750562070.761 [DAT](INFO): DAT read: Rx Time:03:14:34.2750
2025-06-22T03:14:30.761Z,1750562070.761 [DAT](INFO): Rx dataTimestamp_ set to:1750562070.761059
2025-06-22T03:14:30.762Z,1750562070.762 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023469
2025-06-22T03:14:30.906Z,1750562070.906 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Either camera/lights unpowered or charge off not requested, but continuing with undock
2025-06-22T03:14:31.013Z,1750562071.013 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274856
2025-06-22T03:14:31.270Z,1750562071.270 [DAT](INFO): DAT read: 03:14:34.2750 LVL= 14032, 14705, 11506, 22899, AGC= 33, IDX= 393, 0.43,-2.184, 3.001,-2.684,-0.915, PHS=-1.180,-2.320,-1.772, RAW= 118.7, 62.1, CAL= 123.2, 67.6, ROT= 26.8, -67.6
2025-06-22T03:14:31.271Z,1750562071.271 [DAT](INFO): got valid direction response:
03:14:34.2750 LVL= 14032, 14705, 11506, 22899, AGC= 33, IDX= 393, 0.43,-2.184, 3.001,-2.684,-0.915, PHS=-1.180,-2.320,-1.772, RAW= 118.7, 62.1, CAL= 123.2, 67.6, ROT= 26.8, -67.6
2025-06-22T03:14:31.272Z,1750562071.272 [DAT](INFO): DAT read: Range 10 to 50 : 1.0 m (Round-trip 1.4 ms) speed 0.0 m/s
2025-06-22T03:14:31.273Z,1750562071.273 [DAT](INFO): #Rx 1: Read range and direction messages.
2025-06-22T03:14:31.274Z,1750562071.274 [DAT](INFO): direction in FSK: [0.340138,0.171816,0.924546]
2025-06-22T03:14:31.274Z,1750562071.274 [DAT](INFO): publishing direction and range info
2025-06-22T03:14:35.326Z,1750562075.326 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Thruster off.
2025-06-22T03:14:37.365Z,1750562077.365 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-06-22T03:14:37.577Z,1750562077.577 [DAT](INFO): ****** received valid address query ******
2025-06-22T03:14:37.577Z,1750562077.577 [DAT](INFO): ****** received valid ping request ******
2025-06-22T03:14:37.577Z,1750562077.577 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-06-22T03:14:37.832Z,1750562077.832 [DAT](INFO): DAT read: user:3703>
2025-06-22T03:14:37.835Z,1750562077.835 [DAT](INFO): DAT read: Tx time:03:14:41.9696
2025-06-22T03:14:37.844Z,1750562077.844 [DAT](INFO): Ping request sent.
2025-06-22T03:14:37.845Z,1750562077.845 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:14:37.845Z,1750562077.845 [DAT](INFO): publishing transmit ping time
2025-06-22T03:14:37.847Z,1750562077.847 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.002990
2025-06-22T03:14:38.081Z,1750562078.081 [DAT](INFO): DAT read: TxSync time:03:14:41.9688
2025-06-22T03:14:38.082Z,1750562078.082 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.238029
2025-06-22T03:14:38.333Z,1750562078.333 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.489151
2025-06-22T03:14:38.585Z,1750562078.585 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.741446
2025-06-22T03:14:38.840Z,1750562078.840 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.995404
2025-06-22T03:14:39.089Z,1750562079.089 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.245144
2025-06-22T03:14:39.346Z,1750562079.346 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.502011
2025-06-22T03:14:39.597Z,1750562079.597 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.753249
2025-06-22T03:14:39.855Z,1750562079.855 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.007523
2025-06-22T03:14:40.101Z,1750562080.101 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.257169
2025-06-22T03:14:40.353Z,1750562080.353 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.509260
2025-06-22T03:14:40.605Z,1750562080.605 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.761527
2025-06-22T03:14:40.860Z,1750562080.860 [DAT](INFO): DAT read: Rx Time:03:14:44.3764
2025-06-22T03:14:40.862Z,1750562080.862 [DAT](INFO): Rx dataTimestamp_ set to:1750562080.860671
2025-06-22T03:14:40.863Z,1750562080.863 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.019211
2025-06-22T03:14:40.972Z,1750562080.972 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:14:41.109Z,1750562081.109 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.265265
2025-06-22T03:14:41.377Z,1750562081.377 [DAT](INFO): DAT read: 03:14:44.3764 LVL= 16304, 27793, 18242, 30883, AGC= 39, IDX= 457,-0.30, 2.608, 0.862, 1.950, 2.054, PHS= 0.641,-1.145,-0.107, RAW= 125.3, 7.9, CAL= 132.9, 3.0, ROT= 17.1, -3.0
2025-06-22T03:14:41.378Z,1750562081.378 [DAT](INFO): got valid direction response:
03:14:44.3764 LVL= 16304, 27793, 18242, 30883, AGC= 39, IDX= 457,-0.30, 2.608, 0.862, 1.950, 2.054, PHS= 0.641,-1.145,-0.107, RAW= 125.3, 7.9, CAL= 132.9, 3.0, ROT= 17.1, -3.0
2025-06-22T03:14:41.379Z,1750562081.379 [DAT](INFO): DAT read: Bearing 17.1, -3.0 (Local)
2025-06-22T03:14:41.379Z,1750562081.379 [DAT](INFO): Local bearing/azimuth received:
Bearing 17.1, -3.0 (Local)
2025-06-22T03:14:41.385Z,1750562081.385 [DAT](INFO): DAT read: Range 10 to 50 : 2.0 m (Round-trip 2.7 ms) speed -0.2 m/s
2025-06-22T03:14:41.385Z,1750562081.385 [DAT](INFO): #Rx 1: Read range and direction messages.
2025-06-22T03:14:41.386Z,1750562081.386 [DAT](INFO): direction in FSK: [0.954483,0.293637,0.052336]
2025-06-22T03:14:41.386Z,1750562081.386 [DAT](INFO): publishing direction and range info
2025-06-22T03:14:41.976Z,1750562081.976 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:14:47.447Z,1750562087.447 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-06-22T03:14:47.673Z,1750562087.673 [DAT](INFO): ****** received valid address query ******
2025-06-22T03:14:47.673Z,1750562087.673 [DAT](INFO): ****** received valid ping request ******
2025-06-22T03:14:47.673Z,1750562087.673 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-06-22T03:14:47.925Z,1750562087.925 [DAT](INFO): DAT read: user:3704>
2025-06-22T03:14:47.926Z,1750562087.926 [DAT](INFO): DAT read: Tx time:03:14:52.0197
2025-06-22T03:14:47.926Z,1750562087.926 [DAT](INFO): Ping request sent.
2025-06-22T03:14:47.926Z,1750562087.926 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:14:47.927Z,1750562087.927 [DAT](INFO): DAT read: TxSync time:03:14:52.0189
2025-06-22T03:14:47.927Z,1750562087.927 [DAT](INFO): publishing transmit ping time
2025-06-22T03:14:47.928Z,1750562087.928 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001644
2025-06-22T03:14:48.177Z,1750562088.177 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250251
2025-06-22T03:14:48.429Z,1750562088.429 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502309
2025-06-22T03:14:48.684Z,1750562088.684 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.757062
2025-06-22T03:14:48.933Z,1750562088.933 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006285
2025-06-22T03:14:49.185Z,1750562089.185 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258536
2025-06-22T03:14:49.437Z,1750562089.437 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510287
2025-06-22T03:14:49.689Z,1750562089.689 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762282
2025-06-22T03:14:49.945Z,1750562089.945 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.018511
2025-06-22T03:14:50.197Z,1750562090.197 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.270322
2025-06-22T03:14:50.449Z,1750562090.449 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.522252
2025-06-22T03:14:50.701Z,1750562090.701 [DAT](INFO): DAT read: Rx Time:03:14:54.4293
2025-06-22T03:14:50.702Z,1750562090.702 [DAT](INFO): Rx dataTimestamp_ set to:1750562090.701364
2025-06-22T03:14:50.702Z,1750562090.702 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.775701
2025-06-22T03:14:50.954Z,1750562090.954 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.027989
2025-06-22T03:14:51.207Z,1750562091.207 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.280342
2025-06-22T03:14:51.465Z,1750562091.465 [DAT](INFO): DAT read: 03:14:54.4293 LVL= 26496, 32753, 28498, 32755, AGC= 43, IDX= 451,-0.01, 2.794, 1.307, 2.134, 2.471, PHS= 0.411,-1.117,-0.339, RAW= 120.6, 15.6, CAL= 127.2, 12.0, ROT= 22.8, -12.0
2025-06-22T03:14:51.466Z,1750562091.466 [DAT](INFO): got valid direction response:
03:14:54.4293 LVL= 26496, 32753, 28498, 32755, AGC= 43, IDX= 451,-0.01, 2.794, 1.307, 2.134, 2.471, PHS= 0.411,-1.117,-0.339, RAW= 120.6, 15.6, CAL= 127.2, 12.0, ROT= 22.8, -12.0
2025-06-22T03:14:51.467Z,1750562091.467 [DAT](INFO): DAT read: Bearing 22.8, -12.0 (Local)
2025-06-22T03:14:51.467Z,1750562091.467 [DAT](INFO): Local bearing/azimuth received:
Bearing 22.8, -12.0 (Local)
2025-06-22T03:14:51.485Z,1750562091.485 [DAT](INFO): DAT read: Range 10 to 50 : 4.1 m (Round-trip 5.5 ms) speed -0.2 m/s
2025-06-22T03:14:51.486Z,1750562091.486 [DAT](INFO): #Rx 1: Read range and direction messages.
2025-06-22T03:14:51.487Z,1750562091.487 [DAT](INFO): direction in FSK: [0.901718,0.379047,0.207912]
2025-06-22T03:14:51.487Z,1750562091.487 [DAT](INFO): publishing direction and range info
2025-06-22T03:14:57.564Z,1750562097.564 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-06-22T03:14:57.765Z,1750562097.765 [DAT](INFO): ****** received valid address query ******
2025-06-22T03:14:57.765Z,1750562097.765 [DAT](INFO): ****** received valid ping request ******
2025-06-22T03:14:57.765Z,1750562097.765 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-06-22T03:14:58.017Z,1750562098.017 [DAT](INFO): DAT read: user:3705>
2025-06-22T03:14:58.018Z,1750562098.018 [DAT](INFO): DAT read: Tx time:03:15:02.1198
2025-06-22T03:14:58.018Z,1750562098.018 [DAT](INFO): Ping request sent.
2025-06-22T03:14:58.018Z,1750562098.018 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:14:58.019Z,1750562098.019 [DAT](INFO): DAT read: TxSync time:03:15:02.1190
2025-06-22T03:14:58.019Z,1750562098.019 [DAT](INFO): publishing transmit ping time
2025-06-22T03:14:58.020Z,1750562098.020 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001714
2025-06-22T03:14:58.269Z,1750562098.269 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250355
2025-06-22T03:14:58.521Z,1750562098.521 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502425
2025-06-22T03:14:58.773Z,1750562098.773 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754423
2025-06-22T03:14:59.025Z,1750562099.025 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006338
2025-06-22T03:14:59.277Z,1750562099.277 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.259007
2025-06-22T03:14:59.529Z,1750562099.529 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510326
2025-06-22T03:14:59.781Z,1750562099.781 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762295
2025-06-22T03:15:00.033Z,1750562100.033 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014460
2025-06-22T03:15:00.285Z,1750562100.285 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266300
2025-06-22T03:15:00.538Z,1750562100.538 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519234
2025-06-22T03:15:00.789Z,1750562100.789 [DAT](INFO): DAT read: Rx Time:03:15:04.5315
2025-06-22T03:15:00.789Z,1750562100.789 [DAT](INFO): Rx dataTimestamp_ set to:1750562100.789190
2025-06-22T03:15:00.790Z,1750562100.790 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771585
2025-06-22T03:15:01.041Z,1750562101.041 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022266
2025-06-22T03:15:01.296Z,1750562101.296 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.277238
2025-06-22T03:15:01.550Z,1750562101.550 [DAT](INFO): DAT read: 03:15:04.5315 LVL= 30704, 32753, 32754, 32755, AGC= 46, IDX= 440,-0.15, 0.614,-0.753,-0.085, 0.375, PHS= 0.327,-1.081,-0.462, RAW= 116.0, 19.4, CAL= 122.3, 16.7, ROT= 27.7, -16.7
2025-06-22T03:15:01.551Z,1750562101.551 [DAT](INFO): got valid direction response:
03:15:04.5315 LVL= 30704, 32753, 32754, 32755, AGC= 46, IDX= 440,-0.15, 0.614,-0.753,-0.085, 0.375, PHS= 0.327,-1.081,-0.462, RAW= 116.0, 19.4, CAL= 122.3, 16.7, ROT= 27.7, -16.7
2025-06-22T03:15:01.552Z,1750562101.552 [DAT](INFO): DAT read: Bearing 27.7, -16.7 (Local)
2025-06-22T03:15:01.553Z,1750562101.553 [DAT](INFO): Local bearing/azimuth received:
Bearing 27.7, -16.7 (Local)
2025-06-22T03:15:01.554Z,1750562101.554 [DAT](INFO): DAT read: Range 10 to 50 : 5.7 m (Round-trip 7.6 ms) speed -0.1 m/s
2025-06-22T03:15:01.555Z,1750562101.555 [DAT](INFO): #Rx 1: Read range and direction messages.
2025-06-22T03:15:01.556Z,1750562101.556 [DAT](INFO): direction in FSK: [0.848050,0.445236,0.287361]
2025-06-22T03:15:01.556Z,1750562101.556 [DAT](INFO): publishing direction and range info
2025-06-22T03:15:07.674Z,1750562107.674 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-06-22T03:15:07.845Z,1750562107.845 [DAT](INFO): ****** received valid address query ******
2025-06-22T03:15:07.845Z,1750562107.845 [DAT](INFO): ****** received valid ping request ******
2025-06-22T03:15:07.845Z,1750562107.845 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-06-22T03:15:08.097Z,1750562108.097 [DAT](INFO): DAT read: user:3706>
2025-06-22T03:15:08.098Z,1750562108.098 [DAT](INFO): DAT read: Tx time:03:15:12.2199
2025-06-22T03:15:08.098Z,1750562108.098 [DAT](INFO): Ping request sent.
2025-06-22T03:15:08.098Z,1750562108.098 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:15:08.098Z,1750562108.098 [DAT](INFO): publishing transmit ping time
2025-06-22T03:15:08.099Z,1750562108.099 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000712
2025-06-22T03:15:08.349Z,1750562108.349 [DAT](INFO): DAT read: TxSync time:03:15:12.2191
2025-06-22T03:15:08.350Z,1750562108.350 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251765
2025-06-22T03:15:08.601Z,1750562108.601 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502583
2025-06-22T03:15:08.853Z,1750562108.853 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754747
2025-06-22T03:15:09.105Z,1750562109.105 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006612
2025-06-22T03:15:09.357Z,1750562109.357 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258711
2025-06-22T03:15:09.611Z,1750562109.611 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511968
2025-06-22T03:15:09.861Z,1750562109.861 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762779
2025-06-22T03:15:10.113Z,1750562110.113 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.015113
2025-06-22T03:15:10.365Z,1750562110.365 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266636
2025-06-22T03:15:10.617Z,1750562110.617 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518649
2025-06-22T03:15:10.869Z,1750562110.869 [DAT](INFO): DAT read: Rx Time:03:15:14.6329
2025-06-22T03:15:10.869Z,1750562110.869 [DAT](INFO): Rx dataTimestamp_ set to:1750562110.868905
2025-06-22T03:15:10.870Z,1750562110.870 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771553
2025-06-22T03:15:11.121Z,1750562111.121 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022842
2025-06-22T03:15:11.373Z,1750562111.373 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274961
2025-06-22T03:15:11.630Z,1750562111.630 [DAT](INFO): DAT read: 03:15:14.6329 LVL= 18816, 32753, 24418, 32755, AGC= 47, IDX= 440,-0.24, 2.501, 0.926, 1.709, 2.004, PHS= 0.585,-1.031,-0.298, RAW= 116.9, 10.6, CAL= 125.4, 7.2, ROT= 24.6, -7.2
2025-06-22T03:15:11.632Z,1750562111.632 [DAT](INFO): got valid direction response:
03:15:14.6329 LVL= 18816, 32753, 24418, 32755, AGC= 47, IDX= 440,-0.24, 2.501, 0.926, 1.709, 2.004, PHS= 0.585,-1.031,-0.298, RAW= 116.9, 10.6, CAL= 125.4, 7.2, ROT= 24.6, -7.2
2025-06-22T03:15:11.633Z,1750562111.633 [DAT](INFO): DAT read: Bearing 24.6, -7.2 (Local)
2025-06-22T03:15:11.634Z,1750562111.634 [DAT](INFO): Local bearing/azimuth received:
Bearing 24.6, -7.2 (Local)
2025-06-22T03:15:11.636Z,1750562111.636 [DAT](INFO): DAT read: Range 10 to 50 : 6.6 m (Round-trip 8.8 ms) speed -0.1 m/s
2025-06-22T03:15:11.637Z,1750562111.637 [DAT](INFO): #Rx 1: Read range and direction messages.
2025-06-22T03:15:11.638Z,1750562111.638 [DAT](INFO): direction in FSK: [0.902067,0.412998,0.125333]
2025-06-22T03:15:11.638Z,1750562111.638 [DAT](INFO): publishing direction and range info
2025-06-22T03:15:12.104Z,1750562112.104 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:15:13.108Z,1750562113.108 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:15:17.795Z,1750562117.795 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-06-22T03:15:17.937Z,1750562117.937 [DAT](INFO): ****** received valid address query ******
2025-06-22T03:15:17.937Z,1750562117.937 [DAT](INFO): ****** received valid ping request ******
2025-06-22T03:15:17.937Z,1750562117.937 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-06-22T03:15:18.189Z,1750562118.189 [DAT](INFO): DAT read: user:3707>
2025-06-22T03:15:18.190Z,1750562118.190 [DAT](INFO): DAT read: Tx time:03:15:22.3200
2025-06-22T03:15:18.191Z,1750562118.191 [DAT](INFO): Ping request sent.
2025-06-22T03:15:18.191Z,1750562118.191 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:15:18.191Z,1750562118.191 [DAT](INFO): publishing transmit ping time
2025-06-22T03:15:18.200Z,1750562118.200 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.009283
2025-06-22T03:15:18.444Z,1750562118.444 [DAT](INFO): DAT read: TxSync time:03:15:22.3192
2025-06-22T03:15:18.446Z,1750562118.446 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.255293
2025-06-22T03:15:18.693Z,1750562118.693 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502574
2025-06-22T03:15:18.949Z,1750562118.949 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.757944
2025-06-22T03:15:19.201Z,1750562119.201 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.009872
2025-06-22T03:15:19.457Z,1750562119.457 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.265810
2025-06-22T03:15:19.705Z,1750562119.705 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.513947
2025-06-22T03:15:19.957Z,1750562119.957 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.765877
2025-06-22T03:15:20.210Z,1750562120.210 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.018868
2025-06-22T03:15:20.463Z,1750562120.463 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.271732
2025-06-22T03:15:20.713Z,1750562120.713 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.521965
2025-06-22T03:15:20.969Z,1750562120.969 [DAT](INFO): DAT read: Rx Time:03:15:24.7344
2025-06-22T03:15:20.970Z,1750562120.970 [DAT](INFO): Rx dataTimestamp_ set to:1750562120.969282
2025-06-22T03:15:20.970Z,1750562120.970 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.779247
2025-06-22T03:15:21.221Z,1750562121.221 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.029945
2025-06-22T03:15:21.478Z,1750562121.478 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.284340
2025-06-22T03:15:21.730Z,1750562121.730 [DAT](INFO): DAT read: 03:15:24.7344 LVL= 25120, 32753, 32210, 32755, AGC= 46, IDX= 439,-0.13,-0.550,-2.103,-1.437,-0.995, PHS= 0.532,-1.062,-0.446, RAW= 112.5, 13.9, CAL= 120.7, 11.4, ROT= 29.3, -11.4
2025-06-22T03:15:21.732Z,1750562121.732 [DAT](INFO): got valid direction response:
03:15:24.7344 LVL= 25120, 32753, 32210, 32755, AGC= 46, IDX= 439,-0.13,-0.550,-2.103,-1.437,-0.995, PHS= 0.532,-1.062,-0.446, RAW= 112.5, 13.9, CAL= 120.7, 11.4, ROT= 29.3, -11.4
2025-06-22T03:15:21.733Z,1750562121.733 [DAT](INFO): DAT read: Bearing 29.3, -11.4 (Local)
2025-06-22T03:15:21.733Z,1750562121.733 [DAT](INFO): Local bearing/azimuth received:
Bearing 29.3, -11.4 (Local)
2025-06-22T03:15:21.734Z,1750562121.734 [DAT](INFO): DAT read: Range 10 to 50 : 7.7 m (Round-trip 10.3 ms) speed -0.2 m/s
2025-06-22T03:15:21.735Z,1750562121.735 [DAT](INFO): #Rx 1: Read range and direction messages.
2025-06-22T03:15:21.737Z,1750562121.737 [DAT](INFO): direction in FSK: [0.854864,0.479727,0.197657]
2025-06-22T03:15:21.737Z,1750562121.737 [DAT](INFO): publishing direction and range info
2025-06-22T03:15:21.880Z,1750562121.880 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detected possible detachment. Starting timer.
2025-06-22T03:15:27.896Z,1750562127.896 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-06-22T03:15:28.029Z,1750562128.029 [DAT](INFO): ****** received valid address query ******
2025-06-22T03:15:28.029Z,1750562128.029 [DAT](INFO): ****** received valid ping request ******
2025-06-22T03:15:28.029Z,1750562128.029 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-06-22T03:15:28.281Z,1750562128.281 [DAT](INFO): DAT read: user:3708>
2025-06-22T03:15:28.282Z,1750562128.282 [DAT](INFO): DAT read: Tx time:03:15:32.4200
2025-06-22T03:15:28.282Z,1750562128.282 [DAT](INFO): Ping request sent.
2025-06-22T03:15:28.282Z,1750562128.282 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:15:28.282Z,1750562128.282 [DAT](INFO): publishing transmit ping time
2025-06-22T03:15:28.283Z,1750562128.283 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000735
2025-06-22T03:15:28.533Z,1750562128.533 [DAT](INFO): DAT read: TxSync time:03:15:32.4192
2025-06-22T03:15:28.534Z,1750562128.534 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251672
2025-06-22T03:15:28.785Z,1750562128.785 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502840
2025-06-22T03:15:29.037Z,1750562129.037 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.755161
2025-06-22T03:15:29.289Z,1750562129.289 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.007050
2025-06-22T03:15:29.543Z,1750562129.543 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.260789
2025-06-22T03:15:29.794Z,1750562129.794 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.511674
2025-06-22T03:15:30.045Z,1750562130.045 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763036
2025-06-22T03:15:30.297Z,1750562130.297 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014900
2025-06-22T03:15:30.551Z,1750562130.551 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.268829
2025-06-22T03:15:30.801Z,1750562130.801 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518801
2025-06-22T03:15:31.054Z,1750562131.054 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.772096
2025-06-22T03:15:31.305Z,1750562131.305 [DAT](INFO): DAT read: Rx Time:03:15:34.8363
2025-06-22T03:15:31.305Z,1750562131.305 [DAT](INFO): Rx dataTimestamp_ set to:1750562131.305025
2025-06-22T03:15:31.306Z,1750562131.306 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023884
2025-06-22T03:15:31.557Z,1750562131.557 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.275155
2025-06-22T03:15:31.814Z,1750562131.814 [DAT](INFO): DAT read: 03:15:34.8363 LVL= 14496, 30449, 22610, 32755, AGC= 47, IDX= 440,-0.20, 0.794,-0.904,-0.241, 0.115, PHS= 0.767,-0.973,-0.359, RAW= 110.3, 7.4, CAL= 120.5, 4.7, ROT= 29.5, -4.7
2025-06-22T03:15:31.815Z,1750562131.815 [DAT](INFO): got valid direction response:
03:15:34.8363 LVL= 14496, 30449, 22610, 32755, AGC= 47, IDX= 440,-0.20, 0.794,-0.904,-0.241, 0.115, PHS= 0.767,-0.973,-0.359, RAW= 110.3, 7.4, CAL= 120.5, 4.7, ROT= 29.5, -4.7
2025-06-22T03:15:31.816Z,1750562131.816 [DAT](INFO): DAT read: Bearing 29.5, -4.7 (Local)
2025-06-22T03:15:31.817Z,1750562131.817 [DAT](INFO): Local bearing/azimuth received:
Bearing 29.5, -4.7 (Local)
2025-06-22T03:15:31.818Z,1750562131.818 [DAT](INFO): DAT read: Range 10 to 50 : 9.0 m (Round-trip 12.1 ms) speed -0.1 m/s
2025-06-22T03:15:31.819Z,1750562131.819 [DAT](INFO): #Rx 1: Read range and direction messages.
2025-06-22T03:15:31.820Z,1750562131.820 [DAT](INFO): direction in FSK: [0.867429,0.490768,0.081939]
2025-06-22T03:15:31.820Z,1750562131.820 [DAT](INFO): publishing direction and range info
2025-06-22T03:15:37.994Z,1750562137.994 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-06-22T03:15:38.108Z,1750562138.108 [DAT](INFO): ****** received valid address query ******
2025-06-22T03:15:38.109Z,1750562138.109 [DAT](INFO): ****** received valid ping request ******
2025-06-22T03:15:38.109Z,1750562138.109 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-06-22T03:15:38.361Z,1750562138.361 [DAT](INFO): DAT read: user:3709>
2025-06-22T03:15:38.362Z,1750562138.362 [DAT](INFO): DAT read: Tx time:03:15:42.4701
2025-06-22T03:15:38.362Z,1750562138.362 [DAT](INFO): Ping request sent.
2025-06-22T03:15:38.362Z,1750562138.362 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:15:38.363Z,1750562138.363 [DAT](INFO): DAT read: TxSync time:03:15:42.4693
2025-06-22T03:15:38.363Z,1750562138.363 [DAT](INFO): publishing transmit ping time
2025-06-22T03:15:38.364Z,1750562138.364 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.001544
2025-06-22T03:15:38.613Z,1750562138.613 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.250747
2025-06-22T03:15:38.865Z,1750562138.865 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.503142
2025-06-22T03:15:39.117Z,1750562139.117 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754918
2025-06-22T03:15:39.369Z,1750562139.369 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006778
2025-06-22T03:15:39.621Z,1750562139.621 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258775
2025-06-22T03:15:39.873Z,1750562139.873 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510699
2025-06-22T03:15:40.125Z,1750562140.125 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.763131
2025-06-22T03:15:40.377Z,1750562140.377 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014801
2025-06-22T03:15:40.629Z,1750562140.629 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266702
2025-06-22T03:15:40.881Z,1750562140.881 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.519177
2025-06-22T03:15:41.133Z,1750562141.133 [DAT](INFO): DAT read: Rx Time:03:15:44.8875
2025-06-22T03:15:41.133Z,1750562141.133 [DAT](INFO): Rx dataTimestamp_ set to:1750562141.133008
2025-06-22T03:15:41.134Z,1750562141.134 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771777
2025-06-22T03:15:41.385Z,1750562141.385 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.023003
2025-06-22T03:15:41.641Z,1750562141.641 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.278031
2025-06-22T03:15:41.898Z,1750562141.898 [DAT](INFO): DAT read: 03:15:44.8876 LVL= 20208, 32753, 25506, 32755, AGC= 49, IDX= 437, 0.09,-1.132,-2.832,-2.295,-1.855, PHS= 0.811,-0.929,-0.443, RAW= 105.7, 7.3, CAL= 115.8, 5.2, ROT= 34.2, -5.2
2025-06-22T03:15:41.899Z,1750562141.899 [DAT](INFO): got valid direction response:
03:15:44.8876 LVL= 20208, 32753, 25506, 32755, AGC= 49, IDX= 437, 0.09,-1.132,-2.832,-2.295,-1.855, PHS= 0.811,-0.929,-0.443, RAW= 105.7, 7.3, CAL= 115.8, 5.2, ROT= 34.2, -5.2
2025-06-22T03:15:41.900Z,1750562141.900 [DAT](INFO): DAT read: Bearing 34.2, -5.2 (Local)
2025-06-22T03:15:41.900Z,1750562141.900 [DAT](INFO): Local bearing/azimuth received:
Bearing 34.2, -5.2 (Local)
2025-06-22T03:15:41.902Z,1750562141.902 [DAT](INFO): DAT read: Range 10 to 50 : 9.9 m (Round-trip 13.3 ms) speed -0.1 m/s
2025-06-22T03:15:41.902Z,1750562141.902 [DAT](INFO): #Rx 1: Read range and direction messages.
2025-06-22T03:15:41.903Z,1750562141.903 [DAT](INFO): direction in FSK: [0.823677,0.559770,0.090633]
2025-06-22T03:15:41.903Z,1750562141.903 [DAT](INFO): publishing direction and range info
2025-06-22T03:15:42.062Z,1750562142.062 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Detached at range: 9.90 m. Transitioning docking module to standby.
2025-06-22T03:15:42.434Z,1750562142.434 [DockingStepper](INFO): Changing to mode: 1
2025-06-22T03:15:42.435Z,1750562142.435 [DockingStepper](INFO): Standby mode.
2025-06-22T03:15:42.500Z,1750562142.500 [DockingStepper](INFO): Commanding positive:54586
2025-06-22T03:15:43.228Z,1750562143.228 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:15:44.232Z,1750562144.232 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:15:48.077Z,1750562148.077 [DefaultWithUndock:LeaveDock:A.](INFO): *** querying acoustic contact ***
2025-06-22T03:15:48.193Z,1750562148.193 [DAT](INFO): ****** received valid address query ******
2025-06-22T03:15:48.193Z,1750562148.193 [DAT](INFO): ****** received valid ping request ******
2025-06-22T03:15:48.194Z,1750562148.194 [DAT](INFO): Querying Benthos address 50 with one ping in standard two-way mode.
2025-06-22T03:15:48.445Z,1750562148.445 [DAT](INFO): DAT read: user:3710>
2025-06-22T03:15:48.446Z,1750562148.446 [DAT](INFO): DAT read: Tx time:03:15:52.5702
2025-06-22T03:15:48.446Z,1750562148.446 [DAT](INFO): Ping request sent.
2025-06-22T03:15:48.446Z,1750562148.446 [DAT](INFO): transmitted an acoustic signal
2025-06-22T03:15:48.446Z,1750562148.446 [DAT](INFO): publishing transmit ping time
2025-06-22T03:15:48.447Z,1750562148.447 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.000733
2025-06-22T03:15:48.521Z,1750562148.521 [DefaultWithUndock:LeaveDock:B.Undock](INFO): Docking module at standby.
2025-06-22T03:15:48.697Z,1750562148.697 [DAT](INFO): DAT read: TxSync time:03:15:52.5694
2025-06-22T03:15:48.698Z,1750562148.698 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.251448
2025-06-22T03:15:48.949Z,1750562148.949 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.502780
2025-06-22T03:15:48.953Z,1750562148.953 [DefaultWithUndock:LeaveDock:B.Undock](IMPORTANT): Undocking sequence complete.
2025-06-22T03:15:48.953Z,1750562148.953 [DefaultWithUndock:LeaveDock:B.Undock] Stopped
2025-06-22T03:15:48.954Z,1750562148.954 [DefaultWithUndock:LeaveDock](INFO): Completed DefaultWithUndock:LeaveDock
2025-06-22T03:15:48.954Z,1750562148.954 [DefaultWithUndock:LeaveDock] Stopped
2025-06-22T03:15:48.954Z,1750562148.954 [DefaultWithUndock:LeaveDock](DEBUG): Aggregate::uninitialize DefaultWithUndock:LeaveDock
2025-06-22T03:15:48.954Z,1750562148.954 [DefaultWithUndock:LeaveDock:A.] Stopped
2025-06-22T03:15:48.954Z,1750562148.954 [DefaultWithUndock:LeaveDock:A.](DEBUG): Uninitializing TrackAcousticContact.
2025-06-22T03:15:48.954Z,1750562148.954 [DefaultWithUndock:SurfaceDefault] Running Loop=1
2025-06-22T03:15:48.954Z,1750562148.954 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault
2025-06-22T03:15:48.954Z,1750562148.954 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Running Loop=1
2025-06-22T03:15:48.954Z,1750562148.954 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-06-22T03:15:48.955Z,1750562148.955 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2025-06-22T03:15:48.955Z,1750562148.955 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2025-06-22T03:15:48.955Z,1750562148.955 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2025-06-22T03:15:48.956Z,1750562148.956 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2025-06-22T03:15:48.956Z,1750562148.956 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-06-22T03:15:48.956Z,1750562148.956 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-06-22T03:15:49.201Z,1750562149.201 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=0.754603
2025-06-22T03:15:49.281Z,1750562149.281 [DockingStepper](INFO): Pause
2025-06-22T03:15:49.453Z,1750562149.453 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.006615
2025-06-22T03:15:49.705Z,1750562149.705 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.258551
2025-06-22T03:15:49.788Z,1750562149.788 [Radio_Surface](INFO): Powering up
2025-06-22T03:15:49.957Z,1750562149.957 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.510592
2025-06-22T03:15:50.209Z,1750562150.209 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=1.762488
2025-06-22T03:15:50.461Z,1750562150.461 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.014807
2025-06-22T03:15:50.713Z,1750562150.713 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.266640
2025-06-22T03:15:50.965Z,1750562150.965 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.518744
2025-06-22T03:15:51.217Z,1750562151.217 [DAT](INFO): DAT read: Rx Time:03:15:54.9887
2025-06-22T03:15:51.218Z,1750562151.218 [DAT](INFO): Rx dataTimestamp_ set to:1750562151.217312
2025-06-22T03:15:51.218Z,1750562151.218 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=2.771897
2025-06-22T03:15:51.469Z,1750562151.469 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.022609
2025-06-22T03:15:51.721Z,1750562151.721 [DAT](INFO): checking for new query: numPingsReceived=0, elapsed TxPingTime=3.274493
2025-06-22T03:15:51.979Z,1750562151.979 [DAT](INFO): DAT read: 03:15:54.9887 LVL= 20640, 32753, 31730, 32755, AGC= 46, IDX= 432, 0.15, 0.874,-0.791,-0.326, 0.209, PHS= 0.753,-0.953,-0.538, RAW= 103.5, 9.6, CAL= 112.9, 8.2, ROT= 37.1, -8.2
2025-06-22T03:15:51.980Z,1750562151.980 [DAT](INFO): got valid direction response:
03:15:54.9887 LVL= 20640, 32753, 31730, 32755, AGC= 46, IDX= 432, 0.15, 0.874,-0.791,-0.326, 0.209, PHS= 0.753,-0.953,-0.538, RAW= 103.5, 9.6, CAL= 112.9, 8.2, ROT= 37.1, -8.2
2025-06-22T03:15:51.981Z,1750562151.981 [DAT](INFO): DAT read: Bearing 37.1, -8.2 (Local)
2025-06-22T03:15:51.981Z,1750562151.981 [DAT](INFO): Local bearing/azimuth received:
Bearing 37.1, -8.2 (Local)
2025-06-22T03:15:51.983Z,1750562151.983 [DAT](INFO): DAT read: Range 10 to 50 : 10.8 m (Round-trip 14.4 ms) speed -0.1 m/s
2025-06-22T03:15:51.983Z,1750562151.983 [DAT](INFO): #Rx 1: Read range and direction messages.
2025-06-22T03:15:51.985Z,1750562151.985 [DAT](INFO): direction in FSK: [0.789430,0.597041,0.142629]
2025-06-22T03:15:51.985Z,1750562151.985 [DAT](INFO): publishing direction and range info
2025-06-22T03:15:55.040Z,1750562155.040 [Radio_Surface](INFO): Checking local IP, expecting subnet 10.89.10
2025-06-22T03:15:55.041Z,1750562155.041 [Radio_Surface](INFO): Found local IP address 134.89.93.61 for eth0
2025-06-22T03:15:55.041Z,1750562155.041 [Radio_Surface](IMPORTANT): Local IP not on subnet 10.89.10, restarting DHCP
2025-06-22T03:15:55.094Z,1750562155.094 [CommandExec](IMPORTANT): got command ! /mnt/mmc/LRAUV/Tools/dhcp.sh
2025-06-22T03:15:55.492Z,1750562155.492 [CommandExec](IMPORTANT): /mnt/mmc/started/2025-06-22UTC031555_sh
2025-06-22T03:16:14.352Z,1750562174.352 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:16:15.356Z,1750562175.356 [DataOverHttps](INFO): Radio surface powered ON.
2025-06-22T03:16:15.356Z,1750562175.356 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:17:59.226Z,1750562279.226 [DefaultWithUndock:SurfaceDefault:CheckIn] Running Loop=1
2025-06-22T03:17:59.226Z,1750562279.226 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::initialize DefaultWithUndock:SurfaceDefault:CheckIn
2025-06-22T03:17:59.226Z,1750562279.226 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Running Loop=1
2025-06-22T03:18:31.993Z,1750562311.993 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2025-06-22T03:18:32.076Z,1750562312.076 [NAL9602](ERROR): received:
+CSQ:0
OK683, 2, 0, 0, 0
OK
2025-06-22T03:18:51.996Z,1750562331.996 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:18:53.001Z,1750562333.001 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:19:10.326Z,1750562350.326 [NAL9602](INFO): SBD MO Status=0, MOMSN=48683, MT Status=0, MTMSN=0
2025-06-22T03:19:10.326Z,1750562350.326 [NAL9602](INFO): No messages in MT queue
2025-06-22T03:19:11.531Z,1750562351.531 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,031924.00,A,3654.31903,N,12206.90527,W,2.857,123.81,220625,,,A*73
2025-06-22T03:19:11.541Z,1750562351.541 [NAL9602](INFO): GPS fix at 20250622T031924: (36.905317, -122.115088)
2025-06-22T03:19:11.555Z,1750562351.555 [UniversalFixResidualReporter](INFO): Fix residual: 4.3 %DT, over the last 3256.9 m. Residual distance 139.0 m at bearing -103.2 degrees. Fix at (36.9053, -122.1151) with 801.2 m made good.
2025-06-22T03:19:11.559Z,1750562351.559 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_GPS] Stopped
2025-06-22T03:19:11.560Z,1750562351.560 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Running Loop=1
2025-06-22T03:19:23.136Z,1750562363.136 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:19:24.140Z,1750562364.140 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:19:33.815Z,1750562373.815 [NAL9602](INFO): SBD MO Status=1, MOMSN=48684, MT Status=0, MTMSN=0
2025-06-22T03:19:33.864Z,1750562373.864 [NAL9602](INFO): Sent 72 bytes from file Logs/20250621T140000/Courier0111.lzma
2025-06-22T03:19:33.864Z,1750562373.864 [NAL9602](INFO): Packets left to send: 0
2025-06-22T03:19:41.935Z,1750562381.935 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.019159
2025-06-22T03:19:45.474Z,1750562385.474 [NAL9602](INFO): SBD MO Status=1, MOMSN=48685, MT Status=0, MTMSN=0
2025-06-22T03:19:45.524Z,1750562385.524 [NAL9602](INFO): Sent 194 bytes from file Logs/20250622T011825/Courier0000.lzma
2025-06-22T03:19:45.524Z,1750562385.524 [NAL9602](INFO): Packets left to send: 0
2025-06-22T03:19:51.071Z,1750562391.071 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T011825/Courier0003.lzma
2025-06-22T03:20:02.382Z,1750562402.382 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0003.lzma.bak
2025-06-22T03:20:02.382Z,1750562402.382 [DataOverHttps](INFO): SBD MOMSN=25235202
2025-06-22T03:20:16.169Z,1750562416.169 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-22T03:21:24.943Z,1750562484.943 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.741997
2025-06-22T03:21:47.485Z,1750562507.485 [NAL9602](INFO): SBD MO Status=2, MOMSN=48686, MT Status=2, MTMSN=0
2025-06-22T03:21:47.486Z,1750562507.486 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-22T03:21:56.064Z,1750562516.064 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:21:57.068Z,1750562517.068 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:22:05.035Z,1750562525.035 [NAL9602](INFO): SBD MO Status=2, MOMSN=48686, MT Status=2, MTMSN=0
2025-06-22T03:22:05.035Z,1750562525.035 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-22T03:22:23.592Z,1750562543.592 [NAL9602](INFO): SBD MO Status=1, MOMSN=48686, MT Status=0, MTMSN=0
2025-06-22T03:22:23.645Z,1750562543.645 [NAL9602](INFO): Sent 39 bytes from file Logs/20250622T011825/Courier0006.lzma
2025-06-22T03:22:23.645Z,1750562543.645 [NAL9602](INFO): Packets left to send: 0
2025-06-22T03:22:27.200Z,1750562547.200 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:22:28.204Z,1750562548.204 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:22:34.510Z,1750562554.510 [NAL9602](INFO): SBD MO Status=2, MOMSN=48687, MT Status=2, MTMSN=0
2025-06-22T03:22:34.510Z,1750562554.510 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2025-06-22T03:22:40.641Z,1750562560.641 [BPC1](INFO): Calculating totals. Valid battery stick count: 46. Valid reserve battery stick count: 4.
2025-06-22T03:22:40.644Z,1750562560.644 [BPC1](FAULT): Failed to receive data from 2 sticks prior to timeout. Will not retry this scan cycle. Missing stick IDs are: 8, 46.
2025-06-22T03:22:58.336Z,1750562578.336 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:22:59.340Z,1750562579.340 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:23:29.481Z,1750562609.481 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:23:30.484Z,1750562610.484 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:24:00.604Z,1750562640.604 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:24:01.608Z,1750562641.608 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:24:31.728Z,1750562671.728 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:24:32.732Z,1750562672.732 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:25:02.857Z,1750562702.857 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:25:03.860Z,1750562703.860 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:25:33.980Z,1750562733.980 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:25:34.984Z,1750562734.984 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:26:05.104Z,1750562765.104 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2025-06-22T03:26:06.108Z,1750562766.108 [DataOverHttps](DEBUG): Managing dock network, ignoring radio surface power off
2025-06-22T03:26:10.231Z,1750562770.231 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,-32768,-32768,-
2025-06-22T03:26:25.336Z,1750562785.336 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.002979
2025-06-22T03:26:32.987Z,1750562792.987 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T011825/Courier0009.lzma
2025-06-22T03:26:44.038Z,1750562804.038 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0009.lzma.bak
2025-06-22T03:26:44.038Z,1750562804.038 [DataOverHttps](INFO): SBD MOMSN=25235219
2025-06-22T03:26:55.605Z,1750562815.605 [NAL9602](INFO): Not Powering down - fast GPS
2025-06-22T03:27:10.503Z,1750562830.503 [DataOverHttps](INFO): Sending 49 bytes from file Logs/20250622T011825/Courier0012.lzma
2025-06-22T03:27:23.766Z,1750562843.766 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0012.lzma.bak
2025-06-22T03:27:23.766Z,1750562843.766 [DataOverHttps](INFO): SBD MOMSN=25235224
2025-06-22T03:27:49.315Z,1750562869.315 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T011825/Courier0015.lzma
2025-06-22T03:28:00.358Z,1750562880.358 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0015.lzma.bak
2025-06-22T03:28:00.358Z,1750562880.358 [DataOverHttps](INFO): SBD MOMSN=25235226
2025-06-22T03:28:28.615Z,1750562908.615 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T011825/Courier0018.lzma
2025-06-22T03:28:39.658Z,1750562919.658 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0018.lzma.bak
2025-06-22T03:28:39.658Z,1750562919.658 [DataOverHttps](INFO): SBD MOMSN=25235228
2025-06-22T03:29:05.339Z,1750562945.339 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T011825/Courier0021.lzma
2025-06-22T03:29:16.382Z,1750562956.382 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0021.lzma.bak
2025-06-22T03:29:16.382Z,1750562956.382 [DataOverHttps](INFO): SBD MOMSN=25235236
2025-06-22T03:29:26.324Z,1750562966.324 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for water mass range. Device response is::WD, , +286, -19, +256,A
2025-06-22T03:29:43.007Z,1750562983.007 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T011825/Courier0024.lzma
2025-06-22T03:29:54.062Z,1750562994.062 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0024.lzma.bak
2025-06-22T03:29:54.062Z,1750562994.062 [DataOverHttps](INFO): SBD MOMSN=25235238
2025-06-22T03:30:23.589Z,1750563023.589 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20250622T011825/Courier0027.lzma
2025-06-22T03:30:34.630Z,1750563034.630 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0027.lzma.bak
2025-06-22T03:30:34.630Z,1750563034.630 [DataOverHttps](INFO): SBD MOMSN=25235240
2025-06-22T03:31:01.007Z,1750563061.007 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T011825/Courier0030.lzma
2025-06-22T03:31:06.511Z,1750563066.511 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging
2025-06-22T03:31:13.300Z,1750563073.300 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0030.lzma.bak
2025-06-22T03:31:13.300Z,1750563073.300 [DataOverHttps](INFO): SBD MOMSN=25235242
2025-06-22T03:31:50.687Z,1750563110.687 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T011825/Courier0033.lzma
2025-06-22T03:32:02.738Z,1750563122.738 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0033.lzma.bak
2025-06-22T03:32:02.738Z,1750563122.738 [DataOverHttps](INFO): SBD MOMSN=25235244
2025-06-22T03:32:32.479Z,1750563152.479 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T011825/Courier0036.lzma
2025-06-22T03:32:45.530Z,1750563165.530 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0036.lzma.bak
2025-06-22T03:32:45.530Z,1750563165.530 [DataOverHttps](INFO): SBD MOMSN=25235246
2025-06-22T03:33:15.007Z,1750563195.007 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T011825/Courier0039.lzma
2025-06-22T03:33:26.050Z,1750563206.050 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Courier0039.lzma.bak
2025-06-22T03:33:26.050Z,1750563206.050 [DataOverHttps](INFO): SBD MOMSN=25235249
2025-06-22T03:33:55.392Z,1750563235.392 [DataOverHttps](INFO): Sending 385 bytes from file Logs/20250622T031224/Courier0000.lzma
2025-06-22T03:34:06.434Z,1750563246.434 [DataOverHttps](INFO): Moved sent file to Logs/20250622T031224/Courier0000.lzma.bak
2025-06-22T03:34:06.434Z,1750563246.434 [DataOverHttps](INFO): SBD MOMSN=25235251
2025-06-22T03:34:37.738Z,1750563277.738 [DataOverHttps](INFO): Sending 192 bytes from file Logs/20250621T140000/Express0112.lzma
2025-06-22T03:34:49.206Z,1750563289.206 [DataOverHttps](INFO): Moved sent file to Logs/20250621T140000/Express0112.lzma.bak
2025-06-22T03:34:49.206Z,1750563289.206 [DataOverHttps](INFO): SBD MOMSN=25235262
2025-06-22T03:35:08.547Z,1750563308.547 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2025-06-22T03:35:17.742Z,1750563317.742 [DataOverHttps](INFO): Sending 623 bytes from file Logs/20250622T011825/Express0001.lzma
2025-06-22T03:35:28.782Z,1750563328.782 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0001.lzma.bak
2025-06-22T03:35:28.782Z,1750563328.782 [DataOverHttps](INFO): SBD MOMSN=25235265
2025-06-22T03:36:00.182Z,1750563360.182 [DataOverHttps](INFO): Sending 498 bytes from file Logs/20250622T011825/Express0004.lzma
2025-06-22T03:36:11.222Z,1750563371.222 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0004.lzma.bak
2025-06-22T03:36:11.222Z,1750563371.222 [DataOverHttps](INFO): SBD MOMSN=25235269
2025-06-22T03:36:50.867Z,1750563410.867 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20250622T011825/Express0007.lzma
2025-06-22T03:37:01.927Z,1750563421.927 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0007.lzma.bak
2025-06-22T03:37:01.927Z,1750563421.927 [DataOverHttps](INFO): SBD MOMSN=25235275
2025-06-22T03:37:29.640Z,1750563449.640 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20250622T011825/Express0010.lzma
2025-06-22T03:37:40.682Z,1750563460.682 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0010.lzma.bak
2025-06-22T03:37:40.682Z,1750563460.682 [DataOverHttps](INFO): SBD MOMSN=25235277
2025-06-22T03:38:08.472Z,1750563488.472 [DataOverHttps](INFO): Sending 230 bytes from file Logs/20250622T011825/Express0013.lzma
2025-06-22T03:38:19.514Z,1750563499.514 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0013.lzma.bak
2025-06-22T03:38:19.514Z,1750563499.514 [DataOverHttps](INFO): SBD MOMSN=25235279
2025-06-22T03:38:50.259Z,1750563530.259 [DataOverHttps](INFO): Sending 139 bytes from file Logs/20250622T011825/Express0016.lzma
2025-06-22T03:39:01.302Z,1750563541.302 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0016.lzma.bak
2025-06-22T03:39:01.302Z,1750563541.302 [DataOverHttps](INFO): SBD MOMSN=25235283
2025-06-22T03:39:31.060Z,1750563571.060 [DataOverHttps](INFO): Sending 126 bytes from file Logs/20250622T011825/Express0019.lzma
2025-06-22T03:39:43.106Z,1750563583.106 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0019.lzma.bak
2025-06-22T03:39:43.106Z,1750563583.106 [DataOverHttps](INFO): SBD MOMSN=25235286
2025-06-22T03:40:11.315Z,1750563611.315 [DataOverHttps](INFO): Sending 127 bytes from file Logs/20250622T011825/Express0022.lzma
2025-06-22T03:40:21.354Z,1750563621.354 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0022.lzma.bak
2025-06-22T03:40:21.354Z,1750563621.354 [DataOverHttps](INFO): SBD MOMSN=25235293
2025-06-22T03:40:53.001Z,1750563653.001 [DataOverHttps](INFO): Sending 219 bytes from file Logs/20250622T011825/Express0025.lzma
2025-06-22T03:41:05.046Z,1750563665.046 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0025.lzma.bak
2025-06-22T03:41:05.046Z,1750563665.046 [DataOverHttps](INFO): SBD MOMSN=25235295
2025-06-22T03:41:06.719Z,1750563666.719 [Sonardyne_Nano](INFO): Battery below minimum, enabling charging
2025-06-22T03:41:38.768Z,1750563698.768 [DataOverHttps](INFO): Sending 231 bytes from file Logs/20250622T011825/Express0028.lzma
2025-06-22T03:41:50.814Z,1750563710.814 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0028.lzma.bak
2025-06-22T03:41:50.814Z,1750563710.814 [DataOverHttps](INFO): SBD MOMSN=25235298
2025-06-22T03:42:23.844Z,1750563743.844 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2025-06-22T03:42:42.617Z,1750563762.617 [DataOverHttps](IMPORTANT): SBD MTMSN=20250622T034255
2025-06-22T03:42:50.432Z,1750563770.432 [DataOverHttps](INFO): Sending 170 bytes from file Logs/20250622T011825/Express0031.lzma
2025-06-22T03:42:50.434Z,1750563770.434 [DataOverHttps](INFO): Received command: schedule list
2025-06-22T03:42:50.458Z,1750563770.458 [CommandExec](IMPORTANT): got command schedule list
2025-06-22T03:42:50.459Z,1750563770.459 [CommandExec](IMPORTANT): Scheduled #77: "load Engineering/undock.tl;set undock.TransitLat 36.91 degree;set undock.TransitLon -122.11 degree;run", AT TIME: 2025-06-22T04:15:00Z
2025-06-22T03:42:50.460Z,1750563770.460 [CommandExec](IMPORTANT): Scheduled #78 (#1 of 2 with id='350sv'): "load Science/profile_station.tl;set profile_station.MissionTimeout 12 h;set profile_station.NeedCommsTime 60 min;set profile_station.Lat 37.02 degree;set profile_station.Lon -122.27 degree;set profile_station.YoYoMaxDepth 50 m", AFTER MISSION
2025-06-22T03:42:50.461Z,1750563770.461 [CommandExec](IMPORTANT): Scheduled #79 (#2 of 2 with id='350sv'): "set profile_station.Speed 1.1 m/s;set profile_station.SinkOffSurface 1 bool;set profile_station.SinkDepth 3 m;run", AFTER MISSION
2025-06-22T03:42:50.461Z,1750563770.461 [CommandExec](IMPORTANT): Scheduled #80: "ubat on", AT TIME: 2025-06-22T04:30:00Z
2025-06-22T03:42:50.462Z,1750563770.462 [CommandExec](IMPORTANT): Scheduled #81 (#1 of 2 with id='351ki'): "load Science/sci2.tl;set sci2.MissionTimeout 12 h;set sci2.NeedCommsTime 60 min;set sci2.Lat1 36.91 degree;set sci2.Lon1 -122.11 degree;set sci2.Speed 0.8 m/s;set sci2.YoYoMaxDepth 25 m;set sci2.SinkOffSurface 1 bool", AT TIME: 2025-06-22T12:00:00Z
2025-06-22T03:42:50.464Z,1750563770.464 [CommandExec](IMPORTANT): Scheduled #82 (#2 of 2 with id='351ki'): "set sci2.SinkDepth 3 m;run", AT TIME: 2025-06-22T12:00:00Z
2025-06-22T03:42:50.464Z,1750563770.464 [CommandExec](IMPORTANT): Scheduled #83: "ubat off", AT TIME: 2025-06-22T12:01:00Z
2025-06-22T03:42:50.465Z,1750563770.465 [CommandExec](FAULT): Scheduling was paused by an error at 2025-06-22T03:13:45Z
2025-06-22T03:43:01.474Z,1750563781.474 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0031.lzma.bak
2025-06-22T03:43:01.474Z,1750563781.474 [DataOverHttps](INFO): SBD MOMSN=25235302
2025-06-22T03:43:28.636Z,1750563808.636 [DataOverHttps](INFO): Sending 169 bytes from file Logs/20250622T031224/Courier0003.lzma
2025-06-22T03:43:39.682Z,1750563819.682 [DataOverHttps](INFO): Moved sent file to Logs/20250622T031224/Courier0003.lzma.bak
2025-06-22T03:43:39.682Z,1750563819.682 [DataOverHttps](INFO): SBD MOMSN=25235306
2025-06-22T03:44:07.365Z,1750563847.365 [DataOverHttps](INFO): Sending 504 bytes from file Logs/20250622T011825/Express0034.lzma
2025-06-22T03:44:18.407Z,1750563858.407 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0034.lzma.bak
2025-06-22T03:44:18.407Z,1750563858.407 [DataOverHttps](INFO): SBD MOMSN=25235308
2025-06-22T03:44:45.970Z,1750563885.970 [DataOverHttps](INFO): Sending 345 bytes from file Logs/20250622T011825/Express0037.lzma
2025-06-22T03:44:57.011Z,1750563897.011 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0037.lzma.bak
2025-06-22T03:44:57.011Z,1750563897.011 [DataOverHttps](IMPORTANT): SBD MOMSN=25235317, MTMSN=20250622T034509
2025-06-22T03:45:05.840Z,1750563905.840 [DataOverHttps](INFO): Received command: schedule clear
2025-06-22T03:45:05.854Z,1750563905.854 [CommandExec](IMPORTANT): got command schedule clear
2025-06-22T03:45:05.854Z,1750563905.854 [CommandExec](IMPORTANT): Cleared 7 scheduled commands.
2025-06-22T03:45:16.078Z,1750563916.078 [RDI_Pathfinder](ERROR): only read 2 of 4 data items for bottom velocity. Device response is::BS,-32768,-2768,V
2025-06-22T03:45:24.621Z,1750563924.621 [DataOverHttps](INFO): Sending 492 bytes from file Logs/20250622T011825/Express0040.lzma
2025-06-22T03:45:35.662Z,1750563935.662 [DataOverHttps](INFO): Moved sent file to Logs/20250622T011825/Express0040.lzma.bak
2025-06-22T03:45:35.662Z,1750563935.662 [DataOverHttps](INFO): SBD MOMSN=25235335
2025-06-22T03:45:54.490Z,1750563954.490 [DataOverHttps](IMPORTANT): SBD MTMSN=20250622T034607
2025-06-22T03:46:04.519Z,1750563964.519 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T031224/Courier0006.lzma
2025-06-22T03:46:04.528Z,1750563964.528 [DataOverHttps](INFO): Received command: sched 20250622T0430 "load Science/profile_station.tl;set profile_station.MissionTimeout 12 h;set profile_station.NeedCommsTime 60 min;set profile_station.Lat 37.02 degree;set profile_station.Lon -122.27 degree" 3594t 1 2
2025-06-22T03:46:04.622Z,1750563964.622 [CommandExec](IMPORTANT): got command schedule 20250622T043000 "load Science/profile_station.tl;set profile_station.MissionTimeout 12 h;set profile_station.NeedCommsTime 60 min;set profile_station.Lat 37.02 degree;set profile_station.Lon -122.27 degree" 3594t 1 2.000000
2025-06-22T03:46:04.622Z,1750563964.622 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=3594t
2025-06-22T03:46:04.623Z,1750563964.623 [CommandExec](IMPORTANT): Scheduled #84 (#1 of 2 with id='3594t'): "load Science/profile_station.tl;set profile_station.MissionTimeout 12 h;set profile_station.NeedCommsTime 60 min;set profile_station.Lat 37.02 degree;set profile_station.Lon -122.27 degree", AT TIME: 2025-06-22T04:30:00Z
2025-06-22T03:46:04.624Z,1750563964.624 [CommandExec](FAULT): Scheduling was paused by an error at 2025-06-22T03:13:45Z
2025-06-22T03:46:15.571Z,1750563975.571 [DataOverHttps](INFO): Moved sent file to Logs/20250622T031224/Courier0006.lzma.bak
2025-06-22T03:46:15.571Z,1750563975.571 [DataOverHttps](IMPORTANT): SBD MOMSN=25235341, MTMSN=20250622T034628
2025-06-22T03:46:23.304Z,1750563983.304 [DataOverHttps](INFO): Received command: sched 20250622T0430 "set profile_station.YoYoMaxDepth 50 m;set profile_station.Speed 1.1 m/s;set profile_station.SinkOffSurface 1 bool;set profile_station.SinkDepth 3 m;run" 3594t 2 2
2025-06-22T03:46:23.346Z,1750563983.346 [CommandExec](IMPORTANT): got command schedule 20250622T043000 "set profile_station.YoYoMaxDepth 50 m;set profile_station.Speed 1.1 m/s;set profile_station.SinkOffSurface 1 bool;set profile_station.SinkDepth 3 m;run" 3594t 2 2.000000
2025-06-22T03:46:23.346Z,1750563983.346 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=3594t
2025-06-22T03:46:23.348Z,1750563983.348 [CommandExec](IMPORTANT): Scheduled #85 (#2 of 2 with id='3594t'): "set profile_station.YoYoMaxDepth 50 m;set profile_station.Speed 1.1 m/s;set profile_station.SinkOffSurface 1 bool;set profile_station.SinkDepth 3 m;run", AT TIME: 2025-06-22T04:30:00Z
2025-06-22T03:46:23.348Z,1750563983.348 [CommandExec](FAULT): Scheduling was paused by an error at 2025-06-22T03:13:45Z
2025-06-22T03:46:34.346Z,1750563994.346 [DataOverHttps](IMPORTANT): SBD MTMSN=20250622T034646
2025-06-22T03:46:42.207Z,1750564002.207 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T031224/Courier0009.lzma
2025-06-22T03:46:42.210Z,1750564002.210 [DataOverHttps](INFO): Received command: sched 20250622T0415 "ubat on"
2025-06-22T03:46:42.223Z,1750564002.223 [CommandExec](IMPORTANT): got command schedule 20250622T041500 "ubat on"
2025-06-22T03:46:42.227Z,1750564002.227 [CommandExec](IMPORTANT): Scheduled #86: "ubat on", AT TIME: 2025-06-22T04:15:00Z
2025-06-22T03:46:42.227Z,1750564002.227 [CommandExec](FAULT): Scheduling was paused by an error at 2025-06-22T03:13:45Z
2025-06-22T03:46:53.250Z,1750564013.250 [DataOverHttps](INFO): Moved sent file to Logs/20250622T031224/Courier0009.lzma.bak
2025-06-22T03:46:53.250Z,1750564013.250 [DataOverHttps](INFO): SBD MOMSN=25235346
2025-06-22T03:47:19.651Z,1750564039.651 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T031224/Courier0012.lzma
2025-06-22T03:47:30.703Z,1750564050.703 [DataOverHttps](INFO): Moved sent file to Logs/20250622T031224/Courier0012.lzma.bak
2025-06-22T03:47:30.703Z,1750564050.703 [DataOverHttps](IMPORTANT): SBD MOMSN=25235350, MTMSN=20250622T034743
2025-06-22T03:47:38.508Z,1750564058.508 [DataOverHttps](INFO): Received command: sched 20250622T12 "load Science/sci2.tl;set sci2.MissionTimeout 12 h;set sci2.NeedCommsTime 60 min;set sci2.Lat1 36.91 degree;set sci2.Lon1 -122.11 degree;set sci2.Speed 0.8 m/s;set sci2.YoYoMaxDepth 25 m;set sci2.SinkOffSurface 1 bool" 3597f 1 2
2025-06-22T03:47:38.566Z,1750564058.566 [CommandExec](IMPORTANT): got command schedule 20250622T120000 "load Science/sci2.tl;set sci2.MissionTimeout 12 h;set sci2.NeedCommsTime 60 min;set sci2.Lat1 36.91 degree;set sci2.Lon1 -122.11 degree;set sci2.Speed 0.8 m/s;set sci2.YoYoMaxDepth 25 m;set sci2.SinkOffSurface 1 bool" 3597f 1 2.000000
2025-06-22T03:47:38.566Z,1750564058.566 [CommandExec](IMPORTANT): Scheduling command #1 of 2 with id=3597f
2025-06-22T03:47:38.567Z,1750564058.567 [CommandExec](IMPORTANT): Scheduled #87 (#1 of 2 with id='3597f'): "load Science/sci2.tl;set sci2.MissionTimeout 12 h;set sci2.NeedCommsTime 60 min;set sci2.Lat1 36.91 degree;set sci2.Lon1 -122.11 degree;set sci2.Speed 0.8 m/s;set sci2.YoYoMaxDepth 25 m;set sci2.SinkOffSurface 1 bool", AT TIME: 2025-06-22T12:00:00Z
2025-06-22T03:47:38.568Z,1750564058.568 [CommandExec](FAULT): Scheduling was paused by an error at 2025-06-22T03:13:45Z
2025-06-22T03:47:49.570Z,1750564069.570 [DataOverHttps](IMPORTANT): SBD MTMSN=20250622T034802
2025-06-22T03:48:00.299Z,1750564080.299 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T031224/Courier0015.lzma
2025-06-22T03:48:00.302Z,1750564080.302 [DataOverHttps](INFO): Received command: sched 20250622T12 "set sci2.SinkDepth 3 m;run" 3597f 2 2
2025-06-22T03:48:00.320Z,1750564080.320 [CommandExec](IMPORTANT): got command schedule 20250622T120000 "set sci2.SinkDepth 3 m;run" 3597f 2 2.000000
2025-06-22T03:48:00.320Z,1750564080.320 [CommandExec](IMPORTANT): Scheduling command #2 of 2 with id=3597f
2025-06-22T03:48:00.322Z,1750564080.322 [CommandExec](IMPORTANT): Scheduled #88 (#2 of 2 with id='3597f'): "set sci2.SinkDepth 3 m;run", AT TIME: 2025-06-22T12:00:00Z
2025-06-22T03:48:00.322Z,1750564080.322 [CommandExec](FAULT): Scheduling was paused by an error at 2025-06-22T03:13:45Z
2025-06-22T03:48:11.366Z,1750564091.366 [DataOverHttps](INFO): Moved sent file to Logs/20250622T031224/Courier0015.lzma.bak
2025-06-22T03:48:11.366Z,1750564091.366 [DataOverHttps](IMPORTANT): SBD MOMSN=25235354, MTMSN=20250622T034823
2025-06-22T03:48:19.268Z,1750564099.268 [DataOverHttps](INFO): Received command: sched 20250622T12 "ubat off"
2025-06-22T03:48:19.291Z,1750564099.291 [CommandExec](IMPORTANT): got command schedule 20250622T120000 "ubat off"
2025-06-22T03:48:19.292Z,1750564099.292 [CommandExec](IMPORTANT): Scheduled #89: "ubat off", AT TIME: 2025-06-22T12:00:00Z
2025-06-22T03:48:19.292Z,1750564099.292 [CommandExec](FAULT): Scheduling was paused by an error at 2025-06-22T03:13:45Z
2025-06-22T03:48:39.827Z,1750564119.827 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T031224/Courier0018.lzma
2025-06-22T03:48:50.870Z,1750564130.870 [DataOverHttps](INFO): Moved sent file to Logs/20250622T031224/Courier0018.lzma.bak
2025-06-22T03:48:50.871Z,1750564130.871 [DataOverHttps](INFO): SBD MOMSN=25235358
2025-06-22T03:49:18.552Z,1750564158.552 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T031224/Courier0021.lzma
2025-06-22T03:49:29.594Z,1750564169.594 [DataOverHttps](INFO): Moved sent file to Logs/20250622T031224/Courier0021.lzma.bak
2025-06-22T03:49:29.595Z,1750564169.595 [DataOverHttps](IMPORTANT): SBD MOMSN=25235361, MTMSN=20250622T034942
2025-06-22T03:49:37.576Z,1750564177.576 [DataOverHttps](INFO): Received command: load Transport/keepstation.tl;set keepstation.MissionTimeout 1 h;set keepstation.NeedCommsTime 45 min;set keepstation.Depth 25 m;run
2025-06-22T03:49:37.673Z,1750564177.673 [CommandExec](IMPORTANT): got command load ./Missions/Transport/keepstation.tl
2025-06-22T03:49:37.674Z,1750564177.674 [MissionManager](INFO): Loading Mission from file: ./Missions/Transport/keepstation.tl
2025-06-22T03:49:37.674Z,1750564177.674 [MissionManager](DEBUG): TethyslAPI: loading: ./Missions/Transport/keepstation.tl
2025-06-22T03:49:37.678Z,1750564177.678 [MissionManager](DEBUG): TethyslAPI: mission file loaded: ./Missions/Transport/keepstation.tl
2025-06-22T03:49:39.155Z,1750564179.155 [MissionManager](DEBUG): TethyslAPI: ./Missions/Transport/keepstation.tl translated into:
4
45
NaN
NaN
30
15
4
0.75
200
10
10
45
2
0
0
1
2
3
NaN
0
Sinking to
Timed out while trying to reach target sink depth at current depth of
2025-06-22T03:49:39.170Z,1750564179.170 [MissionManager](INFO): DefineArg keepstation.MissionTimeout = 4.000000 h
2025-06-22T03:49:39.173Z,1750564179.173 [MissionManager](INFO): DefineArg keepstation.NeedCommsTime = 45.000000 min
2025-06-22T03:49:39.177Z,1750564179.177 [MissionManager](INFO): DefineArg keepstation.Latitude = nan arcdeg
2025-06-22T03:49:39.181Z,1750564179.181 [MissionManager](INFO): DefineArg keepstation.Longitude = nan arcdeg
2025-06-22T03:49:39.185Z,1750564179.185 [MissionManager](INFO): DefineArg keepstation.Depth = 30.000000 m
2025-06-22T03:49:39.189Z,1750564179.189 [MissionManager](INFO): DefineArg keepstation.ApproachDepth = 15.000000 m
2025-06-22T03:49:39.192Z,1750564179.192 [MissionManager](INFO): DefineArg keepstation.DepthDeadband = 4.000000 m
2025-06-22T03:49:39.196Z,1750564179.196 [MissionManager](INFO): DefineArg keepstation.Speed = 0.750000 m/s
2025-06-22T03:49:39.200Z,1750564179.200 [MissionManager](INFO): DefineArg keepstation.Radius = 200.000000 m
2025-06-22T03:49:39.203Z,1750564179.203 [MissionManager](INFO): DefineArg keepstation.SinkOffSurface = 0 bool
2025-06-22T03:49:39.207Z,1750564179.207 [MissionManager](INFO): DefineArg keepstation.SinkDepth = 10.000000 m
2025-06-22T03:49:39.263Z,1750564179.263 [MissionManager](INFO): DefineArg keepstation.SinkDepthTimeout = 10.000000 min
2025-06-22T03:49:39.267Z,1750564179.267 [MissionManager](INFO): DefineArg keepstation.MaxDepth = 45.000000 m
2025-06-22T03:49:39.275Z,1750564179.275 [MissionManager](INFO): DefineArg keepstation.MinOffshore = 2.000000 km
2025-06-22T03:49:39.291Z,1750564179.291 [MissionManager](INFO): DefineOutput keepstation.DiveMode = 0.000000 count
2025-06-22T03:49:39.315Z,1750564179.315 [MissionManager](INFO): DefineOutput keepstation.DoingComms = 0.000000 count
2025-06-22T03:49:39.330Z,1750564179.330 [MissionManager](INFO): DefineOutput keepstation.SurfaceSink = 1.000000 count
2025-06-22T03:49:39.338Z,1750564179.338 [MissionManager](INFO): DefineOutput keepstation.TransitToStation = 2.000000 count
2025-06-22T03:49:39.343Z,1750564179.343 [MissionManager](INFO): DefineOutput keepstation.StationKeep = 3.000000 count
2025-06-22T03:49:39.354Z,1750564179.354 [MissionManager](INFO): DefineOutput keepstation.OnStation = 0 bool
2025-06-22T03:49:39.355Z,1750564179.355 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/NeedComms.tl
2025-06-22T03:49:39.355Z,1750564179.355 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/NeedComms.tl
2025-06-22T03:49:39.372Z,1750564179.372 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/NeedComms.tl
2025-06-22T03:49:39.814Z,1750564179.814 [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-06-22T03:49:39.830Z,1750564179.830 [MissionManager](INFO): DefineArg keepstation:NeedComms.DiveInterval = 1.000000 h
2025-06-22T03:49:39.835Z,1750564179.835 [MissionManager](INFO): DefineArg keepstation:NeedComms.WaitForPitchUp = 10.000000 min
2025-06-22T03:49:39.839Z,1750564179.839 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacePitch = 20.000000 arcdeg
2025-06-22T03:49:39.843Z,1750564179.843 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceDepthRate = nan m/s
2025-06-22T03:49:39.846Z,1750564179.846 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfaceSpeed = 1.000000 m/s
2025-06-22T03:49:39.850Z,1750564179.850 [MissionManager](INFO): DefineArg keepstation:NeedComms.SurfacingTimeout = 1000.000000 s
2025-06-22T03:49:39.854Z,1750564179.854 [MissionManager](INFO): DefineArg keepstation:NeedComms.GPSTimeout = 7.000000 min
2025-06-22T03:49:39.858Z,1750564179.858 [MissionManager](INFO): DefineArg keepstation:NeedComms.CommsTimeout = 30.000000 min
2025-06-22T03:49:39.866Z,1750564179.866 [keepstation:NeedComms:B.GoToSurface](DEBUG): Construct GoToSurface.
2025-06-22T03:49:39.971Z,1750564179.971 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/StandardEnvelopes.tl
2025-06-22T03:49:39.971Z,1750564179.971 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/StandardEnvelopes.tl
2025-06-22T03:49:39.976Z,1750564179.976 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/StandardEnvelopes.tl
2025-06-22T03:49:40.196Z,1750564180.196 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/StandardEnvelopes.tl translated into:
5
1.5
200
2000
2025-06-22T03:49:40.215Z,1750564180.215 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinAltitude = 5.000000 m
2025-06-22T03:49:40.227Z,1750564180.227 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepthIgnore = 1.500000 m
2025-06-22T03:49:40.239Z,1750564180.239 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MaxDepth = 200.000000 m
2025-06-22T03:49:40.247Z,1750564180.247 [MissionManager](INFO): DefineArg keepstation:StandardEnvelopes.MinOffshore = 2000.000000 m
2025-06-22T03:49:40.260Z,1750564180.260 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Construct AltitudeEnvelope.
2025-06-22T03:49:40.284Z,1750564180.284 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Construct DepthEnvelope.
2025-06-22T03:49:40.306Z,1750564180.306 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Construct OffshoreEnvelope.
2025-06-22T03:49:40.346Z,1750564180.346 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/BackseatDriver.tl
2025-06-22T03:49:40.346Z,1750564180.346 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/BackseatDriver.tl
2025-06-22T03:49:40.347Z,1750564180.347 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/BackseatDriver.tl
2025-06-22T03:49:40.397Z,1750564180.397 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/BackseatDriver.tl translated into:
2025-06-22T03:49:40.406Z,1750564180.406 [MissionManager](INFO): DefineArg keepstation:BackseatDriver.EnableBackseat = 0 bool
2025-06-22T03:49:40.410Z,1750564180.410 [keepstation:BackseatDriver:A.BackseatDriver](DEBUG): Construct BackseatDriver.
2025-06-22T03:49:40.425Z,1750564180.425 [MissionManager](INFO): Inserting Stack from file: Missions/Insert/PowerOnly.tl
2025-06-22T03:49:40.425Z,1750564180.425 [MissionManager](DEBUG): TethyslAPI: loading: Missions/Insert/PowerOnly.tl
2025-06-22T03:49:40.426Z,1750564180.426 [MissionManager](DEBUG): TethyslAPI: mission file loaded: Missions/Insert/PowerOnly.tl
2025-06-22T03:49:40.671Z,1750564180.671 [MissionManager](DEBUG): TethyslAPI: Missions/Insert/PowerOnly.tl translated into:
99999
2025-06-22T03:49:40.685Z,1750564180.685 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleAll = 0 bool
2025-06-22T03:49:40.693Z,1750564180.693 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad1 = 0 bool
2025-06-22T03:49:40.700Z,1750564180.700 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad2 = 0 bool
2025-06-22T03:49:40.708Z,1750564180.708 [MissionManager](INFO): DefineArg keepstation:PowerOnly.SampleLoad3 = 0 bool
2025-06-22T03:49:40.716Z,1750564180.716 [MissionManager](INFO): DefineArg keepstation:PowerOnly.EnabledPowerOnly = 0 bool
2025-06-22T03:49:40.733Z,1750564180.733 [keepstation:PowerOnly:E.Wait](DEBUG): Construct Wait.
2025-06-22T03:49:40.735Z,1750564180.735 [keepstation:H.Pitch](DEBUG): Construct.
2025-06-22T03:49:40.795Z,1750564180.795 [keepstation:DiveCmd:SurfaceSink:sink:BuoyancyHold.Buoyancy](DEBUG): Construct Buoyancy.
2025-06-22T03:49:40.799Z,1750564180.799 [keepstation:DiveCmd:SurfaceSink:sink:B.SetSpeed](DEBUG): Construct.
2025-06-22T03:49:40.816Z,1750564180.816 [keepstation:DiveCmd:SurfaceSink:sink:D.Pitch](DEBUG): Construct.
2025-06-22T03:49:40.869Z,1750564180.869 [keepstation:DiveCmd:TransitToStation:dive:A.Buoyancy](DEBUG): Construct Buoyancy.
2025-06-22T03:49:40.877Z,1750564180.877 [keepstation:DiveCmd:TransitToStation:dive:B.Pitch](DEBUG): Construct.
2025-06-22T03:49:40.895Z,1750564180.895 [keepstation:DiveCmd:TransitToStation:dive:C.SetSpeed](DEBUG): Construct.
2025-06-22T03:49:40.923Z,1750564180.923 [keepstation:DiveCmd:StationKeep:B.Pitch](DEBUG): Construct.
2025-06-22T03:49:40.953Z,1750564180.953 [keepstation:DiveCmd:StationKeep:C.KeepStation](DEBUG): Construct KeepStation.
2025-06-22T03:49:41.018Z,1750564181.018 [keepstation:TransitToStation:Wpt1.Waypoint](DEBUG): Construct Waypoint.
2025-06-22T03:49:41.061Z,1750564181.061 [keepstation:KeepStation:B.Wait](DEBUG): Construct Wait.
2025-06-22T03:49:41.103Z,1750564181.103 [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 keepstation {
"""
Vehicle transits to desired waypoint (or stays put if none is commanded)
and stays within the specified radius.
"""
arguments {
MissionTimeout = 4 hour
"""
Maximum duration of mission
"""
NeedCommsTime = 45 minute
"""
How often to surface for communications
"""
Latitude = NaN degree
"""
Latitude of waypoint to hold. If NaN, hold the latitude at start of
mission.
"""
Longitude = NaN degree
"""
Longitude of waypoint to hold. If NaN, hold the longitude at start of
mission.
"""
Depth = 30 meter
"""
Depth held during drift mode
"""
ApproachDepth = 15 meter
"""
Depth for initial approach to station.
"""
DepthDeadband = 4 meter
"""
How much vertical drift from the specified depth is allowed in drift
mode
"""
Speed = 0.75 meter_per_second
"""
Vehicle transit speed.
"""
Radius = 200 meter
"""
Radius of circle around waypoint to hold.
"""
SinkOffSurface = false
"""
If true, use buoyancy only to decend to SinkDepth before driving to first target depth
"""
SinkDepth = 10 meter
"""
Initial depth to decend using only buoyancy before driving
"""
SinkDepthTimeout = 10 minute
"""
Max wait time for the vehicle to reach the target depth
"""
MaxDepth = 45 meter
"""
Maximum allowable depth during the mission.
"""
MinOffshore = 2 kilometer
"""
Minimum distance from the shoreline to maintain
"""
}
output {
DiveMode = 0 count
"""
Mission variable (don't change). The mission sets this variable to
switch between dive modes. Initialized to DoingComms.
"""
DoingComms = 0 count
"""
Mission variable (don't change). The mission will run in this mode
when doing surface comms.
"""
SurfaceSink = 1 count
"""
Mission variable (don't change). The mission will run in this mode
when sinking from the surface using only buoyancy.
"""
TransitToStation = 2 count
"""
Mission variable (don't change). The mission will run in this mode
when performing the transit to station
"""
StationKeep = 3 count
"""
Mission variable (don't change). The mission will run in this mode
when keeping station
"""
OnStation = false
"""
Mission variable (don't change). Determines last mode (Transit or StationKeep)
to resume after needcomms
"""
}
timeout duration=MissionTimeout
insert id="NeedComms" Insert/NeedComms.tl
assign in sequence NeedComms:DiveInterval = NeedCommsTime
insert Insert/StandardEnvelopes.tl
assign in sequence StandardEnvelopes:MaxDepth = MaxDepth
assign in sequence StandardEnvelopes:MinOffshore = MinOffshore
insert Insert/BackseatDriver.tl
insert Insert/PowerOnly.tl
behavior Guidance:Pitch {
run in parallel
set massPosition = Control:VerticalControl.massDefault
}
aggregate SurfaceComms {
run when (
called
or ( elapsed ( Universal:time_fix ) > NeedCommsTime )
)
assign in sequence DiveMode = DoingComms
call priorityHere=false refId="NeedComms"
aggregate setTransit {
run in sequence
break if (
SinkOffSurface
or OnStation
)
assign in sequence DiveMode = TransitToStation
}
aggregate setStation {
run in sequence
break if (
SinkOffSurface
or not OnStation
)
assign in sequence DiveMode = StationKeep
}
aggregate setSink {
run in sequence
break if ( not SinkOffSurface )
assign in sequence DiveMode = SurfaceSink
}
}
call id="StartingMission" priorityHere=false refId="SurfaceComms"
aggregate DiveCmd {
run when ( called )
aggregate SurfaceSink {
run while ( DiveMode == SurfaceSink )
aggregate sink {
run in sequence
behavior Guidance:Buoyancy id="BuoyancyHold" {
run in parallel
set position = NaN cc
}
behavior Guidance:SetSpeed {
run in parallel
set speed = 0 m/s
}
syslog info "Sinking to " + SinkDepth~meter
behavior Guidance:Pitch {
run in sequence
timeout duration=SinkDepthTimeout {
syslog important "Timed out while trying to reach target sink depth at current depth of "
+ Universal:depth~meter
}
set depth = SinkDepth
}
# Once we've sunk, either resume transit or station keeping depths and speeds
aggregate sinkToTransit {
run in sequence
break if ( OnStation )
assign in sequence DiveMode = TransitToStation
}
aggregate sinkToStation {
run in sequence
break if ( not OnStation )
assign in sequence DiveMode = StationKeep
}
}
}
aggregate TransitToStation {
run while ( DiveMode == TransitToStation )
aggregate dive {
run in sequence
behavior Guidance:Buoyancy {
run in parallel
set position = Control:VerticalControl.buoyancyNeutral
}
behavior Guidance:Pitch {
run in parallel
set depth = ApproachDepth
}
behavior Guidance:SetSpeed {
run in parallel
set speed = Speed
}
}
}
aggregate StationKeep {
run while ( DiveMode == StationKeep )
assign in parallel Control:VerticalControl.depthDeadband = DepthDeadband
behavior Guidance:Pitch {
run in parallel
set depth = Depth
}
behavior Guidance:KeepStation {
run in parallel
set latitude = Latitude
set longitude = Longitude
set radius = Radius
set speed = Speed
}
}
}
aggregate TransitToStation {
"""
Need a separate aggregate for transit if we want to specify a
different depth for the approach.
"""
run in sequence
aggregate Dive {
run while ( not ( DiveMode == DoingComms ) )
call priorityHere=false refId="DiveCmd"
}
behavior Guidance:Waypoint id="Wpt1" {
run in sequence
set latitude = Latitude
set longitude = Longitude
}
assign in sequence DiveMode = StationKeep
assign in sequence OnStation = true
}
call id="OnStation" priorityHere=false refId="NeedComms"
aggregate KeepStation {
run in sequence
aggregate Dive {
run while ( not ( DiveMode == DoingComms ) )
call priorityHere=false refId="DiveCmd"
}
behavior Guidance:Wait {
"""
Due to the way the KeepStation behavior is currently
implemented, we must run it in parallel and use a Wait to keep
from completing the mission before the timeout expires. However,
this new version of the mission uses a top-level timeout so that
the entire mission will not run for longer then MissionTimeout.
"""
run in sequence
set duration = MissionTimeout
}
}
}
2025-06-22T03:49:41.108Z,1750564181.108 [CommandExec](IMPORTANT): Loaded ./Missions/Transport/keepstation.tl id=keepstation
2025-06-22T03:50:05.796Z,1750564205.796 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20250622T031224/Courier0024.lzma
2025-06-22T03:50:15.568Z,1750564215.568 [CommandExec](IMPORTANT): got command set keepstation.MissionTimeout 1 hour
2025-06-22T03:50:15.569Z,1750564215.569 [CommandExec](IMPORTANT): got command set keepstation.NeedCommsTime 45 minute
2025-06-22T03:50:15.570Z,1750564215.570 [CommandExec](IMPORTANT): got command set keepstation.Depth 25 meter
2025-06-22T03:50:15.571Z,1750564215.571 [CommandExec](IMPORTANT): got command run
2025-06-22T03:50:15.573Z,1750564215.573 [CommandExec](IMPORTANT): Running
2025-06-22T03:50:15.968Z,1750564215.968 [DefaultWithUndock] Stopped
2025-06-22T03:50:15.969Z,1750564215.969 [DefaultWithUndock](DEBUG): Aggregate::uninitialize DefaultWithUndock
2025-06-22T03:50:15.969Z,1750564215.969 [DefaultWithUndock:SurfaceDefault] Stopped
2025-06-22T03:50:15.969Z,1750564215.969 [DefaultWithUndock:SurfaceDefault](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault
2025-06-22T03:50:15.969Z,1750564215.969 [DefaultWithUndock:SurfaceDefault:A.GoToSurface] Stopped
2025-06-22T03:50:15.969Z,1750564215.969 [DefaultWithUndock:SurfaceDefault:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2025-06-22T03:50:15.969Z,1750564215.969 [DefaultWithUndock:SurfaceDefault:CheckIn] Stopped
2025-06-22T03:50:15.969Z,1750564215.969 [DefaultWithUndock:SurfaceDefault:CheckIn](DEBUG): Aggregate::uninitialize DefaultWithUndock:SurfaceDefault:CheckIn
2025-06-22T03:50:15.969Z,1750564215.969 [DefaultWithUndock:SurfaceDefault:CheckIn:Read_Iridium] Stopped
2025-06-22T03:50:15.969Z,1750564215.969 [MissionManager](IMPORTANT): Started mission keepstation
2025-06-22T03:50:15.970Z,1750564215.970 [keepstation] Running Loop=1
2025-06-22T03:50:15.970Z,1750564215.970 [keepstation](DEBUG): Aggregate::initialize keepstation
2025-06-22T03:50:15.970Z,1750564215.970 [keepstation:StandardEnvelopes] Running Loop=1
2025-06-22T03:50:15.970Z,1750564215.970 [keepstation:StandardEnvelopes](DEBUG): Aggregate::initialize keepstation:StandardEnvelopes
2025-06-22T03:50:15.970Z,1750564215.970 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-06-22T03:50:15.970Z,1750564215.970 [keepstation:StandardEnvelopes:A.AltitudeEnvelope](DEBUG): Initialize AltitudeEnvelopeComponent.
2025-06-22T03:50:15.970Z,1750564215.970 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-06-22T03:50:15.970Z,1750564215.970 [keepstation:StandardEnvelopes:B.DepthEnvelope](DEBUG): Initialize DepthEnvelopeComponent.
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:StandardEnvelopes:C.OffshoreEnvelope](DEBUG): Initialize OffshoreEnvelopeComponent.
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:BackseatDriver] Running Loop=1
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:BackseatDriver](DEBUG): Aggregate::initialize keepstation:BackseatDriver
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:BackseatDriver:A.BackseatDriver] Running Loop=1
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:PowerOnly] Running Loop=1
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:PowerOnly](DEBUG): Aggregate::initialize keepstation:PowerOnly
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:PowerOnly:A] Running Loop=1
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:PowerOnly:B] Running Loop=1
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:PowerOnly:C] Running Loop=1
2025-06-22T03:50:15.971Z,1750564215.971 [keepstation:PowerOnly:D] Running Loop=1
2025-06-22T03:50:15.972Z,1750564215.972 [keepstation:PowerOnly:E.Wait] Running Loop=1
2025-06-22T03:50:15.972Z,1750564215.972 [keepstation:PowerOnly:E.Wait](DEBUG): Initialize Wait Component.
2025-06-22T03:50:15.972Z,1750564215.972 [keepstation:H.Pitch] Running Loop=1
2025-06-22T03:50:15.972Z,1750564215.972 [keepstation:H.Pitch](DEBUG): Initialize.
2025-06-22T03:50:15.972Z,1750564215.972 [keepstation:B] Running Loop=1
2025-06-22T03:50:15.973Z,1750564215.973 [keepstation:H.Pitch] Running Loop=1
2025-06-22T03:50:15.973Z,1750564215.973 [keepstation:PowerOnly] Running Loop=1
2025-06-22T03:50:15.974Z,1750564215.974 [keepstation:PowerOnly:D] Stopped
2025-06-22T03:50:15.974Z,1750564215.974 [keepstation:PowerOnly:C] Stopped
2025-06-22T03:50:15.974Z,1750564215.974 [keepstation:PowerOnly:B] Stopped
2025-06-22T03:50:15.974Z,1750564215.974 [keepstation:PowerOnly:A] Stopped
2025-06-22T03:50:15.974Z,1750564215.974 [keepstation:BackseatDriver] Running Loop=1
2025-06-22T03:50:15.974Z,1750564215.974 [keepstation:StandardEnvelopes] Running Loop=1
2025-06-22T03:50:15.974Z,1750564215.974 [keepstation:StandardEnvelopes:C.OffshoreEnvelope] Running Loop=1
2025-06-22T03:50:15.974Z,1750564215.974 [keepstation:StandardEnvelopes:B.DepthEnvelope] Running Loop=1
2025-06-22T03:50:15.975Z,1750564215.975 [keepstation:StandardEnvelopes:A.AltitudeEnvelope] Running Loop=1
2025-06-22T03:50:15.975Z,1750564215.975 [keepstation:B] Stopped
2025-06-22T03:50:15.975Z,1750564215.975 [keepstation:D] Running Loop=1
2025-06-22T03:50:16.331Z,1750564216.331 [keepstation:D] Stopped
2025-06-22T03:50:16.332Z,1750564216.332 [keepstation:E] Running Loop=1
2025-06-22T03:50:16.813Z,1750564216.813 [keepstation:E] Stopped
2025-06-22T03:50:16.813Z,1750564216.813 [keepstation:StartingMission] Running Loop=1
2025-06-22T03:50:16.814Z,1750564216.814 [keepstation:StartingMission](DEBUG): Aggregate::initialize keepstation:StartingMission
2025-06-22T03:50:16.842Z,1750564216.842 [DataOverHttps](INFO): Moved sent file to Logs/20250622T031224/Courier0024.lzma.bak
2025-06-22T03:50:16.842Z,1750564216.842 [DataOverHttps](IMPORTANT): SBD MOMSN=25235365, MTMSN=20250622T035029
2025-06-22T03:50:17.121Z,1750564217.121 [keepstation:SurfaceComms] Running Loop=1
2025-06-22T03:50:17.122Z,1750564217.122 [keepstation:SurfaceComms](DEBUG): Aggregate::initialize keepstation:SurfaceComms
2025-06-22T03:50:17.122Z,1750564217.122 [keepstation:SurfaceComms:A] Running Loop=1
2025-06-22T03:50:17.122Z,1750564217.122 [keepstation:SurfaceComms:A] Stopped
2025-06-22T03:50:17.122Z,1750564217.122 [keepstation:SurfaceComms:B] Running Loop=1
2025-06-22T03:50:17.122Z,1750564217.122 [keepstation:SurfaceComms:B](DEBUG): Aggregate::initialize keepstation:SurfaceComms:B
2025-06-22T03:50:17.545Z,1750564217.545 [keepstation:NeedComms] Running Loop=1
2025-06-22T03:50:17.545Z,1750564217.545 [keepstation:NeedComms](DEBUG): Aggregate::initialize keepstation:NeedComms
2025-06-22T03:50:17.545Z,1750564217.545 [keepstation:NeedComms:B.GoToSurface] Running Loop=1
2025-06-22T03:50:17.545Z,1750564217.545 [keepstation:NeedComms:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2025-06-22T03:50:17.546Z,1750564217.546 [keepstation:NeedComms:B.GoToSurface](INFO): Received depth rate setting nan m/s.
2025-06-22T03:50:17.546Z,1750564217.546 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch setting 19.999999 degrees.
2025-06-22T03:50:17.546Z,1750564217.546 [keepstation:NeedComms:B.GoToSurface](INFO): Received speed setting 1.000000 m/s.
2025-06-22T03:50:17.547Z,1750564217.547 [keepstation:NeedComms:B.GoToSurface](INFO): Received surface timeout setting 1000.000000 seconds.
2025-06-22T03:50:17.547Z,1750564217.547 [keepstation:NeedComms:B.GoToSurface](DEBUG): No altitude timeout specified. Using default value of 600.000000 seconds.
2025-06-22T03:50:17.547Z,1750564217.547 [keepstation:NeedComms:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2025-06-22T03:50:17.548Z,1750564217.548 [keepstation:NeedComms:A] Running Loop=1
2025-06-22T03:50:17.549Z,1750564217.549 [keepstation:NeedComms:A](INFO): last time_fix was: 1750562364.000000 second since 1970/01/01T00:00:00Z
2025-06-22T03:50:17.549Z,1750564217.549 [keepstation:NeedComms:A] Stopped
2025-06-22T03:50:18.007Z,1750564218.007 [keepstation:NeedComms:C] Running Loop=1
2025-06-22T03:50:18.325Z,1750564218.325 [keepstation:NeedComms:C](DEBUG): Initialize ReadDataComponent to sense time_fix
2025-06-22T03:50:19.989Z,1750564219.989 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,035032.00,A,3653.93630,N,12206.85111,W,1.108,234.54,220625,,,D*74
2025-06-22T03:50:19.991Z,1750564219.991 [NAL9602](INFO): GPS fix at 20250622T035032: (36.898938, -122.114185)
2025-06-22T03:50:20.087Z,1750564220.087 [UniversalFixResidualReporter](INFO): Fix residual: 13.7 %DT, over the last 1277.8 m. Residual distance 174.5 m at bearing -97.0 degrees. Fix at (36.8989, -122.1142) with 713.8 m made good.
2025-06-22T03:50:20.093Z,1750564220.093 [keepstation:NeedComms:C] Stopped
2025-06-22T03:50:20.093Z,1750564220.093 [keepstation:NeedComms:D] Running Loop=1
2025-06-22T03:50:20.400Z,1750564220.400 [keepstation:NeedComms:D](DEBUG): Initialize ReadDataComponent to sense platform_communications