DM-31801: Clean up log usage

python/lsst/cp/pipe/cpCombine.py

@@ -20,6 +20,7 @@
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 import numpy as np
 import time
+import logging
 
 import lsst.pex.config as pexConfig
 import lsst.pipe.base as pipeBase
@@ -28,7 +29,6 @@
 import lsst.afw.image as afwImage
 
 from lsst.geom import Point2D
-from lsst.log import Log
 from astro_metadata_translator import merge_headers, ObservationGroup
 from astro_metadata_translator.serialize import dates_to_fits
 
@@ -593,7 +593,7 @@ def vignetteExposure(exposure, polygon=None,
         Set image value for vignetted area?
     vignetteValue : `float`, optional
         Value to assign.
-    log : `lsst.log.Log`, optional
+    log : `logging.Logger`, optional
         Log to write to.
 
     Raises
@@ -604,7 +604,7 @@ def vignetteExposure(exposure, polygon=None,
     polygon = polygon if polygon else exposure.getInfo().getValidPolygon()
     if not polygon:
         raise RuntimeError("Could not find valid polygon!")
-    log = log if log else Log.getLogger(__name__.partition(".")[2])
+    log = log if log else logging.getLogger(__name__)
 
     fullyIlluminated = True
     for corner in exposure.getBBox().getCorners():

python/lsst/cp/pipe/cpFlatNormTask.py

@@ -406,9 +406,11 @@ def measureScales(self, bgMatrix, bgCounts=None, iterations=10):
             fluxLevel = np.average(np.exp(logG), weights=np.sum(bgCounts, axis=1))
 
             logG -= np.log(fluxLevel)
-            self.log.debug(f"ITER {iter}: Flux: {fluxLevel}")
-            self.log.debug(f"Exps: {np.exp(logE)}")
-            self.log.debug(f"{np.mean(logG)}")
+            if self.log.isEnabledFor(self.log.DEBUG):
+                # Only calculate these values if debug log is enabled.
+                self.log.debug("ITER %d: Flux: %f", iter, fluxLevel)
+                self.log.debug("Exps: %s", np.exp(logE))
+                self.log.debug("%f", np.mean(logG))
 
         logE = np.array([np.average(logMeas[:, iexp] - logG,
                                     weights=bgCounts[:, iexp]) for iexp in range(numExps)])

python/lsst/cp/pipe/linearity.py

@@ -238,7 +238,7 @@ def run(self, inputPtc, dummy, camera, inputDims):
                 continue
 
             if (len(inputPtc.expIdMask[ampName]) == 0) or self.config.ignorePtcMask:
-                self.log.warning(f"Mask not found for {ampName} in non-linearity fit. Using all points.")
+                self.log.warning("Mask not found for %s in non-linearity fit. Using all points.", ampName)
                 mask = np.repeat(True, len(inputPtc.expIdMask[ampName]))
             else:
                 mask = np.array(inputPtc.expIdMask[ampName], dtype=bool)
@@ -275,7 +275,7 @@ def run(self, inputPtc, dummy, camera, inputDims):
                 k1 = polyFit[1]
                 linearityFit = [-coeff/(k1**order) for order, coeff in enumerate(polyFit)]
                 significant = np.where(np.abs(linearityFit) > 1e-10, True, False)
-                self.log.info(f"Significant polynomial fits: {significant}")
+                self.log.info("Significant polynomial fits: %s", significant)
 
                 modelOrdinate = funcPolynomial(polyFit, linearAbscissa)
                 self.debugFit('polyFit', linearAbscissa, fitOrdinate, modelOrdinate, None, ampName)

python/lsst/cp/pipe/makeBrighterFatterKernel.py

@@ -526,7 +526,7 @@ def successiveOverRelax(self, source, maxIter=None, eLevel=None):
 
         if nIter >= maxIter*2:
             self.log.warning("Failure: SuccessiveOverRelaxation did not converge in %s iterations."
-                             "\noutError: %s, inError: %s," % (nIter//2, outError, inError*eLevel))
+                             "\noutError: %s, inError: %s,", nIter//2, outError, inError*eLevel)
         else:
             self.log.info("Success: SuccessiveOverRelaxation converged in %s iterations."
                           "\noutError: %s, inError: %s", nIter//2, outError, inError*eLevel)

python/lsst/cp/pipe/ptc/astierCovPtcFit.py

@@ -23,9 +23,9 @@
 import copy
 from scipy.signal import fftconvolve
 from scipy.optimize import leastsq
-from .astierCovFitParameters import FitParameters
+import logging
 
-import lsst.log as lsstLog
+from .astierCovFitParameters import FitParameters
 
 __all__ = ["CovFit"]
 
@@ -186,7 +186,7 @@ def __init__(self, meanSignals, covariances, covsSqrtWeights, maxRangeFromTuple=
         # make it nan safe, replacing nan's with 0 in weights
         self.sqrtW = np.nan_to_num(covsSqrtWeights)[meanSignalsMask]
         self.r = maxRangeFromTuple
-        self.logger = lsstLog.Log.getDefaultLogger()
+        self.logger = logging.getLogger(__name__)
 
     def copy(self):
         """Make a copy of params"""

python/lsst/cp/pipe/ptc/cpExtractPtcTask.py

@@ -277,24 +277,23 @@ def run(self, inputExp, inputDims):
 
         if self.config.numEdgeSuspect > 0:
             isrTask = IsrTask()
-            self.log.info(f"Masking {self.config.numEdgeSuspect} pixels from the edges "
-                          "of all exposures as SUSPECT.")
+            self.log.info("Masking %d pixels from the edges of all exposures as SUSPECT.",
+                          self.config.numEdgeSuspect)
 
         for expTime in inputExp:
             exposures = inputExp[expTime]
             if len(exposures) == 1:
-                self.log.warning(f"Only one exposure found at expTime {expTime}. Dropping exposure "
-                                 f"{exposures[0][1]}")
+                self.log.warning("Only one exposure found at expTime %f. Dropping exposure %s.",
+                                 expTime, exposures[0][1])
                 continue
             else:
                 # Only use the first two exposures at expTime. Each
                 # elements is a tuple (exposure, expId)
                 exp1, expId1 = exposures[0]
                 exp2, expId2 = exposures[1]
                 if len(exposures) > 2:
-                    self.log.warning(f"Already found 2 exposures at expTime {expTime}. "
-                                     "Ignoring exposures: "
-                                     f"{i[1] for i in exposures[2:]}")
+                    self.log.warning("Already found 2 exposures at expTime %f. Ignoring exposures: %s",
+                                     expTime, ", ".join(i[1] for i in exposures[2:]))
             # Mask pixels at the edge of the detector or of each amp
             if self.config.numEdgeSuspect > 0:
                 isrTask.maskEdges(exp1, numEdgePixels=self.config.numEdgeSuspect,
@@ -331,8 +330,8 @@ def run(self, inputExp, inputDims):
 
                 expIdMask = True
                 if np.isnan(muDiff) or np.isnan(varDiff) or (covAstier is None):
-                    msg = (f"NaN mean or var, or None cov in amp {ampName} in exposure pair {expId1},"
-                           f" {expId2} of detector {detNum}.")
+                    msg = ("NaN mean or var, or None cov in amp %s in exposure pair %s, %s of detector %d.",
+                           ampName, expId1, expId2, detNum)
                     self.log.warning(msg)
                     nAmpsNan += 1
                     expIdMask = False
@@ -451,7 +450,7 @@ def measureMeanVarCov(self, exposure1, exposure2, region=None, covAstierRealSpac
         mu1 = afwMath.makeStatistics(im1Area, afwMath.MEANCLIP, im1StatsCtrl).getValue()
         mu2 = afwMath.makeStatistics(im2Area, afwMath.MEANCLIP, im2StatsCtrl).getValue()
         if np.isnan(mu1) or np.isnan(mu2):
-            self.log.warning(f"Mean of amp in image 1 or 2 is NaN: {mu1}, {mu2}.")
+            self.log.warning("Mean of amp in image 1 or 2 is NaN: %f, %f.", mu1, mu2)
             return np.nan, np.nan, None
         mu = 0.5*(mu1 + mu2)
 
@@ -490,8 +489,8 @@ def measureMeanVarCov(self, exposure1, exposure2, region=None, covAstierRealSpac
         w = unmasked*wDiff
 
         if np.sum(w) < self.config.minNumberGoodPixelsForCovariance:
-            self.log.warning(f"Number of good points for covariance calculation ({np.sum(w)}) is less "
-                             f"(than threshold {self.config.minNumberGoodPixelsForCovariance})")
+            self.log.warning("Number of good points for covariance calculation (%s) is less "
+                             "(than threshold %s)", np.sum(w), self.config.minNumberGoodPixelsForCovariance)
             return np.nan, np.nan, None
 
         maxRangeCov = self.config.maximumRangeCovariancesAstier
@@ -517,6 +516,6 @@ def measureMeanVarCov(self, exposure1, exposure2, region=None, covAstierRealSpac
         fractionalDiff = 100*np.fabs(1 - varDiff/(covDiffAstier[0][3]*0.5))
         if fractionalDiff >= thresholdPercentage:
             self.log.warning("Absolute fractional difference between afwMatch.VARIANCECLIP and Cov[0,0] "
-                             f"is more than {thresholdPercentage}%: {fractionalDiff}")
+                             "is more than %f%%: %f", thresholdPercentage, fractionalDiff)
 
         return mu, varDiff, covDiffAstier

python/lsst/cp/pipe/ptc/cpSolvePtcTask.py

@@ -628,7 +628,8 @@ def errFunc(p, x, y):
                     self.fillBadAmp(dataset, ptcFitType, ampName)
                     break
                 nDroppedTotal = Counter(mask)[False]
-                self.log.debug(f"Iteration {count}: discarded {nDroppedTotal} points in total for {ampName}")
+                self.log.debug("Iteration %d: discarded %d points in total for %s",
+                               count, nDroppedTotal, ampName)
                 count += 1
                 # objects should never shrink
                 assert (len(mask) == len(timeVecOriginal) == len(meanVecOriginal) == len(varVecOriginal))
@@ -645,8 +646,8 @@ def errFunc(p, x, y):
             varVecFinal = varVecOriginal[mask]
 
             if Counter(mask)[False] > 0:
-                self.log.info((f"Number of points discarded in PTC of amplifier {ampName}:"
-                               f" {Counter(mask)[False]} out of {len(meanVecOriginal)}"))
+                self.log.info("Number of points discarded in PTC of amplifier %s:"
+                              " %d out of %d", ampName, Counter(mask)[False], len(meanVecOriginal))
 
             if (len(meanVecFinal) < len(parsIniPtc)):
                 msg = (f"SERIOUS: Not enough data points ({len(meanVecFinal)}) compared to the number of "

python/lsst/cp/pipe/ptc/plotPtc.py

@@ -22,6 +22,7 @@
 
 __all__ = ['PlotPhotonTransferCurveTask']
 
+import logging
 import numpy as np
 import matplotlib.pyplot as plt
 import matplotlib as mpl
@@ -36,7 +37,6 @@
 from matplotlib.ticker import MaxNLocator
 from lsst.cp.pipe.ptc.astierCovPtcUtils import getFitDataFromCovariances
 from lsst.ip.isr import PhotonTransferCurveDataset
-import lsst.log as lsstLog
 
 
 class PlotPhotonTransferCurveTask():
@@ -108,7 +108,7 @@ def runDataRef(self):
             linearizer = isr.linearize.Linearizer.readFits(self.linearizerFileName)
         else:
             linearizer = None
-        self.run(filenameFull, datasetPtc, linearizer=linearizer, log=lsstLog)
+        self.run(filenameFull, datasetPtc, linearizer=linearizer, log=logging.getLogger(__name__))
 
         return
 
@@ -146,7 +146,7 @@ def covAstierMakeAllPlots(self, dataset, pdfPages,
         pdfPages : `matplotlib.backends.backend_pdf.PdfPages`
             PDF file where the plots will be saved.
 
-        log : `lsst.log.Log`, optional
+        log : `logging.Logger`, optional
             Logger to handle messages
         """
         mu = dataset.finalMeans
@@ -465,7 +465,7 @@ def plotNormalizedCovariances(self, i, j, inputMu, covs, covsModel, covsWeights,
             Plot the top plot with the covariances, and the bottom
             plot with the model residuals?
 
-        log : `lsst.log.Log`, optional
+        log : `logging.Logger`, optional
             Logger to handle messages.
         """
         if not topPlot:

python/lsst/cp/pipe/ptc/plotPtcGen2.py

@@ -180,7 +180,7 @@ def covAstierMakeAllPlots(self, dataset, pdfPages,
         pdfPages : `matplotlib.backends.backend_pdf.PdfPages`
             PDF file where the plots will be saved.
 
-        log : `lsst.log.Log`, optional
+        log : `logging.Logger`, optional
             Logger to handle messages
         """
         mu = dataset.finalMeans
@@ -499,7 +499,7 @@ def plotNormalizedCovariances(self, i, j, inputMu, covs, covsModel, covsWeights,
             Plot the top plot with the covariances, and the bottom
             plot with the model residuals?
 
-        log : `lsst.log.Log`, optional
+        log : `logging.Logger`, optional
             Logger to handle messages.
         """
         if not topPlot:

python/lsst/cp/pipe/utils.py

@@ -29,11 +29,11 @@
 from scipy.optimize import leastsq
 import numpy.polynomial.polynomial as poly
 from scipy.stats import norm
+import logging
 
 import lsst.pipe.base as pipeBase
 import lsst.ip.isr as ipIsr
 from lsst.ip.isr import isrMock
-import lsst.log
 import lsst.afw.image
 
 import galsim
@@ -798,9 +798,9 @@ def validateIsrConfig(isrTask, mandatory=None, forbidden=None, desirable=None, u
     configDict = isrTask.config.toDict()
 
     if logName and isinstance(logName, str):
-        log = lsst.log.getLogger(logName)
+        log = logging.getLogger(logName)
     else:
-        log = lsst.log.getLogger("isrValidation")
+        log = logging.getLogger("lsst.isrValidation")
 
     if mandatory:
         for configParam in mandatory:
@@ -812,31 +812,31 @@ def validateIsrConfig(isrTask, mandatory=None, forbidden=None, desirable=None, u
     if forbidden:
         for configParam in forbidden:
             if configParam not in configDict:
-                log.warning(f"Failed to find forbidden key {configParam} in the isr config. The keys in the"
+                log.warning("Failed to find forbidden key %s in the isr config. The keys in the"
                             " forbidden list should each have an associated Field in IsrConfig:"
-                            " check that there is not a typo in this case.")
+                            " check that there is not a typo in this case.", configParam)
                 continue
             if configDict[configParam] is True:
                 raise RuntimeError(f"Must set config.isr.{configParam} to False for this task.")
 
     if desirable:
         for configParam in desirable:
             if configParam not in configDict:
-                log.info(f"Failed to find key {configParam} in the isr config. You probably want"
-                         " to set the equivalent for your obs_package to True.")
+                log.info("Failed to find key %s in the isr config. You probably want"
+                         " to set the equivalent for your obs_package to True.", configParam)
                 continue
             if configDict[configParam] is False:
-                log.warning(f"Found config.isr.{configParam} set to False for this task."
-                            " The cp_pipe Config recommends setting this to True.")
+                log.warning("Found config.isr.%s set to False for this task."
+                            " The cp_pipe Config recommends setting this to True.", configParam)
     if undesirable:
         for configParam in undesirable:
             if configParam not in configDict:
-                log.info(f"Failed to find key {configParam} in the isr config. You probably want"
-                         " to set the equivalent for your obs_package to False.")
+                log.info("Failed to find key %s in the isr config. You probably want"
+                         " to set the equivalent for your obs_package to False.", configParam)
                 continue
             if configDict[configParam] is True:
-                log.warning(f"Found config.isr.{configParam} set to True for this task."
-                            " The cp_pipe Config recommends setting this to False.")
+                log.warning("Found config.isr.%s set to True for this task."
+                            " The cp_pipe Config recommends setting this to False.", configParam)
 
     if checkTrim:  # subtask setting, seems non-trivial to combine with above lists
         if not isrTask.assembleCcd.config.doTrim:

tests/test_utils.py

@@ -35,7 +35,6 @@
 from lsst.geom import Box2I, Point2I, Extent2I
 import lsst.ip.isr as ipIsr
 from lsst.ip.isr import isrMock
-import lsst.log
 
 import lsst.cp.pipe.utils as cpUtils
 
@@ -130,16 +129,18 @@ def test_validateIsrConfig(self):
             cpUtils.validateIsrConfig(task, mandatory + ['test'], forbidden, desirable, undesirable)
 
         logName = 'testLogger'
-        with lsst.log.UsePythonLogging():  # otherwise none of this is caught
-            with self.assertLogs(logName, level='INFO'):  # not found info-logs for (un)desirable
-                cpUtils.validateIsrConfig(task, mandatory, forbidden,
-                                          desirable + ['test'], undesirable, logName=logName)
-                cpUtils.validateIsrConfig(task, mandatory, forbidden,
-                                          desirable, undesirable + ['test'], logName=logName)
-
-            with self.assertLogs(logName, "WARN"):  # not found warnings for forbidden
-                cpUtils.validateIsrConfig(task, mandatory, forbidden + ['test'],
-                                          desirable, undesirable, logName=logName)
+        with self.assertLogs(logName, level='INFO'):  # not found info-logs for (un)desirable
+            cpUtils.validateIsrConfig(task, mandatory, forbidden,
+                                      desirable + ['test'], undesirable, logName=logName)
+            cpUtils.validateIsrConfig(task, mandatory, forbidden,
+                                      desirable, undesirable + ['test'], logName=logName)
+
+        with self.assertLogs(logName, "WARN"):  # not found warnings for forbidden
+            cpUtils.validateIsrConfig(task, mandatory, forbidden + ['test'],
+                                      desirable, undesirable, logName=logName)
+        with self.assertLogs("lsst", "WARN"):  # not found warnings for forbidden
+            cpUtils.validateIsrConfig(task, mandatory, forbidden + ['test'],
+                                      desirable, undesirable, logName=None)
 
 
 class TestMemory(lsst.utils.tests.MemoryTestCase):