Performance regression loading pp files with 3.13

[david-bentley]

📰 Custom Issue

Performance regression with v3.13

Attempting to load the following set of pp files takes significantly longer under Iris v3.13 compared to v3.12.

$ ls -lhtr *pp
-rw-r--r--. 1 owner group 511M Oct 20 17:15 prodm_op_gl-mn_20251001_00_003.pp
-rw-r--r--. 1 owner group 171M Oct 20 17:23 prodm_op_gl-mn_20251001_00_006.pp
-rw-r--r--. 1 owner group  189M Oct 20 17:23 prodm_op_gl-mn_20251001_00_000.pp
-rw-r--r--. 1 owner group  151M Oct 20 18:14 prods_op_gl-mn_20251001_00_000.pp
-rw-r--r--. 1 owner group 20M Oct 20 18:14 prods_op_gl-mn_20251001_00_006.pp
-rw-r--r--. 1 owner group  152M Oct 20 18:16 prods_op_gl-mn_20251001_00_003.pp

The Python script to load the files

import glob
import iris

files = sorted(glob.glob("*pp"))

policy = "legacy"  # or "default"
iris.LOAD_POLICY.set(policy)

cubes = iris.load(files)
print(cubes)

and running this script under Iris v3.12 and v3.13 gives

$ python -c "import iris; print(iris.__version__)"
3.12.0
$ time python load_files.py 
/data/apps/sss/environments/default-2025_04_01/lib/python3.12/site-packages/iris/fileformats/rules.py:45: IrisUserWarning: Multiple reference cubes for orography
  ...suppressing lots of FutureWarning: You are using legacy date precision for Iris units - max precision is seconds. In future, Iris will use microsecond precision - available since cf-units version 3.3 - which may affect core behaviour. To opt-in to the new behaviour, set `iris.FUTURE.date_microseconds = True`...
0: m01s03i318 / (unknown)              (pseudo_level: 5; time: 2; latitude: 1920; longitude: 2560)
1: high_type_cloud_area_fraction / (1) (time: 5; latitude: 1920; longitude: 2560)
2: land_binary_mask / (1)              (latitude: 1920; longitude: 2560)
3: land_binary_mask / (1)              (latitude: 1920; longitude: 2560)
4: low_type_cloud_area_fraction / (1)  (time: 5; latitude: 1920; longitude: 2560)
5: mass_fraction_of_cloud_ice_in_air / (kg kg-1) (time: 5; model_level_number: 71; latitude: 1920; longitude: 2560)
6: mass_fraction_of_cloud_liquid_water_in_air / (kg kg-1) (time: 5; model_level_number: 71; latitude: 1920; longitude: 2560)
7: medium_type_cloud_area_fraction / (1) (time: 5; latitude: 1920; longitude: 2560)
8: surface_altitude / (m)              (time: 5; latitude: 1920; longitude: 2560)
9: surface_altitude / (m)              (time: 5; latitude: 1920; longitude: 2560)
10: surface_snow_amount / (kg m-2)      (time: 5; latitude: 1920; longitude: 2560)
11: x_wind / (m s-1)                    (time: 5; latitude: 1921; longitude: 2560)
12: y_wind / (m s-1)                    (time: 5; latitude: 1921; longitude: 2560)

real	1m4.448s
user	0m49.322s
sys	0m7.180s

and

$ python -c "import iris; print(iris.__version__)"
3.13.0
$ time python load_files.py 
/data/apps/sss/environments/default-2025_08_19/lib/python3.12/site-packages/iris/fileformats/rules.py:45: IrisUserWarning: Multiple reference cubes for orography
...suppressing lots of FutureWarning: You are using legacy date precision for Iris units - max precision is seconds. In future, Iris will use microsecond precision - available since cf-units version 3.3 - which may affect core behaviour. To opt-in to the new behaviour, set `iris.FUTURE.date_microseconds = True`...
  warnings.warn(message, category=FutureWarning)
0: m01s03i318 / (unknown)              (pseudo_level: 5; time: 2; latitude: 1920; longitude: 2560)
1: high_type_cloud_area_fraction / (1) (time: 5; latitude: 1920; longitude: 2560)
2: land_binary_mask / (1)              (latitude: 1920; longitude: 2560)
3: land_binary_mask / (1)              (latitude: 1920; longitude: 2560)
4: low_type_cloud_area_fraction / (1)  (time: 5; latitude: 1920; longitude: 2560)
5: mass_fraction_of_cloud_ice_in_air / (kg kg-1) (time: 5; model_level_number: 71; latitude: 1920; longitude: 2560)
6: mass_fraction_of_cloud_liquid_water_in_air / (kg kg-1) (time: 5; model_level_number: 71; latitude: 1920; longitude: 2560)
7: medium_type_cloud_area_fraction / (1) (time: 5; latitude: 1920; longitude: 2560)
8: surface_altitude / (m)              (time: 5; latitude: 1920; longitude: 2560)
9: surface_altitude / (m)              (time: 5; latitude: 1920; longitude: 2560)
10: surface_snow_amount / (kg m-2)      (time: 5; latitude: 1920; longitude: 2560)
11: x_wind / (m s-1)                    (time: 5; latitude: 1921; longitude: 2560)
12: y_wind / (m s-1)                    (time: 5; latitude: 1921; longitude: 2560)

real	21m18.005s
user	31m5.224s
sys	6m22.358s

[david-bentley]

Some more timings for different numbers of model levels:

import glob
import iris

files = sorted(glob.glob("*pp"))

policy = "legacy"  # or "default"
iris.LOAD_POLICY.set(policy)

n_levels = 5
cubes = iris.load(files, constraints=iris.Constraint(model_level_number=lambda cell: cell.point < n_levels))
print(cubes)

gives

$ time python load_files.py 
0: mass_fraction_of_cloud_ice_in_air / (kg kg-1) (time: 5; model_level_number: 5; latitude: 1920; longitude: 2560)
1: mass_fraction_of_cloud_liquid_water_in_air / (kg kg-1) (time: 5; model_level_number: 5; latitude: 1920; longitude: 2560)

real	3m58.945s
user	2m47.290s
sys	3m32.438s

and

$ time python load_files.py 
0: mass_fraction_of_cloud_ice_in_air / (kg kg-1) (time: 5; model_level_number: 10; latitude: 1920; longitude: 2560)
1: mass_fraction_of_cloud_liquid_water_in_air / (kg kg-1) (time: 5; model_level_number: 10; latitude: 1920; longitude: 2560)

real	5m30.348s
user	4m33.687s
sys	5m0.027s

for 5 and 10 levels respectively. In case it is useful, here is a screenshot of the CPU/memory/network usage covering the 5 levels case.

[bjlittle]

@SciTools/peloton Thanks for taking the time to raise this issue.

We've added it to our iris 3.14 sprint backlog and will investigate further, we may need to touch base with you for further details to help us progress this.

Perhaps related to #6404

[stephenworsley]

I believe this is due to #6517. Performance reverts to normal when this PR is reversed. Also, I believe the slowdown is happening in the merge call rather than the load call.