Looking at persisted metric values with print_metricvalues

print_metricvalues

Science pipelines developers and users who work with measurements of metrics may be interested in a tool I added to the lsst.verify package this summer. print_metricvalues can output all of the metricvalues stored in a butler collection, sorted by their dataIds. If given two butler repos or collections, it will print out a summary of the differences between the metric values stored in those repos. This can be useful when analyzing metric changes between two runs, without needing to upload results to the SQuaRE/Chronograph dashboard.

I added this tool on DM-34865 as part of our work on the AP performance characterization sprint. It was made specifically to work with the output of running ap_verify on one of the ap_verify datasets, and I have not used it to look at other metric values in other repositories. If you find it useful, please send me feedback on how it behaves with metrics produced from sources other than ap_verify.

Example usage

Here are some examples of using this tool on a run of ap_verify on the ci_cosmos data. See the command line documentation, and the functions in lsst.verify.extract_metricvalues to use this functionality in a notebook.

These examples are all taken from ap_verify runs on the cosmos_pdr2 CI dataset. I’m very curious to see if this tool is useful for others in contexts outside of ap_verify.

Example printing all “value” metrics

$ print_metricvalues cosmos-main/repo ap_verify-output --data-id-keys detector visit

{instrument: 'HSC'}
ap_association.totalUnassociatedDiaObjects: 421.0 ct

detector: 50, visit: 59150
ap_association.numAssociatedSsObjects: 0.0 ct
ap_association.numNewDiaObjects: 268.0 ct
ap_association.numTotalSolarSystemObjects: 0.0 ct
ap_association.numUnassociatedDiaObjects: 0.0 ct
ip_diffim.fracDiaSourcesToSciSources: 0.08153331305141466
ip_diffim.numSciSources: 3287.0 ct
pipe_tasks.numDeblendedSciSources: 504.0

detector: 51, visit: 59160
ap_association.fracUpdatedDiaObjects: 0.09183673469387756
ap_association.numAssociatedSsObjects: 1.0 ct
ap_association.numNewDiaObjects: 171.0 ct
ap_association.numTotalSolarSystemObjects: 1.0 ct
ap_association.numUnassociatedDiaObjects: 178.0 ct
ip_diffim.fracDiaSourcesToSciSources: 0.05608028335301062
ip_diffim.numSciSources: 3388.0 ct
pipe_tasks.numDeblendedSciSources: 534.0

Example printing difference between two runs

$ print_metricvalues cosmos-main/repo ap_verify-output cosmos-DM-34539-fakes/repo
Showing difference of ci_cosmos-DM-34539-fakes/repo#ap_verify-output - ci_cosmos-main/repo#ap_verify-output

{instrument: 'HSC'}
ap_association.totalUnassociatedDiaObjects: 26.0 ct / 372.0 ct

{instrument: 'HSC', detector: 50, visit: 59150, ...}
ap_association.numNewDiaObjects: 21.0 ct / 242.0 ct

{instrument: 'HSC', detector: 51, visit: 59160, ...}
ap_association.fracUpdatedDiaObjects: 0.06349726775956285 / 0.07650273224043716
ap_association.numNewDiaObjects: 19.0 ct / 144.0 ct
ap_association.numUnassociatedDiaObjects: 3.0 ct / 169.0 ct
Number of metrics that are the same in both runs: 11 / 30

Example printing timing metrics

$ print_metricvalues cosmos-main/repo ap_verify-output --kind timing

{instrument: 'HSC', detector: 50, visit: 59150, ...}
ap_association.AssociationTime: 0.001145 s
ap_association.DiaForcedSourceTime: 0.3135 s
ap_association.DiaPipelineTime: 4.738 s
ap_association.LoadDiaCatalogsTime: 0.02981 s
ap_association.MapDiaSourceTime: 0.06324 s
ap_association.PackageAlertsTime: 2.544 s
ip_diffim.DipoleFitTime: 4.052 s
ip_diffim.ImagePsfMatchTime: 27.33 s
ip_isr.IsrTime: 4.782 s
meas_algorithms.SourceDetectionTime: 0.9188 s
pipe_tasks.CalibrateTime: 32.04 s
pipe_tasks.CharacterizeImageTime: 30.54 s
pipe_tasks.ImageDifferenceTime: 36.63 s

{instrument: 'HSC', detector: 51, visit: 59160, ...}
ap_association.AssociationTime: 0.004256 s
ap_association.DiaForcedSourceTime: 0.4046 s
ap_association.DiaPipelineTime: 3.514 s
ap_association.LoadDiaCatalogsTime: 0.05953 s
ap_association.MapDiaSourceTime: 0.06118 s
ap_association.PackageAlertsTime: 1.778 s
ip_diffim.DipoleFitTime: 4.267 s
ip_diffim.ImagePsfMatchTime: 27.52 s
ip_isr.IsrTime: 4.731 s
meas_algorithms.SourceDetectionTime: 0.9358 s
pipe_tasks.CalibrateTime: 36.68 s
pipe_tasks.CharacterizeImageTime: 31.88 s
pipe_tasks.ImageDifferenceTime: 36.88 s
3 Likes

This is fantastic, John! I think it will be super useful for many other contexts. I’ve just started playing around with it, but one initial comment: I was initially confused by the format of outputs when comparing two repos (in fact, I’m still not positive what it’s printing). Might be good to print a message to the screen explaining that the two values are (1) the difference (and whether its repo2-repo1, or repo1-repo2), and (2) the value in one of the repos (which one?).

I know it’s been a while since you tried this out, but I’m using it again myself and I’m tweaking the header message to hopefully make it more obvious what it’s outputting. Of course, you still have to see that header message at all, and I’m not sure what to do about making it more prominent.

This work is on branch tickets/DM-39858.

% print_metricvalues -v dc2-main/repo ap_verify-output dc2-DM-39858/repo
Printed values are `repo2 - repo1 = delta`, where:
repo2 = dc2-DM-39858/repo#None
repo1 = dc2-main/repo#ap_verify-output
delta = (dc2-DM-39858/repo#ap_verify-output) - (dc2-main/repo#ap_verify-output

{instrument: 'LSSTCam-imSim'}
ap_association.totalUnassociatedDiaObjects: 202.0 ct - 387.0 ct = 185.0 ct

{instrument: 'LSSTCam-imSim', detector: 164, visit: 982985, ...}
ap_association.fracUpdatedDiaObjects: 0.1984126984126984 - 0.24609375 = 0.0476810515873016
ap_association.numAssociatedSsObjects: 0.0 ct - 0.0 ct = 0.0 ct
ap_association.numNewDiaObjects: 70.0 ct - 145.0 ct = 75.0 ct
ap_association.numTotalSolarSystemObjects: 0.0 ct - 0.0 ct = 0.0 ct
ap_association.numUnassociatedDiaObjects: 101.0 ct - 193.0 ct = 92.0 ct
ip_diffim.fracDiaSourcesToSciSources: 0.028936947913493757 - 0.6208955223880597 = 0.5919585744745659
ip_diffim.numSciSources: 3283.0 ct - 335.0 ct = -2948.0 ct
pipe_tasks.numDeblendedSciSources: 310.0 - 0.0 = -310.0

{instrument: 'LSSTCam-imSim', detector: 168, visit: 943296, ...}
ap_association.numAssociatedSsObjects: 0.0 ct - 0.0 ct = 0.0 ct
ap_association.numNewDiaObjects: 157.0 ct - 305.0 ct = 148.0 ct
ap_association.numTotalSolarSystemObjects: 0.0 ct - 0.0 ct = 0.0 ct
ap_association.numUnassociatedDiaObjects: 0.0 ct - 0.0 ct = 0.0 ct
ip_diffim.fracDiaSourcesToSciSources: 0.06382113821138212 - 1.085409252669039 = 1.021588114457657
ip_diffim.numSciSources: 2460.0 ct - 281.0 ct = -2179.0 ct
pipe_tasks.numDeblendedSciSources: 241.0 - 0.0 = -241.0
Number of metrics that are the same in both runs: 5 / 16

???

(I’m not sure we should be using # for collection-refs at all, given that it’s already used for pipeline subsets, and that’s the meaning most people are familiar with. But I’ll admit my own preference of : is too easy to overlook.)

I swear I had a conversation with someone (quite possibly you, during the initial review, but I didn’t see it in the review comments) about what to use to separate butler location from collection in this sort of thing, but I cannot find it now. I think at the time I wrote this originally (last summer) there was some precedent for using # as that separator. I’m not wedded to it, and I agree that : is easy to miss.

The None there is a bug: I’ve just fixed that. Thanks for the catch.