Closed loerum closed 3 years ago
After updating to the latest version I also see this with AVHRR data.
Two different versions:
[DEBUG: 2020-09-28 12:36:48 : trollflow2.plugins] Publishing pytroll://ears/avhrr/image/EPSG3035 file satman@sat7-polar-ears 2020-09-28T09:36:48.645130 v1.01 application/json {"sensor": "avhrr", "platform_name": "Metop-C", "start_time": "2020-09-28T08:55:00", "end_time": "2020-09-28T09:06:00", "processing_time": "2020-09-28T08:57:28", "origin": "193.166.192.62:9104", "collection_area_id": "EPSG_3035_1km", "filename": "hrpt_metop03_20200928_0855_09822.l1b", "uri": "/home/users/satman/hrpt_metop03_20200928_0855_09822.l1b", "uid": "hrpt_metop03_20200928_0855_09822.l1b", "orbit_number": 9822, "format": "tif", "type": "Binary", "data_processing_level": "1B", "station": "helsinki", "env": "ears", "product": "overview_with_cloudtop", "area": "EPSG_3035_1km", "productname": "overview_with_cloudtop", "areaname": "EPSG3035", "area_coverage_percent": 71.84041563304172}
where also the uri
contains the l1b
file, and
[DEBUG: 2020-09-28 12:36:48 : trollflow2.plugins] Publishing pytroll://ears/avhrr/image/EPSG3035 file satman@sat7-polar-ears 2020-09-28T09:36:48.645951 v1.01 application/json {"sensor": "avhrr", "platform_name": "Metop-C", "start_time": "2020-09-28T08:55:00", "end_time": "2020-09-28T09:06:00", "processing_time": "2020-09-28T08:57:28", "origin": "193.166.192.62:9104", "collection_area_id": "EPSG_3035_1km", "filename": "hrpt_metop03_20200928_0855_09822.l1b", "uri": "/satellite/data/products/avhrr/ears/level3/EPSG3035/img/20200928_0855_Metop-C_EPSG3035_red_snow_with_colorized_ir_clouds.tif", "uid": "20200928_0855_Metop-C_EPSG3035_red_snow_with_colorized_ir_clouds.tif", "orbit_number": 9822, "format": "tif", "type": "Binary", "data_processing_level": "1B", "station": "helsinki", "env": "ears", "product": "red_snow_with_colorized_ir_clouds", "area": "EPSG_3035_1km", "productname": "red_snow_with_colorized_ir_clouds", "areaname": "EPSG3035", "area_coverage_percent": 71.84041563304172}
where only filename
has l1b
filename in it.
The most curious thing is, I haven't seen this happen with EARS/VIIRS, MSG/0deg nor MSG/RSS chains (the three other chains using current Trollflow2 version), only with EARS/AVHRR.
I'm going to try and find what happens and fix it, but I'll have time for this at earliest tomorrow.
@mraspaud made the correct question: Are the desired products actually produced?
The answer, at least in my case is: no, these are the files that were not created at all. This narrows down the bug quite a bit. I'll see if I can figure this out tomorrow morning.
Some log messages follow:
[INFO: 2020-09-28 13:24:05 : trollflow2.plugins] Skipping day_microphysical_3a_with_night_microphysical: "No dataset matching 'DataQuery(name='day_microphysical_3a_with_night_microphysical')' found"
[INFO: 2020-09-28 13:24:05 : trollflow2.plugins] Skipping day_microphysical_3b_with_night_microphysical: "No dataset matching 'DataQuery(name='day_microphysical_3b_with_night_microphysical')' found"
...
[DEBUG: 2020-09-28 13:25:51 : trollflow2.plugins] Publishing pytroll://ears/avhrr/image/EPSG3035 file satman@sat7-polar-ears 2020-09-28T10:25:51.814586 v1.01 application/json {"sensor": "avhrr", "platform_name": "Metop-B", "start_time": "2020-09-28T09:41:00", "end_time": "2020-09-28T09:54:00", "processing_time": "2020-09-28T09:44:58", "origin": "193.166.192.62:9102", "collection_area_id": "EPSG_3035_1km", "filename": "hrpt_metop01_20200928_0941_41665.l1b", "uri": "/home/users/satman/hrpt_metop01_20200928_0941_41665.l1b", "uid": "hrpt_metop01_20200928_0941_41665.l1b", "orbit_number": 41665, "format": "tif", "type": "Binary", "data_processing_level": "1B", "station": "helsinki", "env": "ears", "product": "day_microphysical_3a_with_night_microphysical", "area": "EPSG_3035_1km", "productname": "day_microphysical_3a_with_night_microphysical", "areaname": "EPSG3035", "area_coverage_percent": 76.71685899525993}
[DEBUG: 2020-09-28 13:25:51 : trollflow2.plugins] Publishing pytroll://ears/avhrr/image/EPSG3035 file satman@sat7-polar-ears 2020-09-28T10:25:51.815287 v1.01 application/json {"sensor": "avhrr", "platform_name": "Metop-B", "start_time": "2020-09-28T09:41:00", "end_time": "2020-09-28T09:54:00", "processing_time": "2020-09-28T09:44:58", "origin": "193.166.192.62:9102", "collection_area_id": "EPSG_3035_1km", "filename": "hrpt_metop01_20200928_0941_41665.l1b", "uri": "/home/users/satman/hrpt_metop01_20200928_0941_41665.l1b", "uid": "hrpt_metop01_20200928_0941_41665.l1b", "orbit_number": 41665, "format": "tif", "type": "Binary", "data_processing_level": "1B", "station": "helsinki", "env": "ears", "product": "day_microphysical_3b_with_night_microphysical", "area": "EPSG_3035_1km", "productname": "day_microphysical_3b_with_night_microphysical", "areaname": "EPSG3035", "area_coverage_percent": 76.71685899525993}
I think the product should be removed from the product list here when the (delayed) saving fails: https://github.com/pytroll/trollflow2/blob/master/trollflow2/plugins/__init__.py#L212-L213
Ok, I read that bit incorrectly. The object is added to the produced files only if it doesn't fail.
The next quess is that here the removed products are re-added when the copy of base_mda
is updated with the original product list: https://github.com/pytroll/trollflow2/blob/c8ee8da9ffd0c19870fcbb4a1fc6fa911fc65860/trollflow2/dict_tools.py#L43
It seems trollflow2.dict_tools.plist_iter()
isn't tested with any keyword arguments: https://github.com/pytroll/trollflow2/blob/master/trollflow2/tests/test_dict_tools.py#L154
Another look with fresh-ish eyes. The produced files are set here, but that bit of dictionary is never accessed in FilePublisher.create_message()
.
Another look with fresh-ish eyes. The produced files are set here, but that bit of dictionary is never accessed in FilePublisher.create_message().
And the produced_files
is a queue that is used in launcher.check_results()
to put out log messages. It's not used in checking the successful product generation before a message is sent.
I think this should be something like:
if obj None:
self._remove_product_from_job(some_arguments_here)
continue
objs.append(obj)
job['produced_files'].put(fmat_config['filename'])
Not sure what plist_iter
is doing (despite the docstring), and what's the structure of job['product_list']['product_list']
after things have been overwritten and modified by all the previous steps in the previous steps. And why are these modifications done to the original product list? Maybe a simple del
would work, but how to reference what to delete based on what plist_iter
is returning?
The missing product could be deleted from the job
based on the filename. This will require:
job['product_list']['product_list']
to avoid RuntimeError: dictionary changed size during iteration
job['product_list']['product_list']
and returns the area and product name_remove_product_from_job(job, area_name, product_name)
that does del job['product_list']['product_list']['areas'][area_name]['products'][product_name]
Scratch that. The fmat_config['filename']
is set only if the (lazy) saving was successful. But this, more direct version, should work: _remove_product_from_job(job, fmat['area'], fmat['product'])
.
I noticed that the plugins.FilePublisher once in a while is publishing the AAPP l1b file (with a weird path), fx:
"uri": "/opt/aapp8/AAPP/orbelems/hrpt_metop03_20200313_1231_06996.l1b", "uid": "hrpt_metop03_20200313_1231_06996.l1b" "product": "ir_037" "productname": "pol_ir3.7" "format": "tif"
The product pol_ir3.7 is not been produced and is been skipped in plugings.save_dataset. Could it be that skipped products are not been removed from the final product list send to plugins.FilePublisher ? It's also seen for other product, fx. cloudtop
Also, it looks hard to filter out in a trollmoves.dispatcher config file, since it has all the right tags