Skip to content

Commit

Permalink
Replace print statements by logging at verbosity 9 (== importance -9)
Browse files Browse the repository at this point in the history
Also removed unconditional override of verbosity of "meas_deblending.baseline".

To enable these prints say
	-T meas_deblender.baseline=9
to cmdLineTask (e.g. processCcd.py), or put
    pexLog.Trace.setVerbosity('meas_deblender.baseline', 9)
somewhere in your code.

Why 9?  Because Dstn put them in as prints, and logging at verbosity
10 (== -DEBUG) would turn on other meas_deblender.baseline debug statements.
  • Loading branch information
RobertLuptonTheGood committed Jul 3, 2014
1 parent 28bb96d commit 6428a77
Showing 1 changed file with 13 additions and 14 deletions.
27 changes: 13 additions & 14 deletions python/lsst/meas/deblender/baseline.py
Expand Up @@ -264,11 +264,12 @@ def deblend(footprint, maskedImage, psf, psffwhm,

if log is None:
import lsst.pex.logging as pexLogging
loglvl = pexLogging.Log.INFO
if verbose:
loglvl = pexLogging.Log.DEBUG
log = pexLogging.Log(pexLogging.Log.getDefaultLog(),
'meas_deblender.baseline', loglvl)

component = 'meas_deblender.baseline'
log = pexLogging.Log(pexLogging.Log.getDefaultLog(), component)

if verbose: # pexLogging defines DEBUG in terms of "importance" == -verbosity
pexLogging.Trace.setVerbosity(component, -pexLogging.Log.DEBUG)

img = maskedImage.getImage()
varimg = maskedImage.getVariance()
Expand Down Expand Up @@ -781,7 +782,7 @@ def _overlap(xlo, xhi, xmin, xmax):
w = np.sqrt(rw[valid] / var_sub[valid])
# save the effective number of pixels
sumr = np.sum(rw[valid])
print 'sumr =', sumr
log.log(-9, 'sumr = %g' % sumr)

del ii

Expand Down Expand Up @@ -825,8 +826,7 @@ def _overlap(xlo, xhi, xmin, xmax):
pkres.setPsfFitFailed()
return

print 'r1', r1
print 'r2', r2
log.log(-9, 'r1 r2 %g %g' % (r1, r2))

# r is weighted chi-squared = sum over pixels: ramp * (model -
# data)**2/sigma**2
Expand All @@ -840,7 +840,7 @@ def _overlap(xlo, xhi, xmin, xmax):
chisq2 = 1e30
dof1 = sumr - len(X1)
dof2 = sumr - len(X2)
print 'dof1, dof2', dof1, dof2
log.log(-9, 'dof1, dof2 %g %g' % (dof1, dof2))

# This can happen if we're very close to the edge (?)
if dof1 <= 0 or dof2 <= 0:
Expand Down Expand Up @@ -899,13 +899,12 @@ def _overlap(xlo, xhi, xmin, xmax):
Aw = Ab * w[:,np.newaxis]
# re-solve...
Xb,rb,rankb,sb = np.linalg.lstsq(Aw, bw)
print 'rb', rb
if len(rb) > 0:
chisqb = rb[0]
else:
chisqb = 1e30
dofb = sumr - len(Xb)
print 'dofb', dofb
log.log(-9, 'rb, dofb %g %g' %(rb, dofb))
qb = chisqb / dofb
ispsf2 = (qb < psfChisqCut2b)
q2 = qb
Expand All @@ -920,7 +919,7 @@ def _overlap(xlo, xhi, xmin, xmax):
Xpsf = X2
chisq = chisq2
dof = dof2
print 'dof', dof
log.log(-9, 'dof %g' % dof)
log.logdebug('Keeping shifted-PSF model')
cx += dx
cy += dy
Expand All @@ -930,7 +929,7 @@ def _overlap(xlo, xhi, xmin, xmax):
Xpsf = X1
chisq = chisq1
dof = dof1
print 'dof', dof
log.log(-9, 'dof %g' % dof)
log.logdebug('Keeping unshifted PSF model')

ispsf = (ispsf1 or ispsf2)
Expand Down Expand Up @@ -979,7 +978,7 @@ def _overlap(xlo, xhi, xmin, xmax):
pkres.psfFitR1 = R1
pkres.psfFitStampExtent = (xlo, xhi, ylo, yhi)
pkres.psfFitCenter = (cx,cy)
print 'saving chisq,dof', chisq, dof
log.log(-9, 'saving chisq,dof %g %g' % (chisq, dof))
pkres.psfFitBest = (chisq, dof)
pkres.psfFitParams = Xpsf
pkres.psfFitFlux = Xpsf[I_psf]
Expand Down

6 comments on commit 6428a77

@RobertLuptonTheGood
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have consistently asked for more fine-grained control of logging than just "DEBUG". The choice of 9 for verbosity (the negative sign was the result of lack of understanding by the authors of pex_logging) was chosen to play well with other debug statements. I apparently thought that these were at a level between normal output and full debugging.

How many levels of debug logging do we now support?

@hsinfang
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Formally there are two: DEBUG level and TRACE level. If more are needed, either loggers of different component names can be used and they can be controlled separated, or we may define more fine-grained trace control such as in the demo code in RFC-203.

My understanding of this code is two levels are used for the component 'meas_deblender.baseline': log.logdebug(...) and log.log(-9, ...). My naive thinking is to map these two to DEBUG and TRACE. Is that acceptable?

@RobertLuptonTheGood
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I never thought that two were enough (I think I asked for five)

For now, mapping the -9 to TRACE is OK

@hsinfang
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Aahh, reading the code and your message more carefully, I realized I misunderstood. These log.log(-9, ...) (at -9) are more important than those log.logdebug(...) (at -10). So the mapping should be log.log(-9, ...) -> DEBUG and log.logdebug(...) -> TRACE in this code, right?

@RobertLuptonTheGood
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, I think so.

@hsinfang
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you Robert.

Please sign in to comment.