general HDF5 module support

[shanedsnyder]

We've made a ton of progress recently in getting v1 of the summary reports completed, but wanted to create an issue so we don't forget to generally include HDF5 support in our figures. I imagine it's not too difficult to extend the different figures to include HDF5 module data. I notice we do have some HDF5 data related to access sizes already, but we could probably include it in the op counts graphs, as well as in the I/O cost graph.

Thinking about it more, the HDF5 module probably requires a bit of special care since it's really 2 modules (H5F for file access, and H5D for dataset access). For I/O cost graphs and op count graphs, we will probably want to just combine the info from each module into a single "HDF5" field. Similarly, the per-module section of the report probably has an "HDF5" module section that characterizes both the H5F and H5D modules.

[shanedsnyder]

Maybe we can just flesh out details at our next meeting and I can update the issue once it's more clear what the plan is.

[nawtrey]

If we are going to combine module data that could take some care. We probably want it handled in some kind of aggregator that stores it in the DarshanReport, like we have for some of the other figures.

For HDF5 logs, we currently only have ior_hdf5_example.darshan and shane_macsio_id29959_5-22-32552-7035573431850780836_1590156158.darshan that contain H5F and H5D modules, are these are sufficient cases for testing? If we plan to officially support HDF5 we should probably have representative logs for testing.

[nawtrey]

Tyler had some good comments in today's meeting about collecting testing logs for this issue which I don't think my comment above captured. He suggested that we collect/create logs with known or easy-to-determine values (say we know it opened 5 files) for testing. Since we can't use the original darshan reports to confirm our outputs for HDF5-related things, this would give us a lot more confidence moving forward, especially if the data post-processing gets complicated.

[tylerjereddy]

A Python-based approach like the one in darshan-hpc/darshan-logs#22 and https://github.com/tylerjereddy/heatmap_diagonal could likely be used with h5py to do pretty much anything you want for producing custom darshan logs with "ground truth" HDF5 activity.

[nawtrey]

I've been trying to develop some logs for testing here, and I've created logs for a couple cases that I would like some feedback on. I started with Tyler's approach and used h5py to write to 1 file/dataset per rank:

HDF5 diagonal code

import os
import time
import argparse

import numpy as np
from mpi4py import MPI
import h5py


def handle_io(test_dir_path, rank_val, delay_time, n_bytes, mode):
    # read/write n_bytes to/from a file from
    # rank rank_val after delay_time seconds
    time.sleep(delay_time)
    filename = f"test_{rank_val}.h5"
    file_path = os.path.join(test_dir_path, filename)

    if mode == "read":
        with h5py.File(file_path, "r") as f:
            data = np.asarray(f.get('data')).tobytes()
    elif mode == "write":
        bytes_to_write = np.void(bytes(1) * n_bytes)
        with h5py.File(file_path, "w") as f:
            f.create_dataset("dataset", data=bytes_to_write)


def main(mode, n_bytes):
    comm = MPI.COMM_WORLD
    rank = comm.Get_rank()
    size = comm.Get_size()

    # each rank should write data
    # at a specific offset time to
    # produce diagonal heatmap IO
    # activity like this:
    #       x
    #     x
    #   x
    # x

    dir_name = f"test_files_{mode}_{n_bytes}_bytes"
    test_dir_path = os.path.join(os.getcwd(), dir_name)

    delay_time = 0.5 + (rank * 0.2)
    for rank_val in range(size):
        if rank == rank_val:
            handle_io(
                test_dir_path=test_dir_path,
                rank_val=rank_val,
                delay_time=delay_time,
                n_bytes=n_bytes,
                mode=mode,
            )    


if __name__ == "__main__":
    parser = argparse.ArgumentParser()
    parser.add_argument(
        "run_mode",
        type=str,
        help="Specify run mode (i.e. 'read' or 'write')",
    )
    parser.add_argument(
        "n_bytes",
        type=int,
        help="Specify number of bytes to read/write",
    )
    args = parser.parse_args()
    mode = args.run_mode
    n_bytes = args.n_bytes
    main(mode=mode, n_bytes=n_bytes)

Note: Most of the code here isn't important, but it might be worth looking over the "read" and "write" modes of handling_io().

Writing data

Running this in the "write" mode will mimic Tyler's MPI code pretty closely, with heatmaps like the following:

This case wrote 1 byte of data to 10 different files/datasets using 10 ranks. The H5D data for this log reflect this:

0    0
1    0
2    0
3    0
4    0
5    0
6    0
7    0
8    0
9    0
Name: H5D_BYTES_READ, dtype: int64
0    1
1    1
2    1
3    1
4    1
5    1
6    1
7    1
8    1
9    1
Name: H5D_BYTES_WRITTEN, dtype: int64

Reading data

With that working as intended, I wanted to see if I could get a similar log where we read instead of write. To do this, I just create a bunch of files, each with a single dataset and number of bytes stored in it (usually 1), then retrieve that dataset at runtime using the handling_io(mode="read") function in my code above. The leg work for setting up the files is handled in a separate script that I wrote.

The issue for me is when I run my script this way, I don't get any H5D data at all. I only get H5F data:

   rank  H5F_OPENS  H5F_FLUSHES  H5F_USE_MPIIO
0     0          1            0              0
1     1          1            0              0
2     2          1            0              0
3     3          1            0              0
4     4          1            0              0
5     5          1            0              0
6     6          1            0              0
7     7          1            0              0
8     8          1            0              0
9     9          1            0              0

Here is the heatmap for the same log (read only):

While this is useful in terms of having a log that has only H5F data (likely a very rare case), it doesn't satisfy my goal of getting a "read-only" HDF5 log.

Question:

Is it obvious to anyone else why we would see reading at the POSIX level and not pick it up in H5D? I have double-checked that each file contains the correct data to be read, but I feel like I'm missing something conceptually. My guess is the approach in my handling_io(mode="read") mode is naive.

[nawtrey]

Unrelated to my last comment, my understanding of how we want to combine the H5F and H5D "Operation Counts" data is to sum the H5F and H5D totals. Both modules contain "Opens" and "Flush" counters which can be combined. As an example, ior_hdf5_example.darshan has the following "Opens" data:

rank, H5F_OPENS
0    2
1    2
2    2

rank, H5D_OPENS
0    2
1    2
2    2

For each module the total "Opens" is 6, so if we sum these values together, we get a total of 12 "Opens" for HDF5. Is that how we want to combine the HDF5 module data? I ask because when these values are separate, I get the understanding that there were 6 instances where a file was opened and its dataset(s) were accessed. But with the values summed to 12 under a single "HDF5" banner, I feel like it gives the impression that 12 files were opened, at least at a glance.

I know we are going to lose some granularity either way, but would it make more sense to use the H5F "Opens" summed value for the combined HDF5 "Opens"? The H5F sum is always going to be greater than or equal to the H5D sum, but it would avoid the sort of "double counting" that we would get with a simple sum.

[tylerjereddy]

To address #663 (comment) first, I was able to reproduce the read-invisbility of H5D, and I also confirmed that round-tripping is not recorded either:

from mpi4py import MPI
import numpy as np
from numpy.testing import assert_array_equal
import h5py

def main():
    comm = MPI.COMM_WORLD
    rank = comm.Get_rank()

    # round trip HDF5 IO test
    file_path = f"./test_rank_{rank}.hdf5"
    n_bytes = 10 * (rank + 1)

    bytes_to_write = np.ones(shape=n_bytes, dtype=np.int8)

    with h5py.File(file_path, "w") as f:
        f.create_dataset("dataset", data=bytes_to_write)

    with h5py.File(file_path, "r") as g:
        retrieved_data = np.asarray(g['dataset'])
        assert_array_equal(retrieved_data, bytes_to_write)

if __name__ == "__main__":
    main()

The ramped up bytes written per rank is correctly recorded, and the increase in bytes read is true according to the NumPy assertion, but completely invisible to the darshan-runtime (see below the fold). In fact, H5D seems completely unaware of the file opens that happen for reading, while H5F records the file handle opening for both events. So either there's a bug in the runtime or the runtime bindings aren't capable of handling the Python layering on the read side. I'll leave that to @carns or @shanedsnyder to assess.

mpirun -x DXT_ENABLE_IO_TRACE=1 -x DARSHAN_LOGPATH=/yellow/users/treddy/generated_darshan_logs -x DARSHAN_DISABLE_SHARED_REDUCTION=1 -x LD_PRELOAD=/yellow/users/treddy/darshan_install/lib/libdarshan.so:/usr/projects/hpcsoft/toss3/snow/hdf5/1.10.7_gcc-9.3.0_openmpi-3.1.6/lib/libhdf5.so -np 10 python3 test.py

{'POSIX': <darshan.report.DarshanRecordCollection object at 0x7f28ef2b7670>, 'H5F': <darshan.report.DarshanRecordCollection object at 0x7f28eed3e5b0>, 'H5D': <darshan.report.DarshanRecordCollection object at 0x7f28eed3efd0>, 'DXT_POSIX': <darshan.report.DarshanRecordCollection object at 0x7f28ef28e670>}
H5D dataframe counters:
    rank                    id  H5D_OPENS  H5D_READS  H5D_WRITES  H5D_FLUSHES  H5D_BYTES_READ  H5D_BYTES_WRITTEN  H5D_RW_SWITCHES  ...  H5D_CHUNK_SIZE_D3  H5D_CHUNK_SIZE_D4  H5D_CHUNK_SIZE_D5  H5D_USE_MPIIO_COLLECTIVE  H5D_USE_DEPRECATED  H5D_FASTEST_RANK  H5D_FASTEST_RANK_BYTES  H5D_SLOWEST_RANK  H5D_SLOWEST_RANK_BYTES
0     0  11686675357054819694          1          0           1            0               0                 10                0  ...                  0                  0                  0                         0                   0                 0                       0                 0                       0
1     1  13816125359238839068          1          0           1            0               0                 20                0  ...                  0                  0                  0                         0                   0                 0                       0                 0                       0
2     2   8163471921814110286          1          0           1            0               0                 30                0  ...                  0                  0                  0                         0                   0                 0                       0                 0                       0
3     3   5704909803088537921          1          0           1            0               0                 40                0  ...                  0                  0                  0                         0                   0                 0                       0                 0                       0
4     4   5895888996501598751          1          0           1            0               0                 50                0  ...                  0                  0                  0                         0                   0                 0                       0                 0                       0
5     5  10662237727056981784          1          0           1            0               0                 60                0  ...                  0                  0                  0                         0                   0                 0                       0                 0                       0
6     6  11021700834876979282          1          0           1            0               0                 70                0  ...                  0                  0                  0                         0                   0                 0                       0                 0                       0
7     7  15718980487096942502          1          0           1            0               0                 80                0  ...                  0                  0                  0                         0                   0                 0                       0                 0                       0
8     8   6635034257651523170          1          0           1            0               0                 90                0  ...                  0                  0                  0                         0                   0                 0                       0                 0                       0
9     9   7789431687327723946          1          0           1            0               0                100                0  ...                  0                  0                  0                         0                   0                 0                       0                 0                       0

[10 rows x 96 columns]
H5D dataframe fcounters:
    rank                    id  H5D_F_OPEN_START_TIMESTAMP  H5D_F_READ_START_TIMESTAMP  H5D_F_WRITE_START_TIMESTAMP  H5D_F_CLOSE_START_TIMESTAMP  ...  H5D_F_MAX_READ_TIME  H5D_F_MAX_WRITE_TIME  H5D_F_FASTEST_RANK_TIME  H5D_F_SLOWEST_RANK_TIME  H5D_F_VARIANCE_RANK_TIME  H5D_F_VARIANCE_RANK_BYTES
0     0  11686675357054819694                    0.759960                         0.0                     0.760155                          0.0  ...                  0.0              0.000046                      0.0                      0.0                       0.0                        0.0
1     1  13816125359238839068                    0.758065                         0.0                     0.758297                          0.0  ...                  0.0              0.000040                      0.0                      0.0                       0.0                        0.0
2     2   8163471921814110286                    0.758488                         0.0                     0.758685                          0.0  ...                  0.0              0.000034                      0.0                      0.0                       0.0                        0.0
3     3   5704909803088537921                    0.759318                         0.0                     0.759495                          0.0  ...                  0.0              0.000034                      0.0                      0.0                       0.0                        0.0
4     4   5895888996501598751                    0.759557                         0.0                     0.759741                          0.0  ...                  0.0              0.000034                      0.0                      0.0                       0.0                        0.0
5     5  10662237727056981784                    0.755550                         0.0                     0.755747                          0.0  ...                  0.0              0.000048                      0.0                      0.0                       0.0                        0.0
6     6  11021700834876979282                    0.755203                         0.0                     0.755376                          0.0  ...                  0.0              0.000042                      0.0                      0.0                       0.0                        0.0
7     7  15718980487096942502                    0.757642                         0.0                     0.757850                          0.0  ...                  0.0              0.000033                      0.0                      0.0                       0.0                        0.0
8     8   6635034257651523170                    0.754759                         0.0                     0.754982                          0.0  ...                  0.0              0.000041                      0.0                      0.0                       0.0                        0.0
9     9   7789431687327723946                    0.756886                         0.0                     0.757096                          0.0  ...                  0.0              0.000032                      0.0                      0.0                       0.0                        0.0

[10 rows x 19 columns]
H5F dataframe counters:
    rank                    id  H5F_OPENS  H5F_FLUSHES  H5F_USE_MPIIO
0     0  12338924892616139460          2            0              0
1     1   2374806179835333680          2            0              0
2     2   4741602306122135968          2            0              0
3     3   6304996309454365857          2            0              0
4     4  14038849941392865518          2            0              0
5     5  17284205279612898412          2            0              0
6     6  11364139169532633768          2            0              0
7     7  12429378654238249285          2            0              0
8     8   1186195185660660511          2            0              0
9     9  10257107547145179444          2            0              0
H5F dataframe fcounters:
    rank                    id  H5F_F_OPEN_START_TIMESTAMP  H5F_F_CLOSE_START_TIMESTAMP  H5F_F_OPEN_END_TIMESTAMP  H5F_F_CLOSE_END_TIMESTAMP  H5F_F_META_TIME
0     0  12338924892616139460                    0.750439                          0.0                  0.762948                        0.0         0.011012
1     1   2374806179835333680                    0.750282                          0.0                  0.761436                        0.0         0.009390
2     2   4741602306122135968                    0.750133                          0.0                  0.761668                        0.0         0.009890
3     3   6304996309454365857                    0.750318                          0.0                  0.762342                        0.0         0.010498
4     4  14038849941392865518                    0.750317                          0.0                  0.762754                        0.0         0.010261
5     5  17284205279612898412                    0.749981                          0.0                  0.759153                        0.0         0.007335
6     6  11364139169532633768                    0.750280                          0.0                  0.758589                        0.0         0.006231
7     7  12429378654238249285                    0.750204                          0.0                  0.761028                        0.0         0.008457
8     8   1186195185660660511                    0.750030                          0.0                  0.758631                        0.0         0.006761
9     9  10257107547145179444                    0.750031                          0.0                  0.760369                        0.0         0.008668

[tylerjereddy]

I'm also wondering if H5G activity may be invisible to H5D monitoring in the runtime--I'll send a message about that in Slack channel.

[nawtrey]

For reference, Shane gave an update on how to combine the HDF5 modules in this comment:

Yep, sorry about the confusion guys. Just to make sure we're on the same page, I think the op counts graph would have the following:

• "file opens" (aggregated H5F_OPENS values)
• "dataset opens" (aggregated H5D_OPENS values)
• "dataset writes" (aggregated H5D_WRITES values)
• "dataset reads" (aggregated H5D_READS values)
• "file flushes" (aggregated H5F_FLUSHES values)
• "dataset flushes" (aggregated H5D_FLUSHES values)

(Not necessarily related to this PR, but as Tyler mentions, for the I/O cost plots that independently measure read/write/meta time components, you will need to combine the total META_TIMES from dataset and file modules. You shouldn't need to do anything like that for the op counts, though).

[nawtrey]

As far as "ground truth" HDF5 testing logs go, these are the current cases we've been able to create successfully:

1. open a file but never read/write to it (to get a small log with only H5F data)
2. open N files over N ranks, create N datasets, write n_bytes to each (my original "write" strategy above)
3. the same as 2, but vary n_bytes (like Tyler did above)
4. open N files over N ranks, create N/2 datasets, write n_bytes to each (like Tyler did here)
5. open N files over N ranks, create N datasets, write n_bytes to each, flush N/2 files (like I did here)

I think we would still want to supplement these with some others where H5D picks up the read events, but I think some of these are useful already. Should I create a log for each case and open PRs for them in the logs repo? And if so, I'm guessing it's fine to group them together in a single directory too, since they are all for the same purpose?

[tylerjereddy]

I suspect a single directory would be ok for some of these simple cooked-up HDF5 cases. The Python code is almost small enough to put in there too (though we haven't been doing that), or just link to the small source snippets I suppose. I guess the team might even be "ok" with just a short description of how each log was generated without needing the source connections/links.

[tylerjereddy]

Closing due to merge of gh-707 -- if there are residual issues discussed here it may be easier to split them off into other issues, though I believe at least Shane's initial comment is dealt with.