Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Log readable step pars #140

Merged
merged 6 commits into from
Mar 6, 2024

Conversation

jdavies-st
Copy link
Contributor

This PR makes the logging of Step or Pipeline parameters legible.

  1. Format them as hierarchical YAML, though use python types True, False and None instead of YAML types true, false and null.
  2. Only log from the top level. So if running a step, log the step parameters; if running a pipeline, log the pipeline and constituent step parameters once at the beginning.
  3. If a step is skipped, no need to log that it is "done". That's implied.

This change depends on pyyaml, but we already implicitly depend on it via asdf which pulls it in. Still the dependency is made explicit here in pyproject.toml.

Plus a small context manager cleanup in a very old test that uses StringIO. In Python 2, this did not have a context manager. It does in Python 3, so use it.

Resolves #137

@jdavies-st jdavies-st requested a review from a team as a code owner February 12, 2024 10:02
Copy link

codecov bot commented Feb 12, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 59.33%. Comparing base (f9411a9) to head (e747142).
Report is 2 commits behind head on main.

Additional details and impacted files
@@            Coverage Diff             @@
##             main     #140      +/-   ##
==========================================
+ Coverage   59.25%   59.33%   +0.07%     
==========================================
  Files          24       24              
  Lines        1615     1618       +3     
==========================================
+ Hits          957      960       +3     
  Misses        658      658              

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

@jdavies-st
Copy link
Contributor Author

The resulting log when running JWST calwebb_detector1 now:

$ strun calwebb_detector1 jw01345002001_14201_00003_nrcalong_uncal.fits --steps.persistence.skip true
2024-02-12 10:57:14,226 - stpipe - INFO - PARS-JUMPSTEP parameters found: /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_pars-jumpstep_0002.asdf
2024-02-12 10:57:14,231 - stpipe - INFO - PARS-DETECTOR1PIPELINE parameters found: /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_pars-detector1pipeline_0002.asdf
2024-02-12 10:57:14,238 - stpipe.Detector1Pipeline - INFO - Detector1Pipeline instance created.
2024-02-12 10:57:14,238 - stpipe.Detector1Pipeline.group_scale - INFO - GroupScaleStep instance created.
2024-02-12 10:57:14,239 - stpipe.Detector1Pipeline.dq_init - INFO - DQInitStep instance created.
2024-02-12 10:57:14,239 - stpipe.Detector1Pipeline.emicorr - INFO - EmiCorrStep instance created.
2024-02-12 10:57:14,239 - stpipe.Detector1Pipeline.saturation - INFO - SaturationStep instance created.
2024-02-12 10:57:14,239 - stpipe.Detector1Pipeline.ipc - INFO - IPCStep instance created.
2024-02-12 10:57:14,240 - stpipe.Detector1Pipeline.superbias - INFO - SuperBiasStep instance created.
2024-02-12 10:57:14,240 - stpipe.Detector1Pipeline.refpix - INFO - RefPixStep instance created.
2024-02-12 10:57:14,240 - stpipe.Detector1Pipeline.rscd - INFO - RscdStep instance created.
2024-02-12 10:57:14,240 - stpipe.Detector1Pipeline.firstframe - INFO - FirstFrameStep instance created.
2024-02-12 10:57:14,240 - stpipe.Detector1Pipeline.lastframe - INFO - LastFrameStep instance created.
2024-02-12 10:57:14,241 - stpipe.Detector1Pipeline.linearity - INFO - LinearityStep instance created.
2024-02-12 10:57:14,241 - stpipe.Detector1Pipeline.dark_current - INFO - DarkCurrentStep instance created.
2024-02-12 10:57:14,241 - stpipe.Detector1Pipeline.reset - INFO - ResetStep instance created.
2024-02-12 10:57:14,241 - stpipe.Detector1Pipeline.persistence - INFO - PersistenceStep instance created.
2024-02-12 10:57:14,241 - stpipe.Detector1Pipeline.charge_migration - INFO - ChargeMigrationStep instance created.
2024-02-12 10:57:14,242 - stpipe.Detector1Pipeline.jump - INFO - JumpStep instance created.
2024-02-12 10:57:14,242 - stpipe.Detector1Pipeline.ramp_fit - INFO - RampFitStep instance created.
2024-02-12 10:57:14,242 - stpipe.Detector1Pipeline.gain_scale - INFO - GainScaleStep instance created.
2024-02-12 10:57:14,279 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline parameters are: 
pre_hooks: []
post_hooks: []
output_file: None
output_dir: None
output_ext: .fits
output_use_model: False
output_use_index: True
save_results: True
skip: False
suffix: None
search_output_file: True
input_dir: ''
save_calibrated_ramp: False
steps:
  group_scale:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
  dq_init:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
  emicorr:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: True
    suffix: None
    search_output_file: True
    input_dir: ''
    save_intermediate_results: False
    user_supplied_reffile: None
    nints_to_phase: None
    nbins: None
    scale_reference: True
  saturation:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
    n_pix_grow_sat: 1
  ipc:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: True
    suffix: None
    search_output_file: True
    input_dir: ''
  superbias:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
  refpix:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
    odd_even_columns: True
    use_side_ref_pixels: True
    side_smoothing_length: 11
    side_gain: 1.0
    odd_even_rows: True
    ovr_corr_mitigation_ftr: 3.0
  rscd:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
    type: baseline
  firstframe:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
  lastframe:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
  linearity:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
  dark_current:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
    dark_output: None
  reset:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
  persistence:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: True
    suffix: None
    search_output_file: True
    input_dir: ''
    input_trapsfilled: ''
    flag_pers_cutoff: 40.0
    save_persistence: False
    save_trapsfilled: True
  charge_migration:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: True
    suffix: None
    search_output_file: True
    input_dir: ''
    signal_threshold: 25000.0
  jump:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
    rejection_threshold: 4.0
    three_group_rejection_threshold: 6.0
    four_group_rejection_threshold: 5.0
    maximum_cores: '1'
    flag_4_neighbors: True
    max_jump_to_flag_neighbors: 1000.0
    min_jump_to_flag_neighbors: 10.0
    after_jump_flag_dn1: 1000
    after_jump_flag_time1: 90
    after_jump_flag_dn2: 0
    after_jump_flag_time2: 0
    expand_large_events: False
    min_sat_area: 1
    min_jump_area: 5
    expand_factor: 2.0
    use_ellipses: False
    sat_required_snowball: True
    min_sat_radius_extend: 2.5
    sat_expand: 2
    edge_size: 25
    find_showers: False
    extend_snr_threshold: 1.2
    extend_min_area: 90
    extend_inner_radius: 1.0
    extend_outer_radius: 2.6
    extend_ellipse_expand_ratio: 1.1
    time_masked_after_shower: 15.0
    max_extended_radius: 200
    minimum_groups: 3
    minimum_sigclip_groups: 100
    only_use_ints: True
  ramp_fit:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
    int_name: ''
    save_opt: False
    opt_name: ''
    suppress_one_group: True
    maximum_cores: '1'
  gain_scale:
    pre_hooks: []
    post_hooks: []
    output_file: None
    output_dir: None
    output_ext: .fits
    output_use_model: False
    output_use_index: True
    save_results: False
    skip: False
    suffix: None
    search_output_file: True
    input_dir: ''
2024-02-12 10:57:14,392 - stpipe.Detector1Pipeline - INFO - Prefetching reference files for dataset: 'jw01345002001_14201_00003_nrcalong_uncal.fits' reftypes = ['dark', 'gain', 'linearity', 'mask', 'readnoise', 'refpix', 'reset', 'rscd', 'saturation', 'superbias']
2024-02-12 10:57:14,393 - stpipe.Detector1Pipeline - INFO - Prefetch for DARK reference file is '/Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_dark_0424.fits'.
2024-02-12 10:57:14,393 - stpipe.Detector1Pipeline - INFO - Prefetch for GAIN reference file is '/Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_gain_0097.fits'.
2024-02-12 10:57:14,393 - stpipe.Detector1Pipeline - INFO - Prefetch for LINEARITY reference file is '/Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_linearity_0052.fits'.
2024-02-12 10:57:14,393 - stpipe.Detector1Pipeline - INFO - Prefetch for MASK reference file is '/Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_mask_0063.fits'.
2024-02-12 10:57:14,393 - stpipe.Detector1Pipeline - INFO - Prefetch for READNOISE reference file is '/Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_readnoise_0266.fits'.
2024-02-12 10:57:14,393 - stpipe.Detector1Pipeline - INFO - Prefetch for REFPIX reference file is 'N/A'.
2024-02-12 10:57:14,393 - stpipe.Detector1Pipeline - INFO - Prefetch for RESET reference file is 'N/A'.
2024-02-12 10:57:14,393 - stpipe.Detector1Pipeline - INFO - Prefetch for RSCD reference file is 'N/A'.
2024-02-12 10:57:14,393 - stpipe.Detector1Pipeline - INFO - Prefetch for SATURATION reference file is '/Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_saturation_0097.fits'.
2024-02-12 10:57:14,393 - stpipe.Detector1Pipeline - INFO - Prefetch for SUPERBIAS reference file is '/Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_superbias_0220.fits'.
2024-02-12 10:57:14,394 - stpipe.Detector1Pipeline - INFO - Starting calwebb_detector1 ...
2024-02-12 10:57:14,654 - stpipe.Detector1Pipeline.group_scale - INFO - NFRAMES and FRMDIVSR are equal; correction not needed
2024-02-12 10:57:14,654 - stpipe.Detector1Pipeline.group_scale - INFO - Step will be skipped
2024-02-12 10:57:14,655 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale done
2024-02-12 10:57:14,698 - stpipe.Detector1Pipeline.dq_init - INFO - Using MASK reference file /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_mask_0063.fits
2024-02-12 10:57:14,862 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init done
2024-02-12 10:57:14,907 - stpipe.Detector1Pipeline.saturation - INFO - Using SATURATION reference file /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_saturation_0097.fits
2024-02-12 10:57:15,567 - stpipe.Detector1Pipeline.saturation - INFO - Detected 4022 saturated pixels
2024-02-12 10:57:15,577 - stpipe.Detector1Pipeline.saturation - INFO - Detected 0 A/D floor pixels
2024-02-12 10:57:15,586 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation done
2024-02-12 10:57:15,623 - stpipe.Detector1Pipeline.ipc - INFO - Step skipped.
2024-02-12 10:57:15,658 - stpipe.Detector1Pipeline.superbias - INFO - Using SUPERBIAS reference file /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_superbias_0220.fits
2024-02-12 10:57:15,808 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias done
2024-02-12 10:57:15,888 - stpipe.Detector1Pipeline.refpix - INFO - NIR full frame data
2024-02-12 10:57:15,888 - stpipe.Detector1Pipeline.refpix - INFO - The following parameters are valid for this mode:
2024-02-12 10:57:15,888 - stpipe.Detector1Pipeline.refpix - INFO - use_side_ref_pixels = True
2024-02-12 10:57:15,888 - stpipe.Detector1Pipeline.refpix - INFO - odd_even_columns = True
2024-02-12 10:57:15,888 - stpipe.Detector1Pipeline.refpix - INFO - side_smoothing_length = 11
2024-02-12 10:57:15,888 - stpipe.Detector1Pipeline.refpix - INFO - side_gain = 1.0
2024-02-12 10:57:15,888 - stpipe.Detector1Pipeline.refpix - INFO - The following parameter is not applicable and is ignored:
2024-02-12 10:57:15,888 - stpipe.Detector1Pipeline.refpix - INFO - odd_even_rows = False
2024-02-12 10:57:16,700 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix done
2024-02-12 10:57:16,741 - stpipe.Detector1Pipeline.linearity - INFO - Using Linearity reference file /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_linearity_0052.fits
2024-02-12 10:57:17,345 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity done
2024-02-12 10:57:17,384 - stpipe.Detector1Pipeline.persistence - INFO - Step skipped.
2024-02-12 10:57:17,425 - stpipe.Detector1Pipeline.dark_current - INFO - Using DARK reference file /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_dark_0424.fits
2024-02-12 10:57:18,865 - stpipe.Detector1Pipeline.dark_current - INFO - Science data nints=1, ngroups=9, nframes=8, groupgap=2
2024-02-12 10:57:18,869 - stpipe.Detector1Pipeline.dark_current - INFO - Dark data nints=1, ngroups=130, nframes=1, groupgap=0
2024-02-12 10:57:20,269 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current done
2024-02-12 10:57:20,329 - stpipe.Detector1Pipeline.charge_migration - INFO - Step skipped.
2024-02-12 10:57:20,359 - stpipe.Detector1Pipeline.jump - INFO - CR rejection threshold = 4 sigma
2024-02-12 10:57:20,359 - stpipe.Detector1Pipeline.jump - INFO - Maximum cores to use = 1
2024-02-12 10:57:20,365 - stpipe.Detector1Pipeline.jump - INFO - Using GAIN reference file: /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_gain_0097.fits
2024-02-12 10:57:20,385 - stpipe.Detector1Pipeline.jump - INFO - Using READNOISE reference file: /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_readnoise_0266.fits
2024-02-12 10:57:20,488 - stpipe.Detector1Pipeline.jump - INFO - Executing two-point difference method
2024-02-12 10:57:43,325 - stpipe.Detector1Pipeline.jump - INFO - Step jump done
2024-02-12 10:57:43,372 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using READNOISE reference file: /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_readnoise_0266.fits
2024-02-12 10:57:43,372 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using GAIN reference file: /Users/jdavies/crds_cache/jwst_ops/references/jwst/nircam/jwst_nircam_gain_0097.fits
2024-02-12 10:57:43,395 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using algorithm = ols
2024-02-12 10:57:43,395 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using weighting = optimal
2024-02-12 10:58:01,005 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of groups per integration: 9
2024-02-12 10:58:01,005 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of integrations: 1
2024-02-12 10:58:01,195 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit done
2024-02-12 10:58:01,254 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2024-02-12 10:58:01,254 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2024-02-12 10:58:01,256 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2024-02-12 10:58:01,307 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2024-02-12 10:58:01,307 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2024-02-12 10:58:01,309 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2024-02-12 10:58:01,382 - stpipe.Detector1Pipeline - INFO - Saved model in jw01345002001_14201_00003_nrcalong_rateints.fits
2024-02-12 10:58:01,382 - stpipe.Detector1Pipeline - INFO - ... ending calwebb_detector1
2024-02-12 10:58:01,384 - stpipe.Detector1Pipeline - INFO - Results used CRDS context: jwst_1193.pmap
2024-02-12 10:58:01,431 - stpipe.Detector1Pipeline - INFO - Saved model in jw01345002001_14201_00003_nrcalong_rate.fits
2024-02-12 10:58:01,431 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline done

@jdavies-st jdavies-st force-pushed the log-readable-step-pars branch from bc3b861 to b191918 Compare February 22, 2024 12:53
@nden
Copy link
Collaborator

nden commented Feb 27, 2024

This looks readable now. Perhaps print pre_hooks and post_hooks only if they are not empty (I wonder if the check will noticeably slow things down, probably not). Otherwise it's very repetitive.

@perrygreenfield
Copy link
Collaborator

Much needed in my opinion.

@hbushouse
Copy link
Collaborator

Looks good. Some of it does get a bit repetitive (all the params that are common to all steps), but not sure how we could about intelligently fixing that.

@jdavies-st
Copy link
Contributor Author

Yeah, it's very repetitive on all the common Step parameters, including pre- and post-hooks, and including input_dir, output_dir, output_ext, etc. That said, I don't think we want to remove those as otherwise the spec is not complete.

We could conditionally print them out if they are different from the default? Thoughts?

That said, it might be worth revisiting what things should be user-settable via spec (and checked, and printed in the log) vs just a standard class variable that is inherited from Step. For example, I don't think the user will ever want to customize output_ext, but a step might want to. Same with output_use_model, output_use_index and search_output_file. Users don't modify these, but they are modified by developers in subclasses of Step, so maybe these should be class variables that are set in the subclass and not part of the spec. Thoughts?

For example, output_use_model should always be true for a Step subclass that takes an association with N members as input and outputs N members as output. But that's a class behavior, not a user-settable behavior. There's no reason a user would ever want to change output_use_model in a class, unless it was improperly set in the class to begin with.

So worth revisiting in a separate issue or PR, but perhaps not here.

@jdavies-st jdavies-st force-pushed the log-readable-step-pars branch from b191918 to e3c8fba Compare February 28, 2024 11:44
@nden
Copy link
Collaborator

nden commented Feb 28, 2024

We could conditionally print them out if they are different from the default? Thoughts?

👍

@hbushouse
Copy link
Collaborator

We could conditionally print them out if they are different from the default? Thoughts?

IMHO, I'm not sure that's a good thing, especially for steps like jump or tweakreg or resample, where there are lots of keywords normally set to defaults, but those defaults are not something benign like None or a null string, they're a real value of some kind. I think those are valuable to see, otherwise you have to go look up what the default values are for all the params that did not get printed.

I agree that we could potentially omit ones like pre_hook, post_hook, suffix, search_output_file, output_use_model, etc. when they have a null default value and are never actually used by users (I'm not sure what half of them even do!).

@jdavies-st
Copy link
Contributor Author

How about we decide what in spec to cull from printing, if anything, in a future PR?

There's a couple downstream test failures in jwst because the tests capture the log and now the log has changed, specifically " are printed as ' now, so these tests should be updated to be less fragile. Will do in a PR in jwst, which can be merged before this one. Will link here.

@hbushouse
Copy link
Collaborator

Making tweaks in another PR is fine with me. Let's at least get the major formatting change from this ticket merged.

@braingram
Copy link
Collaborator

One question/suggestion/comment. If outputting the config in yaml, any reason to not keep true false null so that the output is copy and paste-able in a valid format? Alternatively, the pretty print output (although a bit less pleasing on the eyes) would be compatible with jupyter/ipython and keep True False None.

@jdavies-st
Copy link
Contributor Author

One question/suggestion/comment. If outputting the config in yaml, any reason to not keep true false null so that the output is copy and paste-able in a valid format?

Only the written ASDF config file actually contains the yaml. But generally one shouldn't be cut-and-pasting to make these, and there's a method for writing ASDF config files out already. If one wants to cut-and-paste, it's usually in a python script or notebook, so as you point out it's good to have python types. And the pprint format is ugly enough to prefer the yaml, I think. See the issue for the comparison.

@perrygreenfield
Copy link
Collaborator

I haven't looked at the code, but is it hard to keep a stack of the parameters, and when printing just print ones have changed relative to the level above?

@jdavies-st
Copy link
Contributor Author

jdavies-st commented Feb 29, 2024

@perrygreenfield parameters are always set at the beginning of a step or pipeline (which has steps) and don't change, but pipelines have steps and each step can set all the standard parameters. Most are not set differently from default, but occasionally they are. Longer log, but perhaps more readable. On balance, because we are not repetitively printing out the parameters at each pipeline step (just the whole pipeline at the beginning), the logs will actually be a bit shorter.

Agree that it would be nice to give users useful information instead of repetitive, content-free information. We can think about improvements in a future PR.

Btw, I added a commit to add back the running with args log message:

2024-02-29 10:51:20,303 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline running with args ('jw01345002001_14201_00001_nrcblong_uncal.fits',).

Excluding it was causing 3 downstream tests in jwst to fail. Those should now pass - no need for a PR in jwst. Correction, one test needs an update. And it is actually useful seeing what the args are passed to each step or pipeline.

@jdavies-st
Copy link
Contributor Author

jdavies-st commented Feb 29, 2024

spacetelescope/jwst#8317 should be merged before this is merged. This fixes the failing downstream test in jwst that is fragile to log Step.spec formatting.

@jdavies-st jdavies-st force-pushed the log-readable-step-pars branch from 7200a6a to e747142 Compare February 29, 2024 22:27
@jdavies-st
Copy link
Contributor Author

The one downstream test fix in jwst is now merged, so this is ready for 🚀

@braingram
Copy link
Collaborator

@braingram
Copy link
Collaborator

romancal regtests showed no errors
jwst regtests showed the 2 usual msa log message errors:
jwst.regtest.test_nirspec_exceptions.[stable-deps] test_nirspec_missing_msa_fail
jwst.regtest.test_nirspec_exceptions.[stable-deps] test_nirspec_missing_msa_nofail

I believe the above errors are unrelated to the logging changes in this PR.

@schlafly would you like to weigh in as this will impact romancal?

@schlafly
Copy link

schlafly commented Mar 6, 2024

I'm happy. @ddavis-stsci , do you want to weigh in here?

@ddavis-stsci
Copy link
Collaborator

I'm fine with this. I certainly makes the output more readable!

@braingram braingram merged commit a8cca6c into spacetelescope:main Mar 6, 2024
16 checks passed
@jdavies-st jdavies-st deleted the log-readable-step-pars branch March 7, 2024 09:27
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Formatting of Step parameters in log should be readable
7 participants