INFO 2023-09-02 14:59:42,153 process.py process_mission():357 [1] self.commandline = 'src/data/process_dorado.py --noinput --num_cores 1 -v' INFO 2023-09-02 14:59:42,153 process.py process_mission():362 [1] dorado_info[mission]["comment"] = 'MBTS mission - Overnight diamond in Monterey Bay QC note: Best CTD is ctd1, ctd1 is bad in salt, ctd2 is worse. Nearly all salinity is bad - ctdToUse = ctd1 ' INFO 2023-09-02 14:59:42,153 process.py process_mission():374 [1] Processing Monterey Bay Diamond mission 2018.099.00 by user docker_user on host 0383e5772514 INFO 2023-09-02 14:59:42,153 process.py download_process():144 [1] Download and processing steps for 2018.099.00 INFO 2023-09-02 14:59:42,153 logs2netcdfs.py download_process_logs():664 [1] src_dir = '/Volumes/AUVCTD/missionlogs/2018/2018099/2018.099.00' INFO 2023-09-02 14:59:42,153 logs2netcdfs.py download_process_logs():692 [1] Rsyncing /Volumes/AUVCTD/missionlogs/2018/2018099/2018.099.00 to /data/auv_data/dorado/missionlogs/2018.099.00 INFO 2023-09-02 15:00:05,566 logs2netcdfs.py download_process_logs():700 [1] Processing mission: dorado 2018.099.00 INFO 2023-09-02 15:00:05,567 logs2netcdfs.py download_process_logs():709 [1] Processing file /data/auv_data/dorado/missionlogs/2018.099.00/ctdDriver.log (29699046 bytes) INFO 2023-09-02 15:00:10,877 logs2netcdfs.py download_process_logs():709 [1] Processing file /data/auv_data/dorado/missionlogs/2018.099.00/ctdDriver2.log (29705471 bytes) INFO 2023-09-02 15:00:16,144 logs2netcdfs.py download_process_logs():709 [1] Processing file /data/auv_data/dorado/missionlogs/2018.099.00/gps.log (808484 bytes) INFO 2023-09-02 15:00:16,359 logs2netcdfs.py download_process_logs():709 [1] Processing file /data/auv_data/dorado/missionlogs/2018.099.00/hydroscatlog.log (25987018 bytes) INFO 2023-09-02 15:00:22,670 logs2netcdfs.py download_process_logs():709 [1] Processing file /data/auv_data/dorado/missionlogs/2018.099.00/navigation.log (114476438 bytes) INFO 2023-09-02 15:00:43,358 logs2netcdfs.py download_process_logs():709 [1] Processing file /data/auv_data/dorado/missionlogs/2018.099.00/isuslog.log (1930453 bytes) INFO 2023-09-02 15:00:43,776 logs2netcdfs.py download_process_logs():709 [1] Processing file /data/auv_data/dorado/missionlogs/2018.099.00/parosci.log (36449270 bytes) INFO 2023-09-02 15:00:50,962 logs2netcdfs.py download_process_logs():709 [1] Processing file /data/auv_data/dorado/missionlogs/2018.099.00/tailCone.log (18572011 bytes) INFO 2023-09-02 15:00:56,278 logs2netcdfs.py download_process_logs():709 [1] Processing file /data/auv_data/dorado/missionlogs/2018.099.00/biolume.log (21608562 bytes) INFO 2023-09-02 15:01:01,931 logs2netcdfs.py write_variables():523 [1] Expanding original timeTag to time60Hz variable for raw data INFO 2023-09-02 15:01:03,289 logs2netcdfs.py download_process_logs():726 [1] Time to process: 57.72 seconds INFO 2023-09-02 15:01:03,289 process.py download_process():172 [1] Processing file /data/auv_data/dorado/missionlogs/2018.099.00/lopc.bin (140420355 bytes) INFO 2023-09-02 15:01:03,290 lopcToNetCDF.py main():2282 [1] Processing begun: Sat Sep 2 15:01:03 2023 INFO 2023-09-02 15:01:03,290 lopcToNetCDF.py constructTimestampList():1300 [1] parosci_nc = /data/auv_data/dorado/missionnetcdfs/2018.099.00/parosci.nc INFO 2023-09-02 15:01:03,290 lopcToNetCDF.py constructTimestampList():1301 [1] Using NetCDF4 to get start and end epoch seconds for this mission from this URL: INFO 2023-09-02 15:01:03,290 lopcToNetCDF.py constructTimestampList():1304 [1] /data/auv_data/dorado/missionnetcdfs/2018.099.00/parosci.nc INFO 2023-09-02 15:01:03,294 lopcToNetCDF.py constructTimestampList():1321 [1] From associated parosci.nc file: sensor_on_time = 1523301781.2, sensor_off_time = 1523379160.9 INFO 2023-09-02 15:01:03,294 lopcToNetCDF.py constructTimestampList():1325 [1] Duration is 77379 seconds. Expecting to read 154758 L frames from the lopc.bin file. INFO 2023-09-02 15:01:03,295 lopcToNetCDF.py constructTimestampList():1335 [1] recCount not passed in, assuming we'll have 154758 records from the lopc.bin file. INFO 2023-09-02 15:01:05,115 lopcToNetCDF.py main():2304 [1] Examined sibling parosci.nc file to find startTime = 2018-04-09 19:23:01 Z and endTime = 2018-04-10 16:52:40 Z with 154758 records expected to be read from lopc.bin INFO 2023-09-02 15:01:05,115 lopcToNetCDF.py unpackLOPCbin():727 [1] >>> Unpacking LOPC data from /data/auv_data/dorado/missionlogs/2018.099.00/lopc.bin INFO 2023-09-02 15:01:05,115 lopcToNetCDF.py unpackLOPCbin():728 [1] >>> Will write to NetCDF file /data/auv_data/dorado/missionnetcdfs/2018.099.00/lopc.nc INFO 2023-09-02 15:01:05,116 lopcToNetCDF.py openNetCDFFile():1858 [1] Will output NetCDF file to /data/auv_data/dorado/missionnetcdfs/2018.099.00/lopc.nc INFO 2023-09-02 15:01:05,116 lopcToNetCDF.py openNetCDFFile():1888 [1] missionName = 2018.099.00 INFO 2023-09-02 15:01:05,117 lopcToNetCDF.py openNetCDFFile():1907 [1] Writing bin axis for len(self.dataStructure['binSizeList']) = 994 INFO 2023-09-02 15:01:05,255 lopcToNetCDF.py unpackLOPCbin():953 [1] L Frames sample M Frames ShortLFrame LBeforeMEnd MBeforeLEnd UnknownFrame Garbled L INFO 2023-09-02 15:01:05,256 lopcToNetCDF.py unpackLOPCbin():971 [1] Count Count Count Error Error Error Error Error INFO 2023-09-02 15:01:05,256 lopcToNetCDF.py unpackLOPCbin():989 [1] -------- -------- -------- ----------- ----------- ----------- ----------- ------------ ERROR 2023-09-02 15:01:05,538 process.py download_process():193 [1] UnexpectedAreaOfCode: Encountered unexpected area of code - lopc.nc file is probably corrupt INFO 2023-09-02 15:01:05,541 process.py calibrate():197 [1] Calibration steps for 2018.099.00 INFO 2023-09-02 15:01:06,591 calibrate.py _nudge_pos():884 [1] seg# end_sec_diff end_lon_diff end_lat_diff len(segi) seg_min u_drift (cm/s) v_drift (cm/s) start datetime of segment INFO 2023-09-02 15:01:06,593 calibrate.py _nudge_pos():908 [1] - - - 0 0.00 - - - INFO 2023-09-02 15:01:07,111 calibrate.py _nudge_pos():1003 [1] 80: 0.020 -0.0004111 0.0013787 2551 8.50 -7.177 30.056 2018-04-09T19:32:43.884625664 INFO 2023-09-02 15:01:09,158 calibrate.py _nudge_pos():1003 [1] 299: 0.090 -0.0007825 0.0016581 4370 14.56 -7.972 21.098 2018-04-09T19:50:55.889818112 INFO 2023-09-02 15:01:10,377 calibrate.py _nudge_pos():1003 [1] 433: 0.100 -0.0014646 -0.0002339 13016 43.38 -5.011 -0.999 2018-04-09T20:36:32.082376192 INFO 2023-09-02 15:01:12,459 calibrate.py _nudge_pos():1003 [1] 660: 0.080 -0.0007349 0.0002996 10511 35.03 -3.115 1.585 2018-04-09T21:15:20.282883584 INFO 2023-09-02 15:01:13,067 calibrate.py _nudge_pos():1003 [1] 723: 0.070 0.0000043 0.0000101 125 0.41 1.538 4.525 2018-04-09T21:16:47.286923520 INFO 2023-09-02 15:01:14,284 calibrate.py _nudge_pos():1003 [1] 846: 0.080 0.0000772 -0.0000627 30 0.10 118.625 -120.111 2018-04-09T21:18:55.288154624 INFO 2023-09-02 15:01:14,315 calibrate.py _nudge_pos():1003 [1] 849: 0.020 -0.0004922 0.0002447 9640 32.13 -2.275 1.411 2018-04-09T21:51:06.485858560 INFO 2023-09-02 15:01:15,506 calibrate.py _nudge_pos():1003 [1] 967: 0.030 -0.0004986 0.0003328 120 0.40 -186.681 155.483 2018-04-09T21:53:27.486199296 INFO 2023-09-02 15:01:16,454 calibrate.py _nudge_pos():1003 [1] 1066: 0.030 -0.0004517 0.0003617 15 0.05 -1437.527 1436.457 2018-04-09T21:55:08.489280256 INFO 2023-09-02 15:01:19,881 calibrate.py _nudge_pos():1003 [1] 1426: 0.070 -0.0004058 0.0006013 300 1.00 -60.467 111.778 2018-04-09T22:02:12.490234112 INFO 2023-09-02 15:01:19,930 calibrate.py _nudge_pos():1003 [1] 1431: 0.070 -0.0004193 0.0006032 15 0.05 -1334.613 2395.144 2018-04-09T22:02:19.489754624 INFO 2023-09-02 15:01:20,695 calibrate.py _nudge_pos():1003 [1] 1510: 0.080 -0.0004000 0.0006493 15 0.05 -1273.147 2578.320 2018-04-09T22:03:40.484206080 INFO 2023-09-02 15:01:24,572 calibrate.py _nudge_pos():1003 [1] 1928: 0.130 -0.0003266 0.0009725 920 3.06 -15.836 58.826 2018-04-09T22:13:45.482760960 INFO 2023-09-02 15:01:25,085 calibrate.py _nudge_pos():1003 [1] 1983: 0.120 -0.0003988 0.0009830 15 0.05 -1269.378 3903.652 2018-04-09T22:14:43.488787200 INFO 2023-09-02 15:01:25,205 calibrate.py _nudge_pos():1003 [1] 1996: 0.130 -0.0003119 0.0010139 40 0.13 -356.336 1445.225 2018-04-09T22:15:03.487417344 INFO 2023-09-02 15:01:27,713 calibrate.py _nudge_pos():1003 [1] 2272: 0.150 -0.0002720 0.0012102 55 0.18 -224.441 1245.938 2018-04-09T22:19:54.487482368 INFO 2023-09-02 15:01:28,121 calibrate.py _nudge_pos():1003 [1] 2316: 0.160 -0.0002174 0.0012277 85 0.28 -115.321 812.549 2018-04-09T22:20:55.483303680 INFO 2023-09-02 15:01:28,733 calibrate.py _nudge_pos():1003 [1] 2383: 0.160 -0.0000120 -0.0000079 15 0.05 -38.342 -31.200 2018-04-09T22:22:07.488371200 INFO 2023-09-02 15:01:28,797 calibrate.py _nudge_pos():1003 [1] 2390: 0.160 0.0000488 0.0000226 15 0.05 155.364 89.919 2018-04-09T22:22:16.487754496 INFO 2023-09-02 15:01:29,185 calibrate.py _nudge_pos():1003 [1] 2429: 0.160 -0.0000514 0.0000456 20 0.06 -120.596 133.397 2018-04-09T22:23:05.484398080 INFO 2023-09-02 15:01:29,277 calibrate.py _nudge_pos():1003 [1] 2438: 0.160 -0.0000387 0.0000661 15 0.05 -123.243 262.292 2018-04-09T22:23:17.483576064 INFO 2023-09-02 15:01:30,191 calibrate.py _nudge_pos():1003 [1] 2530: 0.110 -0.0020721 0.0007626 9961 33.20 -9.272 4.257 2018-04-09T22:58:02.690729728 INFO 2023-09-02 15:01:30,252 calibrate.py _nudge_pos():1003 [1] 2536: 0.110 0.0000031 -0.0000005 65 0.21 2.162 -0.439 2018-04-09T22:58:20.689496832 INFO 2023-09-02 15:01:32,392 calibrate.py _nudge_pos():1003 [1] 2761: 0.060 -0.0003750 -0.0000152 9270 30.90 -1.804 -0.091 2018-04-09T23:32:58.887130624 INFO 2023-09-02 15:01:34,624 calibrate.py _nudge_pos():1003 [1] 2991: 0.200 -0.0005660 0.0006989 8355 27.85 -3.022 4.650 2018-04-10T00:04:39.886903040 INFO 2023-09-02 15:01:37,945 calibrate.py _nudge_pos():1003 [1] 3334: 0.030 -0.0003897 0.0008620 35 0.11 -511.214 1409.390 2018-04-10T00:10:31.082844416 INFO 2023-09-02 15:01:39,578 calibrate.py _nudge_pos():1003 [1] 3498: 0.040 -0.0003322 0.0009416 25 0.08 -617.389 2181.100 2018-04-10T00:13:20.091266560 INFO 2023-09-02 15:01:39,588 calibrate.py _nudge_pos():1003 [1] 3499: 0.040 -0.0003038 0.0009740 380 1.26 -35.748 142.868 2018-04-10T00:14:36.086060544 INFO 2023-09-02 15:01:43,561 calibrate.py _nudge_pos():1003 [1] 3908: 0.070 0.0051315 0.0005969 13571 45.23 16.859 2.445 2018-04-10T01:06:39.292106496 INFO 2023-09-02 15:01:43,625 calibrate.py _nudge_pos():1003 [1] 3914: 0.070 0.0051319 0.0006197 15 0.05 16344.008 2460.979 2018-04-10T01:06:47.291558144 INFO 2023-09-02 15:01:44,222 calibrate.py _nudge_pos():1003 [1] 3972: 0.070 0.0000001 0.0000059 15 0.05 0.175 23.448 2018-04-10T01:07:48.287379712 INFO 2023-09-02 15:01:44,492 calibrate.py _nudge_pos():1003 [1] 3998: 0.080 0.0000248 -0.0000038 15 0.05 78.839 -14.983 2018-04-10T01:08:17.285393152 INFO 2023-09-02 15:01:45,203 calibrate.py _nudge_pos():1003 [1] 4067: 0.080 0.0000188 -0.0000368 65 0.21 13.090 -31.980 2018-04-10T01:09:41.289638400 INFO 2023-09-02 15:01:45,757 calibrate.py _nudge_pos():1003 [1] 4122: 0.090 0.0000178 -0.0000212 35 0.11 23.396 -34.654 2018-04-10T01:10:46.285186048 INFO 2023-09-02 15:01:45,987 calibrate.py _nudge_pos():1003 [1] 4145: 0.090 0.0000514 -0.0000546 15 0.05 163.834 -216.754 2018-04-10T01:11:12.283405056 INFO 2023-09-02 15:01:46,127 calibrate.py _nudge_pos():1003 [1] 4158: 0.080 0.0000080 -0.0000034 15 0.05 25.353 -13.477 2018-04-10T01:11:29.292239872 INFO 2023-09-02 15:01:46,160 calibrate.py _nudge_pos():1003 [1] 4161: 0.050 0.0056327 0.0011250 11021 36.73 22.784 5.675 2018-04-10T01:48:16.491036416 INFO 2023-09-02 15:01:46,699 calibrate.py _nudge_pos():1003 [1] 4215: 0.060 0.0056639 0.0011841 65 0.21 3945.082 1028.563 2018-04-10T01:49:23.486446848 INFO 2023-09-02 15:01:46,740 calibrate.py _nudge_pos():1003 [1] 4219: 0.060 0.0056612 0.0011925 40 0.13 6470.854 1699.945 2018-04-10T01:49:34.485693440 INFO 2023-09-02 15:01:46,905 calibrate.py _nudge_pos():1003 [1] 4235: 0.060 -0.0000130 0.0000103 225 0.75 -2.583 2.544 2018-04-10T01:50:35.491514112 INFO 2023-09-02 15:01:48,669 calibrate.py _nudge_pos():1003 [1] 4411: 0.060 0.0067516 0.0015200 12576 41.92 23.927 6.719 2018-04-10T02:35:26.687154688 INFO 2023-09-02 15:01:50,165 calibrate.py _nudge_pos():1003 [1] 4567: 0.080 0.0067609 0.0014069 20 0.06 15859.014 4116.647 2018-04-10T02:38:09.685988608 INFO 2023-09-02 15:01:50,176 calibrate.py _nudge_pos():1003 [1] 4568: 0.070 0.0067022 0.0014533 15 0.05 21336.154 5771.004 2018-04-10T02:38:12.685783040 INFO 2023-09-02 15:01:50,187 calibrate.py _nudge_pos():1003 [1] 4569: 0.160 0.0067245 0.0014347 11 0.03 29970.115 7976.155 2018-04-10T02:38:14.885632256 INFO 2023-09-02 15:01:50,219 calibrate.py _nudge_pos():1003 [1] 4572: 0.070 0.0067534 0.0013989 15 0.05 21499.153 5555.017 2018-04-10T02:38:19.685303552 INFO 2023-09-02 15:01:50,259 calibrate.py _nudge_pos():1003 [1] 4576: 0.080 0.0066356 0.0013467 425 1.41 697.416 176.553 2018-04-10T02:39:47.689274880 INFO 2023-09-02 15:01:52,012 calibrate.py _nudge_pos():1003 [1] 4755: 0.110 0.0063383 0.0009140 1410 4.70 200.477 36.059 2018-04-10T02:47:32.687420416 INFO 2023-09-02 15:01:53,601 calibrate.py _nudge_pos():1003 [1] 4917: 0.130 0.0000125 -0.0000122 15 0.05 39.755 -48.281 2018-04-10T02:50:16.686185472 INFO 2023-09-02 15:01:53,612 calibrate.py _nudge_pos():1003 [1] 4918: 0.120 0.0000724 -0.0000393 35 0.11 94.939 -64.295 2018-04-10T02:50:23.685706240 INFO 2023-09-02 15:01:54,194 calibrate.py _nudge_pos():1003 [1] 4976: 0.160 0.0062142 0.0024390 12721 42.40 21.767 10.659 2018-04-10T03:33:44.887511552 INFO 2023-09-02 15:01:54,297 calibrate.py _nudge_pos():1003 [1] 4986: 0.120 0.0002360 -0.0001066 140 0.46 75.646 -42.649 2018-04-10T03:34:22.884908800 INFO 2023-09-02 15:01:55,573 calibrate.py _nudge_pos():1003 [1] 5115: 0.130 0.0002589 -0.0002389 15 0.05 823.991 -948.601 2018-04-10T03:36:35.885797376 INFO 2023-09-02 15:01:55,616 calibrate.py _nudge_pos():1003 [1] 5119: 0.130 0.0002219 -0.0002235 15 0.05 706.421 -887.511 2018-04-10T03:36:41.885386496 INFO 2023-09-02 15:01:55,649 calibrate.py _nudge_pos():1003 [1] 5122: 0.130 0.0002741 -0.0002496 15 0.05 872.261 -991.295 2018-04-10T03:36:46.885043968 INFO 2023-09-02 15:01:56,100 calibrate.py _nudge_pos():1003 [1] 5166: 0.020 0.0009589 0.0028252 19367 64.55 2.206 8.110 2018-04-10T04:42:03.286752000 INFO 2023-09-02 15:02:01,390 calibrate.py _nudge_pos():1003 [1] 5684: 0.060 -0.0000563 0.0022457 770 2.56 -3.261 162.340 2018-04-10T04:53:14.290785024 INFO 2023-09-02 15:02:02,362 calibrate.py _nudge_pos():1003 [1] 5774: 0.070 -0.0005816 0.0019960 370 1.23 -70.212 300.672 2018-04-10T04:55:57.289618944 INFO 2023-09-02 15:02:02,622 calibrate.py _nudge_pos():1003 [1] 5799: 0.080 -0.0006455 0.0019447 320 1.06 -90.145 338.917 2018-04-10T04:57:25.283590912 INFO 2023-09-02 15:02:03,668 calibrate.py _nudge_pos():1003 [1] 5904: 0.090 0.0000148 -0.0000031 15 0.05 47.231 -12.348 2018-04-10T04:59:12.286260480 INFO 2023-09-02 15:02:04,594 calibrate.py _nudge_pos():1003 [1] 5994: 0.090 -0.0000093 0.0000097 15 0.05 -29.706 38.406 2018-04-10T05:00:44.289957888 INFO 2023-09-02 15:02:04,837 calibrate.py _nudge_pos():1003 [1] 6017: 0.050 0.0032013 0.0028302 10401 34.67 13.710 15.128 2018-04-10T05:35:46.485947904 INFO 2023-09-02 15:02:05,094 calibrate.py _nudge_pos():1003 [1] 6041: 0.050 0.0031906 0.0028474 30 0.10 4900.437 5458.582 2018-04-10T05:36:15.483961344 INFO 2023-09-02 15:02:05,353 calibrate.py _nudge_pos():1003 [1] 6067: 0.050 0.0031279 0.0028694 25 0.08 5804.968 6646.814 2018-04-10T05:36:50.491563008 INFO 2023-09-02 15:02:05,482 calibrate.py _nudge_pos():1003 [1] 6080: 0.050 0.0030607 0.0028649 100 0.33 1377.045 1608.808 2018-04-10T05:37:24.489233920 INFO 2023-09-02 15:02:06,548 calibrate.py _nudge_pos():1003 [1] 6184: 0.060 -0.0000227 -0.0000190 15 0.05 -72.165 -75.451 2018-04-10T05:39:13.491767040 INFO 2023-09-02 15:02:06,934 calibrate.py _nudge_pos():1003 [1] 6221: 0.060 -0.0000050 -0.0000032 20 0.06 -11.776 -9.459 2018-04-10T05:39:56.488821248 INFO 2023-09-02 15:02:07,828 calibrate.py _nudge_pos():1003 [1] 6307: 0.120 -0.0010326 0.0012964 3120 10.40 -14.745 23.105 2018-04-10T05:51:45.490251520 INFO 2023-09-02 15:02:17,321 calibrate.py _nudge_pos():1003 [1] 7229: 0.190 0.0000128 0.0000892 35 0.11 16.777 145.885 2018-04-10T06:07:14.486610944 INFO 2023-09-02 15:02:17,547 calibrate.py _nudge_pos():1003 [1] 7251: 0.170 -0.0034090 0.0046196 12371 41.23 -12.270 20.760 2018-04-10T06:48:50.685609472 INFO 2023-09-02 15:02:21,059 calibrate.py _nudge_pos():1003 [1] 7591: 0.180 0.0000237 0.0000223 30 0.10 36.388 42.677 2018-04-10T06:54:36.691906560 INFO 2023-09-02 15:02:21,340 calibrate.py _nudge_pos():1003 [1] 7618: 0.150 -0.0029162 0.0034633 10806 36.02 -12.013 17.818 2018-04-10T07:31:03.892072960 INFO 2023-09-02 15:02:23,665 calibrate.py _nudge_pos():1003 [1] 7843: 0.120 -0.0023019 0.0030946 10641 35.47 -9.627 16.168 2018-04-10T08:10:17.090867712 INFO 2023-09-02 15:02:26,228 calibrate.py _nudge_pos():1003 [1] 8092: 0.070 -0.0059333 0.0047586 22397 74.65 -11.784 11.812 2018-04-10T09:29:04.487019008 INFO 2023-09-02 15:02:28,478 calibrate.py _nudge_pos():1003 [1] 8314: 0.010 -0.0026179 0.0019614 8336 27.78 -13.968 13.081 2018-04-10T10:00:34.687531520 INFO 2023-09-02 15:02:28,721 calibrate.py _nudge_pos():1003 [1] 8339: 0.010 -0.0025989 0.0019501 15 0.05 -8256.000 7743.633 2018-04-10T10:01:03.685544960 INFO 2023-09-02 15:02:28,906 calibrate.py _nudge_pos():1003 [1] 8358: 0.010 -0.0025864 0.0019332 15 0.05 -8216.365 7676.881 2018-04-10T10:01:25.684037888 INFO 2023-09-02 15:02:29,319 calibrate.py _nudge_pos():1003 [1] 8400: 0.020 -0.0022745 0.0016527 1475 4.91 -68.623 62.331 2018-04-10T10:07:04.690814208 INFO 2023-09-02 15:02:29,447 calibrate.py _nudge_pos():1003 [1] 8413: 0.030 -0.0022574 0.0016649 15 0.05 -7171.273 6611.397 2018-04-10T10:07:20.689718272 INFO 2023-09-02 15:02:29,674 calibrate.py _nudge_pos():1003 [1] 8436: 0.030 -0.0022392 0.0016698 30 0.10 -3433.956 3201.054 2018-04-10T10:07:53.687457792 INFO 2023-09-02 15:02:29,901 calibrate.py _nudge_pos():1003 [1] 8458: 0.040 -0.0021929 0.0016527 25 0.08 -4063.663 3828.444 2018-04-10T10:08:21.685539840 INFO 2023-09-02 15:02:30,289 calibrate.py _nudge_pos():1003 [1] 8493: 0.050 -0.0021392 0.0016217 50 0.16 -1941.586 1839.930 2018-04-10T10:09:07.682388736 INFO 2023-09-02 15:02:30,583 calibrate.py _nudge_pos():1003 [1] 8519: 0.060 -0.0020894 0.0014391 455 1.51 -204.678 176.225 2018-04-10T10:11:04.684373504 INFO 2023-09-02 15:02:31,153 calibrate.py _nudge_pos():1003 [1] 8569: 0.050 -0.0000212 -0.0000431 15 0.05 -67.363 -171.156 2018-04-10T10:11:58.690674176 INFO 2023-09-02 15:02:31,286 calibrate.py _nudge_pos():1003 [1] 8581: 0.050 0.0001119 0.0002318 35 0.11 146.354 379.018 2018-04-10T10:12:17.689372416 INFO 2023-09-02 15:02:31,340 calibrate.py _nudge_pos():1003 [1] 8586: 0.050 0.0000766 0.0001013 25 0.08 141.910 234.677 2018-04-10T10:12:26.688755968 INFO 2023-09-02 15:02:31,674 calibrate.py _nudge_pos():1003 [1] 8616: 0.060 -0.0000382 -0.0000481 15 0.05 -121.398 -190.950 2018-04-10T10:13:01.686358528 INFO 2023-09-02 15:02:31,810 calibrate.py _nudge_pos():1003 [1] 8628: 0.070 -0.0000360 -0.0000761 25 0.08 -66.655 -176.261 2018-04-10T10:13:18.685193984 INFO 2023-09-02 15:02:32,193 calibrate.py _nudge_pos():1003 [1] 8665: 0.060 0.0001573 0.0002125 15 0.05 498.024 840.640 2018-04-10T10:14:00.692316416 INFO 2023-09-02 15:02:32,265 calibrate.py _nudge_pos():1003 [1] 8672: 0.060 0.0000109 0.0000344 25 0.08 20.176 79.716 2018-04-10T10:14:11.691563008 INFO 2023-09-02 15:02:32,276 calibrate.py _nudge_pos():1003 [1] 8673: 0.060 -0.0000547 -0.0000774 20 0.06 -128.050 -226.616 2018-04-10T10:14:15.691288832 INFO 2023-09-02 15:02:32,553 calibrate.py _nudge_pos():1003 [1] 8700: 0.070 -0.0000283 -0.0000393 20 0.06 -66.280 -115.098 2018-04-10T10:14:45.689233664 INFO 2023-09-02 15:02:32,685 calibrate.py _nudge_pos():1003 [1] 8713: 0.020 -0.0045780 0.0024200 10321 34.40 -19.722 13.035 2018-04-10T10:49:22.886936064 INFO 2023-09-02 15:02:35,277 calibrate.py _nudge_pos():1003 [1] 8966: 0.030 -0.0000041 0.0000072 25 0.08 -7.554 16.759 2018-04-10T10:53:41.889192960 INFO 2023-09-02 15:02:35,310 calibrate.py _nudge_pos():1003 [1] 8969: 0.030 -0.0000017 0.0000321 65 0.21 -1.198 27.925 2018-04-10T10:53:56.888165632 INFO 2023-09-02 15:02:35,402 calibrate.py _nudge_pos():1003 [1] 8978: 0.120 -0.0019661 0.0010131 5315 17.71 -16.447 10.598 2018-04-10T11:11:47.884797440 INFO 2023-09-02 15:02:36,112 calibrate.py _nudge_pos():1003 [1] 9048: 0.120 0.0000053 0.0000196 15 0.05 16.971 77.731 2018-04-10T11:13:02.889659136 INFO 2023-09-02 15:02:37,976 calibrate.py _nudge_pos():1003 [1] 9215: 0.110 0.0010192 0.0064994 11986 39.95 3.781 30.146 2018-04-10T11:55:49.083862784 INFO 2023-09-02 15:02:38,810 calibrate.py _nudge_pos():1003 [1] 9289: 0.110 0.0009946 0.0065569 15 0.05 3158.801 26037.255 2018-04-10T11:57:10.088313600 INFO 2023-09-02 15:02:38,938 calibrate.py _nudge_pos():1003 [1] 9301: 0.120 0.0010497 0.0065651 15 0.05 3333.701 26069.844 2018-04-10T11:57:25.087286016 INFO 2023-09-02 15:02:40,494 calibrate.py _nudge_pos():1003 [1] 9440: 0.130 0.0010390 0.0066518 15 0.05 3299.693 26414.290 2018-04-10T11:59:50.087353088 INFO 2023-09-02 15:02:40,835 calibrate.py _nudge_pos():1003 [1] 9472: 0.130 0.0010158 0.0066627 15 0.05 3226.258 26457.505 2018-04-10T12:00:27.084818432 INFO 2023-09-02 15:02:41,551 calibrate.py _nudge_pos():1003 [1] 9540: 0.170 0.0009024 0.0068381 2385 7.95 16.828 159.451 2018-04-10T12:09:35.087277568 INFO 2023-09-02 15:02:41,826 calibrate.py _nudge_pos():1003 [1] 9566: 0.170 0.0009174 0.0068388 15 0.05 2913.602 27156.598 2018-04-10T12:10:05.085222656 INFO 2023-09-02 15:02:41,890 calibrate.py _nudge_pos():1003 [1] 9572: 0.170 0.0009144 0.0068548 330 1.10 123.559 1158.141 2018-04-10T12:11:16.090358528 INFO 2023-09-02 15:02:43,433 calibrate.py _nudge_pos():1003 [1] 9716: 0.180 0.0000343 -0.0000221 20 0.06 80.346 -64.557 2018-04-10T12:13:57.089329152 INFO 2023-09-02 15:02:44,873 calibrate.py _nudge_pos():1003 [1] 9847: 0.180 0.0020013 0.0047242 12841 42.80 6.932 20.453 2018-04-10T12:58:58.284284928 INFO 2023-09-02 15:02:46,865 calibrate.py _nudge_pos():1003 [1] 10028: 0.190 -0.0000439 -0.0000045 35 0.11 -57.372 -7.395 2018-04-10T13:02:05.291473920 INFO 2023-09-02 15:02:48,570 calibrate.py _nudge_pos():1003 [1] 10191: 0.170 0.0015366 0.0038910 11215 37.38 6.095 19.288 2018-04-10T13:42:10.486706688 INFO 2023-09-02 15:02:51,591 calibrate.py _nudge_pos():1003 [1] 10457: 0.170 0.0014549 0.0036906 11947 39.82 5.419 17.174 2018-04-10T14:26:24.884867840 INFO 2023-09-02 15:02:51,618 calibrate.py _nudge_pos():1003 [1] 10459: 0.160 0.0014619 0.0036846 15 0.05 4646.417 14631.607 2018-04-10T14:26:28.684607744 INFO 2023-09-02 15:02:51,631 calibrate.py _nudge_pos():1003 [1] 10460: 0.170 0.0013872 0.0037456 25 0.08 2571.859 8676.428 2018-04-10T14:26:33.684265216 INFO 2023-09-02 15:02:53,679 calibrate.py _nudge_pos():1003 [1] 10627: 0.180 0.0000939 0.0000003 25 0.08 174.130 0.589 2018-04-10T14:29:26.682414080 INFO 2023-09-02 15:02:53,940 calibrate.py _nudge_pos():1003 [1] 10648: 0.170 0.0000321 -0.0000220 25 0.08 59.489 -50.952 2018-04-10T14:29:53.690563840 INFO 2023-09-02 15:02:54,327 calibrate.py _nudge_pos():1003 [1] 10679: 0.160 0.0017822 0.0044024 11106 37.02 7.142 22.038 2018-04-10T15:07:24.886346240 INFO 2023-09-02 15:02:57,456 calibrate.py _nudge_pos():1003 [1] 10919: 0.110 0.0016178 0.0030023 9966 33.22 7.226 16.748 2018-04-10T15:44:37.083430400 INFO 2023-09-02 15:03:00,251 calibrate.py _nudge_pos():1003 [1] 11142: 0.130 -0.0016509 -0.0002510 14486 48.28 -5.073 -0.963 2018-04-10T16:36:36.289750016 INFO 2023-09-02 15:03:00,863 calibrate.py _nudge_pos():1003 [1] 11189: 0.200 -0.0023743 0.0009304 4450 14.83 -23.754 11.625 2018-04-10T16:52:13.285561600 INFO 2023-09-02 15:03:01,215 calibrate.py _nudge_pos():1060 [1] 11178: - - - 2 0.00 - - INFO 2023-09-02 15:03:01,215 calibrate.py _nudge_pos():1066 [1] Points in final series = 386465 INFO 2023-09-02 15:03:05,706 calibrate.py _hs2_process():1574 [1] Number of bad hs2 points: 38 of 309357 INFO 2023-09-02 15:03:09,777 calibrate.py _geometric_depth_correction():2497 [1] hs2: d_beg_time_diff: -2 seconds, d_end_time_diff: -1 seconds, INFO 2023-09-02 15:03:14,883 calibrate.py _geometric_depth_correction():2497 [1] ctd1: d_beg_time_diff: 36 seconds, d_end_time_diff: -1 seconds, INFO 2023-09-02 15:03:18,615 calibrate.py _geometric_depth_correction():2497 [1] ctd1: d_beg_time_diff: 36 seconds, d_end_time_diff: -1 seconds, INFO 2023-09-02 15:03:18,625 calibrate.py _ctd_process():2047 [1] Performing range checking of ['ctd1_salinity'] in 2018.099.00/ctd1.nc INFO 2023-09-02 15:03:18,628 calibrate.py _range_qc_combined_nc():400 [1] Setting 6 ctd1_salinity values to NaN INFO 2023-09-02 15:03:18,629 calibrate.py _range_qc_combined_nc():414 [1] Checked for data outside of these variables and ranges: [('ctd1_salinity', Range(min=30, max=40))] INFO 2023-09-02 15:03:18,629 calibrate.py _range_qc_combined_nc():440 [1] Done range checking ctd1 INFO 2023-09-02 15:03:23,112 calibrate.py _geometric_depth_correction():2497 [1] ctd2: d_beg_time_diff: 19 seconds, d_end_time_diff: -1 seconds, INFO 2023-09-02 15:03:26,628 calibrate.py _geometric_depth_correction():2497 [1] ctd2: d_beg_time_diff: 19 seconds, d_end_time_diff: -1 seconds, INFO 2023-09-02 15:03:26,640 calibrate.py _ctd_process():2047 [1] Performing range checking of ['ctd2_salinity'] in 2018.099.00/ctd2.nc INFO 2023-09-02 15:03:26,643 calibrate.py _range_qc_combined_nc():400 [1] Setting 5 ctd2_salinity values to NaN INFO 2023-09-02 15:03:26,643 calibrate.py _range_qc_combined_nc():414 [1] Checked for data outside of these variables and ranges: [('ctd2_salinity', Range(min=30, max=40))] INFO 2023-09-02 15:03:26,643 calibrate.py _range_qc_combined_nc():440 [1] Done range checking ctd2 INFO 2023-09-02 15:03:27,050 calibrate.py _biolume_process():2223 [1] Checking for non-monotonic increasing time60hz INFO 2023-09-02 15:03:39,692 calibrate.py _geometric_depth_correction():2497 [1] biolume: d_beg_time_diff: -7 seconds, d_end_time_diff: -1 seconds, ERROR 2023-09-02 15:03:40,129 calibrate.py process_logs():2613 [1] Error processing lopc: lopc has no time coordinate - likely an incomplete lopc.nc file in missionlogs/2018.099.00 ERROR 2023-09-02 15:03:40,129 calibrate.py process_logs():2613 [1] Error processing ecopuck: ecopuck has no orig_data - likely a missing or zero-sized .log file in missionlogs/2018.099.00 INFO 2023-09-02 15:03:41,069 calibrate.py write_netcdf():2584 [1] Writing calibrated instrument data to /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00_cal.nc INFO 2023-09-02 15:03:42,192 calibrate.py write_netcdf():2588 [1] Data variables written: biolume_avg_biolume, biolume_depth, biolume_flow, biolume_raw, biolume_time, biolume_time60hz, ctd1_conductivity, ctd1_conductivity_onboard, ctd1_depth, ctd1_dissolvedO2, ctd1_flow1, ctd1_oxygen_mll, ctd1_oxygen_umolkg, ctd1_salinity, ctd1_salinity_onboard, ctd1_temperature, ctd1_temperature_onboard, ctd1_time, ctd2_conductivity, ctd2_conductivity_onboard, ctd2_depth, ctd2_flow2, ctd2_salinity, ctd2_salinity_onboard, ctd2_temperature, ctd2_temperature_onboard, ctd2_time, depth_filtdepth, depth_filtpres, depth_time, gps_latitude, gps_longitude, gps_time, hs2_bb420, hs2_bb700, hs2_depth, hs2_fl700, hs2_time, isus_nitrate, isus_temp, isus_time, navigation_depth, navigation_latitude, navigation_longitude, navigation_mWaterSpeed, navigation_pitch, navigation_posx, navigation_posy, navigation_roll, navigation_time, navigation_yaw, nudged_latitude, nudged_longitude, tailcone_propRpm, tailcone_time, time INFO 2023-09-02 15:03:42,205 process.py align():220 [1] Alignment steps for 2018.099.00 INFO 2023-09-02 15:03:42,424 align.py process_cal():145 [1] Processing dorado_2018.099.00_cal.nc from /data/auv_data/dorado/missionnetcdfs/2018.099.00 INFO 2023-09-02 15:03:42,576 align.py process_cal():221 [1] Using pitch corrected navigation_depth: mDepth from navigation.nc INFO 2023-09-02 15:03:42,588 align.py process_cal():282 [1] navigation_roll: instrument_sample_rate_hz = 5.00 INFO 2023-09-02 15:03:42,971 align.py process_cal():221 [1] Using pitch corrected navigation_depth: mDepth from navigation.nc INFO 2023-09-02 15:03:42,992 align.py process_cal():282 [1] navigation_pitch: instrument_sample_rate_hz = 5.00 INFO 2023-09-02 15:03:43,470 align.py process_cal():221 [1] Using pitch corrected navigation_depth: mDepth from navigation.nc INFO 2023-09-02 15:03:43,486 align.py process_cal():282 [1] navigation_yaw: instrument_sample_rate_hz = 5.00 INFO 2023-09-02 15:03:43,692 align.py process_cal():168 [1] Skipping navigation_posx INFO 2023-09-02 15:03:43,692 align.py process_cal():168 [1] Skipping navigation_posy INFO 2023-09-02 15:03:43,845 align.py process_cal():221 [1] Using pitch corrected navigation_depth: mDepth from navigation.nc INFO 2023-09-02 15:03:43,862 align.py process_cal():282 [1] navigation_mWaterSpeed: instrument_sample_rate_hz = 5.00 INFO 2023-09-02 15:03:44,205 align.py process_cal():221 [1] Using pitch corrected hs2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to hs2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:44,220 align.py process_cal():282 [1] hs2_bb420: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:44,555 align.py process_cal():221 [1] Using pitch corrected hs2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to hs2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:44,568 align.py process_cal():282 [1] hs2_bb700: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:44,875 align.py process_cal():221 [1] Using pitch corrected hs2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to hs2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:44,888 align.py process_cal():282 [1] hs2_fl700: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:45,193 align.py process_cal():221 [1] Using pitch corrected hs2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to hs2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:45,206 align.py process_cal():282 [1] hs2_depth: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:45,515 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:45,529 align.py process_cal():282 [1] ctd1_temperature: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:45,831 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:45,845 align.py process_cal():282 [1] ctd1_conductivity: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:46,150 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:46,166 align.py process_cal():282 [1] ctd1_salinity: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:46,484 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:46,499 align.py process_cal():282 [1] ctd1_temperature_onboard: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:46,806 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:46,821 align.py process_cal():282 [1] ctd1_conductivity_onboard: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:47,133 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:47,153 align.py process_cal():282 [1] ctd1_salinity_onboard: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:47,464 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:47,479 align.py process_cal():282 [1] ctd1_dissolvedO2: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:47,785 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:47,799 align.py process_cal():282 [1] ctd1_oxygen_mll: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:48,106 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:48,121 align.py process_cal():282 [1] ctd1_oxygen_umolkg: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:48,431 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:48,446 align.py process_cal():282 [1] ctd1_flow1: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:48,759 align.py process_cal():221 [1] Using pitch corrected ctd1_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd1_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:48,773 align.py process_cal():282 [1] ctd1_depth: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:49,085 align.py process_cal():221 [1] Using pitch corrected ctd2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:49,101 align.py process_cal():282 [1] ctd2_temperature: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:49,422 align.py process_cal():221 [1] Using pitch corrected ctd2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:49,437 align.py process_cal():282 [1] ctd2_conductivity: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:49,750 align.py process_cal():221 [1] Using pitch corrected ctd2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:49,765 align.py process_cal():282 [1] ctd2_salinity: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:50,075 align.py process_cal():221 [1] Using pitch corrected ctd2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:50,091 align.py process_cal():282 [1] ctd2_temperature_onboard: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:50,414 align.py process_cal():221 [1] Using pitch corrected ctd2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:50,430 align.py process_cal():282 [1] ctd2_conductivity_onboard: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:50,738 align.py process_cal():221 [1] Using pitch corrected ctd2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:50,754 align.py process_cal():282 [1] ctd2_salinity_onboard: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:51,063 align.py process_cal():221 [1] Using pitch corrected ctd2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:51,079 align.py process_cal():282 [1] ctd2_flow2: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:51,404 align.py process_cal():221 [1] Using pitch corrected ctd2_depth: Variable depth_filtdepth from dorado_2018.099.00_cal.nc linearly interpolated to ctd2_time and corrected for pitch using SensorOffset(x=4.5, y=0.0) INFO 2023-09-02 15:03:51,419 align.py process_cal():282 [1] ctd2_depth: instrument_sample_rate_hz = 4.00 INFO 2023-09-02 15:03:51,819 align.py process_cal():282 [1] isus_nitrate: instrument_sample_rate_hz = 0.78 INFO 2023-09-02 15:03:52,081 align.py process_cal():282 [1] isus_temp: instrument_sample_rate_hz = 0.78 INFO 2023-09-02 15:03:52,354 align.py process_cal():282 [1] biolume_flow: instrument_sample_rate_hz = 0.98 INFO 2023-09-02 15:03:52,627 align.py process_cal():282 [1] biolume_avg_biolume: instrument_sample_rate_hz = 0.98 INFO 2023-09-02 15:03:53,151 align.py process_cal():282 [1] biolume_raw: instrument_sample_rate_hz = 58.98 INFO 2023-09-02 15:03:56,766 align.py process_cal():282 [1] tailcone_propRpm: instrument_sample_rate_hz = 5.00 INFO 2023-09-02 15:03:57,040 align.py write_netcdf():367 [1] Writing aligned data to /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00_align.nc INFO 2023-09-02 15:03:57,939 align.py write_netcdf():372 [1] Data variables written: biolume_avg_biolume, biolume_depth, biolume_flow, biolume_latitude, biolume_longitude, biolume_raw, biolume_time, biolume_time60hz, ctd1_conductivity, ctd1_conductivity_onboard, ctd1_depth, ctd1_dissolvedO2, ctd1_flow1, ctd1_latitude, ctd1_longitude, ctd1_oxygen_mll, ctd1_oxygen_umolkg, ctd1_salinity, ctd1_salinity_onboard, ctd1_temperature, ctd1_temperature_onboard, ctd1_time, ctd2_conductivity, ctd2_conductivity_onboard, ctd2_depth, ctd2_flow2, ctd2_latitude, ctd2_longitude, ctd2_salinity, ctd2_salinity_onboard, ctd2_temperature, ctd2_temperature_onboard, ctd2_time, hs2_bb420, hs2_bb700, hs2_depth, hs2_fl700, hs2_latitude, hs2_longitude, hs2_time, isus_depth, isus_latitude, isus_longitude, isus_nitrate, isus_temp, isus_time, navigation_depth, navigation_latitude, navigation_longitude, navigation_mWaterSpeed, navigation_pitch, navigation_roll, navigation_time, navigation_yaw, tailcone_depth, tailcone_latitude, tailcone_longitude, tailcone_propRpm, tailcone_time INFO 2023-09-02 15:03:57,945 process.py resample():241 [1] Resampling steps for 2018.099.00 INFO 2023-09-02 15:03:58,103 resample.py instruments_variables():233 [1] Reading variables from /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00_align.nc mission netCDF file INFO 2023-09-02 15:03:58,122 resample.py instruments_variables():233 [1] Reading variables from /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00_align.nc mission netCDF file INFO 2023-09-02 15:03:58,125 resample.py get_mission_start_end():815 [1] navigation: 2018-04-09T19:23:33.692316416 to 2018-04-10T16:52:40.883670784 (0 days 00:00:00.069995520 before mission_end) INFO 2023-09-02 15:03:58,130 resample.py get_mission_start_end():815 [1] hs2 : 2018-04-09T19:22:59.904631040 to 2018-04-10T16:52:40.753679872 (0 days 00:00:00.199986432 before mission_end) INFO 2023-09-02 15:03:58,134 resample.py get_mission_start_end():815 [1] ctd1 : 2018-04-09T19:23:37.652045312 to 2018-04-10T16:52:40.743680512 (0 days 00:00:00.209985792 before mission_end) INFO 2023-09-02 15:03:58,138 resample.py get_mission_start_end():815 [1] ctd2 : 2018-04-09T19:23:21.103179008 to 2018-04-10T16:52:40.873671424 (0 days 00:00:00.079994880 before mission_end) INFO 2023-09-02 15:03:58,141 resample.py get_mission_start_end():815 [1] isus : 2018-04-09T19:24:12.209677824 to 2018-04-10T16:52:40.953666304 (0 days 00:00:00 before mission_end) INFO 2023-09-02 15:03:58,143 resample.py get_mission_start_end():815 [1] biolume : 2018-04-09T19:22:54.015000320 to 2018-04-10T16:52:39.763713280 (0 days 00:00:01.189953024 before mission_end) INFO 2023-09-02 15:03:58,148 resample.py get_mission_start_end():815 [1] tailcone : 2018-04-09T19:22:59.304672256 to 2018-04-10T16:52:40.873671424 (0 days 00:00:00.079994880 before mission_end) INFO 2023-09-02 15:03:58,150 resample.py instruments_variables():233 [1] Reading variables from /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00_align.nc mission netCDF file INFO 2023-09-02 15:03:58,152 resample.py resample_coordinates():247 [1] Resampling coordinates depth, latitude and longitude with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:58,620 resample.py resample_variable():710 [1] Resampling navigation_roll with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:58,772 resample.py resample_variable():710 [1] Resampling navigation_pitch with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:58,918 resample.py resample_variable():710 [1] Resampling navigation_yaw with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:59,066 resample.py resample_variable():710 [1] Resampling navigation_mWaterSpeed with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:59,199 resample.py resample_variable():710 [1] Resampling hs2_bb420 with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:59,327 resample.py resample_variable():710 [1] Resampling hs2_bb700 with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:59,453 resample.py resample_variable():710 [1] Resampling hs2_fl700 with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:59,574 resample.py resample_variable():710 [1] Resampling ctd1_temperature with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:59,688 resample.py resample_variable():710 [1] Resampling ctd1_conductivity with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:59,801 resample.py resample_variable():710 [1] Resampling ctd1_salinity with frequency 1S following 3 point median filter INFO 2023-09-02 15:03:59,911 resample.py resample_variable():710 [1] Resampling ctd1_temperature_onboard with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:00,025 resample.py resample_variable():710 [1] Resampling ctd1_conductivity_onboard with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:00,139 resample.py resample_variable():710 [1] Resampling ctd1_salinity_onboard with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:00,255 resample.py resample_variable():710 [1] Resampling ctd1_dissolvedO2 with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:00,366 resample.py resample_variable():710 [1] Resampling ctd1_oxygen_mll with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:00,479 resample.py resample_variable():710 [1] Resampling ctd1_oxygen_umolkg with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:00,590 resample.py resample_variable():710 [1] Resampling ctd1_flow1 with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:00,710 resample.py resample_variable():710 [1] Resampling ctd2_temperature with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:00,839 resample.py resample_variable():710 [1] Resampling ctd2_conductivity with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:00,969 resample.py resample_variable():710 [1] Resampling ctd2_salinity with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:01,091 resample.py resample_variable():710 [1] Resampling ctd2_temperature_onboard with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:01,218 resample.py resample_variable():710 [1] Resampling ctd2_conductivity_onboard with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:01,344 resample.py resample_variable():710 [1] Resampling ctd2_salinity_onboard with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:01,467 resample.py resample_variable():710 [1] Resampling ctd2_flow2 with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:01,519 resample.py resample_variable():710 [1] Resampling isus_nitrate with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:01,561 resample.py resample_variable():710 [1] Resampling isus_temp with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:01,602 resample.py resample_variable():710 [1] Resampling biolume_flow with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:01,644 resample.py resample_variable():710 [1] Resampling biolume_avg_biolume with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:01,659 resample.py add_biolume_proxies():493 [1] Adding biolume proxy variables computed from biolume_raw INFO 2023-09-02 15:04:06,224 resample.py add_biolume_proxies():571 [1] Zero flow values found: 106 of 77386 - replaced with 350 ml/s INFO 2023-09-02 15:04:06,224 resample.py add_biolume_proxies():576 [1] Computing flashes per liter: nbflash_high, nbflash_low INFO 2023-09-02 15:04:06,721 resample.py add_biolume_proxies():604 [1] Saving flash intensity: biolume_intflash - the upper bound of the background envelope INFO 2023-09-02 15:04:06,958 resample.py add_biolume_proxies():624 [1] Saving Background bioluminescence (dinoflagellates proxy) INFO 2023-09-02 15:04:07,072 resample.py select_nighttime_bl_raw():422 [1] Extracting biolume_raw data between sunset 2018-04-10 03:33:33.884882176 and sunrise 2018-04-10 12:33:33.892095744 INFO 2023-09-02 15:04:07,642 resample.py add_biolume_proxies():656 [1] Using proxy_ratio_adinos = 3.9811e+13 INFO 2023-09-02 15:04:07,642 resample.py add_biolume_proxies():657 [1] Using proxy_cal_factor = 0.004700 INFO 2023-09-02 15:04:08,073 resample.py resample_variable():710 [1] Resampling tailcone_propRpm with frequency 1S following 3 point median filter INFO 2023-09-02 15:04:09,475 resample.py resample_mission():946 [1] Saved resampled mission to /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00_1S.nc INFO 2023-09-02 15:04:16,294 create_products.py _get_best_ctd():107 [1] Best CTD is ctd1 INFO 2023-09-02 15:04:48,826 create_products.py gulper_odv():250 [1] Wrote 16 Gulper data lines to /data/auv_data/dorado/missionodvs/2018.099.00/dorado_2018.099.00_1S_Gulper.txt INFO 2023-09-02 15:04:48,826 process.py archive():280 [1] Archiving steps for 2018.099.00 INFO 2023-09-02 15:04:48,828 archive.py copy_to_AUVTCD():53 [1] Archiving /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00 files to /Volumes/AUVCTD/surveys/2018/netcdf INFO 2023-09-02 15:04:49,032 archive.py copy_to_AUVTCD():65 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00_1S.nc /Volumes/AUVCTD/surveys/2018/netcdf done. INFO 2023-09-02 15:04:49,847 archive.py copy_to_AUVTCD():65 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00_cal.nc /Volumes/AUVCTD/surveys/2018/netcdf done. INFO 2023-09-02 15:04:50,911 archive.py copy_to_AUVTCD():65 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00_align.nc /Volumes/AUVCTD/surveys/2018/netcdf done. INFO 2023-09-02 15:04:51,125 archive.py copy_to_AUVTCD():80 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/ctdDriver.nc /Volumes/AUVCTD/missionnetcdfs/2018/2018099/2018.099.00 done. INFO 2023-09-02 15:04:51,311 archive.py copy_to_AUVTCD():80 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/ctdDriver2.nc /Volumes/AUVCTD/missionnetcdfs/2018/2018099/2018.099.00 done. INFO 2023-09-02 15:04:51,390 archive.py copy_to_AUVTCD():80 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/gps.nc /Volumes/AUVCTD/missionnetcdfs/2018/2018099/2018.099.00 done. INFO 2023-09-02 15:04:51,555 archive.py copy_to_AUVTCD():80 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/hydroscatlog.nc /Volumes/AUVCTD/missionnetcdfs/2018/2018099/2018.099.00 done. INFO 2023-09-02 15:04:52,029 archive.py copy_to_AUVTCD():80 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/navigation.nc /Volumes/AUVCTD/missionnetcdfs/2018/2018099/2018.099.00 done. INFO 2023-09-02 15:04:52,110 archive.py copy_to_AUVTCD():80 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/isuslog.nc /Volumes/AUVCTD/missionnetcdfs/2018/2018099/2018.099.00 done. INFO 2023-09-02 15:04:52,309 archive.py copy_to_AUVTCD():80 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/parosci.nc /Volumes/AUVCTD/missionnetcdfs/2018/2018099/2018.099.00 done. INFO 2023-09-02 15:04:52,470 archive.py copy_to_AUVTCD():80 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/tailCone.nc /Volumes/AUVCTD/missionnetcdfs/2018/2018099/2018.099.00 done. INFO 2023-09-02 15:04:52,857 archive.py copy_to_AUVTCD():80 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/biolume.nc /Volumes/AUVCTD/missionnetcdfs/2018/2018099/2018.099.00 done. INFO 2023-09-02 15:04:52,858 archive.py copy_to_AUVTCD():85 [1] Archiving product files INFO 2023-09-02 15:04:52,937 archive.py copy_to_AUVTCD():94 [1] rsync /data/auv_data/dorado/missionodvs/2018.099.00/* /Volumes/AUVCTD/surveys/2018/odv done. INFO 2023-09-02 15:04:52,938 archive.py copy_to_AUVTCD():107 [1] rsync /data/auv_data/dorado/missionnetcdfs/2018.099.00/dorado_2018.099.00_processing.log /Volumes/AUVCTD/surveys/2018/netcdf