WIP: Refactor stpipe logging

[melanieclarke]

Resolves JP-1866
Resolves JP-4008
Resolves RCAL-nnnn

Draft proposal to simplify and consolidate logging under a single "stpipe" root logger.

This will need discussion and coordination across romancal and jwst teams, as it is currently a breaking change. To demonstrate the changes needed, I filed draft PRs for jwst, stdatamodels, and stcal here:
spacetelescope/jwst#9547
spacetelescope/stdatamodels#499
spacetelescope/stcal#377

If we like this proposal, these repositories will also need similar changes before this PR can be merged:
romancal
roman_datamodels

Note:

I intended this PR to be a platform for discussion for the logging refactor, but there are a couple other concurrent ideas about logging and it’s not clear at this point if the work will continue here or elsewhere.

In case it helps the discussion or future work, these are the design principles I was working toward here.

Goal: align ST calibration pipeline logging with Python best practices
Principles:

• Nothing happens on import other than getting a logger by name
  • To address this, the delegation logging needs to be removed from stpipe.
  • Downstream packages should not use setLevel or addHandler after getting a logger by name.
• Log handlers are only added at the application level.
  • For stpipe, this means handlers should only be added in the command line script.
  • Since this would be a surprising change to users, INS requests that a stream handler is also optionally added in the call function. It should be removed when the call process is complete.
• Users should be able to configure logging for calibration in their Python code using only the standard logging module.
  • For stpipe, this means removing the logcfg arguments to command line and call/run.
  • For the call function, the default option to add a stream handler should not override any previous configuration set by the user.
• Users should be able to easily configure the log from the command line script.
  • For stpipe, replace the logcfg file with simpler command line arguments to control the log level and format and optionally write to a log file.
• Remove the self.log anti-pattern.
  • In stpipe, remove the step.log attribute.
  • In downstream packages, use getLogger to get logs by name and log to them instead of self.log.
• Don’t add handlers to the root logger.
  • In stpipe, this is also addressed by removing the delegation logging.
  • In downstream packages, always use loggers that start with a known parent name so that stpipe can manage their configuration.
• Preferably provide a single entry point for configuring the log for all packages in the ST system.
  • In downstream packages, log all messages to loggers that start with the name “stpipe”.

The last principle I think is optional, but I felt would be nice for maximum utility to users. If all cal packages agree to log to the same parent log name, then all a user needs to do to configure all logs from all our complex interdependent packages is to set it up once on the "stpipe" parent log. If it is objectionable to log to an stpipe logger from a non-stpipe package, we could all agree on a different parent name, e.g. "stlog" – the actual name of the log is arbitrary. Alternately, if we do not want to have all packages log to the same logger, we could also consider white-listing known log names, either through entry points or some other configuration local to the jwst and romancal packages, so that stpipe knows which ones it should handle. The option implemented here is currently the simplest one: stpipe configures only one log, called "stpipe".

Tasks

• update or add relevant tests
• update relevant docstrings and / or docs/ page
• Does this PR change any API used downstream? (if not, label with no-changelog-entry-needed)
  • write news fragment(s) in changes/: echo "changed something" > changes/<PR#>.<changetype>.rst (see below for change types)
  • run regression tests with this branch installed ("git+https://github.com/<fork>/stpipe@<branch>")
    • jwst regression test
    • romancal regression test

news fragment change types...

• changes/<PR#>.feature.rst: new feature
• changes/<PR#>.bugfix.rst: fixes an issue
• changes/<PR#>.doc.rst: documentation change
• changes/<PR#>.removal.rst: deprecation or removal of public API
• changes/<PR#>.misc.rst: infrastructure or miscellaneous change

[codecov]

Codecov Report

❌ Patch coverage is 87.77293% with 28 lines in your changes missing coverage. Please review.
✅ Project coverage is 93.64%. Comparing base (37c74ed) to head (f678d58).
⚠️ Report is 66 commits behind head on main.

Files with missing lines	Patch %	Lines
src/stpipe/cmdline.py	60.52%	15 Missing ⚠️
src/stpipe/step.py	93.75%	7 Missing ⚠️
src/stpipe/log_config.py	93.33%	3 Missing ⚠️
src/stpipe/pipeline.py	91.66%	1 Missing ⚠️
src/stpipe/subproc.py	85.71%	1 Missing ⚠️
tests/test_step.py	80.00%	1 Missing ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##             main     #238      +/-   ##
==========================================
- Coverage   95.34%   93.64%   -1.71%     
==========================================
  Files          37       37              
  Lines        3414     3271     -143     
==========================================
- Hits         3255     3063     -192     
- Misses        159      208      +49     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

[melanieclarke]

I will close this prototype PR to start fresh from the current state in stpipe, following the merge of #240.

From various discussions, it sounds like there is a strong desire to make sure the standard convention of getting a local logger with logging.getLogger(__name__) continues to work in the downstream packages. In the next prototype, I'll look into whitelisting expected loggers instead of configuring only one log.

There is also significant concern about the impact on downstream packages, so I will prioritize incremental improvements and appropriate deprecations in the next version.