DM-37258: Logs getting dropped in prompt processing #42
Conversation
Previously, the logger configured debug logging for prompt_prototype code but left all other loggers at the default of WARNING, causing us to miss most pipeline output. The new settings emulate pipetask without committing us to other aspects of Middleware logging that aren't necessarily appropriate for a containerized service.
These messages give us something to search for when trying to determine when, and for how long, a pod was handling a particular request. A dedicated message avoids any assumptions about what are the first or last steps in processing, which is very subject to change.
We haven't needed to debug uploading in some time, and the DEBUG messages actually make it harder to follow what the uploader is doing -- too much noise.
This change is needed to get meas_* logs handled correctly in service output. It also lets us factor out the warning redirection, which we want for all loggers.
This lets us add --log-level-style logging specifications to the prompt processing service. In daf_butler, this code is implemented by Click, so is not accessible to us.
kfindeisen
force-pushed
the
tickets/DM-37258
branch
from
0dfdf1f to
65d7479
Compare
kfindeisen
force-pushed
the
tickets/DM-37258
branch
from
65d7479 to
6278f3d
Compare
This environment variable is intended for debugging (i.e., getting more detail from a particular package). The default logging levels are what we want in normal operation.
kfindeisen
force-pushed
the
tickets/DM-37258
branch
from
6278f3d to
ae19204
Compare
| This ensures that all service output is formatted consistently, making it easier to parse. | ||
| """ | ||
| if lsst_log is not None: | ||
| lsst_log.configure_pylog_MDC("DEBUG", MDC_class=None) |
There was a problem hiding this comment.
Is what happens that the root logger gets set to DEBUG level here, and later the (None, "WARNING") in _set_lsst_logging_levels() (line 63) resets it to WARNING? So the level here doesn't really matter?
There was a problem hiding this comment.
I'll admit I cargo-culted this from daf_butler, but it's possible to change the root logging level from the envvar, and I think we'd want the log4cxx-Python bridge to work regardless.
There was a problem hiding this comment.
You need to call this to get forwarding from C++ logs to python logging. I'm pretty sure that if you set this to INFO or WARNING then you will not be able to ever get DEBUG logs out of C++ (I might be wrong on this). The explicit setting of the log level later means that using DEBUG here is not a problem.
| # Don't call CliLog.initLog because we need different formatters from what | ||
| # Butler assumes. | ||
| default_levels = [(None, "WARNING"), # De-prioritize output from 3rd-party packages. | ||
| ("lsst", "INFO"), # Capture output from Middleware and pipeline. |
There was a problem hiding this comment.
Would it make sense to set the default lsst.activator log level here?
There was a problem hiding this comment.
It would be a bit strange, since that configuration is just for the one module (and does not cover, e.g., middleware_interface). To me this kind of "system-wide" configuration feels like something different.
| This function consistently sets both the Python logger and lsst.log. | ||
| """ | ||
| # Don't call CliLog.initLog because we need different formatters from what |
There was a problem hiding this comment.
If there is demand I'm open to moving that code out of butler and into utils and allowing more configuration of things like the long log template.
There was a problem hiding this comment.
I don't think there's demand, at least not yet. Maybe once we've got a clearer picture from commissioning runs about what we actually need in the service environment.
3 participants
This PR fixes and refactors the logging configuration to better emulate the behavior expected from
pipetaskand BPS. It also adds a log level environment variable, which was requested for debugging our slow run times.