Frossie Economou requests that we tackle this within the first couple of months of S17.

Jim Bosch I am rather confused about how this is supposed to be done. I altered the python code in ci_hsc to use lsst.log instead of pex_logging, and in some cases that seemed to work OK. In particular, I used lsst.log.Log.getLogger() to replace the pex_logging getDefaultLog, since the two classes both suppor the log.info, debug, warn, and error signatures which seem to be used by a lot of the underlying code.

However, I see two problems with this approach:

(1) the log which is created seems to sometimes call code which expects the values -1 or -2 to be acceptable values for the log level. I think these were meaningful to pex_logging, but not to lsst,log.

(2) I seem to run into code which is called by ci_hsc which expect to be able to call routine in _loggingLib in pex_logging, even though I am not myself including or calling classes in that Library. That seems to indicate that there is code under ci_hsc which depends on pex_logging, even if ci_hsc does not. Am I supposed to chase down anything called by ci_hsc and remove its dependence on pex_logging? Could involve considerably more modules than ci_hsc.

Hey Perry Gee — although Jim is always a fount of knowledge, you'll probably find that others, and in particular Hsin-Fang, are able to provide the expertise you need here.

I don't know the answer to your question 1, but as for 2 I think you should limit yourself to only converting code within ci_hsc itself: other packages will be ported on other tickets.

John Swinbank I don't think I can leave ci_hsc in a state where it doesn't run, so I pretty much have to understand what is going on with (2). What I find is that when I don't setup pex_logging, I eventually get the following message:

ImportError: Unable to read stored config file processCcd_config (No module named _loggingLib)

I'm not actually sure what is causing it. I don't see any stored config file which might be causing this.

(1) Yes. Those calls will need to be ported to use the new log. This page in the Developer Guide may be useful.

Logging with negative numeric level in pex_logging were for debug messages. But I also saw that -1 was used for warning messages in some old coldes. I'd leave the specific mapping to your judgement.

(2) Yes. It's possible that dependent packages need to remove pex_logging use before ci_hsc can remove pex_logging. In other words, this ticket may be blocked by DM-8357 and other packages.

Hsin-Fang Chiang Looking over meas_modelfit, the usage seems to be to set a log level from 1 to 10, which gets translated into -1 to -10. The debug log can then be filtered for importance. Is this functionality completely missing from lsst.log, or can it be resurrected somehow?

@jbosch, do you care about this debugLog functionality for meas_ modelfit, or can I turn them all to log.debug's?

Perry Gee please see the Logging page in the Developer Guide, section "Fine-level Verbosity in Tracing".

How many levels are actually used? How many do you want? There are examples in afw and ip_diffim if you decide to go for fine-level tracing.

OK, thanks for the information. I can replicate what is in meas_modelfit with the Fine-level capability.

Hsin-Fang Chiang

After examining the code, it appears to me that I can replace the log.debug<n> templates with traceLogging. However, it will create the following difference in behavior:

Since values which are used in the pex_logging log.debug<n> code all translate into log levels between -1 and -10, some could be enabled even if the whole range of values from -1 to -10 are not enabled. But the new lsst.log fine resolution Trace<n> capabilities all require that the level be set to TRACE. The difference is that all messages of level DEBUG and larger will also be enabled.

I'm not sure if this is a problem, because I am not sure how the debug<n> construct in pex_logging was used previously,

If you decide to go for the scheme as in https://developer.lsst.io/coding/logging.html "Fine-level Verbosity in Tracing", to avoid confusion please only log in the DEBUG level (not TRACE) using logger names such as "TRACE2.meas.algorithms.starSelector". There are some more examples in ip_diffim and afw.

You can enable a single TRACEn via its specific logger name (e.g. {{lsst.log.Log.getLogger("TRACE2.meas.algorithms.starSelector").setLevel(lsst.log.DEBUG) }}), although I'm not sure if that is practically useful. It's probably more useful to set a threshold using {{lsst.log.utils.traceSetAt() }}. If more syntactic sugar is desired please file new tickets.

Sometimes it may not be necessary to convert codes to this scheme described above/in the Dev Guide. For example, in meas_modelfit/src/TruncatedGaussian.cc pex::logging::Debug debug<8> is used, but only numeric level 8 is used. In meas_modelfit/src/SoftenedLinearPrior.cc debug<7> is used and only 7 is used. Because only one fine level is used in one logger, I see no reasons to use the more complicated scheme; why not convert them all to DEBUG level, they can be controlled separately through the different logger names anyway. With that said, I don't understand these science codes well enough, so it's up to you whether it is important to keep the number 8 or 7.

It's understood that the behavior of the new system is not exactly the same as the old pex_logging. If you are interested in how we reached here, you may want to read RFC-203.

I did a quick search in meas_modelfit and found 5 c++ files that use pex::logging::Debug:

• src/TruncatedGaussian.cc
  Only debug level <8> is used in a logger named "meas.modelfit.TruncatedGaussian"

• src/AdaptiveImportanceSampler.cc
  Debug level <7> and <8> are used in a logger named "meas.modelfit.AdaptiveImportanceSample". Only <8> in computeRobustWeights; only <7> in AdaptiveImportanceSampler::run.

• src/optimizer.cc
  Debug level <7> and <10> are used.

• src/integrals.cc
  Only debug level <8> is used in a logger named "meas.modelfit.integrals"

• src/SoftenedLinearPrior.cc
  Only debug level <7> is used in a logger named "meas.modelfit.SoftenedLinearPrior"

I'm not exactly sure how they are used, either. I was planning to give this the Jim to review, since I suppose that the primary usage is during debugging.

I've already done the conversion of this code to use TraceLogging, though I am not exactly sure if it was necessary. So I will probably just leave it as I've change it, and see how the review goes.

Thanks.
Perry

I substituted the lsst.log.Log.getDefaultLogger() for the lsst.pex.logging.getDefaultLog(). That appeared to be the only change required.

The two loggers are not identical in behavio r(some of the methods, such as log.debug differ). But by default they log only to the screen and are unnamed.

I do not see any calls in this package which differ between the two packages.

Changes are in tickets/DM-8356

This should be a 10 minute review

Going to steal this review for myself, since I'd like to learn about the new logger. Sorry Merlin Fisher-Levine!

I'm confused by all the discussion above about meas_modelfit, while the only changes on the ticket branch seem to be in ci_hsc. Perry Gee, can you clarify what's happening here, please?

Huh, looks like the _modelfit changes landed in DM-8357, but were discussed here. How confusing!

I think that the thread was natural enough. The discussion started up on this thread because running ci_hsc with lsst.log caused downstream failures in meas_modelfit. This conversation is referred to in 8357.

Hey Hsin-Fang Chiang —

I understood from the discussion above that it was necessary that all the dependencies of ci_hsc be converted to use pex_logging before it was possible to convert ci_hsc itself. However, I just tried running the tickets/DM-8356 branch of ci_hsc with the latest weekly (w51) of meas_modelfit which pre-dates the logging conversion, and it worked fine!

Can you explain a bit what's going on here? Do dependencies need to be converted or not? How do the logging systems interact?

Thanks!

I said it's possible (not necessary!) that dependent packages need to remove pex_logging first. From my experience, the dependency blocking sometimes happened in c++ codes; mostly it was afw and somehow I couldn't remove downstream pex_logging dependency in c++ while afw still used pex_logging. I suspected it was some SWIG thing but didn't follow through to know exactly why. If you are really curious I may go back to find an example.

On second thought, it's indeed puzzling how meas_modelfit could block ci_hsc. There seems no log passing, and after all, ci_hsc is pure python, right? I didn't try anything practical here. Maybe Perry Gee can say more what he saw?

No, it's not pure python. It runs the pipeline, which calls C++ for most of its measurement algorithms. The problem was occurring in swig I believe, though it has been weeks, and I don't really recall. I never tracked down the smoking gun, nor did I feel motivated to do so when the problem when away. But I will try to reproduce it when I have the time. I may not have been in the build and setup state I thought I was.

Change looks basically fine. Trivial comment on the PR.

As a reminder, our procedure is that the author of the code makes the PR before they submit it for review. See e.g. here.

Thanks both. I suspect that the problem Perry saw was just a coincidence, and wasn't actually related to the logging transition at all. Not worth spending more timing tracking it down.