Hi,

I'm working with some data that's chunked; dimensions of the chunks are (1, 510, 1068). It was originally shuffled and compressed; it was decompressed, then I modified the nccopy utility to deshuffle it following observation of miserable performance to test the hypothesis that shuffling might be the source.

Unfortunately, even without shuffling, I observed some pretty dismal performance when reading in small sections of this data; upon further digging, it seems that the NetCDF library is reading in the entire field to extract just a few values. This can be observed when using ncks to extract a small subset of the data (it's observable with other software too) by stracing the program and observing the size of the reads:

$ strace -f ncks -d lat,0,1 -d lon,0,1 -d time,0,4 ~/public_html/pr+tasmax+tasmin_day_BCCAQ+ANUSPLIN300+MRI-CGCM3_historical+rcp85_r1i1p1_19500101-21001231.nc.sub
--- CUT ---
lseek(3, 17462119, SEEK_SET)            = 17462119
read(3, "TREE\1\0\5\0\377\377\377\377\377\377\377\377\377\377\377\377\377\377\377\377\240>!\0\0\0\0\0"..., 3136) = 3136
brk(0x1e8d000)                          = 0x1e8d000
read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 2178720) = 2178720
brk(0x20a1000)                          = 0x20a1000
read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 2178720) = 2178720
brk(0x22b5000)                          = 0x22b5000
read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 2178720) = 2178720
read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 2178720) = 2178720
lseek(3, 30539671, SEEK_SET)            = 30539671
read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 2178720) = 2178720
write(1, "time[0]=0 lat[0]=41.041666665 lo"..., 74time[0]=0 lat[0]=41.041666665 lon[0]=-140.958333335 tasmin[0]=-32768 degC
) = 74
write(1, "time[0]=0 lat[0]=41.041666665 lo"..., 74time[0]=0 lat[0]=41.041666665 lon[1]=-140.875000005 tasmin[1]=-32768 degC
) = 74
write(1, "time[0]=0 lat[1]=41.124999995 lo"..., 77time[0]=0 lat[1]=41.124999995 lon[0]=-140.958333335 tasmin[1068]=-32768 degC
) = 77
write(1, "time[0]=0 lat[1]=41.124999995 lo"..., 77time[0]=0 lat[1]=41.124999995 lon[1]=-140.875000005 tasmin[1069]=-32768 degC
) = 77
write(1, "time[1]=1 lat[0]=41.041666665 lo"..., 79time[1]=1 lat[0]=41.041666665 lon[0]=-140.958333335 tasmin[544680]=-32768 degC
) = 79
write(1, "time[1]=1 lat[0]=41.041666665 lo"..., 79time[1]=1 lat[0]=41.041666665 lon[1]=-140.875000005 tasmin[544681]=-32768 degC
) = 79
write(1, "time[1]=1 lat[1]=41.124999995 lo"..., 79time[1]=1 lat[1]=41.124999995 lon[0]=-140.958333335 tasmin[545748]=-32768 degC
) = 79
write(1, "time[1]=1 lat[1]=41.124999995 lo"..., 79time[1]=1 lat[1]=41.124999995 lon[1]=-140.875000005 tasmin[545749]=-32768 degC
) = 79
write(1, "time[2]=2 lat[0]=41.041666665 lo"..., 80time[2]=2 lat[0]=41.041666665 lon[0]=-140.958333335 tasmin[1089360]=-32768 degC
) = 80
write(1, "time[2]=2 lat[0]=41.041666665 lo"..., 80time[2]=2 lat[0]=41.041666665 lon[1]=-140.875000005 tasmin[1089361]=-32768 degC
) = 80
write(1, "time[2]=2 lat[1]=41.124999995 lo"..., 80time[2]=2 lat[1]=41.124999995 lon[0]=-140.958333335 tasmin[1090428]=-32768 degC
) = 80
write(1, "time[2]=2 lat[1]=41.124999995 lo"..., 80time[2]=2 lat[1]=41.124999995 lon[1]=-140.875000005 tasmin[1090429]=-32768 degC
) = 80
write(1, "time[3]=3 lat[0]=41.041666665 lo"..., 80time[3]=3 lat[0]=41.041666665 lon[0]=-140.958333335 tasmin[1634040]=-32768 degC
) = 80
write(1, "time[3]=3 lat[0]=41.041666665 lo"..., 80time[3]=3 lat[0]=41.041666665 lon[1]=-140.875000005 tasmin[1634041]=-32768 degC
) = 80
write(1, "time[3]=3 lat[1]=41.124999995 lo"..., 80time[3]=3 lat[1]=41.124999995 lon[0]=-140.958333335 tasmin[1635108]=-32768 degC
) = 80
write(1, "time[3]=3 lat[1]=41.124999995 lo"..., 80time[3]=3 lat[1]=41.124999995 lon[1]=-140.875000005 tasmin[1635109]=-32768 degC
) = 80
write(1, "time[4]=4 lat[0]=41.041666665 lo"..., 80time[4]=4 lat[0]=41.041666665 lon[0]=-140.958333335 tasmin[2178720]=-32768 degC
) = 80
write(1, "time[4]=4 lat[0]=41.041666665 lo"..., 80time[4]=4 lat[0]=41.041666665 lon[1]=-140.875000005 tasmin[2178721]=-32768 degC
) = 80
write(1, "time[4]=4 lat[1]=41.124999995 lo"..., 80time[4]=4 lat[1]=41.124999995 lon[0]=-140.958333335 tasmin[2179788]=-32768 degC
) = 80
write(1, "time[4]=4 lat[1]=41.124999995 lo"..., 80time[4]=4 lat[1]=41.124999995 lon[1]=-140.875000005 tasmin[2179789]=-32768 degC

Note that the result of the read calls is a block of 2178720 bytes, which equals the product of the sizes of the X and Y dimensions and the size of the storage type (float). It should be 8 bytes, which means about 250000 times as much I/O bandwidth is used than should be required.

I have also used strace on other data with different chunk sizes (and possibly different internal metadata); these full-field reads are not present with other data I have examined.

I have also experimented with reading in data using native HDF5 applications, specifically the rhdf5 library; the read pattern when using rhdf5 is what one would expect: reading in only the values that are required (that is, 8 bytes at a time).

I'm at a loss for where to go from here. I've dug into the NetCDF library source code, but I don't have experience with either the NetCDF library source code or the HDF5 library, so it's very slow going. I think this might have to do with non-ideal caching behaviour of the NetCDF library, but that's just a guess. However, given the apparent ubiquity of this problem, and the apparent lack of the problem when using the HDF5 library without the NetCDF library in the middle, it suggests a library bug with the NetCDF library, whatever the source.

A representative subset of the file in question is available here: http://www.pacificclimate.org/~bronaugh/pr+tasmax+tasmin_day_BCCAQ+ANUSPLIN300+MRI-CGCM3_historical+rcp85_r1i1p1_19500101-21001231.nc.sub

The performance problem is due to the your chunk shapes. Here's an explanation:

http://www.unidata.ucar.edu/blogs/developer/en/entry/chunking_data_why_it_matters

This may be exacerbated in your case by making time an "unlimited" dimension, which makes the default chunk length 1 for the time dimension. If you will be accessing multiple times for a single variable as the most common access pattern, it would be advisable to reorganize the data to use contiguous storage for each variable by using the "-u" option of nccopy.

I'm well aware of the impact of chunking -- chunking affects the locality of the data, which causes different behaviour wrt read-ahead, seeking, and the number of system calls, all of which have a seriously detrimental effect on performance. I have already read up on chunking and I believe I understand it reasonably well.

However, note that "reading in the entire field" is not a direct consequence of chunking. This should never happen when reading in only a few values if the data is not compressed or shuffled; it's trivial to compute the offset into the field, then retrieve those values. As stated above, when the HDF5 library is used directly, this is exactly what happens.

You said "dimensions of the chunks are (1, 510, 1068)" for this float variable, which means the size of a chunk is 2178720 bytes, the same as the size of one time slice. A chunk, in either netCDF-4 or HDF5 is the unit of disk access, though chunks can be cached in memory if the chunk cache is large enough. When you "read in only a few values" in either netCDF or HDF5, you read the entire chunks containing those values, unless they are in the in-memory chunk cache, in which case you access the values from cache. If the few values you read are in different time slices and each chunk only holds the values from one time slice, you will read as many chunks as values (modulo chunk cache). That's what the HDF5 User Guide says:

The HDF5 library treats chunks as atomic objects -- disk I/O is always in terms of complete chunks(1). http://www.hdfgroup.org/HDF5/doc/H5.user/Chunking.html

The default value of the chunk cache in HDF5 is smaller than your chunks:

By default, the chunk cache will store 521 chunks or 1MB of data (whichever is less) but these values can be modified with H5Pset_cache().

In netCDF-4 configured with defaults, the chunk cache is 4194304 bytes, still only large enough to hold one of your 2.17MB chunks. The chunk cache size can be modified by calling nc_set_chunk_cache().

If you want fast access to a field for N times at one location, you either need to have a chunk cache large enough to hold N chunks or you need to rechunk your data to shapes something like (N, 510/sqrt(N), 1068/sqrt(N)), if you want to keep the chunks about 2MB in size. You could also use smaller chunks closer to the size of your physical disk blocks, e.g. 4KB, if you want to use less memory but still have fast disk access.

The document you link doesn't match up with my observations. Furthermore, note Footnote 1:

Footnote 1: Parallel versions of the library can access individual bytes of a chunk when the underlying file uses MPI-IO.

This would appear to be true with hdf5 serial as of at least v1.8.12, which I am using. This is a trace from reading a X=1:2, Y=1:2, T=1:5 slice from the example file:

lseek(3, 29169, SEEK_SET)               = 29169
read(3, "\0\0\0\307\0\0\0\307", 8)      = 8
lseek(3, 33441, SEEK_SET)               = 33441
read(3, "\0\0\0\307\0\0\0\307", 8)      = 8
lseek(3, 2207889, SEEK_SET)             = 2207889
read(3, "\0\0\0\307\0\0\0\307", 8)      = 8
lseek(3, 2212161, SEEK_SET)             = 2212161
read(3, "\0\0\0\307\0\0\0\307", 8)      = 8
lseek(3, 4386609, SEEK_SET)             = 4386609
read(3, "\0\0\0\307\0\0\0\307", 8)      = 8
lseek(3, 4390881, SEEK_SET)             = 4390881
read(3, "\0\0\0\307\0\0\0\307", 8)      = 8
lseek(3, 6565329, SEEK_SET)             = 6565329
read(3, "\0\0\0\307\0\0\0\307", 8)      = 8
lseek(3, 6569601, SEEK_SET)             = 6569601
read(3, "\0\0\0\307\0\0\0\307", 8)      = 8
lseek(3, 8744049, SEEK_SET)             = 8744049
read(3, "\0\0\0\307\0\0\0\307", 8)      = 8
lseek(3, 8748321, SEEK_SET)             = 8748321
read(3, "\0\0\0\307\0\0\0\307", 8)      = 8

Note the 8-byte reads, and note the distance between the seeks. 8 bytes = 2 floats. It is crystal clear that HDF5 1.8.12, at the very least, is not following the user documentation you have presented, possibly because the HDF5 library's serial read routine has been updated to match the parallel read routine. And yes, I did verify that I am using the serial I/O version of the HDF5 library.

I've played around experimentally since then... I think I have figured out the root cause, though it doesn't make much sense. I experimentally reduced the cache size to 2M, so that a single block would not fit into the cache. This results in identical read behaviour to that quoted above.

I'm not sure what the right answer here is, because clearly the caching behaviour is maladaptive in the case of multiple independent readers or any read which won't span the full chunk. The cache appears to help in the case of multiple reads to the same chunk, but it cripples the common case of reading a column of data through the chunk stack. I doubt this was the designed-for behaviour...

That's puzzling, because I've never seen an update in the HDF5 Release Notes about changing this chunk-at-a-time I/O for serial I/O, and I hadn't even noticed the different behavior for parallel I/O..

When you say

... I experimentally reduced the cache size to 2M, so that a single block would not fit into the cache. This results in identical read behaviour to that quoted above.

I assume you meant you reduced the netCDF chunk cache from 4MB to 2MB, and that actually improved the netCDF performance by only doing 8-byte reads to get all the data you selected from 5 different chunks.

I'm going to have to ask an HDF5 developer to explain that, because I can't understand how or why lowering the chunk cache size could improve the performance. Also, I'd like to know whether the user documentation is wrong for the current HDF5 release, and if so, when that change was made to the release.

Thanks for being persistent with this problem. It looks like you've identified a peculiarity with performance that we may be able to exploit, once we understand it.

Yes, I reduced the netCDF chunk cache size by changing the defines in config.h (both CHUNK_CACHE_SIZE and DEFAULT_CHUNK_SIZE). And yes, it did improve the performance as you paraphrased.

I'm experimenting with using nc_set_chunk_cache instead; unsurprisingly, it does the same thing. So I definitely did this the hard way... oh well.

Hmm, I'm unable to duplicate this problem... I've built the latest nco (4.4.2), and I'm using the latest HDF5 1.8 from the subversion repository (http://svn.hdfgroup.uiuc.edu/hdf5/branches/hdf5_1_8) and netCDF-4 from the git repository (https://github.com/Unidata/netcdf-c). Given all that, and applying the following patch to HDF5:

Index: src/H5Dchunk.c

--- src/H5Dchunk.c (revision 24815) +++ src/H5Dchunk.c (working copy) @@ -1862,6 +1862,7 @@

             /* Point I/O info at contiguous I/O info for this chunk */
             chk_io_info = &cpt_io_info;

+HDfprintf(stderr, "%s: Will perform I/O from cached chunk\n", FUNC); } /* end if _/ else if(H5F_addrdefined(udata.addr)) { / Set up the storage address information for this chunk */ @@ -1872,6 +1873,7 @@

             /* Point I/O info at temporary I/O info for this chunk */
             chk_io_info = &ctg_io_info;

+HDfprintf(stderr, "%s: Will perform I/O from chunk in file\n", FUNC); } /* end else if / else { / No chunk cached */ @@ -2879,6 +2881,7 @@ H5_ASSIGN_OVERFLOW(chunk_alloc, udata->nbytes, uint32_t, size_t); if(NULL == (chunk = H5D__chunk_alloc(chunk_alloc, pline))) HGOTO_ERROR(H5E_RESOURCE, H5E_NOSPACE, NULL, "memory allocation failed for raw data chunk") +HDfprintf(stderr, "%s: Before reading chunk from file\n", FUNC); if(H5F_block_read(dset->oloc.file, H5FD_MEM_DRAW, chunk_addr, chunk_alloc, io_info->dxpl_id, chunk) < 0) HGOTO_ERROR(H5E_IO, H5E_READERROR, NULL, "unable to read raw data chunk")

Index: src/H5Dio.c

--- src/H5Dio.c (revision 24815) +++ src/H5Dio.c (working copy) @@ -135,6 +135,7 @@ FUNC_ENTER_API(FAIL) H5TRACE6("e", "iiiiix", dset_id, mem_type_id, mem_space_id, file_space_id, plist_id, buf); +HDfprintf(stderr, "%s: Called!\n", FUNC);

 /* check arguments */
 if(NULL == (dset = (H5D_t *)H5I_object_verify(dset_id, H5I_DATASET)))

Index: src/H5FDsec2.c

--- src/H5FDsec2.c (revision 24815) +++ src/H5FDsec2.c (working copy) @@ -678,6 +678,7 @@ herr_t ret_value = SUCCEED; /* Return value */

 FUNC_ENTER_NOAPI_NOINIT

+HDfprintf(stderr, "%s: Called!, type = %u, addr = %a, size = %Zu\n", FUNC, type, addr, size);

 HDassert(file && file->pub.cls);
 HDassert(buf);

I'm seeing a few 8-byte reads, but those appear to be whole chunks that are defined to be size 1 element. Here's my sample output from: src/nco/ncks -d lat,0,1 -d lon,0,1 -d time,0,4 bronaugh.nc

H5FD_sec2_read: Called!, type = 1, addr = 0, size = 8 H5FD_sec2_read: Called!, type = 1, addr = 0, size = 8 H5FD_sec2_read: Called!, type = 1, addr = 0, size = 9 H5FD_sec2_read: Called!, type = 1, addr = 9, size = 39 H5FD_sec2_read: Called!, type = 6, addr = 48, size = 512 H5FD_sec2_read: Called!, type = 6, addr = 560, size = 9 H5FD_sec2_read: Called!, type = 6, addr = 1944, size = 512 H5FD_sec2_read: Called!, type = 6, addr = 10213, size = 178 H5FD_sec2_read: Called!, type = 6, addr = 2360, size = 512 H5FD_sec2_read: Called!, type = 6, addr = 9136, size = 178 H5FD_sec2_read: Called!, type = 6, addr = 2777, size = 512 H5FD_sec2_read: Called!, type = 6, addr = 3289, size = 44 H5FD_sec2_read: Called!, type = 6, addr = 4892, size = 148 H5FD_sec2_read: Called!, type = 3, addr = 5040, size = 4096 H5FD_sec2_read: Called!, type = 6, addr = 4495, size = 512 H5FD_sec2_read: Called!, type = 6, addr = 10034, size = 179 H5FD_sec2_read: Called!, type = 6, addr = 3333, size = 512 H5FD_sec2_read: Called!, type = 6, addr = 3845, size = 69 H5FD_sec2_read: Called!, type = 6, addr = 9575, size = 148 H5FD_sec2_read: Called!, type = 6, addr = 3914, size = 512 H5FD_sec2_read: Called!, type = 6, addr = 4426, size = 69 H5FD_sec2_read: Called!, type = 6, addr = 9886, size = 148 H5FD_sec2_read: Called!, type = 2, addr = 715, size = 38 H5FD_sec2_read: Called!, type = 6, addr = 569, size = 146 H5FD_sec2_read: Called!, type = 2, addr = 873, size = 512 H5FD_sec2_read: Called!, type = 6, addr = 9723, size = 54 H5FD_sec2_read: Called!, type = 5, addr = 12439, size = 1024 H5FD_sec2_read: Called!, type = 5, addr = 11415, size = 1024 H5FD_sec2_read: Called!, type = 5, addr = 10391, size = 1024 Summary of ../chunking/bronaugh.nc: filetype = NC_FORMAT_NETCDF4, 0 groups (max. depth = 0), 3 dimensions (2 fixed, 1 record), 6 variables (6 atomic-type, 0 non-atomic), 58 attributes (29 global, 0 group, 29 variable)

Root record dimension 0: name = time, size = 5

Global attributes: Global attribute 0: institution, size = 79 NC_CHAR, value = Pacific Climate Impacts Consortium (PCIC), Victoria, BC, www.pacificclimate.org Global attribute 1: Conventions, size = 6 NC_CHAR, value = CF-1.4 Global attribute 2: institute_id, size = 4 NC_CHAR, value = PCIC Global attribute 3: version, size = 1 NC_CHAR, value = 1 Global attribute 4: frequency, size = 3 NC_CHAR, value = day Global attribute 5: product, size = 6 NC_CHAR, value = output Global attribute 6: modeling_realm, size = 5 NC_CHAR, value = atmos Global attribute 7: realization, size = 1 NC_CHAR, value = 1 Global attribute 8: references, size = 254 NC_CHAR, value = Maurer, E.P., Hidalgo, H.G., Das, T., Dettinger, M.D., and Cayan, D.R., 2010. The utility of daily large-scale climate data in the assessment of climate change impacts on daily streamflow in California. Hydrology and Earth System Sciences, 14: 1125-1138. Global attribute 9: comment, size = 63 NC_CHAR, value = Quantile mapping extrapolation based on delta-method; tol=0.001 Global attribute 10: contact, size = 29 NC_CHAR, value = Alex Cannon (acannon@uvic.ca) Global attribute 11: driving_institution, size = 33 NC_CHAR, value = Meteorological Research Institute Global attribute 12: driving_institute_id, size = 3 NC_CHAR, value = MRI Global attribute 13: driving_experiment, size = 35 NC_CHAR, value = MRI-CGCM3, historical+rcp85, r1i1p1 Global attribute 14: driving_model_id, size = 9 NC_CHAR, value = MRI-CGCM3 Global attribute 15: driving_model_ensemble_member, size = 6 NC_CHAR, value = r1i1p1 Global attribute 16: driving_experiment_name, size = 18 NC_CHAR, value = historical, RCP8.5 Global attribute 17: target_institution, size = 49 NC_CHAR, value = Canadian Forest Service, Natural Resources Canada Global attribute 18: target_institute_id, size = 9 NC_CHAR, value = CFS-NRCan Global attribute 19: target_dataset, size = 63 NC_CHAR, value = ANUSPLIN interpolated Canada daily 300 arc second climate grids Global attribute 20: target_id, size = 11 NC_CHAR, value = ANUSPLIN300 Global attribute 21: target_references, size = 550 NC_CHAR, value = McKenney, D.W., Hutchinson, M.F., Papadopol, P., Lawrence, K., Pedlar, J., Campbell, K., Milewska, E., Hopkinson, R., Price, D., and Owen, T.,

Customized spatial climate models for North America. Bulletin of the American Meteorological Society, 92(12): 1611-1622.

Hopkinson, R.F., McKenney, D.W., Milewska, E.J., Hutchinson, M.F., Papadopol, P., Vincent, L.A., 2011. Impact of aligning climatological day on gridding daily maximum-minimum temperature and precipitation over Canada. Journal of Applied Meteorology and Climatology 50: 1654-1665. Global attribute 22: target_version, size = 27 NC_CHAR, value = canada_daily_standard_grids Global attribute 23: target_history, size = 57 NC_CHAR, value = obtained: 2 April 2012, 14 June 2012, and 30 January 2013 Global attribute 24: target_contact, size = 47 NC_CHAR, value = Pia Papadopol (pia.papadopol@nrcan-rncan.gc.ca) Global attribute 25: title, size = 97 NC_CHAR, value = Bias Correction/Constructed Analogue Quantile Mapping (BCCAQ) downscaling model output for Canada Global attribute 26: creation_date, size = 20 NC_CHAR, value = 2013-10-16T15:54:58Z Global attribute 27: history, size = 303 NC_CHAR, value = Tue Mar 11 16:42:17 2014: ncks -d time,0,4 /home/data/climate/downscale/CMIP5/BCCAQ/pr+tasmax+tasmin_day_BCCAQ+ANUSPLIN300+MRI-CGCM3_historical+rcp85_r1i1p1_19500101-21001231.nc /home/bronaugh/public_html/pr+tasmax+tasmin_day_BCCAQ+ANUSPLIN300+MRI-CGCM3_historical+rcp85_r1i1p1_19500101-21001231.nc.sub Global attribute 28: NCO, size = 6 NC_CHAR, value = 4.0.9

lat: type NC_DOUBLE, 1 dimension, 4 attributes, chunked? no, compressed? no, packed? no lat size (RAM) = 2_sizeof(NC_DOUBLE) = 2_8 = 16 bytes lat dimension 0: lat, size = 2 NC_DOUBLE (Coordinate is lat) lat attribute 0: standard_name, size = 8 NC_CHAR, value = latitude lat attribute 1: long_name, size = 8 NC_CHAR, value = latitude lat attribute 2: units, size = 13 NC_CHAR, value = degrees_north lat attribute 3: axis, size = 1 NC_CHAR, value = Y

lon: type NC_DOUBLE, 1 dimension, 4 attributes, chunked? no, compressed? no, packed? no lon size (RAM) = 2_sizeof(NC_DOUBLE) = 2_8 = 16 bytes lon dimension 0: lon, size = 2 NC_DOUBLE (Coordinate is lon) lon attribute 0: standard_name, size = 9 NC_CHAR, value = longitude lon attribute 1: long_name, size = 9 NC_CHAR, value = longitude lon attribute 2: units, size = 12 NC_CHAR, value = degrees_east lon attribute 3: axis, size = 1 NC_CHAR, value = X

pr: type NC_FLOAT, 3 dimensions, 6 attributes, chunked? yes, compressed? no, packed? no pr size (RAM) = 5_2_2_sizeof(NC_FLOAT) = 20_4 = 80 bytes pr dimension 0: time, size = 5 NC_DOUBLE, chunksize = 1 (Record coordinate is time) pr dimension 1: lat, size = 2 NC_DOUBLE, chunksize = 510 (Coordinate is lat) pr dimension 2: lon, size = 2 NC_DOUBLE, chunksize = 1068 (Coordinate is lon) pr attribute 0: standard_name, size = 18 NC_CHAR, value = precipitation_flux pr attribute 1: long_name, size = 13 NC_CHAR, value = Precipitation pr attribute 2: units, size = 8 NC_CHAR, value = mm day-1 pr attribute 3: _FillValue, size = 1 NC_FLOAT, value = -32768 pr attribute 4: missing_value, size = 1 NC_FLOAT, value = -32768 pr attribute 5: cell_methods, size = 10 NC_CHAR, value = time: mean

tasmax: type NC_FLOAT, 3 dimensions, 6 attributes, chunked? yes, compressed? no, packed? no tasmax size (RAM) = 5_2_2_sizeof(NC_FLOAT) = 20_4 = 80 bytes tasmax dimension 0: time, size = 5 NC_DOUBLE, chunksize = 1 (Record coordinate is time) tasmax dimension 1: lat, size = 2 NC_DOUBLE, chunksize = 510 (Coordinate is lat) tasmax dimension 2: lon, size = 2 NC_DOUBLE, chunksize = 1068 (Coordinate is lon) tasmax attribute 0: standard_name, size = 15 NC_CHAR, value = air_temperature tasmax attribute 1: long_name, size = 42 NC_CHAR, value = Daily Maximum Near-Surface Air Temperature tasmax attribute 2: units, size = 4 NC_CHAR, value = degC tasmax attribute 3: _FillValue, size = 1 NC_FLOAT, value = -32768 tasmax attribute 4: missing_value, size = 1 NC_FLOAT, value = -32768 tasmax attribute 5: cell_methods, size = 13 NC_CHAR, value = time: maximum

tasmin: type NC_FLOAT, 3 dimensions, 6 attributes, chunked? yes, compressed? no, packed? no tasmin size (RAM) = 5_2_2_sizeof(NC_FLOAT) = 20_4 = 80 bytes tasmin dimension 0: time, size = 5 NC_DOUBLE, chunksize = 1 (Record coordinate is time) tasmin dimension 1: lat, size = 2 NC_DOUBLE, chunksize = 510 (Coordinate is lat) tasmin dimension 2: lon, size = 2 NC_DOUBLE, chunksize = 1068 (Coordinate is lon) tasmin attribute 0: standard_name, size = 15 NC_CHAR, value = air_temperature tasmin attribute 1: long_name, size = 42 NC_CHAR, value = Daily Minimum Near-Surface Air Temperature tasmin attribute 2: units, size = 4 NC_CHAR, value = degC tasmin attribute 3: _FillValue, size = 1 NC_FLOAT, value = -32768 tasmin attribute 4: missing_value, size = 1 NC_FLOAT, value = -32768 tasmin attribute 5: cell_methods, size = 13 NC_CHAR, value = time: minimum

time: type NC_DOUBLE, 1 dimension, 3 attributes, chunked? yes, compressed? no, packed? no time size (RAM) = 5_sizeof(NC_DOUBLE) = 5_8 = 40 bytes time dimension 0: time, size = 5 NC_DOUBLE, chunksize = 1 (Record coordinate is time) time attribute 0: standard_name, size = 4 NC_CHAR, value = time time attribute 1: units, size = 30 NC_CHAR, value = days since 1950-01-01 00:00:00 time attribute 2: calendar, size = 8 NC_CHAR, value = standard

H5Dread: Called! H5FD_sec2_read: Called!, type = 3, addr = 13463, size = 4080 H5Dread: Called! lat[0]=41.041666665 degrees_north lat[1]=41.124999995 degrees_north H5Dread: Called! H5FD_sec2_read: Called!, type = 3, addr = 17543, size = 8544 H5Dread: Called!

lon[0]=-140.958333335 degrees_east lon[1]=-140.875000005 degrees_east H5Dread: Called! H5FD_sec2_read: Called!, type = 2, addr = 26087, size = 3136 H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 29223, size = 2178720 H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 2207943, size = 2178720 H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 4386663, size = 2178720 H5Dchunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 6565383, size = 2178720 H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 26182231, size = 2178720 H5Dchunk_read: Will perform I/O from cached chunk H5Dread: Called! H5FD_sec2_read: Called!, type = 2, addr = 26180135, size = 2096 H5D__chunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 9777, size = 8 H5Dchunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 9785, size = 8 H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 9793, size = 8 H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 9801, size = 8 H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 9809, size = 8 H5D__chunk_read: Will perform I/O from cached chunk H5Dread: Called! H5Dread: Called!

time[0]=0 lat[0]=41.041666665 lon[0]=-140.958333335 pr[0]= mm day-1 time[0]=0 lat[0]=41.041666665 lon[1]=-140.875000005 pr[1]= mm day-1 time[0]=0 lat[1]=41.124999995 lon[0]=-140.958333335 pr[1068]= mm day-1 time[0]=0 lat[1]=41.124999995 lon[1]=-140.875000005 pr[1069]= mm day-1 time[1]=1 lat[0]=41.041666665 lon[0]=-140.958333335 pr[544680]= mm day-1 time[1]=1 lat[0]=41.041666665 lon[1]=-140.875000005 pr[544681]= mm day-1 time[1]=1 lat[1]=41.124999995 lon[0]=-140.958333335 pr[545748]= mm day-1 time[1]=1 lat[1]=41.124999995 lon[1]=-140.875000005 pr[545749]= mm day-1 time[2]=2 lat[0]=41.041666665 lon[0]=-140.958333335 pr[1089360]= mm day-1 time[2]=2 lat[0]=41.041666665 lon[1]=-140.875000005 pr[1089361]= mm day-1 time[2]=2 lat[1]=41.124999995 lon[0]=-140.958333335 pr[1090428]= mm day-1 time[2]=2 lat[1]=41.124999995 lon[1]=-140.875000005 pr[1090429]= mm day-1 time[3]=3 lat[0]=41.041666665 lon[0]=-140.958333335 pr[1634040]= mm day-1 time[3]=3 lat[0]=41.041666665 lon[1]=-140.875000005 pr[1634041]= mm day-1 time[3]=3 lat[1]=41.124999995 lon[0]=-140.958333335 pr[1635108]= mm day-1 time[3]=3 lat[1]=41.124999995 lon[1]=-140.875000005 pr[1635109]= mm day-1 time[4]=4 lat[0]=41.041666665 lon[0]=-140.958333335 pr[2178720]= mm day-1 time[4]=4 lat[0]=41.041666665 lon[1]=-140.875000005 pr[2178721]= mm day-1 time[4]=4 lat[1]=41.124999995 lon[0]=-140.958333335 pr[2179788]= mm day-1 time[4]=4 lat[1]=41.124999995 lon[1]=-140.875000005 pr[2179789]= mm day-1 H5Dread: Called! H5FD_sec2_read: Called!, type = 2, addr = 8744103, size = 3136 H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 8747239, size = 2178720 H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 10925959, size = 2178720 H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 13104679, size = 2178720 H5Dchunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 15283399, size = 2178720 H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 28360951, size = 2178720 H5Dchunk_read: Will perform I/O from cached chunk H5Dread: Called! H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_read: Will perform I/O from cached chunk H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_read: Will perform I/O from cached chunk H5Dread: Called! H5Dread: Called!

time[0]=0 lat[0]=41.041666665 lon[0]=-140.958333335 tasmax[0]= degC time[0]=0 lat[0]=41.041666665 lon[1]=-140.875000005 tasmax[1]= degC time[0]=0 lat[1]=41.124999995 lon[0]=-140.958333335 tasmax[1068]= degC time[0]=0 lat[1]=41.124999995 lon[1]=-140.875000005 tasmax[1069]= degC time[1]=1 lat[0]=41.041666665 lon[0]=-140.958333335 tasmax[544680]= degC time[1]=1 lat[0]=41.041666665 lon[1]=-140.875000005 tasmax[544681]= degC time[1]=1 lat[1]=41.124999995 lon[0]=-140.958333335 tasmax[545748]= degC time[1]=1 lat[1]=41.124999995 lon[1]=-140.875000005 tasmax[545749]= degC time[2]=2 lat[0]=41.041666665 lon[0]=-140.958333335 tasmax[1089360]= degC time[2]=2 lat[0]=41.041666665 lon[1]=-140.875000005 tasmax[1089361]= degC time[2]=2 lat[1]=41.124999995 lon[0]=-140.958333335 tasmax[1090428]= degC time[2]=2 lat[1]=41.124999995 lon[1]=-140.875000005 tasmax[1090429]= degC time[3]=3 lat[0]=41.041666665 lon[0]=-140.958333335 tasmax[1634040]= degC time[3]=3 lat[0]=41.041666665 lon[1]=-140.875000005 tasmax[1634041]= degC time[3]=3 lat[1]=41.124999995 lon[0]=-140.958333335 tasmax[1635108]= degC time[3]=3 lat[1]=41.124999995 lon[1]=-140.875000005 tasmax[1635109]= degC time[4]=4 lat[0]=41.041666665 lon[0]=-140.958333335 tasmax[2178720]= degC time[4]=4 lat[0]=41.041666665 lon[1]=-140.875000005 tasmax[2178721]= degC time[4]=4 lat[1]=41.124999995 lon[0]=-140.958333335 tasmax[2179788]= degC time[4]=4 lat[1]=41.124999995 lon[1]=-140.875000005 tasmax[2179789]= degC H5Dread: Called! H5FD_sec2_read: Called!, type = 2, addr = 17462119, size = 3136 H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 17465255, size = 2178720 H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 19643975, size = 2178720 H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 21822695, size = 2178720 H5Dchunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 24001415, size = 2178720 H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_lock: Before reading chunk from file H5FD_sec2_read: Called!, type = 3, addr = 30539671, size = 2178720 H5Dchunk_read: Will perform I/O from cached chunk H5Dread: Called! H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_read: Will perform I/O from cached chunk H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_read: Will perform I/O from cached chunk H5Dread: Called! H5Dread: Called!

time[0]=0 lat[0]=41.041666665 lon[0]=-140.958333335 tasmin[0]= degC time[0]=0 lat[0]=41.041666665 lon[1]=-140.875000005 tasmin[1]= degC time[0]=0 lat[1]=41.124999995 lon[0]=-140.958333335 tasmin[1068]= degC time[0]=0 lat[1]=41.124999995 lon[1]=-140.875000005 tasmin[1069]= degC time[1]=1 lat[0]=41.041666665 lon[0]=-140.958333335 tasmin[544680]= degC time[1]=1 lat[0]=41.041666665 lon[1]=-140.875000005 tasmin[544681]= degC time[1]=1 lat[1]=41.124999995 lon[0]=-140.958333335 tasmin[545748]= degC time[1]=1 lat[1]=41.124999995 lon[1]=-140.875000005 tasmin[545749]= degC time[2]=2 lat[0]=41.041666665 lon[0]=-140.958333335 tasmin[1089360]= degC time[2]=2 lat[0]=41.041666665 lon[1]=-140.875000005 tasmin[1089361]= degC time[2]=2 lat[1]=41.124999995 lon[0]=-140.958333335 tasmin[1090428]= degC time[2]=2 lat[1]=41.124999995 lon[1]=-140.875000005 tasmin[1090429]= degC time[3]=3 lat[0]=41.041666665 lon[0]=-140.958333335 tasmin[1634040]= degC time[3]=3 lat[0]=41.041666665 lon[1]=-140.875000005 tasmin[1634041]= degC time[3]=3 lat[1]=41.124999995 lon[0]=-140.958333335 tasmin[1635108]= degC time[3]=3 lat[1]=41.124999995 lon[1]=-140.875000005 tasmin[1635109]= degC time[4]=4 lat[0]=41.041666665 lon[0]=-140.958333335 tasmin[2178720]= degC time[4]=4 lat[0]=41.041666665 lon[1]=-140.875000005 tasmin[2178721]= degC time[4]=4 lat[1]=41.124999995 lon[0]=-140.958333335 tasmin[2179788]= degC time[4]=4 lat[1]=41.124999995 lon[1]=-140.875000005 tasmin[2179789]= degC H5Dread: Called! H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_read: Will perform I/O from cached chunk H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_read: Will perform I/O from cached chunk H5Dread: Called! H5Dchunk_read: Will perform I/O from cached chunk H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_read: Will perform I/O from cached chunk H5Dchunk_read: Will perform I/O from cached chunk H5D__chunk_read: Will perform I/O from cached chunk

time[0]=0 days since 1950-01-01 00:00:00 time[1]=1 days since 1950-01-01 00:00:00 time[2]=2 days since 1950-01-01 00:00:00 time[3]=3 days since 1950-01-01 00:00:00 time[4]=4 days since 1950-01-01 00:00:00

Basically, the I/O of type "3" is data elements, everything else is metadata of one type or another.

I'd like to chase this further, but I need some help reproducing your output.

Well; I wish there were line numbers on there, but to me it's clear that the HDF5 library is reading in the entire field here for pr, tasmin, tasmax. Every line that looks like this:

H5FD_sec2_read: Called!, type = 3, addr = 17465255, size = 2178720

is showing a read that causes a full-field read to happen. 2178720 is the product of the lat and long dimensions multiplied by 4 (sizeof float).

If you set the NetCDF chunk cache size to 2MiB with nelems=1009 (the default) either in the config.h for NetCDF or by calling nc_set_chunk_cache in ncks, it will begin doing 8 byte reads for this case as I would expect.

A peculiarity I've uncovered is that if you shrink the chunk cache still further (say, to 128KiB) the full-field read behaviour returns... I have no idea what the source of this is, as it makes absolutely no sense to me.

Thanks for looking into this, and please let me know if you need any further clarification, test cases, etc.

On Mar 17, 2014, at 6:45 PM, bronaugh notifications@github.com wrote:

Well; I wish there were line numbers on there, but to me it's clear that the HDF5 library is reading in the entire field here for pr, tasmin, tasmax. Every line that looks like this:

H5FD_sec2_read: Called!, type = 3, addr = 17465255, size = 2178720 is showing a read that causes a full-field read to happen. 2178720 is the product of the lat and long dimensions multiplied by 4 (sizeof float).

Yes, it's reading in the entire chunk, which appears to be the same size as the dataset.  On the other hand, if you look further in the log, you'll see a bunch of these lines:

H5D__chunk_read: Will perform I/O from cached chunk

with no corresponding I/O to the file.  So, it's saved a bunch of I/O operations by holding the entire chunk in the cache.

If you set the NetCDF chunk cache size to 2MiB with nelems=1009 (the default) either in the config.h for NetCDF or by calling nc_set_chunk_cache in ncks, it will begin doing 8 byte reads for this case as I would expect.

Yes, I would expect that too.  (Since the entire chunk can't be held in the cache)

A peculiarity I've uncovered is that if you shrink the chunk cache still further (say, to 128KiB) the full-field read behaviour returns... I have no idea what the source of this is, as it makes absolutely no sense to me.

Thanks for looking into this, and please let me know if you need any further clarification, test cases, etc.

Hmm, that's weird, I'll give it a try with the chunk cache turned down that far and see what happens.

OK, I've tried with the 2MiB cache size and I definitely see the switch to reading smaller pieces of the datasets. However, I've tweaked down to 128KiB and I don't see any change (still reading smaller pieces of datasets). Can you send me more information, if you are still seeing this?

Closing until we get more information or this resurfaces.

Unidata / netcdf-c

Low performance with some files caused by reading of entire field #39

Index: src/H5Dchunk.c

Index: src/H5Dio.c

Index: src/H5FDsec2.c