test_tweakreg regression test failing

[braingram]

The test_tweakreg test is failing on main with

FileNotFoundError: [Errno 2] No such file or directory: '/srv/jenkins/workspace/RT/Roman-Developers-Pull-Requests/clone/test_outputs/popen-gw6/test_tweakreg0/r0000101001001001001_01101_0001_WFI01_tweakregstep.asdf'

During a regtest run with -k test_tweakreg -s (to show the log output).

https://plwishmaster.stsci.edu:8081/blue/organizations/jenkins/RT%2FRoman-Developers-Pull-Requests/detail/Roman-Developers-Pull-Requests/638/pipeline/245

The test_tweakreg test failed to produce the output file and there are several warning messages like the following in the log:

2024-03-08 12:55:21,774 - stpipe.TweakRegStep - WARNING - TweakRegStep cannot proceed because of an error that occurred while fetching data from the VO server. Returned error message: 'could not convert string to float: '

[SankarGaneshb]

Hello @braingram Good Morning. My son interested in Astronomy so thought of seeing any open source and got this repository. I just reviewed your comment with the error, as per that I think it could be due to the below line in the romancal/regtest/test_tweakreg.py file line # 27

rtdata.get_truth(f"truth/WFI/image/{truth_data}") it has to be like the below may help to solve this issue.

rtdata.get_truth(f"WFI/image/{truth_data}")

Thanks.

[schlafly]

I think we're passing all the regtests now. e.g.
https://plwishmaster.stsci.edu:8081/job/RT/job/romancal/1267/
I don't remember treating this case specially, but I'd propose we close?

[braingram]

Since the failure disappeared following an input file change, is it expected that tweakreg will pass (exit without errors) but produce no output for some inputs?

[schlafly]

Reviewing your log, I think you're saying that you want this failure mode
2024-03-08 12:56:43,285 - stpipe.TweakRegStep - ERROR - Cannot read catalog nonsense
to lead romancal to return an error instead of just the log message. i.e., do better error handling around here:

romancal/romancal/tweakreg/tweakreg_step.py

Line 593 in 3b1ac52

self.log.error(f"Cannot read catalog {catalog}")

That certainly sounds desirable to me but somewhat low priority as we have a good log message and aren't making any output in this case?

[braingram]

Thanks for the reply and looking into it.

I believe it was a failure to fetch gaia data that caused the step to silently fail and not produce a file.

The Cannot read catalog nonsense error appears to be coming from this test:

romancal/romancal/tweakreg/tests/test_tweakreg.py

Line 1180 in 3b1ac52

img_1.meta["tweakreg_catalog"] = "nonsense"

which did not fail in the linked run (the test passed due to the step raising an exception).

Unfortunately for the jenkins run where I provided -s to capture the log output I filtered the tests with -k test_tweakreg. So the run included many non-failing tests making the output log message difficult to assign.

I think the portion of the log that corresponds to the failed test is:

2024-03-08 12:55:21,685 - stpipe.TweakRegStep - INFO - Detected 368 sources in r0000101001001001001_01101_0001_WFI01_cal.asdf.
2024-03-08 12:55:21,685 - stpipe.TweakRegStep - INFO - 
2024-03-08 12:55:21,685 - stpipe.TweakRegStep - INFO - Number of image groups to be aligned: 1.
2024-03-08 12:55:21,685 - stpipe.TweakRegStep - INFO - Image groups:
2024-03-08 12:55:21,731 - stpipe.TweakRegStep - INFO - * Images in GROUP 'r0000101001001001001_01101_0001_WFI01_cal':
2024-03-08 12:55:21,731 - stpipe.TweakRegStep - INFO -      r0000101001001001001_01101_0001_WFI01_cal
2024-03-08 12:55:21,731 - stpipe.TweakRegStep - INFO - 
2024-03-08 12:55:21,774 - stpipe.TweakRegStep - WARNING - TweakRegStep cannot proceed because of an error that occurred while fetching data from the VO server. Returned error message: 'could not convert string to float: '''
2024-03-08 12:55:21,774 - stpipe.TweakRegStep - WARNING - Skipping 'TweakRegStep'...

With the fetching data warning coming from:

romancal/romancal/tweakreg/tweakreg_step.py

Lines 434 to 448 in 3b1ac52

	try:
	ref_cat = amutils.create_astrometric_catalog(
	images, gaia_cat_name, output=output_name
	)
	except Exception as e:
	self.log.warning(
	"TweakRegStep cannot proceed because of an error that "
	"occurred while fetching data from the VO server. "
	f"Returned error message: '{e}'"
	)
	self.log.warning("Skipping 'TweakRegStep'...")
	self.skip = True
	for model in images:
	model.meta.cal_step["tweakreg"] = "SKIPPED"
	return images

Since that sets skip = True the results are not saved (due to this check in stpipe).

To summarize, if an exception occurs during gaia data fetching tweakreg will be skipped and no output file will be created. Perhaps it would be easier to track this down (when it happens again) if the exception was re-raised instead of turned into a warning log message? This should provide a more informative traceback for pytest (which otherwise hides the log messages).

[schlafly]

Thanks Brett. Yes, I'm confused about whether the step passed or failed; I thought it was this one and it failed?

=========================== short test summary info ============================
FAILED romancal/regtest/test_tweakreg.py::test_tweakreg - FileNotFoundError: [Errno 2] No such file or directory: '/srv/jenkins/workspace/RT/Roman-Developers-Pull-Requests/clone/test_outputs/popen-gw0/test_tweakreg0/r0000101001001001001_01101_0001_WFI01_tweakregstep.asdf'
============ 1 failed, 76 passed, 25 warnings in 110.82s (0:01:50) =============

But yes, I agree that if we don't find a catalog tweakreg isn't doing something and we should fail harder than just skipping the step.

[braingram]

That's the one!

The error FileNotFoundError indicates that no output file was produced. That filename is only used for one test test_tweakreg and provided to the step as the destination via --output_file:

romancal/romancal/regtest/test_tweakreg.py

Lines 35 to 42 in 3b1ac52

	args = [
	"romancal.step.TweakRegStep",
	rtdata.input,
	f"--output_file='{rtdata.output}'",
	"--suffix='tweakregstep'",
	]
	RomanStep.from_cmdline(args)
	tweakreg_out = rdm.open(rtdata.output)

For the failing runs the test failed on the rdm.open.