darshan-parser.c 36.4 KB
Newer Older
1 2 3 4 5
/*
 *  (C) 2009 by Argonne National Laboratory.
 *      See COPYRIGHT in top-level directory.
 */

6 7 8 9 10 11 12 13
#include <stdio.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <unistd.h>
#include <string.h>
#include <zlib.h>
#include <time.h>
14
#include <stdlib.h>
15
#include <getopt.h>
16
#include <assert.h>
17

18
#include "darshan-logutils.h"
19

20
#include "uthash-1.9.2/src/uthash.h"
21 22 23 24

/*
 * Options
 */
25 26 27 28
#define OPTION_BASE  (1 << 0)  /* darshan log fields */
#define OPTION_TOTAL (1 << 1)  /* aggregated fields */
#define OPTION_PERF  (1 << 2)  /* derived performance */
#define OPTION_FILE  (1 << 3)  /* file count totals */
29
#define OPTION_FILE_LIST  (1 << 4)  /* per-file summaries */
30
#define OPTION_FILE_LIST_DETAILED  (1 << 6)  /* per-file summaries with extra detail */
31 32 33 34
#define OPTION_ALL (\
  OPTION_BASE|\
  OPTION_TOTAL|\
  OPTION_PERF|\
35
  OPTION_FILE|\
36 37
  OPTION_FILE_LIST|\
  OPTION_FILE_LIST_DETAILED)
38 39 40 41 42 43 44 45 46 47 48 49 50 51

#define FILETYPE_SHARED (1 << 0)
#define FILETYPE_UNIQUE (1 << 1)
#define FILETYPE_PARTSHARED (1 << 2)

#define max(a,b) (((a) > (b)) ? (a) : (b))
#define max3(a,b,c) (((a) > (b)) ? (((a) > (c)) ? (a) : (c)) : (((b) > (c)) ? (b) : (c)))

/*
 * Datatypes
 */
typedef struct hash_entry_s
{
    UT_hash_handle hlink;
52
    uint64_t hash;
53 54 55 56 57 58
    int64_t type;
    int64_t procs;
    int64_t counters[CP_NUM_INDICES];
    double  fcounters[CP_F_NUM_INDICES];
    double cumul_time;
    double meta_time;
59
    double slowest_time;
Philip Carns's avatar
Philip Carns committed
60
    char name_suffix[CP_NAME_SUFFIX_LEN+1];
61 62 63 64 65 66 67
} hash_entry_t;

typedef struct perf_data_s
{
    int64_t total_bytes;
    double slowest_rank_time;
    double slowest_rank_meta_time;
68
    int slowest_rank_rank;
69 70 71 72 73 74 75 76 77
    double shared_time_by_cumul;
    double shared_time_by_open;
    double shared_time_by_open_lastio;
    double shared_time_by_slowest;
    double shared_meta_time;
    double agg_perf_by_cumul;
    double agg_perf_by_open;
    double agg_perf_by_open_lastio;
    double agg_perf_by_slowest;
78 79
    double *rank_cumul_io_time;
    double *rank_cumul_md_time;
80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109
} perf_data_t;

typedef struct file_data_s
{
    int64_t total;
    int64_t total_size;
    int64_t total_max;
    int64_t read_only;
    int64_t read_only_size;
    int64_t read_only_max;
    int64_t write_only;
    int64_t write_only_size;
    int64_t write_only_max;
    int64_t read_write;
    int64_t read_write_size;
    int64_t read_write_max;
    int64_t unique;
    int64_t unique_size;
    int64_t unique_max;
    int64_t shared;
    int64_t shared_size;
    int64_t shared_max;
} file_data_t;

/*
 * Prototypes
 */
void accum_perf(struct darshan_file *, hash_entry_t *, perf_data_t *);
void calc_perf(struct darshan_job *, hash_entry_t *, perf_data_t *);

110
void accum_file(struct darshan_job *, struct darshan_file *, hash_entry_t *, file_data_t *);
111
void calc_file(struct darshan_job *, hash_entry_t *, file_data_t *);
112
void file_list(struct darshan_job *, hash_entry_t *, int);
113 114 115 116 117 118 119

int usage (char *exename)
{
    fprintf(stderr, "Usage: %s [options] <filename>\n", exename);
    fprintf(stderr, "    --all   : all sub-options are enabled\n");
    fprintf(stderr, "    --base  : darshan log field data [default]\n");
    fprintf(stderr, "    --file  : total file counts\n");
120
    fprintf(stderr, "    --file-list  : per-file summaries\n");
121
    fprintf(stderr, "    --file-list-detailed  : per-file summaries with additional detail\n");
122 123 124 125 126 127 128 129 130 131 132 133 134 135 136
    fprintf(stderr, "    --perf  : derived perf data\n");
    fprintf(stderr, "    --total : aggregated darshan field data\n");

    exit(1);
}

int parse_args (int argc, char **argv, char **filename)
{
    int index;
    int mask;
    static struct option long_opts[] =
    {
        {"all",   0, NULL, OPTION_ALL},
        {"base",  0, NULL, OPTION_BASE},
        {"file",  0, NULL, OPTION_FILE},
137
        {"file-list",  0, NULL, OPTION_FILE_LIST},
138
        {"file-list-detailed",  0, NULL, OPTION_FILE_LIST_DETAILED},
139 140
        {"perf",  0, NULL, OPTION_PERF},
        {"total", 0, NULL, OPTION_TOTAL},
141 142
        {"help",  0, NULL, 0},
        {0, 0, 0, 0}
143 144 145 146 147 148 149 150 151 152 153 154 155 156 157
    };

    mask = 0;

    while(1)
    {
        int c = getopt_long(argc, argv, "", long_opts, &index);

        if (c == -1) break;

        switch(c)
        {
            case OPTION_ALL:
            case OPTION_BASE:
            case OPTION_FILE:
158
            case OPTION_FILE_LIST:
159
            case OPTION_FILE_LIST_DETAILED:
160 161 162 163 164
            case OPTION_PERF:
            case OPTION_TOTAL:
                mask |= c;
                break;
            case 0:
165
            case '?':
166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189
            default:
                usage(argv[0]);
                break;
        }
    }

    if (optind < argc)
    {
        *filename = argv[optind];
    }
    else
    {
        usage(argv[0]);
    }

    /* default mask value if none specified */
    if (mask == 0)
    {
        mask = OPTION_BASE;
    }

    return mask;
}

190 191 192
int main(int argc, char **argv)
{
    int ret;
193 194
    int mask;
    char *filename;
195 196
    struct darshan_job job;
    struct darshan_file cp_file;
197
    char tmp_string[4096];
198
    time_t tmp_time = 0;
199
    darshan_fd file;
200
    int i;
201
    int mount_count;
202
    int64_t* devs;
203 204
    char** mnt_pts;
    char** fs_types;
205
    int last_rank = 0;
206 207
    char *token;
    char *save;
208
    char buffer[DARSHAN_JOB_METADATA_LEN];
209

210 211 212 213 214 215 216 217 218 219 220
    hash_entry_t *file_hash = NULL;
    hash_entry_t *curr = NULL;
    hash_entry_t *tmp = NULL;
    hash_entry_t total;
    perf_data_t pdata;
    file_data_t fdata;

    memset(&pdata, 0, sizeof(pdata));
    memset(&total, 0, sizeof(total));

    mask = parse_args(argc, argv, &filename);
221

222
    file = darshan_log_open(filename, "r");
223 224
    if(!file)
    {
225
        fprintf(stderr, "darshan_log_open() failed to open %s\n.", filename);
226 227 228 229
        return(-1);
    }
   
    /* read job info */
230
    ret = darshan_log_getjob(file, &job);
231
    if(ret < 0)
232
    {
233
        fprintf(stderr, "Error: unable to read job information from log file.\n");
234
        darshan_log_close(file);
235 236 237
        return(-1);
    }

238 239 240
    /* warn user about any missing information in this log format */
    darshan_log_print_version_warnings(&job);

241
    ret = darshan_log_getexe(file, tmp_string);
242
    if(ret < 0)
243
    {
244
        fprintf(stderr, "Error: unable to read trailing job information.\n");
245
        darshan_log_close(file);
246 247 248
        return(-1);
    }

249
    /* print job summary */
250
    printf("# darshan log version: %s\n", job.version_string);
251 252
    printf("# size of file statistics: %zu bytes\n", sizeof(cp_file));
    printf("# size of job statistics: %zu bytes\n", sizeof(job));
253
    printf("# exe: %s\n", tmp_string);
Philip Carns's avatar
Philip Carns committed
254 255 256
    printf("# uid: %" PRId64 "\n", job.uid);
    printf("# jobid: %" PRId64 "\n", job.jobid);
    printf("# start_time: %" PRId64 "\n", job.start_time);
257
    tmp_time += job.start_time;
258
    printf("# start_time_asci: %s", ctime(&tmp_time));
Philip Carns's avatar
Philip Carns committed
259
    printf("# end_time: %" PRId64 "\n", job.end_time);
260 261
    tmp_time = 0;
    tmp_time += job.end_time;
262
    printf("# end_time_asci: %s", ctime(&tmp_time));
Philip Carns's avatar
Philip Carns committed
263 264
    printf("# nprocs: %" PRId64 "\n", job.nprocs);
    printf("# run time: %" PRId64 "\n", job.end_time - job.start_time + 1);
265 266 267 268 269
    for(token=strtok_r(job.metadata, "\n", &save);
        token != NULL;
        token=strtok_r(NULL, "\n", &save))
    {
        char *key;
270 271 272 273 274 275 276 277 278 279 280 281 282 283
        char *value;
        /* NOTE: we intentionally only split on the first = character.
         * There may be additional = characters in the value portion
         * (for example, when storing mpi-io hints).
         */
        strcpy(buffer, token);
        key = buffer;
        value = index(buffer, '=');
        if(!value)
            continue;
        /* convert = to a null terminator to split key and value */
        value[0] = '\0';
        value++;
        printf("# metadata: %s = %s\n", key, value);
284
    }
285 286
 
    /* print table of mounted file systems */
287
    ret = darshan_log_getmounts(file, &devs, &mnt_pts, &fs_types, &mount_count);
288
    printf("\n# mounted file systems (device, mount point, and fs type)\n");
289 290 291
    printf("# -------------------------------------------------------\n");
    for(i=0; i<mount_count; i++)
    {
Philip Carns's avatar
Philip Carns committed
292
        printf("# mount entry: %" PRId64 "\t%s\t%s\n", devs[i], mnt_pts[i], fs_types[i]);
293 294
    }
  
295 296 297 298 299 300 301 302 303
    /* try to retrieve first record (may not exist) */
    ret = darshan_log_getfile(file, &job, &cp_file);
    if(ret < 0)
    {
        fprintf(stderr, "Error: failed to parse log file.\n");
        fflush(stderr);
        return(-1);
    }
    if(ret == 0)
304 305 306
    {
        /* it looks like the app didn't open any files */
        printf("# no files opened.\n");
307
        darshan_log_close(file);
308 309 310
        return(0);
    }

311 312 313 314 315 316 317 318 319
    if ((mask & OPTION_BASE))
    {
        printf("\n# description of columns:\n");
        printf("#   <rank>: MPI rank.  -1 indicates that the file is shared\n");
        printf("#      across all processes and statistics are aggregated.\n");
        printf("#   <file>: hash of file path.  0 indicates that statistics\n");
        printf("#      are condensed to refer to all files opened at the given\n");
        printf("#      process.\n");
        printf("#   <counter> and <value>: statistical counters.\n");
320 321
        printf("#      A value of -1 indicates that Darshan could not monitor\n");
        printf("#      that counter, and its value should be ignored.\n");
322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352
        printf("#   <name suffix>: last %d characters of file name.\n", CP_NAME_SUFFIX_LEN);
        printf("#   <mount pt>: mount point that the file resides on.\n");
        printf("#   <fs type>: type of file system that the file resides on.\n");
        printf("\n# description of counters:\n");
        printf("#   CP_POSIX_*: posix operation counts.\n");
        printf("#   CP_COLL_*: MPI collective operation counts.\n");
        printf("#   CP_INDEP_*: MPI independent operation counts.\n");
        printf("#   CP_SPIT_*: MPI split collective operation counts.\n");
        printf("#   CP_NB_*: MPI non blocking operation counts.\n");
        printf("#   READS,WRITES,OPENS,SEEKS,STATS, and MMAPS are types of operations.\n");
        printf("#   CP_*_NC_OPENS: number of indep. and collective pnetcdf opens.\n");
        printf("#   CP_HDF5_OPENS: number of hdf5 opens.\n");
        printf("#   CP_COMBINER_*: combiner counts for MPI mem and file datatypes.\n");
        printf("#   CP_HINTS: number of times MPI hints were used.\n");
        printf("#   CP_VIEWS: number of times MPI file views were used.\n");
        printf("#   CP_MODE: mode that file was opened in.\n");
        printf("#   CP_BYTES_*: total bytes read and written.\n");
        printf("#   CP_MAX_BYTE_*: highest offset byte read and written.\n");
        printf("#   CP_CONSEC_*: number of exactly adjacent reads and writes.\n");
        printf("#   CP_SEQ_*: number of reads and writes from increasing offsets.\n");
        printf("#   CP_RW_SWITCHES: number of times access alternated between read and write.\n");
        printf("#   CP_*_ALIGNMENT: memory and file alignment.\n");
        printf("#   CP_*_NOT_ALIGNED: number of reads and writes that were not aligned.\n");
        printf("#   CP_MAX_*_TIME_SIZE: size of the slowest read and write operations.\n");
        printf("#   CP_SIZE_READ_*: histogram of read access sizes.\n");
        printf("#   CP_SIZE_READ_AGG_*: histogram of MPI datatype total sizes.\n");
        printf("#   CP_EXTENT_READ_*: histogram of MPI datatype extents.\n");
        printf("#   CP_STRIDE*_STRIDE: the four most common strides detected.\n");
        printf("#   CP_STRIDE*_COUNT: count of the four most common strides.\n");
        printf("#   CP_ACCESS*_ACCESS: the four most common access sizes.\n");
        printf("#   CP_ACCESS*_COUNT: count of the four most common access sizes.\n");
353
        printf("#   CP_DEVICE: File system identifier.\n");
354 355 356 357 358 359 360 361 362 363 364
        printf("#   CP_SIZE_AT_OPEN: size of file when first opened.\n");
        printf("#   CP_*_RANK_BYTES: fastest, slowest and variance of bytes transfer.\n");
        printf("#   CP_F_OPEN_TIMESTAMP: timestamp of first open (mpi or posix).\n");
        printf("#   CP_F_*_START_TIMESTAMP: timestamp of first read/write (mpi or posix).\n");
        printf("#   CP_F_*_END_TIMESTAMP: timestamp of last read/write (mpi or posix).\n");
        printf("#   CP_F_CLOSE_TIMESTAMP: timestamp of last close (mpi or posix).\n");
        printf("#   CP_F_POSIX_READ/WRITE_TIME: cumulative time spent in posix reads or writes.\n");
        printf("#   CP_F_MPI_READ/WRITE_TIME: cumulative time spent in mpi-io reads or writes.\n");
        printf("#   CP_F_POSIX_META_TIME: cumulative time spent in posix open, close, fsync, stat and seek, .\n");
        printf("#   CP_F_MPI_META_TIME: cumulative time spent in mpi-io open, close, set_view, and sync.\n");
        printf("#   CP_MAX_*_TIME: duration of the slowest read and write operations.\n");
Philip Carns's avatar
Philip Carns committed
365
        printf("#   CP_*_RANK_TIME: fastest, slowest variance of transfer time. Note that these counters show MPI-IO time for files accessed using MPI-IO, and POSIX time otherwise.\n");
366 367 368 369

        printf("\n");
        CP_PRINT_HEADER();
    }
370

371 372 373 374 375 376 377 378 379 380 381 382 383 384
    pdata.rank_cumul_io_time = malloc(sizeof(double)*job.nprocs);
    pdata.rank_cumul_md_time = malloc(sizeof(double)*job.nprocs);
    if (!pdata.rank_cumul_io_time || !pdata.rank_cumul_md_time)
    {
        perror("malloc failed");
        darshan_log_close(file);
        return(-1);
    }
    else
    {
        memset(pdata.rank_cumul_io_time, 0, sizeof(double)*job.nprocs);
        memset(pdata.rank_cumul_md_time, 0, sizeof(double)*job.nprocs);
    }

385
    do
386
    {
387 388
        char* mnt_pt = NULL;
        char* fs_type = NULL;
389
        hash_entry_t *hfile = NULL;
390 391 392 393

        if(cp_file.rank != -1 && cp_file.rank < last_rank)
        {
            fprintf(stderr, "Error: log file contains out of order rank data.\n");
394
            fflush(stderr);
395 396 397 398
            return(-1);
        }
        if(cp_file.rank != -1)
            last_rank = cp_file.rank;
399 400 401 402 403 404 405 406 407 408 409 410 411 412 413
        
        for(i=0; i<mount_count; i++)
        {
            if(cp_file.counters[CP_DEVICE] == devs[i])
            {
                mnt_pt = mnt_pts[i];
                fs_type = fs_types[i];
                break;
            }
        }
        if(!mnt_pt)
            mnt_pt = "UNKNOWN";
        if(!fs_type)
            fs_type = "UNKNOWN";

414 415 416 417 418 419 420 421 422 423 424 425 426
        HASH_FIND(hlink,file_hash,&cp_file.hash,sizeof(int64_t),hfile);
        if (!hfile)
        {
            hfile = (hash_entry_t*) malloc(sizeof(*hfile));
            if (!hfile)
            {
                fprintf(stderr,"malloc failure");
                exit(1);
            }

            /* init */
            memset(hfile, 0, sizeof(*hfile));
            hfile->hash          = cp_file.hash;
Philip Carns's avatar
Philip Carns committed
427
            memcpy(hfile->name_suffix, cp_file.name_suffix, CP_NAME_SUFFIX_LEN+1);
428 429 430 431
            hfile->type          = 0;
            hfile->procs         = 0;
            hfile->cumul_time    = 0.0;
            hfile->meta_time     = 0.0;
432
            hfile->slowest_time  = 0.0;
433 434 435 436

            HASH_ADD(hlink,file_hash,hash,sizeof(int64_t),hfile);
        }

437 438
        accum_file(&job, &cp_file, &total, NULL);
        accum_file(&job, &cp_file, hfile, &fdata);
439 440 441 442 443 444 445 446 447 448 449 450 451
        accum_perf(&cp_file, hfile, &pdata);

        if ((mask & OPTION_BASE))
        {
            for(i=0; i<CP_NUM_INDICES; i++)
            {
                CP_PRINT(&job, &cp_file, i, mnt_pt, fs_type);
            }
            for(i=0; i<CP_F_NUM_INDICES; i++)
            {
                CP_F_PRINT(&job, &cp_file, i, mnt_pt, fs_type);
            }
        }
452
    }while((ret = darshan_log_getfile(file, &job, &cp_file)) == 1);
453 454 455 456

    /* Total Calc */
    if ((mask & OPTION_TOTAL))
    {
457 458
        for(i=0; i<CP_NUM_INDICES; i++)
        {
Philip Carns's avatar
Philip Carns committed
459
            printf("total_%s: %" PRId64 "\n",
460
                   darshan_names[i], total.counters[i]);
461 462 463
        }
        for(i=0; i<CP_F_NUM_INDICES; i++)
        {
464 465
            printf("total_%s: %lf\n",
                   darshan_f_names[i], total.fcounters[i]);
466
        }
467 468
    }

469 470 471 472 473 474
    /* Perf Calc */
    calc_perf(&job, file_hash, &pdata);
    if ((mask & OPTION_PERF))
    {
        printf("\n# performance\n");
        printf("# -----------\n");
Philip Carns's avatar
Philip Carns committed
475
        printf("# total_bytes: %" PRId64 "\n", pdata.total_bytes);
476 477 478
        printf("#\n");
        printf("# I/O timing for unique files (seconds):\n");
        printf("# ...........................\n");
479
        printf("# unique files: slowest_rank_io_time: %lf\n", pdata.slowest_rank_time);
480
        printf("# unique files: slowest_rank_meta_time: %lf\n", pdata.slowest_rank_meta_time);
481
        printf("# unique files: slowest rank: %d\n", pdata.slowest_rank_rank);
482 483 484 485 486 487 488 489 490 491 492 493 494
        printf("#\n");
        printf("# I/O timing for shared files (seconds):\n");
        printf("# (multiple estimates shown; time_by_slowest is generally the most accurate)\n");
        printf("# ...........................\n");
        printf("# shared files: time_by_cumul_io_only: %lf\n", pdata.shared_time_by_cumul);
        printf("# shared files: time_by_cumul_meta_only: %lf\n", pdata.shared_meta_time);
        printf("# shared files: time_by_open: %lf\n", pdata.shared_time_by_open);
        printf("# shared files: time_by_open_lastio: %lf\n", pdata.shared_time_by_open_lastio);
        printf("# shared files: time_by_slowest: %lf\n", pdata.shared_time_by_slowest);
        printf("#\n");
        printf("# Aggregate performance, including both shared and unique files (MiB/s):\n");
        printf("# (multiple estimates shown; agg_perf_by_slowest is generally the most accurate)\n");
        printf("# ...........................\n");
495 496 497 498 499
        printf("# agg_perf_by_cumul: %lf\n", pdata.agg_perf_by_cumul);
        printf("# agg_perf_by_open: %lf\n", pdata.agg_perf_by_open);
        printf("# agg_perf_by_open_lastio: %lf\n", pdata.agg_perf_by_open_lastio);
        printf("# agg_perf_by_slowest: %lf\n", pdata.agg_perf_by_slowest);
    }
500

501 502 503 504 505 506
    /* File Calc */
    calc_file(&job, file_hash, &fdata);
    if ((mask & OPTION_FILE))
    {
        printf("\n# files\n");
        printf("# -----\n");
Philip Carns's avatar
Philip Carns committed
507
        printf("# total: %" PRId64 " %" PRId64 " %" PRId64 "\n",
508 509 510
               fdata.total,
               fdata.total_size,
               fdata.total_max);
Philip Carns's avatar
Philip Carns committed
511
        printf("# read_only: %" PRId64 " %" PRId64 " %" PRId64 "\n",
512 513 514
               fdata.read_only,
               fdata.read_only_size,
               fdata.read_only_max);
Philip Carns's avatar
Philip Carns committed
515
        printf("# write_only: %" PRId64 " %" PRId64 " %" PRId64 "\n",
516 517 518
               fdata.write_only,
               fdata.write_only_size,
               fdata.write_only_max);
Philip Carns's avatar
Philip Carns committed
519
        printf("# read_write: %" PRId64 " %" PRId64 " %" PRId64 "\n",
520 521 522
               fdata.read_write,
               fdata.read_write_size,
               fdata.read_write_max);
Philip Carns's avatar
Philip Carns committed
523
        printf("# unique: %" PRId64 " %" PRId64 " %" PRId64 "\n",
524 525 526
               fdata.unique,
               fdata.unique_size,
               fdata.unique_max);
Philip Carns's avatar
Philip Carns committed
527
        printf("# shared: %" PRId64 " %" PRId64 " %" PRId64 "\n",
528 529 530
               fdata.shared,
               fdata.shared_size,
               fdata.shared_max);
531 532
    }

533
    if ((mask & OPTION_FILE_LIST) || mask & OPTION_FILE_LIST_DETAILED)
534
    {
535 536 537 538
        if(mask & OPTION_FILE_LIST_DETAILED)
            file_list(&job, file_hash, 1);
        else
            file_list(&job, file_hash, 0);
539 540
    }

541
    if(ret < 0)
542
    {
543
        fprintf(stderr, "Error: failed to parse log file.\n");
544
        fflush(stderr);
545 546 547
        return(-1);
    }

548 549 550 551 552
    for(i=0; i<mount_count; i++)
    {
        free(mnt_pts[i]);
        free(fs_types[i]);
    }
553 554 555 556 557 558
    if(mount_count > 0)
    {
        free(devs);
        free(mnt_pts);
        free(fs_types);
    }
559
 
560
    darshan_log_close(file);
561 562 563 564 565 566 567

    HASH_ITER(hlink, file_hash, curr, tmp)
    {
        HASH_DELETE(hlink, file_hash, curr);
        free(curr);
    }

568 569
    return(0);
}
570

571 572
void accum_file(struct darshan_job *job,
                struct darshan_file *dfile,
573 574 575 576 577 578 579
                hash_entry_t *hfile, 
                file_data_t *fdata)
{
    int i;

    hfile->procs += 1;

580 581 582 583 584 585 586 587 588 589 590 591 592 593 594 595 596 597 598 599 600 601 602 603 604 605 606 607 608 609 610 611 612 613 614 615 616
    if (dfile->rank == -1)
    {
        if(job->version_string[0] == '1')
        {
            hfile->slowest_time = 
                max((dfile->fcounters[CP_F_READ_END_TIMESTAMP] 
                    - dfile->fcounters[CP_F_OPEN_TIMESTAMP]),
                    (dfile->fcounters[CP_F_WRITE_END_TIMESTAMP] 
                    - dfile->fcounters[CP_F_OPEN_TIMESTAMP]));
            if(hfile->slowest_time < 0)
                hfile->slowest_time = 0;
        }
        else
        {
            hfile->slowest_time = dfile->fcounters[CP_F_SLOWEST_RANK_TIME];
        }
    }
    else
    {
        if(dfile->counters[CP_INDEP_OPENS] || dfile->counters[CP_COLL_OPENS])
        {
            /* MPI file */
            hfile->slowest_time = max(hfile->slowest_time, 
                (dfile->fcounters[CP_F_MPI_META_TIME] +
                dfile->fcounters[CP_F_MPI_READ_TIME] +
                dfile->fcounters[CP_F_MPI_WRITE_TIME]));
        }
        else
        {
            /* POSIX file */
            hfile->slowest_time = max(hfile->slowest_time, 
                (dfile->fcounters[CP_F_POSIX_META_TIME] +
                dfile->fcounters[CP_F_POSIX_READ_TIME] +
                dfile->fcounters[CP_F_POSIX_WRITE_TIME]));
        }
    }

617 618
    if (dfile->rank == -1)
    {
619
        hfile->procs = job->nprocs;
620
        hfile->type |= FILETYPE_SHARED;
621

622 623 624 625 626 627 628 629 630 631 632
    }
    else if (hfile->procs > 1)
    {
        hfile->type &= (~FILETYPE_UNIQUE);
        hfile->type |= FILETYPE_PARTSHARED;
    }
    else
    {
        hfile->type |= FILETYPE_UNIQUE;
    }

633 634 635 636 637 638 639 640 641 642 643 644 645
    if(dfile->counters[CP_INDEP_OPENS] || dfile->counters[CP_COLL_OPENS])
    {
        hfile->cumul_time += dfile->fcounters[CP_F_MPI_META_TIME] +
                             dfile->fcounters[CP_F_MPI_READ_TIME] +
                             dfile->fcounters[CP_F_MPI_WRITE_TIME];
    }
    else
    {
        hfile->cumul_time += dfile->fcounters[CP_F_POSIX_META_TIME] +
                             dfile->fcounters[CP_F_POSIX_READ_TIME] +
                             dfile->fcounters[CP_F_POSIX_WRITE_TIME];
    }

646 647 648 649 650 651 652 653
    for (i = 0; i < CP_NUM_INDICES; i++)
    {
        switch(i)
        {
        case CP_DEVICE:
        case CP_MODE:
        case CP_MEM_ALIGNMENT:
        case CP_FILE_ALIGNMENT:
654 655
            if(CP_FILE_PARTIAL(hfile))
                hfile->counters[i] = dfile->counters[i];
656 657 658 659 660 661
            break;
        case CP_SIZE_AT_OPEN:
            if (hfile->counters[i] == -1)
            {
                hfile->counters[i] = dfile->counters[i];
            }
662
            if (hfile->counters[i] > dfile->counters[i] && !CP_FILE_PARTIAL(dfile))
663 664 665 666 667 668 669 670 671 672 673
            {
                hfile->counters[i] = dfile->counters[i];
            }
            break;
        case CP_MAX_BYTE_READ:
        case CP_MAX_BYTE_WRITTEN:
            if (hfile->counters[i] < dfile->counters[i])
            {
                hfile->counters[i] = dfile->counters[i];
            }
            break;
674 675 676 677 678 679 680 681 682 683 684 685 686 687 688

        case CP_STRIDE1_STRIDE:
        case CP_STRIDE2_STRIDE:
        case CP_STRIDE3_STRIDE:
        case CP_STRIDE4_STRIDE:
        case CP_ACCESS1_ACCESS:
        case CP_ACCESS2_ACCESS:
        case CP_ACCESS3_ACCESS:
        case CP_ACCESS4_ACCESS:
           /*
            * do nothing here because these will be stored
            * when the _COUNT is accessed.
            */
           break;
 
689 690 691 692 693 694 695 696 697 698 699 700 701 702 703 704 705 706 707 708 709 710 711 712 713 714 715 716 717 718 719 720 721
        case CP_STRIDE1_COUNT:
        case CP_STRIDE2_COUNT:
        case CP_STRIDE3_COUNT:
        case CP_STRIDE4_COUNT:
        case CP_ACCESS1_COUNT:
        case CP_ACCESS2_COUNT:
        case CP_ACCESS3_COUNT:
        case CP_ACCESS4_COUNT:
            if (hfile->counters[i] < dfile->counters[i])
            {
                hfile->counters[i]   = dfile->counters[i];
                hfile->counters[i-4] = dfile->counters[i-4];
            }
            break;
        case CP_FASTEST_RANK:
        case CP_SLOWEST_RANK:
        case CP_FASTEST_RANK_BYTES:
        case CP_SLOWEST_RANK_BYTES:
            hfile->counters[i] = 0;
            break;
        case CP_MAX_READ_TIME_SIZE:
        case CP_MAX_WRITE_TIME_SIZE:
            break;
        default:
            hfile->counters[i] += dfile->counters[i];
            break;
        }
    }

    for (i = 0; i < CP_F_NUM_INDICES; i++)
    {
        switch(i)
        {
722 723 724 725 726 727 728 729 730 731 732 733 734 735 736 737 738 739
            case CP_F_OPEN_TIMESTAMP:
            case CP_F_READ_START_TIMESTAMP:
            case CP_F_WRITE_START_TIMESTAMP:
                if(hfile->fcounters[i] == 0 || 
                    hfile->fcounters[i] > dfile->fcounters[i])
                {
                    hfile->fcounters[i] = dfile->fcounters[i];
                }
                break;
            case CP_F_CLOSE_TIMESTAMP:
            case CP_F_READ_END_TIMESTAMP:
            case CP_F_WRITE_END_TIMESTAMP:
                if(hfile->fcounters[i] == 0 || 
                    hfile->fcounters[i] < dfile->fcounters[i])
                {
                    hfile->fcounters[i] = dfile->fcounters[i];
                }
                break;
740 741 742 743 744 745 746 747 748 749 750 751 752 753 754 755 756 757 758 759 760 761 762 763 764 765 766 767 768 769 770
            case CP_F_FASTEST_RANK_TIME:
            case CP_F_SLOWEST_RANK_TIME:
            case CP_F_VARIANCE_RANK_TIME:
            case CP_F_VARIANCE_RANK_BYTES:
                hfile->fcounters[i] = 0;
                break;
            case CP_F_MAX_READ_TIME:
                if (hfile->fcounters[i] > dfile->fcounters[i])
                {
                    hfile->fcounters[i] = dfile->fcounters[i];
                    hfile->counters[CP_MAX_READ_TIME_SIZE] =
                        dfile->counters[CP_MAX_READ_TIME_SIZE];
                }
                break;
            case CP_F_MAX_WRITE_TIME:
                if (hfile->fcounters[i] > dfile->fcounters[i])
                {
                    hfile->fcounters[i] = dfile->fcounters[i];
                    hfile->counters[CP_MAX_WRITE_TIME_SIZE] =
                        dfile->counters[CP_MAX_WRITE_TIME_SIZE];
                }
                break;
            default:
                hfile->fcounters[i] += dfile->fcounters[i];
                break;
        }
    }

    return;
}

771
void file_list(struct darshan_job *djob, hash_entry_t *file_hash, int detail_flag)
772 773 774
{
    hash_entry_t *curr = NULL;
    hash_entry_t *tmp = NULL;
775
    char* type;
776
    int i;
777

778 779 780 781 782 783 784 785 786 787 788 789 790 791 792 793 794 795 796 797
    /* TODO: list of columns:
     *
     * normal mode?
     * - hash
     * - suffix
     * - MPI or POSIX
     * - nprocs
     * - slowest I/O time
     * - average cumulative I/O time
     *
     * detailed mode?
     * - first open
     * - first read
     * - first write
     * - last close
     * - last read
     * - last write
     * - MPI indep opens
     * - MPI coll opens
     * - POSIX opens
798 799
     * - r histogram (POSIX)
     * - w histogram (POSIX)
800 801 802 803 804 805 806
     */

    if(detail_flag)
        printf("\n# Per-file summary of I/O activity (detailed).\n");
    else
        printf("\n# Per-file summary of I/O activity.\n");

807
    printf("# <hash>: hash of file name\n");
Philip Carns's avatar
Philip Carns committed
808
    printf("# <suffix>: last %d characters of file name\n", CP_NAME_SUFFIX_LEN);
809 810
    printf("# <type>: MPI or POSIX\n");
    printf("# <nprocs>: number of processes that opened the file\n");
Philip Carns's avatar
Philip Carns committed
811 812
    printf("# <slowest>: (estimated) time in seconds consumed in IO by slowest process\n");
    printf("# <avg>: average time in seconds consumed in IO per process\n");
813 814 815 816
    if(detail_flag)
    {
        printf("# <start_{open/read/write}>: start timestamp of first open, read, or write\n");
        printf("# <end_{open/read/write}>: end timestamp of last open, read, or write\n");
Philip Carns's avatar
Philip Carns committed
817 818 819
        printf("# <mpi_indep_opens>: independent MPI_File_open calls\n");
        printf("# <mpi_coll_opens>: collective MPI_File_open calls\n");
        printf("# <posix_opens>: POSIX open calls\n");
820 821
        printf("# <CP_SIZE_READ_*>: POSIX read size histogram\n");
        printf("# <CP_SIZE_WRITE_*>: POSIX write size histogram\n");
822
    }
823
    
824 825 826 827
    printf("\n# <hash>\t<suffix>\t<type>\t<nprocs>\t<slowest>\t<avg>");
    if(detail_flag)
    {
        printf("\t<start_open>\t<start_read>\t<start_write>");
Philip Carns's avatar
Philip Carns committed
828 829
        printf("\t<end_open>\t<end_read>\t<end_write>");
        printf("\t<mpi_indep_opens>\t<mpi_coll_opens>\t<posix_opens>");
830 831
        for(i=CP_SIZE_READ_0_100; i<= CP_SIZE_WRITE_1G_PLUS; i++)
            printf("\t%s", darshan_names[i]);
832
    }
Philip Carns's avatar
Philip Carns committed
833 834
    printf("\n");

835 836
    HASH_ITER(hlink, file_hash, curr, tmp)
    {
837 838 839 840 841
        if(curr->counters[CP_INDEP_OPENS] || curr->counters[CP_COLL_OPENS])
            type = "MPI";
        else
            type = "POSIX";

842
        printf("%" PRIu64 "\t%s\t%s\t%" PRId64 "\t%f\t%f",
Philip Carns's avatar
Philip Carns committed
843
            curr->hash,
844 845
            curr->name_suffix,
            type,
846
            curr->procs,
847 848
            curr->slowest_time,
            curr->cumul_time/(double)curr->procs);
849 850 851 852 853 854
        if(detail_flag)
        {
            for(i=CP_F_OPEN_TIMESTAMP; i<=CP_F_WRITE_END_TIMESTAMP; i++)
            {
                printf("\t%f", curr->fcounters[i]);
            }
Philip Carns's avatar
Philip Carns committed
855
            printf("\t%" PRId64 "\t%" PRId64 "\t%" PRId64, curr->counters[CP_INDEP_OPENS], curr->counters[CP_COLL_OPENS], curr->counters[CP_POSIX_OPENS]);
856 857
            for(i=CP_SIZE_READ_0_100; i<= CP_SIZE_WRITE_1G_PLUS; i++)
                printf("\t%" PRId64, curr->counters[i]);
858 859
        }
        printf("\n");
860 861 862 863
    }

    return;
}
864 865 866 867 868 869 870 871 872 873 874 875 876 877 878 879 880 881 882 883 884 885 886 887 888 889 890 891 892 893 894 895 896 897 898 899 900 901 902 903 904 905 906 907 908 909 910 911 912 913 914 915 916 917 918 919 920 921 922 923 924 925 926 927 928 929 930 931 932 933 934 935 936 937 938 939 940 941 942 943 944 945 946 947 948 949 950 951 952 953 954 955 956 957 958 959 960 961 962 963 964 965 966 967 968 969

void calc_file(struct darshan_job *djob,
               hash_entry_t *file_hash, 
               file_data_t *fdata)
{
    hash_entry_t *curr = NULL;
    hash_entry_t *tmp = NULL;

    memset(fdata, 0, sizeof(*fdata));

    HASH_ITER(hlink, file_hash, curr, tmp)
    {
        int64_t max;
        int64_t r;
        int64_t w;

        max = max3(curr->counters[CP_SIZE_AT_OPEN],
                   curr->counters[CP_MAX_BYTE_READ],
                   curr->counters[CP_MAX_BYTE_WRITTEN]);

        r = (curr->counters[CP_POSIX_READS]+
             curr->counters[CP_POSIX_FREADS]+
             curr->counters[CP_INDEP_READS]+
             curr->counters[CP_COLL_READS]+
             curr->counters[CP_SPLIT_READS]+
             curr->counters[CP_NB_READS]);

        w = (curr->counters[CP_POSIX_WRITES]+
             curr->counters[CP_POSIX_FWRITES]+
             curr->counters[CP_INDEP_WRITES]+
             curr->counters[CP_COLL_WRITES]+
             curr->counters[CP_SPLIT_WRITES]+
             curr->counters[CP_NB_WRITES]);

        fdata->total += 1;
        fdata->total_size += max;
        fdata->total_max = max(fdata->total_max, max);

        if (r && !w)
        {
            fdata->read_only += 1;
            fdata->read_only_size += max;
            fdata->read_only_max = max(fdata->read_only_max, max);
        }

        if (!r && w)
        {
            fdata->write_only += 1;
            fdata->write_only_size += max;
            fdata->write_only_max = max(fdata->write_only_max, max);
        }

        if (r && w)
        {
            fdata->read_write += 1;
            fdata->read_write_size += max;
            fdata->read_write_max = max(fdata->read_write_max, max);
        }

        if ((curr->type & (FILETYPE_SHARED|FILETYPE_PARTSHARED)))
        {
            fdata->shared += 1;
            fdata->shared_size += max;
            fdata->shared_max = max(fdata->shared_max, max);
        }

        if ((curr->type & (FILETYPE_UNIQUE)))
        {
            fdata->unique += 1;
            fdata->unique_size += max;
            fdata->unique_max = max(fdata->unique_max, max);
        }
    }

    return;
}

void accum_perf(struct darshan_file *dfile,
                hash_entry_t *hfile,
                perf_data_t *pdata)
{
    int64_t mpi_file;

    pdata->total_bytes += dfile->counters[CP_BYTES_READ] +
                          dfile->counters[CP_BYTES_WRITTEN];

    mpi_file = dfile->counters[CP_INDEP_OPENS] +
               dfile->counters[CP_COLL_OPENS];

    /*
     * Calculation of Shared File Time
     *   Four Methods!!!!
     *     by_cumul: sum time counters and divide by nprocs
     *               (inaccurate if lots of variance between procs)
     *     by_open: difference between timestamp of open and close
     *              (inaccurate if file is left open without i/o happening)
     *     by_open_lastio: difference between timestamp of open and the
     *                     timestamp of last i/o
     *                     (similar to above but fixes case where file is left
     *                      open after io is complete)
     *     by_slowest: use slowest rank time from log data
     *                 (most accurate but requires newer log version)
     */
    if (dfile->rank == -1)
    {
        /* by_open (same for MPI or POSIX) */
970 971 972 973 974 975 976
        if (dfile->fcounters[CP_F_CLOSE_TIMESTAMP] >
            dfile->fcounters[CP_F_OPEN_TIMESTAMP])
        {
            pdata->shared_time_by_open +=
                dfile->fcounters[CP_F_CLOSE_TIMESTAMP] -
                dfile->fcounters[CP_F_OPEN_TIMESTAMP];
        }
977 978 979 980 981

        /* by_open_lastio (same for MPI or POSIX) */
        if (dfile->fcounters[CP_F_READ_END_TIMESTAMP] >
            dfile->fcounters[CP_F_WRITE_END_TIMESTAMP])
        {
982 983 984 985 986 987 988
            /* be careful: file may have been opened but not read or written */
            if(dfile->fcounters[CP_F_READ_END_TIMESTAMP] > dfile->fcounters[CP_F_OPEN_TIMESTAMP])
            {
                pdata->shared_time_by_open_lastio += 
                    dfile->fcounters[CP_F_READ_END_TIMESTAMP] - 
                    dfile->fcounters[CP_F_OPEN_TIMESTAMP];
            }
989 990 991
        }
        else
        {
992 993 994 995 996 997 998
            /* be careful: file may have been opened but not read or written */
            if(dfile->fcounters[CP_F_WRITE_END_TIMESTAMP] > dfile->fcounters[CP_F_OPEN_TIMESTAMP])
            {
                pdata->shared_time_by_open_lastio += 
                    dfile->fcounters[CP_F_WRITE_END_TIMESTAMP] - 
                    dfile->fcounters[CP_F_OPEN_TIMESTAMP];
            }
999 1000 1001 1002 1003 1004 1005 1006 1007 1008 1009 1010 1011 1012 1013 1014 1015 1016 1017 1018 1019 1020 1021 1022 1023 1024 1025 1026 1027 1028 1029 1030 1031
        }

        /* by_cumul */
        if (mpi_file)
        {
            pdata->shared_time_by_cumul +=
                dfile->fcounters[CP_F_MPI_META_TIME] +
                dfile->fcounters[CP_F_MPI_READ_TIME] +
                dfile->fcounters[CP_F_MPI_WRITE_TIME];
            pdata->shared_meta_time += dfile->fcounters[CP_F_MPI_META_TIME];
        }
        else
        {
            pdata->shared_time_by_cumul +=
                dfile->fcounters[CP_F_POSIX_META_TIME] +
                dfile->fcounters[CP_F_POSIX_READ_TIME] +
                dfile->fcounters[CP_F_POSIX_WRITE_TIME];
            pdata->shared_meta_time += dfile->fcounters[CP_F_POSIX_META_TIME];
        }

        /* by_slowest (same for MPI or POSIX) */
        pdata->shared_time_by_slowest +=
            dfile->fcounters[CP_F_SLOWEST_RANK_TIME];
    }

    /*
     * Calculation of Unique File Time
     *   record the data for each file and sum it 
     */
    else
    {
        if (mpi_file)
        {
1032 1033 1034 1035
            pdata->rank_cumul_io_time[dfile->rank] += dfile->fcounters[CP_F_MPI_META_TIME] +
                                dfile->fcounters[CP_F_MPI_READ_TIME] +
                                dfile->fcounters[CP_F_MPI_WRITE_TIME];
            pdata->rank_cumul_md_time[dfile->rank] += dfile->fcounters[CP_F_MPI_META_TIME];
1036 1037 1038
        }
        else
        {
1039 1040 1041 1042 1043
            pdata->rank_cumul_io_time[dfile->rank] += dfile->fcounters[CP_F_POSIX_META_TIME] +
                                dfile->fcounters[CP_F_POSIX_READ_TIME] +
                                dfile->fcounters[CP_F_POSIX_WRITE_TIME];
            pdata->rank_cumul_md_time[dfile->rank] += dfile->fcounters[CP_F_POSIX_META_TIME];

1044 1045 1046 1047 1048 1049 1050 1051 1052 1053
        }
    }

    return;
}

void calc_perf(struct darshan_job *djob,
               hash_entry_t *hash_rank_uniq,
               perf_data_t *pdata)
{
1054
    int64_t i;
1055 1056 1057 1058 1059 1060

    pdata->shared_time_by_cumul =
        pdata->shared_time_by_cumul / (double)djob->nprocs;

    pdata->shared_meta_time = pdata->shared_meta_time / (double)djob->nprocs;

1061
    for (i=0; i<djob->nprocs; i++)
1062
    {
1063
        if (pdata->rank_cumul_io_time[i] > pdata->slowest_rank_time)
1064
        {
1065
            pdata->slowest_rank_time = pdata->rank_cumul_io_time[i];
1066
            pdata->slowest_rank_meta_time = pdata->rank_cumul_md_time[i];
1067
            pdata->slowest_rank_rank = i;
1068 1069 1070
        }
    }

1071
    if (pdata->slowest_rank_time + pdata->shared_time_by_cumul)
1072
    pdata->agg_perf_by_cumul = ((double)pdata->total_bytes / 1048576.0) /
1073 1074 1075 1076
                                  (pdata->slowest_rank_time +
                                   pdata->shared_time_by_cumul);

    if (pdata->slowest_rank_time + pdata->shared_time_by_open)
1077
    pdata->agg_perf_by_open  = ((double)pdata->total_bytes / 1048576.0) / 
1078 1079 1080 1081
                                   (pdata->slowest_rank_time +
                                    pdata->shared_time_by_open);

    if (pdata->slowest_rank_time + pdata->shared_time_by_open_lastio)
1082 1083 1084
    pdata->agg_perf_by_open_lastio = ((double)pdata->total_bytes / 1048576.0) /
                                     (pdata->slowest_rank_time +
                                      pdata->shared_time_by_open_lastio);
1085

1086 1087
    if (pdata->slowest_rank_time + pdata->shared_time_by_slowest)
    pdata->agg_perf_by_slowest = ((double)pdata->total_bytes / 1048576.0) /
1088
                                     (pdata->slowest_rank_time +
1089
                                      pdata->slowest_rank_meta_time +
1090
                                      pdata->shared_time_by_slowest);
1091 1092 1093

    return;
}