spacetelescope / jwst

Python library for science observations from the James Webb Space Telescope
https://jwst-pipeline.readthedocs.io/en/latest/
Other
564 stars 167 forks source link

calwebb_tso3 error when saving level-2c products #2069

Closed hbushouse closed 6 years ago

hbushouse commented 6 years ago

Mike Swam reports the following error during calwebb_tso3 processing using NRS_BRIGHTOBJ exposures, using SDP 7.1.3 and Cal 0.9.3rc1:

3 cases of this same LEVEL_3 TSO failure:
e.g. /ifs/int/jwstc/store/rspencer/tests/SICDIL-Trimmed_OTIS-combined/cstring/JWSTDP-2018_1-180518/2018-05-19-020156/sdp/asn_creation/cal/level3/ jw93056-o001_20180519t045329_tso3_001_asn.json
          a 2 member TSO asn table, fails like this in LEVEL_3:
(full log):
strun /ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/jwst-0.9.3rc1-py3.5-linux-x86_64.egg/jwst/pipeline//calwebb_tso3.cfg /ifs/int/jwstc/store/rspencer/tests/SICDIL-Trimmed_OTIS-combined/cstring/JWSTDP-2018_1-180518/2018-05-19-020156/sdp/asn_creation/cal/level3/jw93056-o001_20180519t045329_tso3_001_asn.json 
2018-05-19 13:27:45,108 - stpipe.Tso3Pipeline - INFO - Tso3Pipeline instance created. 
2018-05-19 13:27:45,111 - stpipe.Tso3Pipeline.outlier_detection - INFO - OutlierDetectionStep instance created. 
2018-05-19 13:27:45,113 - stpipe.Tso3Pipeline.tso_photometry - INFO - TSOPhotometryStep instance created. 
2018-05-19 13:27:45,115 - stpipe.Tso3Pipeline.extract_1d - INFO - Extract1dStep instance created. 
2018-05-19 13:27:45,116 - stpipe.Tso3Pipeline.white_light - INFO - WhiteLightStep instance created. 
2018-05-19 13:27:45,116 - stpipe - INFO - Hostname: iljwdmscdp5.stsci.edu 
2018-05-19 13:27:45,116 - stpipe - INFO - OS: Linux 
2018-05-19 13:27:45,234 - stpipe.Tso3Pipeline - INFO - Step Tso3Pipeline running with args ('/ifs/int/jwstc/store/rspencer/tests/SICDIL-Trimmed_OTIS-combined/cstring/JWSTDP-2018_1-180518/2018-05-19-020156/sdp/asn_creation/cal/level3/jw93056-o001_20180519t045329_tso3_001_asn.json',). 
2018-05-19 13:27:52,827 - stpipe.Tso3Pipeline - INFO - Prefetching reference files for dataset: 'jw93056001001_02101_00001_nrs1_calints.fits' reftypes = ['extract1d'] 
CRDS - DEBUG - ======================================================================================================================== 
CRDS - DEBUG - getreferences() CRDS version: 7.2.3, 7.2.3, f57ce29 
CRDS - DEBUG - getreferences() server: https://jwst-serverless-mode.stsci.edu 
CRDS - DEBUG - getreferences() observatory: jwst 
CRDS - DEBUG - getreferences() reftypes: ('extract1d',) 
CRDS - DEBUG - getreferences() context: None 
CRDS - DEBUG - getreferences() ignore_cache: False 
CRDS - DEBUG - CRDS_PATH = /ifs/int/jwstc/ref/crds/cache 
CRDS - DEBUG - CRDS_SERVER_URL = https://jwst-serverless-mode.stsci.edu 
CRDS - DEBUG - Using CACHED CRDS reference assignment rules last updated on '2018-05-15 16:00:03.492657' 
CRDS - DEBUG - Using reference file selection rules 'jwst_0456.pmap' defined by cache. 
CRDS - DEBUG - Final effective context is 'jwst_0456.pmap' 
CRDS - DEBUG - Computing best references locally. 
CRDS - DEBUG - Bestrefs header: 
{'META.EXPOSURE.READPATT [READPATT]': 'NRSRAPID', 
'META.EXPOSURE.TYPE [EXP_TYPE]': 'NRS_BRIGHTOBJ', 
'META.INSTRUMENT.DETECTOR [DETECTOR]': 'NRS1', 
'META.INSTRUMENT.FILTER [FILTER]': 'F100LP', 
'META.INSTRUMENT.GRATING [GRATING]': 'G140H', 
'META.INSTRUMENT.NAME [INSTRUME]': 'NIRSPEC', 
'META.OBSERVATION.DATE [DATE-OBS]': '2016-01-23', 
'META.OBSERVATION.TIME [TIME-OBS]': '01:01:55.269', 
'META.SUBARRAY.NAME [SUBARRAY]': 'SUB2048', 
'META.SUBARRAY.XSIZE [SUBSIZE1]': '2048.0', 
'META.SUBARRAY.XSTART [SUBSTRT1]': '1.0', 
'META.SUBARRAY.YSIZE [SUBSIZE2]': '32.0', 
'META.SUBARRAY.YSTART [SUBSTRT2]': '963.0', 
'REFTYPE': 'UNDEFINED'} 
CRDS - DEBUG - READONLY CACHE skipping config update. 
CRDS - DEBUG - Reference type 'extract1d' defined as 'jwst_nirspec_extract1d_0006.json' 
2018-05-19 13:27:53,502 - stpipe.Tso3Pipeline - INFO - Prefetch for EXTRACT1D reference file is '/ifs/int/jwstc/ref/crds/cache/references/jwst/nirspec/jwst_nirspec_extract1d_0006.json'. 
2018-05-19 13:27:56,090 - stpipe.Tso3Pipeline - INFO - Prefetching reference files for dataset: 'jw93056001001_02101_00001_nrs2_calints.fits' reftypes = ['extract1d'] 
CRDS - DEBUG - ======================================================================================================================== 
CRDS - DEBUG - getreferences() CRDS version: 7.2.3, 7.2.3, f57ce29 
CRDS - DEBUG - getreferences() server: https://jwst-serverless-mode.stsci.edu 
CRDS - DEBUG - getreferences() observatory: jwst 
CRDS - DEBUG - getreferences() reftypes: ('extract1d',) 
CRDS - DEBUG - getreferences() context: None 
CRDS - DEBUG - getreferences() ignore_cache: False 
CRDS - DEBUG - CRDS_PATH = /ifs/int/jwstc/ref/crds/cache 
CRDS - DEBUG - CRDS_SERVER_URL = https://jwst-serverless-mode.stsci.edu 
CRDS - DEBUG - Final effective context is 'jwst_0456.pmap' 
CRDS - DEBUG - Computing best references locally. 
CRDS - DEBUG - Bestrefs header: 
{'META.EXPOSURE.READPATT [READPATT]': 'NRSRAPID', 
'META.EXPOSURE.TYPE [EXP_TYPE]': 'NRS_BRIGHTOBJ', 
'META.INSTRUMENT.DETECTOR [DETECTOR]': 'NRS2', 
'META.INSTRUMENT.FILTER [FILTER]': 'F100LP', 
'META.INSTRUMENT.GRATING [GRATING]': 'G140H', 
'META.INSTRUMENT.NAME [INSTRUME]': 'NIRSPEC', 
'META.OBSERVATION.DATE [DATE-OBS]': '2016-01-23', 
'META.OBSERVATION.TIME [TIME-OBS]': '01:01:54.885', 
'META.SUBARRAY.NAME [SUBARRAY]': 'SUB2048', 
'META.SUBARRAY.XSIZE [SUBSIZE1]': '2048.0', 
'META.SUBARRAY.XSTART [SUBSTRT1]': '1.0', 
'META.SUBARRAY.YSIZE [SUBSIZE2]': '32.0', 
'META.SUBARRAY.YSTART [SUBSTRT2]': '963.0', 
'REFTYPE': 'UNDEFINED'} 
CRDS - DEBUG - Reference type 'extract1d' defined as 'jwst_nirspec_extract1d_0006.json' 
2018-05-19 13:27:56,098 - stpipe.Tso3Pipeline - INFO - Prefetch for EXTRACT1D reference file is '/ifs/int/jwstc/ref/crds/cache/references/jwst/nirspec/jwst_nirspec_extract1d_0006.json'. 
2018-05-19 13:27:56,099 - stpipe.Tso3Pipeline - INFO - Starting calwebb_tso3... 
2018-05-19 13:32:35,708 - stpipe.Tso3Pipeline - INFO - Performing outlier detection on input images... 
2018-05-19 13:32:38,600 - stpipe.Tso3Pipeline.outlier_detection - INFO - Step outlier_detection running with args (<ModelContainer>,). 
2018-05-19 13:32:38,640 - stpipe.Tso3Pipeline.outlier_detection - INFO - Performing outlier detection on 600 inputs 
2018-05-19 13:33:05,998 - stpipe.Tso3Pipeline.outlier_detection - WARNING - /ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/jwst-0.9.3rc1-py3.5-linux-x86_64.egg/jwst/outlier_detection/outlier_detection.py:405: RuntimeWarning: invalid value encountered in sqrt 
ta = np.sqrt(np.abs(blot_data + subtracted_background) + err_data ** 2) 

2018-05-19 13:33:11,325 - stpipe.Tso3Pipeline.outlier_detection - INFO - Step outlier_detection done 
2018-05-19 13:37:33,432 - stpipe.Tso3Pipeline - INFO - Performing outlier detection on input images... 
2018-05-19 13:37:35,400 - stpipe.Tso3Pipeline.outlier_detection - INFO - Step outlier_detection running with args (<ModelContainer>,). 
2018-05-19 13:37:35,421 - stpipe.Tso3Pipeline.outlier_detection - INFO - Performing outlier detection on 600 inputs 
2018-05-19 13:38:19,598 - stpipe.Tso3Pipeline.outlier_detection - INFO - Step outlier_detection done 
2018-05-19 13:38:19,638 - stpipe.Tso3Pipeline - INFO - Writing Level 2c cubes with updated DQ arrays... 
Traceback (most recent call last): 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/jwst-0.9.3rc1-py3.5-linux-x86_64.egg/EGG-INFO/scripts/strun", line 14, in <module> 
step = Step.from_cmdline(sys.argv[1:]) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/jwst-0.9.3rc1-py3.5-linux-x86_64.egg/jwst/stpipe/step.py", line 157, in from_cmdline 
return cmdline.step_from_cmdline(args) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/jwst-0.9.3rc1-py3.5-linux-x86_64.egg/jwst/stpipe/cmdline.py", line 297, in step_from_cmdline 
step.run(*positional) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/jwst-0.9.3rc1-py3.5-linux-x86_64.egg/jwst/stpipe/step.py", line 391, in run 
step_result = self.process(*args) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/jwst-0.9.3rc1-py3.5-linux-x86_64.egg/jwst/pipeline/calwebb_tso3.py", line 99, in process 
asn_id=input_models.meta.asn_table.asn_id 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/jwst-0.9.3rc1-py3.5-linux-x86_64.egg/jwst/stpipe/step.py", line 739, in save_model 
**components 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/jwst-0.9.3rc1-py3.5-linux-x86_64.egg/jwst/datamodels/model_base.py", line 389, in save 
self.to_fits(output_path, *args, **kwargs) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/jwst-0.9.3rc1-py3.5-linux-x86_64.egg/jwst/datamodels/model_base.py", line 475, in to_fits 
ff.write_to(init, *args, **kwargs) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/asdf/fits_embed.py", line 360, in write_to 
use_image_hdu=use_image_hdu) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/asdf/fits_embed.py", line 347, in _update_asdf_extension 
include_block_index=False) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/asdf/asdf.py", line 1059, in write_to 
self._serial_write(fd, pad_blocks, include_block_index) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/asdf/asdf.py", line 820, in _serial_write 
self._write_tree(self._tree, fd, pad_blocks) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/asdf/asdf.py", line 781, in _write_tree 
yamlutil.dump_tree(tree, fd, self) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/asdf/yamlutil.py", line 336, in dump_tree 
tags=tags) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/yaml/__init__.py", line 188, in dump_all 
dumper.represent(data) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/yaml/representer.py", line 26, in represent 
node = self.represent_data(data) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/asdf/yamlutil.py", line 78, in represent_data 
node = super(AsdfDumper, self).represent_data(data) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/yaml/representer.py", line 47, in represent_data 
node = self.yaml_representers[data_types[0]](self, data) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/asdf/yamlutil.py", line 103, in represent_mapping 
None, mapping.data, flow_style) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/yaml/representer.py", line 116, in represent_mapping 
node_value = self.represent_data(item_value) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/asdf/yamlutil.py", line 78, in represent_data 
node = super(AsdfDumper, self).represent_data(data) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/yaml/representer.py", line 47, in represent_data 
node = self.yaml_representers[data_types[0]](self, data) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/yaml/representer.py", line 197, in represent_list 
return self.represent_sequence('tag:yaml.org,2002:seq', data) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/yaml/representer.py", line 91, in represent_sequence 
node_item = self.represent_data(item) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/asdf/yamlutil.py", line 78, in represent_data 
node = super(AsdfDumper, self).represent_data(data) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/yaml/representer.py", line 57, in represent_data 
node = self.yaml_representers[None](self, data) 
File "/ifs/int/jwstc/pipeline/pkgs/miniconda3/envs/jwstdp-0.9.3rc1-py35/lib/python3.5/site-packages/yaml/representer.py", line 229, in represent_undefined 
raise RepresenterError("cannot represent an object: %s" % data) 
yaml.representer.RepresenterError: cannot represent an object: <gwcs.extension.GWCSExtension object at 0x2ad8566b3550> 
stscieisenhamer commented 6 years ago

With current master, this works fine. Trying 0.9.2 release...

stscieisenhamer commented 6 years ago

And in 0.9.2 gives the error SDP sees. So, unless otherwise commented on, this issue has been resolved since 0.9.2.

hbushouse commented 6 years ago

But the traceback clearly indicates it came from a 0.9.3 environment, e.g. "jwstdp-0.9.3rc1-py35"

hbushouse commented 6 years ago

@stscieisenhamer Current master is not the same as the 0.9.3rc1 release. You should try it with that particular tag.

jdavies-st commented 6 years ago

This looks like some problem between that tagged release and versions of gwcs and asdf used. But of course that tag on the jwst repository doesn't know anything about gwcs or asdf versions, only the conda build package does. So is the conda build package for "jwstdp-0.9.3rc1-py35" using incorrect versions of these?

stscieisenhamer commented 6 years ago

Yep, picked the wrong release. The local install of the 0.9.3 release package reproduces the error.

Of note: using the latest condadev, BUT using the jwst 0.9.3.x tag branch, will reproduce the error also. So, its something that has changed in jwst.

Regardless: Package 0.9.3 does not work. condadev, as of today, works. Issue has been resolved, whatever that was.

OK to close?