Fix logging for python 3.13.4/5 by removing delegation

[braingram]

This PR cleans up the logging to make it compatible with python 3.13.4 and 3.13.5. The main change is the removal of DelegationHandler. This class used to:

• pass root logger messages to the root stpipe logger (if no step was actively running)
• pass root logger messages to the actively running step logger (if a step was running)

This allowed handling of a few types of log messages:

• internal (generated by a stpipe logger) would be handled prior to making it to the root logger, the DelegationHandler would then not delegate these messages (to avoid infinite messages)
• external (generated by a non-stpipe logger) would upon making it to the root logger be delegated to either the stpipe root logger or active step logger

One way to look at this is that DelegationHandler was reassigning a "root" logger allowing the new "root" to handle all messages. Since this new root was configured with the stpipe configuration (from one of the documented configuration sources) this allowed the configuration to apply to all log messages. So a log message from stdatamodels would:

• go to the root logger
• be delegated to the current step logger
• be logged as per the configuration (since the step logger is a stpipe scoped logger)

With this PR abandons the delegation approach and instead applies the logging configuration to the root logger (which already has access to all log messages).

This does introduce a small change to some log messages (which I'd argue is an improvement). For example running assign wcs on main produces log messages like the following:

stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.196992189 deg

with this PR the log message is slightly changed:

jwst.assign_wcs.nirspec - INFO - gwa_ytilt is 0.196992189 deg

and importantly points to the actual logger that generated the message.

Removal of delegation also fixes: #96

While working on this it was discovered that step-specific configuration does not work (#241). This PR issues a UserWarning if a step-specific configuration is provided (one that doesn't use [*]).

This PR also includes some minor cleanup (that could be removed) including:

• removal of stpipe.log.getLogger (which is an alias of logging.getLogger)
• removeal of stpipe.log.log (which is a captured instance of the root logger)
• fixes romancal (and jwst) downstream by running them serially
• adds a few more logging tests

Romancal regtests: https://github.com/spacetelescope/RegressionTests/actions/runs/15692226613
JWST regtests: https://github.com/spacetelescope/RegressionTests/actions/runs/15692232515

A few romancal regtests fail because they are directly accessing log.delegator (which is removed by this PR). That usage is unnecessary and replaced in: spacetelescope/romancal#1804 (however currently romancal does not depend on stpipe dev so merging the romancal PR is not a requirement for this PR).

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 92.94118% with 18 lines in your changes missing coverage. Please review.
✅ Project coverage is 95.35%. Comparing base (37c74ed) to head (6af03b8).
⚠️ Report is 63 commits behind head on main.

Files with missing lines	Patch %	Lines
src/stpipe/step.py	90.42%	9 Missing ⚠️
tests/test_logger.py	96.00%	4 Missing ⚠️
src/stpipe/log.py	92.10%	3 Missing ⚠️
src/stpipe/cmdline.py	90.47%	2 Missing ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##             main     #240      +/-   ##
==========================================
+ Coverage   95.34%   95.35%   +0.01%     
==========================================
  Files          37       37              
  Lines        3414     3486      +72     
==========================================
+ Hits         3255     3324      +69     
- Misses        159      162       +3     

☔ 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.

[braingram]

The unfortunate diff here is due to the change in indentation from the removal of this try block (which was responsible for switching out the log.delegate which is no longer required).

[braingram]

I don't know why I can't request reviewers but pinging @melanieclarke @tapastro @schlafly for comments/testing/reviews.

[tapastro]

I tested this with a custom log config file and with the cal_logs attribute, just to check that both are still behaving properly. It looks good from my point of view.

[braingram]

These tests were moved to test_logger.py which has a fixture to cleanup the logging configuration.

[melanieclarke]

This looks like a reasonable alternate partial refactor for the log, if we want to make sure 3.13.4 and 3.13.5 are covered now.

I will note that it changes the behavior for the root logger, so it may surprise downstream users. For example:

import stpipe
import logging
log = logging.getLogger()
log.info('test')

will print 2025-06-17 16:17:58,159 - root - INFO - test on this branch because a stream handler is added to the root logger with level INFO when stpipe is imported. With the previous delegator solution, no message was printed.

I expect this change will probably lead to things like duplicate log messages for any stpipe user that calls any other code that adds log handlers. I know the stpipe log already interacts poorly with other packages that use logging, but this change may make it worse in some situations.

[melanieclarke]

One more note -- there is significant overlap here with #238, which also removes the delegation logging, in favor of never touching the root logger and only configuring the "stpipe" logger at the application level. This is intended to avoid unexpected issues like the above. I would personally prefer to defer log refactoring to next build, so we have time to test, agree on a solution, and make sure we're not making things worse.

[braingram]

This looks like a reasonable alternate partial refactor for the log, if we want to make sure 3.13.4 and 3.13.5 are covered now.

I will note that it changes the behavior for the root logger, so it may surprise downstream users. For example:

import stpipe
import logging
log = logging.getLogger()
log.info('test')

will print 2025-06-17 16:17:58,159 - root - INFO - test on this branch because a stream handler is added to the root logger with level INFO when stpipe is imported. With the previous delegator solution, no message was printed.

Thanks. I pushed a few commits that test the example you shared and avoid this modification (outside of where it's necessary to capture/format/display the logs).

I expect this change will probably lead to things like duplicate log messages for any stpipe user that calls any other code that adds log handlers. I know the stpipe log already interacts poorly with other packages that use logging, but this change may make it worse in some situations.

For the situation where a logger is already configured with a handler (let's say logger 'foo' has a stream handler to display to stderr) than with this PR (as on main) the log messages emitted during a run will appear twice in stderr. Isn't this the intended result from that setup? Presumably the handler added to the 'foo' logger was added to display those messages in a certain format (as is also the case for the stpipe added handler).

[melanieclarke]

Thanks for your efforts, but I would still very much prefer to wait until next build to tackle log refactoring for stpipe, rather than continuing to add complexity to the workaround here in the last few days of this build.

[braingram]

Thanks for your efforts, but I would still very much prefer to wait until next build to tackle log refactoring for stpipe, rather than continuing to add complexity to the workaround here in the last few days of this build.

No objection from me (as long as the python version is pinned in jwst). At the moment I'm in favor of this over #238

[melanieclarke]

No objection from me (as long as the python version is pinned in jwst). At the moment I'm in favor of this over #238

Understood - let's schedule a meeting to discuss offline.

[braingram]

I'm marking this as draft since pinning is the plan for this build. We can discuss these options after.

[braingram]

Re-opened for review. I haven't yet started on the corresponding jwst PR (see #240 (comment)) but that will need to go along with this.

[braingram]

Summary of logging tests using the romancal regtest suite is here: https://innerspace.stsci.edu/pages/viewpage.action?pageId=601760253

[WilliamJamieson]

These changes look good to me.

Note, I actually prefer the change in log message as it gives more information on what the message is and where it came from. It appears this DelegationHandler is just stripping information from the log and IMOP that information should not be stripped.

[braingram]

Fresh round of regtests (with default python versions)

Roman: https://github.com/spacetelescope/RegressionTests/actions/runs/16171535848
JWST: https://github.com/spacetelescope/RegressionTests/actions/runs/16171538482

all pass

[nden]

I manually tested jwst with this PR and did not see any problems.

[schlafly]

Thanks Brett!

[tapastro]

👏