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

Preload (FCI) filehandlers for eager processing #2686

Open
wants to merge 39 commits into
base: main
Choose a base branch
from

Conversation

gerritholl
Copy link
Collaborator

@gerritholl gerritholl commented Dec 12, 2023

Add functionality to preload filehandlers for files that have not yet arrived on disk. This works by passing a single file (the first chunk) and then it will generate glob patterns for all remaining chunks.

It seems to work for loading only FDHSI data.

Deferred: support for mixing FDHSI and HRFI. This PR is ambitious enough as it is, and I would like to postpone that complication to a later PR.

Remaining problem: segmentation faults due to different dask workers simultaneously opening the same file.

First beginning of work to preload filehandlers before files are
present.  Not much implementation yet, just a skeleton on what it might
look like in the YAMLReader.
Copy link

codecov bot commented Dec 12, 2023

Codecov Report

Attention: 4 lines in your changes are missing coverage. Please review.

Comparison is base (4e85a8f) 95.88% compared to head (fd4b225) 95.94%.
Report is 78 commits behind head on main.

Files Patch % Lines
satpy/tests/reader_tests/test_netcdf_utils.py 98.63% 2 Missing ⚠️
satpy/readers/netcdf_utils.py 99.09% 1 Missing ⚠️
satpy/readers/yaml_reader.py 98.55% 1 Missing ⚠️
Additional details and impacted files
@@            Coverage Diff             @@
##             main    #2686      +/-   ##
==========================================
+ Coverage   95.88%   95.94%   +0.05%     
==========================================
  Files         371      373       +2     
  Lines       52835    53430     +595     
==========================================
+ Hits        50663    51265     +602     
+ Misses       2172     2165       -7     
Flag Coverage Δ
behaviourtests 4.13% <2.97%> (-0.03%) ⬇️
unittests 96.04% <99.14%> (+0.05%) ⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

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

@coveralls
Copy link

coveralls commented Dec 12, 2023

Pull Request Test Coverage Report for Build 7933498151

Warning: This coverage report may be inaccurate.

This pull request's base commit is no longer the HEAD commit of its target branch. This means it includes changes from outside the original pull request, including, potentially, unrelated coverage changes.

Details

  • -4 of 470 (99.15%) changed or added relevant lines in 7 files are covered.
  • No unchanged relevant lines lost coverage.
  • Overall first build on preload-scene-dask-delayed at 96.027%

Changes Missing Coverage Covered Lines Changed/Added Lines %
satpy/readers/netcdf_utils.py 109 110 99.09%
satpy/readers/yaml_reader.py 68 69 98.55%
satpy/tests/reader_tests/test_netcdf_utils.py 144 146 98.63%
Totals Coverage Status
Change from base Build 7801990864: 96.0%
Covered Lines: 51137
Relevant Lines: 53253

💛 - Coveralls

Prepare GeoSegmentYAMLReader for preloading filehandlers for files
corresponding to segments that don't exist yet.  Early draft
implementation that appears to work with limitations.  Implementation in
GEOSegmentYAMLReader still needs tweaking, tests need to be improved,
and the corresponding file handler (for now just FCI) needs to be able
to handle it.
Continue the pre-loading implementation in the GEOSegmentedYAMLReader.
Add unit tests.
Don't raise an error that we can't predict the remaining files if this
functionality was not requested.
Add a Preloadable class to netcdf_utils.  This so far implements
pre-loading filehandlers for to-be-expected files if a single one
already exists, taking a defined set of data variables and their
attributes from the first segment.  Still to be implemented is to take
other information from other repeat cycles, by on-disk caching.
Cache data variables between repeat cycles.
Continue working on repeat-cycle caching.
@gerritholl
Copy link
Collaborator Author

The good news is that my test script now passes without errors.

The bad news is that the resulting image has no data / is all black.

@gerritholl
Copy link
Collaborator Author

sc._readers["fci_l1c_nc"].file_handlers["fci_l1c_fdhsi"][27]["data/ir_105/measured/effective_radiance"][149, 5233].compute() shows valid values, but in the scene it's all NaN... ;·(

Copy link
Member

@djhoese djhoese left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Side request as mentioned on slack: Move the "does NetCDF file exist" functionality to its own function that is Delayed. Hold on to the result of this in your file handler(s). Pass the result of that (the filename I think) to the _get_delayed_value function which is also delayed, and then go on as you are. This way the globbing and sleeping only has to happen once.

@gerritholl
Copy link
Collaborator Author

gerritholl commented Dec 18, 2023

There is something wrong with the values and the calibration. For one test case, for one pixel, loading counts gives array(93.51871, dtype=float32), loading radiance gives array(-5.7980175, dtype=float32), and loading brightness_temperature gives NaN (unsurprising with such radiances). Maybe calibration is applied twice? To be investigated.

@gerritholl
Copy link
Collaborator Author

The bug with the wrong values was because automaskandscale was being applied automatically by the NetCDF library. After unsetting this, the values seem to match with the reference.

This image was created while scene creation, loading, and creating the resampling graph happening before accessing any data:

MTG-I1-fci-202312040810-eurol-airmass-test-preloaded

Processing took 28.4 seconds, took 1.89 GB RAM, and used 121% CPU.

Classical processing took 19.0 seconds, took 2.03 GB RAM, and used 73% CPU.

Now that it's functional, I will work on adding tests and improving the implementation.

@mraspaud
Copy link
Member

Very nice! How long did it take after the last segment had "arrived"?

Split the delayed loading from file into one delayed function that waits
for the file and another that loads a variable from the file.
Add tests for the functionality to wait for a file to appear in a
delayed object.
Add a test method to test getting a delayed value from a (delayed) file
PRogress un nit tests fol the puproses of delayed olading
@gerritholl
Copy link
Collaborator Author

gerritholl commented Dec 18, 2023

Very nice! How long did it take after the last segment had "arrived"?

I haven't done a full test including a realistic simulation of delayed segment arrival yet. But when I skip computing, it takes 19 seconds with 421 MB RAM.

Add more tests for the preloadable mixin in netcdf_utils.  Cleanup some
unused code and add checks/guards in this mixin.
Improve tests for the yaml reader in case of preloading file handlers.
Tests fail.
Improve the tests for the YAML reader and the NetCDF utils.  Tolerate
absence of time_tags and variable_tags for preloadables.  Verify
presence of required_netcdf_filehandlers on creation rather than on
caching time.
Using datetime.min for an artificial date leads to different strftime
results between platforms (see https://bugs.python.org/msg307401).
Use datetime.max instead.
Simplify _new_filehandler_instances.  Hopefully this will satisfy
codescene.

Replace "/dev/null" by os.devnull for cross-platform support.
In test waiting for file to appear, wait longer.  Maybe this will fix
the "file not found" on 3.11 problem.
@gerritholl
Copy link
Collaborator Author

Using this "in the wild" I get HDF5 errors and segmentation faults after files appear. Maybe too many open files (the old problem).

HDF5-DIAG: Error detected in HDF5 (1.12.2) thread 1:
  #000: H5A.c line 528 in H5Aopen_by_name(): can't open attribute
    major: Attribute
    minor: Can't open object
  #001: H5VLcallback.c line 1091 in H5VL_attr_open(): attribute open failed
    major: Virtual Object Layer
    minor: Can't open object
  #002: H5VLcallback.c line 1058 in H5VL__attr_open(): attribute open failed
    major: Virtual Object Layer
    minor: Can't open object
  #003: H5VLnative_attr.c line 130 in H5VL__native_attr_open(): can't open attribute
    major: Attribute
    minor: Can't open object
  #004: H5Aint.c line 545 in H5A__open_by_name(): unable to load attribute info from object header
    major: Attribute
    minor: Unable to initialize object
  #005: H5Oattribute.c line 494 in H5O__attr_open_by_name(): can't locate attribute: '_QuantizeBitGroomNumberOfSignificantDigits'
    major: Attribute
    minor: Object not found
HDF5-DIAG: Error detected in HDF5 (1.12.2) thread 1:
  #000: H5A.c line 528 in H5Aopen_by_name(): can't open attribute
    major: Attribute
    minor: Can't open object
  #001: H5VLcallback.c line 1091 in H5VL_attr_open(): attribute open failed
    major: Virtual Object Layer
    minor: Can't open object
  #002: H5VLcallback.c line 1058 in H5VL__attr_open(): attribute open failed
    major: Virtual Object Layer
    minor: Can't open object
  #003: H5VLnative_attr.c line 130 in H5VL__native_attr_open(): can't open attribute
    major: Attribute
    minor: Can't open object
  #004: H5Aint.c line 545 in H5A__open_by_name(): unable to load attribute info from object header
    major: Attribute
    minor: Unable to initialize object
  #005: H5Oattribute.c line 494 in H5O__attr_open_by_name(): can't locate attribute: '_QuantizeGranularBitRoundNumberOfSignificantDigits'
    major: Attribute
    minor: Object not found

@djhoese
Copy link
Member

djhoese commented Dec 21, 2023

I haven't looked at the code, but are you maybe only waiting for existence of the file? My guess would be it exists, but isn't finished being written.

@gerritholl
Copy link
Collaborator Author

gerritholl commented Dec 21, 2023

I haven't looked at the code, but are you maybe only waiting for existence of the file? My guess would be it exists, but isn't finished being written.

I am, and it sounds plausible, but... I get those error messages even if the files are already there and thus found immediately. But I don't get a segfault, and an image is produced despite the barrage of error messages reported by HDF5-DIAG.

But in any case it would be good to look for the same type of events that trollstalker does.

When it does work (in a test where I manually copy over files), the dask graph looks like this, which might be expected, although it doesn't seem to do a lot before it has the last files that it needs:

image

@djhoese
Copy link
Member

djhoese commented Dec 21, 2023

😨 Is this an HDF5 multiple reader limitation maybe?

@gerritholl
Copy link
Collaborator Author

gerritholl commented Dec 21, 2023

The HDF5-DIAG problem might be not directly related to this issue. https://stackoverflow.com/a/75899745/974555
But I'm confused why I started getting those warnings again.

@gerritholl
Copy link
Collaborator Author

gerritholl commented Dec 21, 2023

The HDF5-diag barrage vanishes if I downgrade netcdf4, but the segfaults still happen. They're not due to incomplete files, because they also occur if I link rather than copy files into the target directory.

I seem to recall working on the segfault problem in May 2019 in Madison and then it was due to too many open files, but pydata/xarray#2954 was fixed by pydata/xarray#3082 so that can't be the explanation.

@gerritholl
Copy link
Collaborator Author

😨 Is this an HDF5 multiple reader limitation maybe?

Maybe... it seems four workers all find the same file simultaneously and then I get the crash:

[DEBUG: 2023-12-21 15:21:32 : satpy.readers.netcdf_utils] Found /media/x21308/scratch/FCI/202312201500b/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231220151120_IDPFI_OPE_20231220150819_20231220150856_N_JLS_C_0091_0036.nc matching /media/x21308/scratch/FCI/202312201500b/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231220??????_IDPFI_OPE_20231220??????_20231220??????_N_JLS_C_0091_0036.nc!
[DEBUG: 2023-12-21 15:21:32 : satpy.readers.netcdf_utils] Found /media/x21308/scratch/FCI/202312201500b/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231220151120_IDPFI_OPE_20231220150819_20231220150856_N_JLS_C_0091_0036.nc matching /media/x21308/scratch/FCI/202312201500b/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231220??????_IDPFI_OPE_20231220??????_20231220??????_N_JLS_C_0091_0036.nc!
[DEBUG: 2023-12-21 15:21:32 : satpy.readers.netcdf_utils] Found /media/x21308/scratch/FCI/202312201500b/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231220151120_IDPFI_OPE_20231220150819_20231220150856_N_JLS_C_0091_0036.nc matching /media/x21308/scratch/FCI/202312201500b/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231220??????_IDPFI_OPE_20231220??????_20231220??????_N_JLS_C_0091_0036.nc!
[DEBUG: 2023-12-21 15:21:32 : satpy.readers.netcdf_utils] Found /media/x21308/scratch/FCI/202312201500b/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231220151120_IDPFI_OPE_20231220150819_20231220150856_N_JLS_C_0091_0036.nc matching /media/x21308/scratch/FCI/202312201500b/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231220??????_IDPFI_OPE_20231220??????_20231220??????_N_JLS_C_0091_0036.nc!
Command terminated by signal 11
        Command being timed: "python /home/gholl/test-scene-expected-files-2.py"
        User time (seconds): 29.01
        System time (seconds): 1.91
        Percent of CPU this job got: 60%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 0:50.75
        Average shared text size (kbytes): 0
        Average unshared data size (kbytes): 0
        Average stack size (kbytes): 0
        Average total size (kbytes): 0
        Maximum resident set size (kbytes): 2257064
        Average resident set size (kbytes): 0
        Major (requiring I/O) page faults: 0
        Minor (reclaiming a frame) page faults: 118791
        Voluntary context switches: 4587
        Involuntary context switches: 2401
        Swaps: 0
        File system inputs: 6112
        File system outputs: 8
        Socket messages sent: 0
        Socket messages received: 0
        Signals delivered: 0
        Page size (bytes): 4096
        Exit status: 0

@gerritholl
Copy link
Collaborator Author

No segfault with DASK_NUM_WORKERS=1

Use xarray rather than netCDF4 for retrieving the variable name.  Maybe
this will help to resolve the concurrency problem.
@gerritholl
Copy link
Collaborator Author

Still getting segfaults when using xarray.open_dataset. python -X faulthandler reveals:

Thread 0x00007f8c6fc5d700 (most recent call first):
  File "/opt/pytroll/pytroll_inst/mambaforge/envs/pytroll-py310/lib/python3.10/site-packages/dask/utils.py", line 1207 in __enter__
  File "/opt/pytroll/pytroll_inst/mambaforge/envs/pytroll-py310/lib/python3.10/site-packages/xarray/backends/locks.py", line 163 in __enter__
  File "/opt/pytroll/pytroll_inst/mambaforge/envs/pytroll-py310/lib/python3.10/site-packages/xarray/backends/netCDF4_.py", line 111 in _getitem
  File "/opt/pytroll/pytroll_inst/mambaforge/envs/pytroll-py310/lib/python3.10/site-packages/xarray/core/indexing.py", line 858 in explicit_indexing_adapter
  File "/opt/pytroll/pytroll_inst/mambaforge/envs/pytroll-py310/lib/python3.10/site-packages/xarray/backends/netCDF4_.py", line 100 in __getitem__

That's when trying to get the lock that it segfaults.

https://github.com/pydata/xarray/blob/main/xarray/backends/locks.py#L161-L163

@gerritholl
Copy link
Collaborator Author

Using the h5netcdf backend solves the problem. The dask graph for loading a single true_color composite also looks much better than before:

image

When the last files have arrived, Satpy only needs ca. 2 seconds to complete the operation.

Will test with a full set of composites and areas tomorrow.

@gerritholl gerritholl marked this pull request as ready for review December 21, 2023 17:25
@gerritholl
Copy link
Collaborator Author

I have not yet tested the non-nominal case, such as when a segment fails to appear. I think the entire repeat cycle would fail, which is not optimal.

@gerritholl
Copy link
Collaborator Author

gerritholl commented Dec 22, 2023

When trying this out with data as they come in, it turns out the distribution of dask tasks to workers is not optimal. The distribution of the 40 "wait for files to appear" tasks over the workers is not consecutive, but appears not deterministic. This means that workers may be occupied waiting for chunk 33-40, while nobody is processing chunks 1–32 until after 33–40 have been processed.

[2023-12-22 08:36:13,907 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0035.nc to appear.
[2023-12-22 08:36:13,911 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0030.nc to appear.
[2023-12-22 08:36:13,921 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0015.nc to appear.
[2023-12-22 08:36:13,924 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0010.nc to appear.
[2023-12-22 08:36:13,932 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0009.nc to appear.
[2023-12-22 08:36:13,937 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0008.nc to appear.
[2023-12-22 08:36:13,947 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0007.nc to appear.
[2023-12-22 08:36:17,539 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0006.nc to appear.
[2023-12-22 08:36:43,681 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083452_IDPFI_OPE_20231222083036_20231222083120_N_JLS_C_0052_0006.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0006.nc!
[2023-12-22 08:36:44,193 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0040.nc to appear.
[2023-12-22 08:36:58,170 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083504_IDPFI_OPE_20231222083049_20231222083137_N_JLS_C_0052_0007.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0007.nc!
[2023-12-22 08:36:58,688 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0039.nc to appear.
[2023-12-22 08:37:14,200 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0035.nc
[2023-12-22 08:37:14,203 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0015.nc
[2023-12-22 08:37:14,207 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083512_IDPFI_OPE_20231222083057_20231222083145_N_JLS_C_0052_0008.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0008.nc!
[2023-12-22 08:37:14,212 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0030.nc
[2023-12-22 08:37:14,217 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0010.nc
[2023-12-22 08:37:14,224 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0009.nc
[2023-12-22 08:37:14,722 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0038.nc to appear.
[2023-12-22 08:37:28,274 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083520_IDPFI_OPE_20231222083112_20231222083203_N_JLS_C_0052_0009.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0009.nc!
[2023-12-22 08:37:28,807 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0005.nc to appear.
[2023-12-22 08:37:28,813 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083444_IDPFI_OPE_20231222083029_20231222083112_N_JLS_C_0052_0005.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0005.nc!
[2023-12-22 08:37:29,296 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0037.nc to appear.
[2023-12-22 08:37:38,311 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083533_IDPFI_OPE_20231222083128_20231222083221_N_JLS_C_0052_0010.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0010.nc!
[2023-12-22 08:37:38,822 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0036.nc to appear.
[2023-12-22 08:37:44,330 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0040.nc
[2023-12-22 08:37:58,833 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0039.nc
[2023-12-22 08:38:14,874 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0038.nc
[2023-12-22 08:38:29,545 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0037.nc
[2023-12-22 08:38:38,959 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0036.nc
[2023-12-22 08:38:58,709 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083617_IDPFI_OPE_20231222083239_20231222083337_N_JLS_C_0052_0015.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0015.nc!
[2023-12-22 08:38:59,216 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0034.nc to appear.
[2023-12-22 08:39:14,772 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0035.nc
[2023-12-22 08:39:14,776 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0030.nc
[2023-12-22 08:39:44,865 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0040.nc
[2023-12-22 08:39:59,134 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0039.nc
[2023-12-22 08:39:59,351 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0034.nc
[2023-12-22 08:40:15,167 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0038.nc
[2023-12-22 08:40:29,842 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0037.nc
[2023-12-22 08:40:39,229 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0036.nc
[2023-12-22 08:41:15,207 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0030.nc
[2023-12-22 08:41:15,215 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0035.nc
[2023-12-22 08:41:35,297 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083914_IDPFI_OPE_20231222083701_20231222083737_N_JLS_C_0052_0030.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0030.nc!
[2023-12-22 08:41:35,855 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0033.nc to appear.
[2023-12-22 08:41:45,348 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0040.nc
[2023-12-22 08:41:59,405 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0039.nc
[2023-12-22 08:41:59,803 DEBUG    satpy.readers.netcdf_utils] Still waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0034.nc
[2023-12-22 08:42:01,921 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083947_IDPFI_OPE_20231222083737_20231222083819_N_JLS_C_0052_0033.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0033.nc!
[2023-12-22 08:42:02,401 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0032.nc to appear.
[2023-12-22 08:42:02,404 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083939_IDPFI_OPE_20231222083729_20231222083803_N_JLS_C_0052_0032.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0032.nc!
[2023-12-22 08:42:02,883 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0031.nc to appear.
[2023-12-22 08:42:02,885 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083928_IDPFI_OPE_20231222083711_20231222083755_N_JLS_C_0052_0031.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0031.nc!
[2023-12-22 08:42:03,395 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0004.nc to appear.
[2023-12-22 08:42:03,398 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083437_IDPFI_OPE_20231222083017_20231222083057_N_JLS_C_0052_0004.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0004.nc!
[2023-12-22 08:42:03,882 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0029.nc to appear.
[2023-12-22 08:42:03,885 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083905_IDPFI_OPE_20231222083643_20231222083729_N_JLS_C_0052_0029.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0029.nc!
[2023-12-22 08:42:04,371 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0028.nc to appear.
[2023-12-22 08:42:04,374 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083853_IDPFI_OPE_20231222083633_20231222083711_N_JLS_C_0052_0028.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0028.nc!
[2023-12-22 08:42:04,897 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0027.nc to appear.
[2023-12-22 08:42:04,903 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083835_IDPFI_OPE_20231222083614_20231222083652_N_JLS_C_0052_0027.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0027.nc!
[2023-12-22 08:42:05,396 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0026.nc to appear.
[2023-12-22 08:42:05,399 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083819_IDPFI_OPE_20231222083554_20231222083633_N_JLS_C_0052_0026.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0026.nc!
[2023-12-22 08:42:05,880 DEBUG    satpy.readers.netcdf_utils] Waiting for /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0025.nc to appear.
[2023-12-22 08:42:05,883 DEBUG    satpy.readers.netcdf_utils] Found /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222083759_IDPFI_OPE_20231222083545_20231222083614_N_JLS_C_0052_0025.nc matching /data/pytroll/IN/FCI_FDHSI/W_XX-EUMETSAT-Darmstadt,IMG+SAT,MTI1+FCI-1C-RRAD-FDHSI-FD--CHK-BODY--DIS-NC4E_C_EUMT_20231222??????_IDPFI_OPE_20231222??????_20231222??????_N_JLS_C_0052_0025.nc!

etc.

I should check how we can prioritise the scheduling.

image

One workaround may be to use 40 workers. In this case, the first image is ready 20 seconds after the last chunk has arrived. The last image is ready after 2 minutes 31 seconds.

image

Write about limitations in the documentation.  Adapt how things are
logged.
@gerritholl
Copy link
Collaborator Author

Unless I install netcdf4=1.5.8, I get many HDF5_DIAG errors and segmentation faults. With netCDF4=1.5.8 (which implies Python 3.10) operational processing appears to work.

@djhoese
Copy link
Member

djhoese commented Dec 22, 2023

The distribution of the 40 "wait for files to appear" tasks over the workers is not consecutive, but appears not deterministic. This means that workers may be occupied waiting for chunk 33-40, while nobody is processing chunks 1–32 until after 33–40 have been processed.

Have you found a workaround for this? I believe dask should be considering these in the order that they are defined, but I could be wrong about that if dask sees them as all happening at the same time. I also think there are ways to define priorities to tasks, but this may only be in the "futures" or distributed workflows.

@gerritholl
Copy link
Collaborator Author

The distribution of the 40 "wait for files to appear" tasks over the workers is not consecutive, but appears not deterministic. This means that workers may be occupied waiting for chunk 33-40, while nobody is processing chunks 1–32 until after 33–40 have been processed.

Have you found a workaround for this? I believe dask should be considering these in the order that they are defined, but I could be wrong about that if dask sees them as all happening at the same time. I also think there are ways to define priorities to tasks, but this may only be in the "futures" or distributed workflows.

The only workaround I've found is to run with 40 workers.

@mraspaud
Copy link
Member

mraspaud commented Jan 9, 2024

I think we should ask the dask community about this. We can't be the first ones to stumble on this.

@gerritholl
Copy link
Collaborator Author

Related reading to find out the "waiting for external files" in the right order, it might be possible to us "secede" and "rejoin" (only with the distributed scheduler?): https://stackoverflow.com/questions/56222869/waiting-for-external-dependencies-in-dask https://docs.dask.org/en/latest/futures.html https://distributed.dask.org/en/stable/task-launch.html#getting-the-client-on-a-worker

Fixing a merge conflict in test_readers.py
Refactor the unit test test_preloaded_instances into multiple unit tests
testing different cases.  This should hopefully improve the code health
as measured by CodeScene.
Refactor _wait_for_file to reduce the cyclomatic complexity
Refactor to simplify conditional logic.
@gerritholl
Copy link
Collaborator Author

The remaining CodeScene warnings are that there are too many functions in test_yaml_reader.py (79) and too many function arguments in FCIL1cNCFileHandler.__init__ (5), even though many modules have more functions (test_readers.py has 99, test_composites.py has 124), and many functions or methods have 5 or more arguments. Do I have to fix those warnings in this PR?

Copy link
Member

@mraspaud mraspaud left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Great work! I have a few questions and comments, but looks good overall.

@@ -1317,6 +1338,129 @@ def _get_new_areadef_heights(self, previous_area, previous_seg_size, **kwargs):

return new_height_proj_coord, new_height_px

def _new_filehandler_instances(self, filetype_info, filename_items, fh_kwargs=None):
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could all these new methods be put into a new subclass? Might help with SOC.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I started that way at some point, but was not sure how to proceed. Suppose we have GEOPreloadableSegmentYAMLReader (GPSYR) as a subclass of GEOSegmentYAMLReader (GSYR), then some questions arise:

  • Would we change the five readers that currently use GSYR directly to use GPSYR instead, or only those where we know pre-loading works? Probably only those where it works.
  • How do we combie GPSYR with GEOVariableSegmentYAMLReader (GVSYR)? Does GVSYR subclass GPSYR, suggesting that every GVSYR support pre-loading? Currently, this is true (fci_l1c_nc is the only GVSYR), but perhaps not in the future. Or are GVSYR and GPSYR bot subclasses of GSYR, and then a dedicated GEOPreloadableVariableSegmentYAMLReader (GPVSYR) would subclass both GVSYR and GPSYR, leading to diamond rule inheritance? I prefer to avoid the diamond problem. Or is the preloadable yaml reader a mixin that doesn't subclass GSYR at all?

I couldn't decide and concluded that I can run away and avoid those questions by now creating a class at all 😄

satpy/readers/netcdf_utils.py Outdated Show resolved Hide resolved
Comment on lines +439 to +445
class Preloadable:
"""Mixin class for pre-loading.

This is a mixin class designed to use with file handlers that support
preloading. Subclasses deriving from this mixin are expected to be
geo-segmentable file handlers, and can be created based on a glob pattern
for a non-existing file (as well as a path or glob pattern to an existing
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should this class be called eg PreloadableSegments to make clear of the main use case?

list(g)


def test_get_cache_filename(tmp_path):
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could this test be split in multiple smaller ones?

Comment on lines +1175 to +1178
def __init__(self, *args, **kwargs):
"""Initialise object."""
self.preload = kwargs.pop("preload", False)
super().__init__(*args, **kwargs)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm wondering if we should use satpy's config system for this instead of adding yet another keyword argument. In my mind, a config would make sense as I don't think we would want to mix preloadable and non preloadable data.

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.

None yet

4 participants