Uploaded image for project: 'Data Management'
  1. Data Management
  2. DM-3141

Reduce verbosity of astrometry

    XMLWordPrintable

    Details

    • Type: Story
    • Status: Done
    • Resolution: Done
    • Fix Version/s: None
    • Component/s: meas_astrom
    • Labels:
      None

      Description

      The astrometry.net solver that runs by default in meas_astrom 10.1 is very verbose. Here's an example running HSC data with an SDSS reference catalog:

      $ processCcd.py /tigress/HSC/HSC --output /tigress/pprice/lsst --id visit=904020 ccd=49 --clobber-config
      : Loading config overrride file '/home/pprice/LSST/obs/subaru/config/processCcd.py'
      WARNING: Unable to use psfex: No module named extensions.psfex.psfexPsfDeterminer
      hscAstrom is not setup; using LSST's meas_astrom instead
      Cannot import lsst.meas.multifit: disabling CModel measurements
      Cannot import lsst.meas.extensions.photometryKron: disabling Kron measurements
      Cannot enable shapeHSM ('MEAS_EXTENSIONS_SHAPEHSM_DIR'): disabling HSM shape measurements
      Cannot import lsst.meas.extensions.photometryKron: disabling Kron measurements
      Cannot enable shapeHSM ('MEAS_EXTENSIONS_SHAPEHSM_DIR'): disabling HSM shape measurements
      : Loading config overrride file '/home/pprice/LSST/obs/subaru/config/hsc/processCcd.py'
      : input=/tigress/HSC/HSC
      : calib=None
      : output=/tigress/pprice/lsst
      CameraMapper: Loading registry registry from /tigress/pprice/lsst/_parent/registry.sqlite3
      CameraMapper: Loading calibRegistry registry from /tigress/HSC/HSC/CALIB/calibRegistry.sqlite3
      processCcd: Processing {'taiObs': '2013-11-02', 'pointing': 671, 'visit': 904020, 'dateObs': '2013-11-02', 'filter': 'HSC-I', 'field': 'STRIPE82L', 'ccd': 49, 'expTime': 30.0}
      processCcd.isr: Performing ISR on sensor {'taiObs': '2013-11-02', 'pointing': 671, 'visit': 904020, 'dateObs': '2013-11-02', 'filter': 'HSC-I', 'field': 'STRIPE82L', 'ccd': 49, 'expTime': 30.0}
      processCcd.isr WARNING: Cannot write thumbnail image; hsc.fitsthumb could not be imported.
      afw.image.MaskedImage WARNING: Expected extension type not found: IMAGE
      processCcd.isr: Applying linearity corrections to Ccd 49
      processCcd.isr.crosstalk: Applying crosstalk correction
      afw.image.MaskedImage WARNING: Expected extension type not found: IMAGE
      : Empty WCS extension, using FITS header
      processCcd.isr: Set 0 BAD pixels to 647.04
      processCcd.isr WARNING: There were 6192 unmasked NaNs
      processCcd.isr WARNING: Cannot write thumbnail image; hsc.fitsthumb could not be imported.
      processCcd.isr: Flattened sky level: 647.130493 +/- 12.733898
      processCcd.isr: Measuring sky levels in 8x16 grids: 648.106765
      processCcd.isr: Sky flatness in 8x16 grids - pp: 0.024087 rms: 0.006057
      processCcd.calibrate: installInitialPsf fwhm=5.88235294312 pixels; size=15 pixels
      processCcd.calibrate.repair: Identified 80 cosmic rays.
      processCcd.calibrate.detection: Detected 303 positive sources to 5 sigma.
      processCcd.calibrate.detection: Resubtracting the background after object detection
      processCcd.calibrate.initialMeasurement: Measuring 303 sources (303 parents, 0 children) 
      processCcd.calibrate.astrometry: Applying distortion correction
      processCcd.calibrate.astrometry: Solving astrometry
      LoadReferenceObjects: read index files
      processCcd.calibrate.astrometry.solver: Number of selected sources for astrometry : 258
      processCcd.calibrate.astrometry.solver: Got astrometric solution from Astrometry.net
      LoadReferenceObjects: getting reference objects using center (1023.5, 2084.5) pix = Fk5Coord(320.3431396, 0.5002365, 2000.00) sky and radius 0.00194896 rad
      LoadReferenceObjects: search for objects at Fk5Coord(320.3431396, 0.5002365, 2000.00) with radius 0.111667372351 deg
      LoadReferenceObjects: found 495 objects
      LoadReferenceObjects: trimmed 257 out-of-bbox objects, leaving 238
      processCcd.calibrate.astrometry.solver: Fit WCS: use iter 2 because it had less linear scatter than the next iter: 0.307471 vs. 0.320229 pixels
      processCcd.calibrate.astrometry: 186 astrometric matches
      processCcd.calibrate.astrometry: Refitting WCS
      processCcd.calibrate.astrometry: Astrometric scatter: 0.047945 arcsec (with non-linear terms, 174 matches, 12 rejected)
      processCcd.calibrate.measurePsf: Measuring PSF
      /tigress/HSC/LSST/stack10_1/Linux64/anaconda/2.1.0-4-g35ca374/lib/python2.7/site-packages/numpy/core/_methods.py:59: RuntimeWarning: Mean of empty slice.
        warnings.warn("Mean of empty slice.", RuntimeWarning)
      /tigress/HSC/LSST/stack10_1/Linux64/anaconda/2.1.0-4-g35ca374/lib/python2.7/site-packages/numpy/core/_methods.py:71: RuntimeWarning: invalid value encountered in double_scalars
        ret = ret.dtype.type(ret / rcount)
      /home/pprice/LSST/meas/algorithms/python/lsst/meas/algorithms/objectSizeStarSelector.py:143: RuntimeWarning: invalid value encountered in less
        update = dist < minDist
      processCcd.calibrate.measurePsf: PSF star selector found 163 candidates
      processCcd.calibrate.measurePsf: PSF determination using 114/163 stars.
      processCcd.calibrate.repair: Identified 92 cosmic rays.
      processCcd.calibrate: Fit and subtracted background
      processCcd.calibrate.measurement: Measuring 303 sources (303 parents, 0 children) 
      processCcd.calibrate.astrometry: Applying distortion correction
      processCcd.calibrate.astrometry: Solving astrometry
      processCcd.calibrate.astrometry.solver: Number of selected sources for astrometry : 258
      Solver:
        Arcsec per pix range: 0.153025, 0.18516
        Image size: 2054 x 4186
        Quad size range: 205.4, 4662.78
        Objs: 0, 50
        Parity: 0, normal
        Use_radec? yes, (320.343, 0.500178), radius 1 deg
        Verify_pix: 1
        Code tol: 0.01
        Dist from quad bonus: yes
        Distractor ratio: 0.25
        Log tune-up threshold: inf
        Log bail threshold: -230.259
        Log stoplooking threshold: inf
        Maxquads 0
        Maxmatches 0
        Set CRPIX? no
        Tweak? no
        Indexes: 3
          /tigress/HSC/astrometry_net_data/sdss-dr9-fink-v5b/sdss-dr9-fink-v5b_and_263_0.fits
          /tigress/HSC/astrometry_net_data/sdss-dr9-fink-v5b/sdss-dr9-fink-v5b_and_263_1.fits
          /tigress/HSC/astrometry_net_data/sdss-dr9-fink-v5b/sdss-dr9-fink-v5b_and_263_2.fits
        Field: 258 stars
      Quad scale range: [641.674, 2208.56] pixels
      object 1 of 50: 0 quads tried, 0 matched.
      object 2 of 50: 0 quads tried, 0 matched.
      object 3 of 50: 0 quads tried, 0 matched.
      object 4 of 50: 0 quads tried, 0 matched.
      object 5 of 50: 0 quads tried, 0 matched.
      object 6 of 50: 0 quads tried, 0 matched.
      Got a new best match: logodds 787.099.
        log-odds ratio 787.099 (inf), 178 match, 1 conflict, 75 distractors, 220 index.
        RA,Dec = (320.343,0.500213), pixel scale 0.167612 arcsec/pix.
        Hit/miss:   Hit/miss: ++-+++++-++++++++++++--++-+--+++++-+-+++++++++-+++++++-+++++-+++++++++++++-++++++-++++++-+++++++-+++
      Pixel scale: 0.167612 arcsec/pix.
      Parity: pos.
      processCcd.calibrate.astrometry.solver: Got astrometric solution from Astrometry.net
      LoadReferenceObjects: getting reference objects using center (1023.5, 2084.5) pix = Fk5Coord(320.3431396, 0.5002365, 2000.00) sky and radius 0.00194896 rad
      LoadReferenceObjects: search for objects at Fk5Coord(320.3431396, 0.5002365, 2000.00) with radius 0.111667328272 deg
      LoadReferenceObjects: found 495 objects
      LoadReferenceObjects: trimmed 257 out-of-bbox objects, leaving 238
      processCcd.calibrate.astrometry.solver: Fit WCS: use iter 2 because it had less linear scatter than the next iter: 0.306732 vs. 0.320115 pixels
      processCcd.calibrate.astrometry: 186 astrometric matches
      processCcd.calibrate.astrometry: Refitting WCS
      processCcd.calibrate.astrometry: Astrometric scatter: 0.048271 arcsec (with non-linear terms, 174 matches, 12 rejected)
      processCcd.calibrate.photocal: Not applying color terms because config.applyColorTerms is False
      processCcd.calibrate.photocal: Magnitude zero point: 30.685281 +/- 0.058711 from 173 stars
      processCcd.calibrate: Photometric zero-point: 30.685281
      processCcd.detection: Detected 1194 positive sources to 5 sigma.
      processCcd.detection: Resubtracting the background after object detection
      processCcd.deblend: Deblending 1194 sources
      processCcd.deblend: Deblended: of 1194 sources, 143 were deblended, creating 358 children, total 1552 sources
      processCcd.measurement: Measuring 1552 sources (1194 parents, 358 children) 
      processCcd WARNING: Persisting background models
      processCcd: Matching icSource and Source catalogs to propagate flags.
      processCcd: Matching src to reference catalogue
      LoadReferenceObjects: getting reference objects using center (1023.5, 2087.5) pix = Fk5Coord(320.3429016, 0.5001781, 2000.00) sky and radius 0.00195667 rad
      LoadReferenceObjects: search for objects at Fk5Coord(320.3429016, 0.5001781, 2000.00) with radius 0.112109149864 deg
      LoadReferenceObjects: found 499 objects
      LoadReferenceObjects: trimmed 261 out-of-bbox objects, leaving 238
      processCcd.calibrate.astrometry.solver: Fit WCS: use iter 1 because it had less linear scatter than the next iter: 0.300624 vs. 0.300652 pixels
      

      The verbosity of the astrometry module is out of proportion with the rest of the modules, which makes it difficult to follow the processing.

      This is a pull request for fixes I have made.

        Attachments

          Activity

          Hide
          price Paul Price added a comment -

          Russell, would you mind reviewing this please? There are two commits on meas_astrom and one on meas_algorithms (see below for details).

          Here's the output from processCcd.py with the fixes. The chatter is much reduced.

          $ processCcd.py /tigress/HSC/HSC --output /tigress/pprice/lsst --id visit=904020 ccd=49 --clobber-config
          : Loading config overrride file '/home/pprice/LSST/obs/subaru/config/processCcd.py'
          WARNING: Unable to use psfex: No module named extensions.psfex.psfexPsfDeterminer
          hscAstrom is not setup; using LSST's meas_astrom instead
          Cannot import lsst.meas.multifit: disabling CModel measurements
          Cannot import lsst.meas.extensions.photometryKron: disabling Kron measurements
          Cannot enable shapeHSM ('MEAS_EXTENSIONS_SHAPEHSM_DIR'): disabling HSM shape measurements
          Cannot import lsst.meas.extensions.photometryKron: disabling Kron measurements
          Cannot enable shapeHSM ('MEAS_EXTENSIONS_SHAPEHSM_DIR'): disabling HSM shape measurements
          : Loading config overrride file '/home/pprice/LSST/obs/subaru/config/hsc/processCcd.py'
          : input=/tigress/HSC/HSC
          : calib=None
          : output=/tigress/pprice/lsst
          CameraMapper: Loading registry registry from /tigress/pprice/lsst/_parent/registry.sqlite3
          CameraMapper: Loading calibRegistry registry from /tigress/HSC/HSC/CALIB/calibRegistry.sqlite3
          processCcd: Processing {'taiObs': '2013-11-02', 'pointing': 671, 'visit': 904020, 'dateObs': '2013-11-02', 'filter': 'HSC-I', 'field': 'STRIPE82L', 'ccd': 49, 'expTime': 30.0}
          processCcd.isr: Performing ISR on sensor {'taiObs': '2013-11-02', 'pointing': 671, 'visit': 904020, 'dateObs': '2013-11-02', 'filter': 'HSC-I', 'field': 'STRIPE82L', 'ccd': 49, 'expTime': 30.0}
          processCcd.isr WARNING: Cannot write thumbnail image; hsc.fitsthumb could not be imported.
          afw.image.MaskedImage WARNING: Expected extension type not found: IMAGE
          processCcd.isr: Applying linearity corrections to Ccd 49
          processCcd.isr.crosstalk: Applying crosstalk correction
          afw.image.MaskedImage WARNING: Expected extension type not found: IMAGE
          : Empty WCS extension, using FITS header
          processCcd.isr: Set 0 BAD pixels to 647.04
          processCcd.isr WARNING: There were 6192 unmasked NaNs
          processCcd.isr WARNING: Cannot write thumbnail image; hsc.fitsthumb could not be imported.
          processCcd.isr: Flattened sky level: 647.130493 +/- 12.733898
          processCcd.isr: Measuring sky levels in 8x16 grids: 648.106765
          processCcd.isr: Sky flatness in 8x16 grids - pp: 0.024087 rms: 0.006057
          processCcd.calibrate: installInitialPsf fwhm=5.88235294312 pixels; size=15 pixels
          processCcd.calibrate.repair: Identified 80 cosmic rays.
          processCcd.calibrate.detection: Detected 303 positive sources to 5 sigma.
          processCcd.calibrate.detection: Resubtracting the background after object detection
          processCcd.calibrate.initialMeasurement: Measuring 303 sources (303 parents, 0 children) 
          processCcd.calibrate.astrometry: Applying distortion correction
          processCcd.calibrate.astrometry: Solving astrometry
          processCcd.calibrate.astrometry.solver: Number of selected sources for astrometry : 258
          processCcd.calibrate.astrometry.solver: Got astrometric solution from Astrometry.net
          LoadReferenceObjects: Loading reference objects using center (1023.5, 2084.5) pix = Fk5Coord(320.3431396, 0.5002365, 2000.00) sky and radius 0.111667372351 deg
          LoadReferenceObjects: Loaded 238 reference objects
          processCcd.calibrate.astrometry: 186 astrometric matches
          processCcd.calibrate.astrometry: Refitting WCS
          processCcd.calibrate.astrometry: Astrometric scatter: 0.047945 arcsec (with non-linear terms, 174 matches, 12 rejected)
          processCcd.calibrate.measurePsf: Measuring PSF
          /tigress/HSC/LSST/stack10_1/Linux64/anaconda/2.1.0-4-g35ca374/lib/python2.7/site-packages/numpy/core/_methods.py:59: RuntimeWarning: Mean of empty slice.
            warnings.warn("Mean of empty slice.", RuntimeWarning)
          /tigress/HSC/LSST/stack10_1/Linux64/anaconda/2.1.0-4-g35ca374/lib/python2.7/site-packages/numpy/core/_methods.py:71: RuntimeWarning: invalid value encountered in double_scalars
            ret = ret.dtype.type(ret / rcount)
          /home/pprice/LSST/meas/algorithms/python/lsst/meas/algorithms/objectSizeStarSelector.py:143: RuntimeWarning: invalid value encountered in less
            update = dist < minDist
          processCcd.calibrate.measurePsf: PSF star selector found 163 candidates
          processCcd.calibrate.measurePsf: PSF determination using 114/163 stars.
          processCcd.calibrate.repair: Identified 92 cosmic rays.
          processCcd.calibrate: Fit and subtracted background
          processCcd.calibrate.measurement: Measuring 303 sources (303 parents, 0 children) 
          processCcd.calibrate.astrometry: Applying distortion correction
          processCcd.calibrate.astrometry: Solving astrometry
          processCcd.calibrate.astrometry.solver: Number of selected sources for astrometry : 258
          processCcd.calibrate.astrometry.solver: Got astrometric solution from Astrometry.net
          LoadReferenceObjects: Loading reference objects using center (1023.5, 2084.5) pix = Fk5Coord(320.3431396, 0.5002365, 2000.00) sky and radius 0.111667328272 deg
          LoadReferenceObjects: Loaded 238 reference objects
          processCcd.calibrate.astrometry: 186 astrometric matches
          processCcd.calibrate.astrometry: Refitting WCS
          processCcd.calibrate.astrometry: Astrometric scatter: 0.048271 arcsec (with non-linear terms, 174 matches, 12 rejected)
          processCcd.calibrate.photocal: Not applying color terms because config.applyColorTerms is False
          processCcd.calibrate.photocal: Magnitude zero point: 30.685281 +/- 0.058711 from 173 stars
          processCcd.calibrate: Photometric zero-point: 30.685281
          processCcd.detection: Detected 1194 positive sources to 5 sigma.
          processCcd.detection: Resubtracting the background after object detection
          processCcd.deblend: Deblending 1194 sources
          processCcd.deblend: Deblended: of 1194 sources, 143 were deblended, creating 358 children, total 1552 sources
          processCcd.measurement: Measuring 1552 sources (1194 parents, 358 children) 
          processCcd WARNING: Persisting background models
          processCcd: Matching icSource and Source catalogs to propagate flags.
          processCcd: Matching src to reference catalogue
          LoadReferenceObjects: Loading reference objects using center (1023.5, 2087.5) pix = Fk5Coord(320.3429016, 0.5001781, 2000.00) sky and radius 0.112109149864 deg
          LoadReferenceObjects: Loaded 238 reference objects
          

          Commits for review:

          pprice@tiger-sumire:~/LSST/meas/astrom (tickets/DM-3141=) $ git --no-pager log --stat --reverse origin/master..
          commit ba83b876f2781efcbf996ed0ec232b87eb0ab2f5
          Author: Paul Price <price@astro.princeton.edu>
          Date:   Tue Jul 14 17:45:18 2015 -0400
           
              reduce verbosity in astrometric solution
              
              Downgraded several detail-oriented messages from "info" log level
              to "debug" log level.
           
           python/lsst/meas/astrom/anetBasicAstrometry.py      | 4 ++--
           python/lsst/meas/astrom/loadAstrometryNetObjects.py | 6 +++---
           2 files changed, 5 insertions(+), 5 deletions(-)
           
          commit 32b101e61c452d61222c1c6e3f4fba843ab5c05c
          Author: Paul Price <price@astro.princeton.edu>
          Date:   Tue Jul 14 17:48:46 2015 -0400
           
              LoadMultiIndexes: remove call to finalize astrometry.net interface
              
              Calling lsst.meas.astrom.astrometry_net.finalize() removes the
              layer placed over astrometry.net to map log levels.  Without this
              layer, we get a lot of detail printed which can overwhelm the user.
              The LoadMultiIndexes context manager doesn't set up logging, so
              shouldn't tear it down.
           
           python/lsst/meas/astrom/loadAstrometryNetObjects.py | 3 +--
           1 file changed, 1 insertion(+), 2 deletions(-)
           
           
          pprice@tiger-sumire:~/LSST/meas/algorithms (tickets/DM-3141=) $ git --no-pager log --stat --reverse origin/master..
          commit 5413a96bb6e7497d2814819f5c10ad15585b4177
          Author: Paul Price <price@astro.princeton.edu>
          Date:   Tue Jul 14 17:42:54 2015 -0400
           
              LoadReferenceObjectsTask: reduce logging verbosity
              
              Converted message with details from "info" level to "debug" level,
              and cleaned up other log messages.
           
           python/lsst/meas/algorithms/loadReferenceObjects.py | 7 ++++---
           1 file changed, 4 insertions(+), 3 deletions(-)
          

          Show
          price Paul Price added a comment - Russell, would you mind reviewing this please? There are two commits on meas_astrom and one on meas_algorithms (see below for details). Here's the output from processCcd.py with the fixes. The chatter is much reduced. $ processCcd.py /tigress/HSC/HSC --output /tigress/pprice/lsst --id visit=904020 ccd=49 --clobber-config : Loading config overrride file '/home/pprice/LSST/obs/subaru/config/processCcd.py' WARNING: Unable to use psfex: No module named extensions.psfex.psfexPsfDeterminer hscAstrom is not setup; using LSST's meas_astrom instead Cannot import lsst.meas.multifit: disabling CModel measurements Cannot import lsst.meas.extensions.photometryKron: disabling Kron measurements Cannot enable shapeHSM ('MEAS_EXTENSIONS_SHAPEHSM_DIR'): disabling HSM shape measurements Cannot import lsst.meas.extensions.photometryKron: disabling Kron measurements Cannot enable shapeHSM ('MEAS_EXTENSIONS_SHAPEHSM_DIR'): disabling HSM shape measurements : Loading config overrride file '/home/pprice/LSST/obs/subaru/config/hsc/processCcd.py' : input=/tigress/HSC/HSC : calib=None : output=/tigress/pprice/lsst CameraMapper: Loading registry registry from /tigress/pprice/lsst/_parent/registry.sqlite3 CameraMapper: Loading calibRegistry registry from /tigress/HSC/HSC/CALIB/calibRegistry.sqlite3 processCcd: Processing {'taiObs': '2013-11-02', 'pointing': 671, 'visit': 904020, 'dateObs': '2013-11-02', 'filter': 'HSC-I', 'field': 'STRIPE82L', 'ccd': 49, 'expTime': 30.0} processCcd.isr: Performing ISR on sensor {'taiObs': '2013-11-02', 'pointing': 671, 'visit': 904020, 'dateObs': '2013-11-02', 'filter': 'HSC-I', 'field': 'STRIPE82L', 'ccd': 49, 'expTime': 30.0} processCcd.isr WARNING: Cannot write thumbnail image; hsc.fitsthumb could not be imported. afw.image.MaskedImage WARNING: Expected extension type not found: IMAGE processCcd.isr: Applying linearity corrections to Ccd 49 processCcd.isr.crosstalk: Applying crosstalk correction afw.image.MaskedImage WARNING: Expected extension type not found: IMAGE : Empty WCS extension, using FITS header processCcd.isr: Set 0 BAD pixels to 647.04 processCcd.isr WARNING: There were 6192 unmasked NaNs processCcd.isr WARNING: Cannot write thumbnail image; hsc.fitsthumb could not be imported. processCcd.isr: Flattened sky level: 647.130493 +/- 12.733898 processCcd.isr: Measuring sky levels in 8x16 grids: 648.106765 processCcd.isr: Sky flatness in 8x16 grids - pp: 0.024087 rms: 0.006057 processCcd.calibrate: installInitialPsf fwhm=5.88235294312 pixels; size=15 pixels processCcd.calibrate.repair: Identified 80 cosmic rays. processCcd.calibrate.detection: Detected 303 positive sources to 5 sigma. processCcd.calibrate.detection: Resubtracting the background after object detection processCcd.calibrate.initialMeasurement: Measuring 303 sources (303 parents, 0 children) processCcd.calibrate.astrometry: Applying distortion correction processCcd.calibrate.astrometry: Solving astrometry processCcd.calibrate.astrometry.solver: Number of selected sources for astrometry : 258 processCcd.calibrate.astrometry.solver: Got astrometric solution from Astrometry.net LoadReferenceObjects: Loading reference objects using center (1023.5, 2084.5) pix = Fk5Coord(320.3431396, 0.5002365, 2000.00) sky and radius 0.111667372351 deg LoadReferenceObjects: Loaded 238 reference objects processCcd.calibrate.astrometry: 186 astrometric matches processCcd.calibrate.astrometry: Refitting WCS processCcd.calibrate.astrometry: Astrometric scatter: 0.047945 arcsec (with non-linear terms, 174 matches, 12 rejected) processCcd.calibrate.measurePsf: Measuring PSF /tigress/HSC/LSST/stack10_1/Linux64/anaconda/2.1.0-4-g35ca374/lib/python2.7/site-packages/numpy/core/_methods.py:59: RuntimeWarning: Mean of empty slice. warnings.warn("Mean of empty slice.", RuntimeWarning) /tigress/HSC/LSST/stack10_1/Linux64/anaconda/2.1.0-4-g35ca374/lib/python2.7/site-packages/numpy/core/_methods.py:71: RuntimeWarning: invalid value encountered in double_scalars ret = ret.dtype.type(ret / rcount) /home/pprice/LSST/meas/algorithms/python/lsst/meas/algorithms/objectSizeStarSelector.py:143: RuntimeWarning: invalid value encountered in less update = dist < minDist processCcd.calibrate.measurePsf: PSF star selector found 163 candidates processCcd.calibrate.measurePsf: PSF determination using 114/163 stars. processCcd.calibrate.repair: Identified 92 cosmic rays. processCcd.calibrate: Fit and subtracted background processCcd.calibrate.measurement: Measuring 303 sources (303 parents, 0 children) processCcd.calibrate.astrometry: Applying distortion correction processCcd.calibrate.astrometry: Solving astrometry processCcd.calibrate.astrometry.solver: Number of selected sources for astrometry : 258 processCcd.calibrate.astrometry.solver: Got astrometric solution from Astrometry.net LoadReferenceObjects: Loading reference objects using center (1023.5, 2084.5) pix = Fk5Coord(320.3431396, 0.5002365, 2000.00) sky and radius 0.111667328272 deg LoadReferenceObjects: Loaded 238 reference objects processCcd.calibrate.astrometry: 186 astrometric matches processCcd.calibrate.astrometry: Refitting WCS processCcd.calibrate.astrometry: Astrometric scatter: 0.048271 arcsec (with non-linear terms, 174 matches, 12 rejected) processCcd.calibrate.photocal: Not applying color terms because config.applyColorTerms is False processCcd.calibrate.photocal: Magnitude zero point: 30.685281 +/- 0.058711 from 173 stars processCcd.calibrate: Photometric zero-point: 30.685281 processCcd.detection: Detected 1194 positive sources to 5 sigma. processCcd.detection: Resubtracting the background after object detection processCcd.deblend: Deblending 1194 sources processCcd.deblend: Deblended: of 1194 sources, 143 were deblended, creating 358 children, total 1552 sources processCcd.measurement: Measuring 1552 sources (1194 parents, 358 children) processCcd WARNING: Persisting background models processCcd: Matching icSource and Source catalogs to propagate flags. processCcd: Matching src to reference catalogue LoadReferenceObjects: Loading reference objects using center (1023.5, 2087.5) pix = Fk5Coord(320.3429016, 0.5001781, 2000.00) sky and radius 0.112109149864 deg LoadReferenceObjects: Loaded 238 reference objects Commits for review: pprice@tiger-sumire:~/LSST/meas/astrom (tickets/DM-3141=) $ git --no-pager log --stat --reverse origin/master.. commit ba83b876f2781efcbf996ed0ec232b87eb0ab2f5 Author: Paul Price <price@astro.princeton.edu> Date: Tue Jul 14 17:45:18 2015 -0400   reduce verbosity in astrometric solution Downgraded several detail-oriented messages from "info" log level to "debug" log level.   python/lsst/meas/astrom/anetBasicAstrometry.py | 4 ++-- python/lsst/meas/astrom/loadAstrometryNetObjects.py | 6 +++--- 2 files changed, 5 insertions(+), 5 deletions(-)   commit 32b101e61c452d61222c1c6e3f4fba843ab5c05c Author: Paul Price <price@astro.princeton.edu> Date: Tue Jul 14 17:48:46 2015 -0400   LoadMultiIndexes: remove call to finalize astrometry.net interface Calling lsst.meas.astrom.astrometry_net.finalize() removes the layer placed over astrometry.net to map log levels. Without this layer, we get a lot of detail printed which can overwhelm the user. The LoadMultiIndexes context manager doesn't set up logging, so shouldn't tear it down.   python/lsst/meas/astrom/loadAstrometryNetObjects.py | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-)     pprice@tiger-sumire:~/LSST/meas/algorithms (tickets/DM-3141=) $ git --no-pager log --stat --reverse origin/master.. commit 5413a96bb6e7497d2814819f5c10ad15585b4177 Author: Paul Price <price@astro.princeton.edu> Date: Tue Jul 14 17:42:54 2015 -0400   LoadReferenceObjectsTask: reduce logging verbosity Converted message with details from "info" level to "debug" level, and cleaned up other log messages.   python/lsst/meas/algorithms/loadReferenceObjects.py | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-)
          Hide
          rowen Russell Owen added a comment -

          Can you please remind me where the "Solver..." text comes from? That seems to be the main source of unwanted chatter and I'm surprised to see that your changes got rid of it. I'm guessing that is due to removing astromNet.finalize() but I if so, I'm puzzled. It looks like diagnostic print output that should never have shown up in the first place (the kind of thing that a verbose argument is often used to enable in the HSC code that I ported over).

          I am not comfortable with your removing the call to astromNet.finalize() in LoadMultiIndexes context manager. Without the automatic call I think one has to finalize manually, which I feel is clumsy and error-prone. (And indeed I don't think finalize is ever called now.)

          The changes from log.info to log.logdebug are safe but they don't remove many log messages and I feel some are useful and in keeping with messages such as:

          processCcd.calibrate.measurePsf: PSF star selector found 163 candidates
          processCcd.calibrate.measurePsf: PSF determination using 114/163 stars.
          processCcd.calibrate.repair: Identified 92 cosmic rays.
          processCcd.calibrate: Fit and subtracted background
          processCcd.calibrate.measurement: Measuring 303 sources (303 parents, 0 children) 
          

          Show
          rowen Russell Owen added a comment - Can you please remind me where the "Solver..." text comes from? That seems to be the main source of unwanted chatter and I'm surprised to see that your changes got rid of it. I'm guessing that is due to removing astromNet.finalize() but I if so, I'm puzzled. It looks like diagnostic print output that should never have shown up in the first place (the kind of thing that a verbose argument is often used to enable in the HSC code that I ported over). I am not comfortable with your removing the call to astromNet.finalize() in LoadMultiIndexes context manager. Without the automatic call I think one has to finalize manually, which I feel is clumsy and error-prone. (And indeed I don't think finalize is ever called now.) The changes from log.info to log.logdebug are safe but they don't remove many log messages and I feel some are useful and in keeping with messages such as: processCcd.calibrate.measurePsf: PSF star selector found 163 candidates processCcd.calibrate.measurePsf: PSF determination using 114/163 stars. processCcd.calibrate.repair: Identified 92 cosmic rays. processCcd.calibrate: Fit and subtracted background processCcd.calibrate.measurement: Measuring 303 sources (303 parents, 0 children)
          Hide
          price Paul Price added a comment -

          The "Solver..." text comes from astrometry.net's logger. As the commit message says:

          Calling lsst.meas.astrom.astrometry_net.finalize() removes the
          layer placed over astrometry.net to map log levels. Without this
          layer, we get a lot of detail printed which can overwhelm the user.
          The LoadMultiIndexes context manager doesn't set up logging, so
          shouldn't tear it down.

          Note the definition of finalize in astrometry_net.i:

          void finalize() {
              stop_an_logging();
          }
          

          Its only purpose is to tear down the logging layer. It is therefore not intended to be called by a context manager for loading index files. We never used to call it at all (it's never called on the HSC side, with no ill effects that we've noticed yet), and it's not clear what the purpose behind adding it was. If you're concerned that it must be called, it should probably be called via atexit.

          Show
          price Paul Price added a comment - The "Solver..." text comes from astrometry.net's logger. As the commit message says: Calling lsst.meas.astrom.astrometry_net.finalize() removes the layer placed over astrometry.net to map log levels. Without this layer, we get a lot of detail printed which can overwhelm the user. The LoadMultiIndexes context manager doesn't set up logging, so shouldn't tear it down. Note the definition of finalize in astrometry_net.i: void finalize() { stop_an_logging(); } Its only purpose is to tear down the logging layer. It is therefore not intended to be called by a context manager for loading index files. We never used to call it at all (it's never called on the HSC side, with no ill effects that we've noticed yet), and it's not clear what the purpose behind adding it was. If you're concerned that it must be called, it should probably be called via atexit .
          Hide
          price Paul Price added a comment -

          If it helps, note that the corresponding function, start_an_logging is called at module initialisation time:

          %init %{
              // Astrometry.net logging
              fits_use_error_system();
              start_an_logging();
              %}
          

          The call to finalize, which only calls stop_an_logging, is intended to finalize use of the python module, not of the index files.

          Show
          price Paul Price added a comment - If it helps, note that the corresponding function, start_an_logging is called at module initialisation time: %init %{ // Astrometry.net logging fits_use_error_system(); start_an_logging(); %} The call to finalize , which only calls stop_an_logging , is intended to finalize use of the python module , not of the index files.
          Hide
          price Paul Price added a comment -

          Regarding downgrading log.info to log.debug, in the first iteration I've reduced 11 lines of output (once we remove the logging directly from astrometry.net due to the finalize issue) to 9. I don't think this is a great loss, given that the only things that have gone are the details on the reference objects (reading, found XXX in the circle, reduced to YYY in the box).

          Ooh, just remembered that the LoadReferenceObjects aren't being printed in the usual hierarchy. I'll see if I can fix that too.

          Original:

          LoadReferenceObjects: read index files
          processCcd.calibrate.astrometry.solver: Number of selected sources for astrometry : 258
          processCcd.calibrate.astrometry.solver: Got astrometric solution from Astrometry.net
          LoadReferenceObjects: getting reference objects using center (1023.5, 2084.5) pix = Fk5Coord(320.3431396, 0.5002365, 2000.00) sky and radius 0.00194896 rad
          LoadReferenceObjects: search for objects at Fk5Coord(320.3431396, 0.5002365, 2000.00) with radius 0.111667372351 deg
          LoadReferenceObjects: found 495 objects
          LoadReferenceObjects: trimmed 257 out-of-bbox objects, leaving 238
          processCcd.calibrate.astrometry.solver: Fit WCS: use iter 2 because it had less linear scatter than the next iter: 0.307471 vs. 0.320229 pixels
          processCcd.calibrate.astrometry: 186 astrometric matches
          processCcd.calibrate.astrometry: Refitting WCS
          processCcd.calibrate.astrometry: Astrometric scatter: 0.047945 arcsec (with non-linear terms, 174 matches, 12 rejected)
          

          Mine:

          processCcd.calibrate.astrometry: Applying distortion correction
          processCcd.calibrate.astrometry: Solving astrometry
          processCcd.calibrate.astrometry.solver: Number of selected sources for astrometry : 258
          processCcd.calibrate.astrometry.solver: Got astrometric solution from Astrometry.net
          LoadReferenceObjects: Loading reference objects using center (1023.5, 2084.5) pix = Fk5Coord(320.3431396, 0.5002365, 2000.00) sky and radius 0.111667372351 deg
          LoadReferenceObjects: Loaded 238 reference objects
          processCcd.calibrate.astrometry: 186 astrometric matches
          processCcd.calibrate.astrometry: Refitting WCS
          processCcd.calibrate.astrometry: Astrometric scatter: 0.047945 arcsec (with non-linear terms, 174 matches, 12 rejected)
          

          Show
          price Paul Price added a comment - Regarding downgrading log.info to log.debug , in the first iteration I've reduced 11 lines of output (once we remove the logging directly from astrometry.net due to the finalize issue) to 9. I don't think this is a great loss, given that the only things that have gone are the details on the reference objects (reading, found XXX in the circle, reduced to YYY in the box). Ooh, just remembered that the LoadReferenceObjects aren't being printed in the usual hierarchy. I'll see if I can fix that too. Original: LoadReferenceObjects: read index files processCcd.calibrate.astrometry.solver: Number of selected sources for astrometry : 258 processCcd.calibrate.astrometry.solver: Got astrometric solution from Astrometry.net LoadReferenceObjects: getting reference objects using center (1023.5, 2084.5) pix = Fk5Coord(320.3431396, 0.5002365, 2000.00) sky and radius 0.00194896 rad LoadReferenceObjects: search for objects at Fk5Coord(320.3431396, 0.5002365, 2000.00) with radius 0.111667372351 deg LoadReferenceObjects: found 495 objects LoadReferenceObjects: trimmed 257 out-of-bbox objects, leaving 238 processCcd.calibrate.astrometry.solver: Fit WCS: use iter 2 because it had less linear scatter than the next iter: 0.307471 vs. 0.320229 pixels processCcd.calibrate.astrometry: 186 astrometric matches processCcd.calibrate.astrometry: Refitting WCS processCcd.calibrate.astrometry: Astrometric scatter: 0.047945 arcsec (with non-linear terms, 174 matches, 12 rejected) Mine: processCcd.calibrate.astrometry: Applying distortion correction processCcd.calibrate.astrometry: Solving astrometry processCcd.calibrate.astrometry.solver: Number of selected sources for astrometry : 258 processCcd.calibrate.astrometry.solver: Got astrometric solution from Astrometry.net LoadReferenceObjects: Loading reference objects using center (1023.5, 2084.5) pix = Fk5Coord(320.3431396, 0.5002365, 2000.00) sky and radius 0.111667372351 deg LoadReferenceObjects: Loaded 238 reference objects processCcd.calibrate.astrometry: 186 astrometric matches processCcd.calibrate.astrometry: Refitting WCS processCcd.calibrate.astrometry: Astrometric scatter: 0.047945 arcsec (with non-linear terms, 174 matches, 12 rejected)
          Hide
          rowen Russell Owen added a comment -

          Thank you for the clarification of finalize(). The LSST code I started from called finalize() all over the place (e.g. in unit tests and such), so I thought it was necessary and felt it should be called automatically if possible. Adding finalize() to the context manager seemed like the obvious solution, but not having to call it at all is even better.

          I would prefer to retain the other messages, but am willing to be overruled.

          Show
          rowen Russell Owen added a comment - Thank you for the clarification of finalize(). The LSST code I started from called finalize() all over the place (e.g. in unit tests and such), so I thought it was necessary and felt it should be called automatically if possible. Adding finalize() to the context manager seemed like the obvious solution, but not having to call it at all is even better. I would prefer to retain the other messages, but am willing to be overruled.
          Hide
          price Paul Price added a comment -

          One more commit on meas_astrom to review, please:

          pprice@tiger-sumire:~/LSST/meas/astrom (tickets/DM-3141=) $ git --no-pager log --patch -1
          commit 356dcf06308add871058e8bad51cf9df412eac06
          Author: Paul Price <price@astro.princeton.edu>
          Date:   Tue Jul 14 21:13:42 2015 -0400
           
              ANetBasicAstrometryTask: set name and log for ref loader
              
              The LoadAstrometryNetObjectsTask is not a subtask, so wasn't a
              proper part of the log hierarchy --- log messages were being
              printed with only the Task's _DefaultName.  Adding the log and
              a name to the constructor puts it in the usual log hierarchy.
           
          diff --git a/python/lsst/meas/astrom/anetBasicAstrometry.py b/python/lsst/meas/astrom/anetBasicAstrometry.py
          index c4ff217..95df12c 100644
          --- a/python/lsst/meas/astrom/anetBasicAstrometry.py
          +++ b/python/lsst/meas/astrom/anetBasicAstrometry.py
          @@ -217,7 +217,8 @@ class ANetBasicAstrometryTask(pipeBase.Task):
                   pipeBase.Task.__init__(self, config=config, **kwargs)
                   self.config = config
                   # this is not a subtask because it cannot safely be retargeted
          -        self.refObjLoader = LoadAstrometryNetObjectsTask(config=self.config, andConfig=andConfig)
          +        self.refObjLoader = LoadAstrometryNetObjectsTask(config=self.config, andConfig=andConfig, log=self.log,
          +                                                         name="loadAN")
                   self.refObjLoader._readIndexFiles()
           
               def memusage(self, prefix=''):
          

          Show
          price Paul Price added a comment - One more commit on meas_astrom to review, please: pprice@tiger-sumire:~/LSST/meas/astrom (tickets/DM-3141=) $ git --no-pager log --patch -1 commit 356dcf06308add871058e8bad51cf9df412eac06 Author: Paul Price <price@astro.princeton.edu> Date: Tue Jul 14 21:13:42 2015 -0400   ANetBasicAstrometryTask: set name and log for ref loader The LoadAstrometryNetObjectsTask is not a subtask, so wasn't a proper part of the log hierarchy --- log messages were being printed with only the Task's _DefaultName. Adding the log and a name to the constructor puts it in the usual log hierarchy.   diff --git a/python/lsst/meas/astrom/anetBasicAstrometry.py b/python/lsst/meas/astrom/anetBasicAstrometry.py index c4ff217..95df12c 100644 --- a/python/lsst/meas/astrom/anetBasicAstrometry.py +++ b/python/lsst/meas/astrom/anetBasicAstrometry.py @@ -217,7 +217,8 @@ class ANetBasicAstrometryTask(pipeBase.Task): pipeBase.Task.__init__(self, config=config, **kwargs) self.config = config # this is not a subtask because it cannot safely be retargeted - self.refObjLoader = LoadAstrometryNetObjectsTask(config=self.config, andConfig=andConfig) + self.refObjLoader = LoadAstrometryNetObjectsTask(config=self.config, andConfig=andConfig, log=self.log, + name="loadAN") self.refObjLoader._readIndexFiles() def memusage(self, prefix=''):
          Hide
          rowen Russell Owen added a comment -

          Your change to how you call the LoadAstrometryNetObjectsTask looks like a good improvement.

          This is presumably outside the scope of this ticket, but is finalize() is even a useful method? The name is deceptive and it just calls stop_an_logging, which has a very clear name, so I wonder if it should be ditched.

          Show
          rowen Russell Owen added a comment - Your change to how you call the LoadAstrometryNetObjectsTask looks like a good improvement. This is presumably outside the scope of this ticket, but is finalize() is even a useful method? The name is deceptive and it just calls stop_an_logging, which has a very clear name, so I wonder if it should be ditched.
          Hide
          price Paul Price added a comment -

          I agree about finalize(), but there's an awful lot of work that needs to be done in cleaning up the astrometry.net stuff, so I would just group it in with that. I don't know what the plans are for improving that code, but given we'll be moving to a different matcher and reference catalog, it's probably not a high priority.

          Going to merge soon.

          Show
          price Paul Price added a comment - I agree about finalize() , but there's an awful lot of work that needs to be done in cleaning up the astrometry.net stuff, so I would just group it in with that. I don't know what the plans are for improving that code, but given we'll be moving to a different matcher and reference catalog, it's probably not a high priority. Going to merge soon.
          Hide
          price Paul Price added a comment -

          Thanks!

          Merged to master.

          Show
          price Paul Price added a comment - Thanks! Merged to master.

            People

            Assignee:
            price Paul Price
            Reporter:
            price Paul Price
            Reviewers:
            Russell Owen
            Watchers:
            Dominique Boutigny, Lauren MacArthur, Paul Price, Russell Owen, Simon Krughoff
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:

                Jenkins

                No builds found.