[PIPE2D-1049] Deadlock in weekly processing Created: 02/Jun/22 Updated: 11/Jun/22 Resolved: 11/Jun/22 |
|
| Status: | Done |
| Project: | DRP 2-D Pipeline |
| Component/s: | None |
| Affects Version/s: | None |
| Fix Version/s: | None |
| Type: | Story | Priority: | Normal |
| Reporter: | price | Assignee: | price |
| Resolution: | Done | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Sprint: | 2DDRP-2022 E |
| Reviewers: | hassan |
| Description |
|
The weekly deadlocked. This appears to be fairly reproducible with w.2022.22: (lsst-scipipe-3.0.0) pprice@tiger2-sumire:~ $ reduceArc.py /scratch/pprice/jenkins/weekly/2022-05-29/process --calib=/scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB --rerun=test --doraise --id visit=39..45:2 --config fitDetectorMap.doSlitOffsets=True reduceExposure.readLineList.exclusionRadius=0.3 fitDetectorMap.minSignalToNoise=20 -j 10 root INFO: Loading config overrride file '/projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/obs_pfs/w.2022.22/config/reduceArc.py' /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/pipe_base/g590c34a36e+5da9528084/python/lsst/pipe/base/argumentParser.py:778: FutureWarning: Gen2 Butler has been deprecated (Butler). It will be removed sometime after v23.0 but no earlier than the end of 2021. namespace.butler = dafPersist.Butler(inputs=inputs, outputs=outputs) /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/pipe_base/g590c34a36e+5da9528084/python/lsst/pipe/base/argumentParser.py:778: FutureWarning: Gen2 Butler has been deprecated (PfsMapper). It will be removed sometime after v23.0 but no earlier than the end of 2021. namespace.butler = dafPersist.Butler(inputs=inputs, outputs=outputs) lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 root INFO: Running: /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/bin/reduceArc.py /scratch/pprice/jenkins/weekly/2022-05-29/process --calib=/scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB --rerun=test --doraise --id visit=39..45:2 --config fitDetectorMap.doSlitOffsets=True reduceExposure.readLineList.exclusionRadius=0.3 fitDetectorMap.minSignalToNoise=20 -j 10 lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 reduceArc.reduceExposure INFO: Processing [{'visit': 45, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'b', 'spectrograph': 1, 'field': 'ARC', 'ccd': 0, 'filter': 'b', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:45:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure INFO: Processing [{'visit': 41, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'r', 'spectrograph': 1, 'field': 'ARC', 'ccd': 1, 'filter': 'r', 'expTime': 5.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:41:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure INFO: Processing [{'visit': 39, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'b', 'spectrograph': 1, 'field': 'ARC', 'ccd': 0, 'filter': 'b', 'expTime': 2.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:39:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure INFO: Processing [{'visit': 39, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'n', 'spectrograph': 1, 'field': 'ARC', 'ccd': 2, 'filter': 'n', 'expTime': 2.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:39:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure INFO: Processing [{'visit': 43, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'n', 'spectrograph': 1, 'field': 'ARC', 'ccd': 2, 'filter': 'n', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:43:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure INFO: Processing [{'visit': 39, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'r', 'spectrograph': 1, 'field': 'ARC', 'ccd': 1, 'filter': 'r', 'expTime': 2.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:39:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure INFO: Processing [{'visit': 43, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'b', 'spectrograph': 1, 'field': 'ARC', 'ccd': 0, 'filter': 'b', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:43:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure INFO: Processing [{'visit': 41, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'b', 'spectrograph': 1, 'field': 'ARC', 'ccd': 0, 'filter': 'b', 'expTime': 5.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:41:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure INFO: Processing [{'visit': 43, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'r', 'spectrograph': 1, 'field': 'ARC', 'ccd': 1, 'filter': 'r', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:43:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure INFO: Processing [{'visit': 41, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'n', 'spectrograph': 1, 'field': 'ARC', 'ccd': 2, 'filter': 'n', 'expTime': 5.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:41:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 41, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'b', 'spectrograph': 1, 'field': 'ARC', 'ccd': 0, 'filter': 'b', 'expTime': 5.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:41:00', 'pfsDesignId': 1, 'slitOffset': 0.0} reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 45, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'b', 'spectrograph': 1, 'field': 'ARC', 'ccd': 0, 'filter': 'b', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:45:00', 'pfsDesignId': 1, 'slitOffset': 0.0} reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 41, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'n', 'spectrograph': 1, 'field': 'ARC', 'ccd': 2, 'filter': 'n', 'expTime': 5.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:41:00', 'pfsDesignId': 1, 'slitOffset': 0.0} reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 41, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'r', 'spectrograph': 1, 'field': 'ARC', 'ccd': 1, 'filter': 'r', 'expTime': 5.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:41:00', 'pfsDesignId': 1, 'slitOffset': 0.0} reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 43, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'r', 'spectrograph': 1, 'field': 'ARC', 'ccd': 1, 'filter': 'r', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:43:00', 'pfsDesignId': 1, 'slitOffset': 0.0} reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 43, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'n', 'spectrograph': 1, 'field': 'ARC', 'ccd': 2, 'filter': 'n', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:43:00', 'pfsDesignId': 1, 'slitOffset': 0.0} reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 43, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'b', 'spectrograph': 1, 'field': 'ARC', 'ccd': 0, 'filter': 'b', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:43:00', 'pfsDesignId': 1, 'slitOffset': 0.0} reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 39, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'n', 'spectrograph': 1, 'field': 'ARC', 'ccd': 2, 'filter': 'n', 'expTime': 2.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:39:00', 'pfsDesignId': 1, 'slitOffset': 0.0} reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 39, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'b', 'spectrograph': 1, 'field': 'ARC', 'ccd': 0, 'filter': 'b', 'expTime': 2.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:39:00', 'pfsDesignId': 1, 'slitOffset': 0.0} reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 39, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'r', 'spectrograph': 1, 'field': 'ARC', 'ccd': 1, 'filter': 'r', 'expTime': 2.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:39:00', 'pfsDesignId': 1, 'slitOffset': 0.0} lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.isr INFO: Set 29 BAD pixels to 0.616691. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.isr INFO: Set 38 BAD pixels to 0.783048. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.isr INFO: Set 32 BAD pixels to 0.449544. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.repair INFO: Identified 3151 cosmic rays. reduceArc.reduceExposure.repair INFO: Identified 6475 cosmic rays. reduceArc.reduceExposure.repair INFO: Identified 1878 cosmic rays. reduceArc.reduceExposure.repair INFO: Identified 1847 cosmic rays. reduceArc.reduceExposure.repair INFO: Identified 807 cosmic rays. reduceArc.reduceExposure.repair INFO: Identified 46 cosmic rays. reduceArc.reduceExposure.repair INFO: Identified 32 cosmic rays. reduceArc.reduceExposure.repair INFO: Identified 33 cosmic rays. reduceArc.reduceExposure.repair INFO: Identified 37 cosmic rays. reduceArc.reduceExposure.repair INFO: Identified 15888 cosmic rays. reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'HgI', 'ArI'}. reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'NeI'}. reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'HgI', 'ArI'}. reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'HgI', 'ArI'}. reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'XeI'}. reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'XeI'}. reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'XeI'}. reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'KrI'}. reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'NeI'}. reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'NeI'}. reduceArc.reduceExposure.centroidLines INFO: Measured 43442 line centroids reduceArc.reduceExposure.centroidLines INFO: Measured 54434 line centroids reduceArc.reduceExposure.centroidLines INFO: Measured 88800 line centroids reduceArc.reduceExposure.centroidLines INFO: Measured 79918 line centroids reduceArc.reduceExposure.centroidLines INFO: Measured 145968 line centroids reduceArc.reduceExposure.centroidLines INFO: Measured 94348 line centroids reduceArc.reduceExposure.photometerLines INFO: Photometered 43442 lines reduceArc.reduceExposure.centroidLines INFO: Measured 168085 line centroids reduceArc.reduceExposure.photometerLines INFO: Photometered 54434 lines /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 reduceArc.reduceExposure INFO: Processing [{'visit': 45, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'r', 'spectrograph': 1, 'field': 'ARC', 'ccd': 1, 'filter': 'r', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:45:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for lsst.CameraMapper INFO: Loading exposure registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/registry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 lsst.CameraMapper INFO: Loading calib registry from /scratch/pprice/jenkins/weekly/2022-05-29/process/CALIB/calibRegistry.sqlite3 reduceArc.reduceExposure INFO: Processing [{'visit': 45, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'n', 'spectrograph': 1, 'field': 'ARC', 'ccd': 2, 'filter': 'n', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:45:00', 'pfsDesignId': 1, 'slitOffset': 0.0}] reduceArc.reduceExposure.isr INFO: Performing ISR on sensor {'visit': 45, 'dateObs': '2020-01-01', 'site': 'F', 'category': 'A', 'arm': 'n', 'spectrograph': 1, 'field': 'ARC', 'ccd': 2, 'filter': 'n', 'expTime': 1.0, 'dataType': 'ARC', 'taiObs': '2020-01-01T00:45:00', 'pfsDesignId': 1, 'slitOffset': 0.0} reduceArc.reduceExposure.centroidLines INFO: Measured 171200 line centroids lsst.CameraMapper INFO: darkTime is NaN/Inf; using exposureTime reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.centroidLines INFO: Measured 187888 line centroids reduceArc.reduceExposure.isr WARN: filterLabel is None. Setting physicalFilter to "Unknown". reduceArc.reduceExposure.isr INFO: Converting exposure to floating point values. reduceArc.reduceExposure.isr INFO: Assembling CCD from amplifiers. reduceArc.reduceExposure.isr INFO: Applying bias correction. reduceArc.reduceExposure.isr INFO: Masking defects. reduceArc.reduceExposure.isr INFO: Masking non-finite (NAN, inf) value pixels. reduceArc.reduceExposure.isr INFO: Widening saturation trails. reduceArc.reduceExposure.isr INFO: Applying dark correction. reduceArc.reduceExposure.isr INFO: Applying flat correction. reduceArc.reduceExposure.isr INFO: Interpolating masked pixels. reduceArc.reduceExposure.photometerLines INFO: Photometered 88800 lines reduceArc.reduceExposure.photometerLines INFO: Photometered 79918 lines reduceArc.reduceExposure.repair INFO: Identified 33 cosmic rays. /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for reduceArc.reduceExposure.readLineList INFO: Filtered line lists, keeping species {'KrI'}. /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for reduceArc.reduceExposure.photometerLines INFO: Photometered 94348 lines /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for reduceArc.reduceExposure.photometerLines INFO: Photometered 145968 lines reduceArc.reduceExposure.centroidLines INFO: Measured 48456 line centroids /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for reduceArc.reduceExposure.photometerLines INFO: Photometered 168085 lines /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for reduceArc.reduceExposure.photometerLines INFO: Photometered 171200 lines reduceArc.reduceExposure.photometerLines INFO: Photometered 48456 lines reduceArc.reduceExposure.photometerLines INFO: Photometered 187888 lines /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for reduceArc.reduceExposure.centroidLines INFO: Measured 336600 line centroids /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for reduceArc.reduceExposure.photometerLines INFO: Photometered 336600 lines /projects/HSC/PFS/stack/20220525/stack/miniconda3-py38_4.9.2-3.0.0/Linux64/drp_stella/w.2022.22/python/pfs/drp/stella/pickleUtils.py:9: FutureWarning: Call to deprecated method getExposureId. (Replaced by VisitInfo.id for full focal plane identifiers and by ExposureInfo.id for detector-level identifiers. Will be removed after v25.) -- Deprecated since version v24.0. tuple(getattr(info, "get" + prop)() for |
| Comments |
| Comment by price [ 03/Jun/22 ] |
|
At least some of the deadlocks are coming from the threading.RLock in astropy.utils.decorators.lazyproperty. Removing that allows the operation to work more often. |
| Comment by price [ 03/Jun/22 ] |
|
I believe the deadlocks are occurring because the lock is being created and then the process is forked (as part of multiprocessing), resulting in a process that has a lock that's meant for a different process. I think the locking should be removed from lazyproperty (and any locking implemented at a higher level). An alternative would be to store the locks by PID, but then I think there's a race condition on creating the lock (we'd need a lock on the creation of the lock...). |
| Comment by rhl [ 04/Jun/22 ] |
|
Do we need astropy.utils.decorators.lazyproperty? It looks cute, but dangerous. How hard is it to implement something similar for the cases that the performance is important? |
| Comment by price [ 04/Jun/22 ] |
|
The problem is that astropy.io.fits uses it. |
| Comment by price [ 08/Jun/22 ] |
|
Bruce Merry (author of the astropy thread locking code) has pointed out that there are intrinsic problems with multiprocessing using the "fork" start method and maxtasksperchild=1, and I believe we're running afoul of those for a reason I haven't been able to discern. I've not been able to get the "forkserver" or "spawn" start methods to work reliably in order to work around this problem that way. But as far as we know, this is a Gen2-only problem, and Gen2 is dying, so I'm putting in the only workaround that I've been able to get to work, which is stripping the locks out of lazyproperty. We should be able to remove it once we burn Gen2 with fire. |
| Comment by hassan [ 11/Jun/22 ] |
|
Workaround looks fine to me. |
| Comment by price [ 11/Jun/22 ] |
|
Merged. |