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

VERBOSE log-level in pipetask run sometimes issues DEBUG log messages

    XMLWordPrintable

    Details

    • Story Points:
      1
    • Team:
      Architecture
    • Urgent?:
      No

      Description

      Michelle Gower reports that running pipelines_check with --log-level=VERBOSE results in some DEBUG messages appearing. For example:

      + pipetask --long-log --log-level VERBOSE run -b ./tmp_execution_butler --output-run demo_collection_exe/YYYYMMDD --qgraph test_exe.qgraph --qgraph-node-id 0 --skip-init-writes --extend-run --clobber-outputs --skip-existing
      INFO 2021-09-08T13:45:10.606-07:00 ctrl.mpexec.cmdLineFwk ()(cmdLineFwk.py:578) - QuantumGraph contains 1 quanta for 1 tasks, graph ID: '1631133890.30657-73494'
      WARNING 2021-09-08T13:45:11.182-07:00 afw.image.MaskedImageFitsReader (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(MaskedImageFitsReader.cc:94) - Expected extension type not found: IMAGE
      WARNING 2021-09-08T13:45:11.328-07:00 afw.image.MaskedImageFitsReader (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(MaskedImageFitsReader.cc:94) - Expected extension type not found: IMAGE
      WARNING 2021-09-08T13:45:13.743-07:00 isr (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(isrTask.py:1032) - Constructing linearizer from cameraGeom information.
      INFO 2021-09-08T13:45:13.743-07:00 isr (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(isrTask.py:1444) - Converting exposure to floating point values.
      INFO 2021-09-08T13:45:13.913-07:00 isr (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(isrTask.py:1511) - Assembling CCD from amplifiers.
      INFO 2021-09-08T13:45:13.979-07:00 isr (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(isrTask.py:1523) - Applying bias correction.
      INFO 2021-09-08T13:45:14.275-07:00 isr (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(isrTask.py:1555) - Applying linearizer.
      INFO 2021-09-08T13:45:14.291-07:00 isr (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(isrTask.py:1560) - Applying crosstalk correction.
      INFO 2021-09-08T13:45:14.291-07:00 isr.crosstalk (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(crosstalk.py:722) - Applying crosstalk correction.
      DEBUG 2021-09-08T13:45:14.292-07:00 ip.isr.calibType (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(crosstalk.py:519) - CT COEFF: [[ 0.       -0.000124 -0.000171 -0.000157]
       [-0.000125  0.       -0.000134 -0.000151]
       [-0.000149 -0.000132  0.       -0.000137]
       [-0.000156 -0.000157 -0.000153  0.      ]]
      INFO 2021-09-08T13:45:15.302-07:00 isr (isr:{instrument: 'HSC', detector: 10, exposure: 903342, ...})(isrTask.py:1569) - Masking defects.
      

      Investigate.

        Attachments

          Activity

          Hide
          tjenness Tim Jenness added a comment -

          The problem seems to be that setting the log-level to VERBOSE results in lsst.log thinking it has a DEBUG level logger. This is really showing us that we have lsst.log loggers hanging around. The ip_isr is definitely down to that and I have fixed it.

          I will take a look at the other two examples but if they are in C++ I will need to look into why lsst.log can't set an intermediate logging level.

          Show
          tjenness Tim Jenness added a comment - The problem seems to be that setting the log-level to VERBOSE results in lsst.log thinking it has a DEBUG level logger. This is really showing us that we have lsst.log loggers hanging around. The ip_isr is definitely down to that and I have fixed it. I will take a look at the other two examples but if they are in C++ I will need to look into why lsst.log can't set an intermediate logging level.
          Hide
          tjenness Tim Jenness added a comment -

          Kian-Tat Lim can you take a quick look at this please. Only the daf_butler pull request: when setting log level for lsst.log I force VERBOSE to become INFO and that solves the underlying problem of everything going DEBUG.

          Christopher Waters thanks for looking at the ip_isr changes.

          I have decided not to fix ip_diffim just yet since it is using the trace facility in lsst.log and I can fix that once I move the logging utilities to the utils package (and fixing pipetask fixes the reported problem).

          Show
          tjenness Tim Jenness added a comment - Kian-Tat Lim can you take a quick look at this please. Only the daf_butler pull request: when setting log level for lsst.log I force VERBOSE to become INFO and that solves the underlying problem of everything going DEBUG. Christopher Waters thanks for looking at the ip_isr changes. I have decided not to fix ip_diffim just yet since it is using the trace facility in lsst.log and I can fix that once I move the logging utilities to the utils package (and fixing pipetask fixes the reported problem).
          Hide
          ktl Kian-Tat Lim added a comment -

          Looks like I'm the last one, so I'll mark as complete. The changes to daf_butler look OK.

          Show
          ktl Kian-Tat Lim added a comment - Looks like I'm the last one, so I'll mark as complete. The changes to daf_butler look OK.

            People

            Assignee:
            tjenness Tim Jenness
            Reporter:
            tjenness Tim Jenness
            Reviewers:
            Kian-Tat Lim
            Watchers:
            Christopher Waters, Kian-Tat Lim, Michelle Gower, Tim Jenness
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:

                Jenkins

                No builds found.