darshan-parser.c 34.5 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 68 69 70 71 72 73 74 75 76
} hash_entry_t;

typedef struct perf_data_s
{
    int64_t total_bytes;
    double slowest_rank_time;
    double slowest_rank_meta_time;
    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;
77 78
    double *rank_cumul_io_time;
    double *rank_cumul_md_time;
79 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
} 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 *);

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

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");
119
    fprintf(stderr, "    --file-list  : per-file summaries\n");
120
    fprintf(stderr, "    --file-list-detailed  : per-file summaries with additional detail\n");
121 122 123 124 125 126 127 128 129 130 131 132 133 134 135
    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},
136
        {"file-list",  0, NULL, OPTION_FILE_LIST},
137
        {"file-list-detailed",  0, NULL, OPTION_FILE_LIST_DETAILED},
138 139
        {"perf",  0, NULL, OPTION_PERF},
        {"total", 0, NULL, OPTION_TOTAL},
140 141
        {"help",  0, NULL, 0},
        {0, 0, 0, 0}
142 143 144 145 146 147 148 149 150 151 152 153 154 155 156
    };

    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:
157
            case OPTION_FILE_LIST:
158
            case OPTION_FILE_LIST_DETAILED:
159 160 161 162 163
            case OPTION_PERF:
            case OPTION_TOTAL:
                mask |= c;
                break;
            case 0:
164
            case '?':
165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188
            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;
}

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

209 210 211 212 213 214 215 216 217 218 219
    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);
220

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

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

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

248
    /* print job summary */
249
    printf("# darshan log version: %s\n", job.version_string);
250 251
    printf("# size of file statistics: %zu bytes\n", sizeof(cp_file));
    printf("# size of job statistics: %zu bytes\n", sizeof(job));
252
    printf("# exe: %s\n", tmp_string);
Philip Carns's avatar
Philip Carns committed
253 254 255
    printf("# uid: %" PRId64 "\n", job.uid);
    printf("# jobid: %" PRId64 "\n", job.jobid);
    printf("# start_time: %" PRId64 "\n", job.start_time);
256
    tmp_time += job.start_time;
257
    printf("# start_time_asci: %s", ctime(&tmp_time));
Philip Carns's avatar
Philip Carns committed
258
    printf("# end_time: %" PRId64 "\n", job.end_time);
259 260
    tmp_time = 0;
    tmp_time += job.end_time;
261
    printf("# end_time_asci: %s", ctime(&tmp_time));
Philip Carns's avatar
Philip Carns committed
262 263
    printf("# nprocs: %" PRId64 "\n", job.nprocs);
    printf("# run time: %" PRId64 "\n", job.end_time - job.start_time + 1);
264 265 266 267 268
    for(token=strtok_r(job.metadata, "\n", &save);
        token != NULL;
        token=strtok_r(NULL, "\n", &save))
    {
        char *key;
269 270 271 272 273 274 275 276 277 278 279 280 281 282
        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);
283
    }
284 285
 
    /* print table of mounted file systems */
286
    ret = darshan_log_getmounts(file, &devs, &mnt_pts, &fs_types, &mount_count);
287
    printf("\n# mounted file systems (device, mount point, and fs type)\n");
288 289 290
    printf("# -------------------------------------------------------\n");
    for(i=0; i<mount_count; i++)
    {
Philip Carns's avatar
Philip Carns committed
291
        printf("# mount entry: %" PRId64 "\t%s\t%s\n", devs[i], mnt_pts[i], fs_types[i]);
292 293
    }
  
294 295 296 297 298 299 300 301 302
    /* 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)
303 304 305
    {
        /* it looks like the app didn't open any files */
        printf("# no files opened.\n");
306
        darshan_log_close(file);
307 308 309
        return(0);
    }

310 311 312 313 314 315 316 317 318
    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");
319 320
        printf("#      A value of -1 indicates that Darshan could not monitor\n");
        printf("#      that counter, and its value should be ignored.\n");
321 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
        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");
352
        printf("#   CP_DEVICE: File system identifier.\n");
353 354 355 356 357 358 359 360 361 362 363 364 365 366 367 368
        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");
        printf("#   CP_*_RANK_TIME: fastest, slowest variance of transfer time.\n");

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

370 371 372 373 374 375 376 377 378 379 380 381 382 383
    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);
    }

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

        if(cp_file.rank != -1 && cp_file.rank < last_rank)
        {
            fprintf(stderr, "Error: log file contains out of order rank data.\n");
393
            fflush(stderr);
394 395 396 397
            return(-1);
        }
        if(cp_file.rank != -1)
            last_rank = cp_file.rank;
398 399 400 401 402 403 404 405 406 407 408 409 410 411 412
        
        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";

413 414 415 416 417 418 419 420 421 422 423 424 425
        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
426
            memcpy(hfile->name_suffix, cp_file.name_suffix, CP_NAME_SUFFIX_LEN+1);
427 428 429 430
            hfile->type          = 0;
            hfile->procs         = 0;
            hfile->cumul_time    = 0.0;
            hfile->meta_time     = 0.0;
431
            hfile->slowest_time  = 0.0;
432 433 434 435

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

436 437
        accum_file(&job, &cp_file, &total, NULL);
        accum_file(&job, &cp_file, hfile, &fdata);
438 439 440 441 442 443 444 445 446 447 448 449 450
        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);
            }
        }
451
    }while((ret = darshan_log_getfile(file, &job, &cp_file)) == 1);
452 453 454 455

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

468 469 470 471 472 473
    /* 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
474
        printf("# total_bytes: %" PRId64 "\n", pdata.total_bytes);
475 476 477 478 479 480 481 482 483 484 485
        printf("# slowest_rank_time: %lf\n", pdata.slowest_rank_time);
        printf("# slowest_rank_meta_time: %lf\n", pdata.slowest_rank_meta_time);
        printf("# shared_time_by_cumul: %lf\n", pdata.shared_time_by_cumul);
        printf("# shared_time_by_open: %lf\n", pdata.shared_time_by_open);
        printf("# shared_time_by_open_lastio: %lf\n", pdata.shared_time_by_open_lastio);
        printf("# shared_meta_time: %lf\n", pdata.shared_meta_time);
        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);
    }
486

487 488 489 490 491 492
    /* 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
493
        printf("# total: %" PRId64 " %" PRId64 " %" PRId64 "\n",
494 495 496
               fdata.total,
               fdata.total_size,
               fdata.total_max);
Philip Carns's avatar
Philip Carns committed
497
        printf("# read_only: %" PRId64 " %" PRId64 " %" PRId64 "\n",
498 499 500
               fdata.read_only,
               fdata.read_only_size,
               fdata.read_only_max);
Philip Carns's avatar
Philip Carns committed
501
        printf("# write_only: %" PRId64 " %" PRId64 " %" PRId64 "\n",
502 503 504
               fdata.write_only,
               fdata.write_only_size,
               fdata.write_only_max);
Philip Carns's avatar
Philip Carns committed
505
        printf("# read_write: %" PRId64 " %" PRId64 " %" PRId64 "\n",
506 507 508
               fdata.read_write,
               fdata.read_write_size,
               fdata.read_write_max);
Philip Carns's avatar
Philip Carns committed
509
        printf("# unique: %" PRId64 " %" PRId64 " %" PRId64 "\n",
510 511 512
               fdata.unique,
               fdata.unique_size,
               fdata.unique_max);
Philip Carns's avatar
Philip Carns committed
513
        printf("# shared: %" PRId64 " %" PRId64 " %" PRId64 "\n",
514 515 516
               fdata.shared,
               fdata.shared_size,
               fdata.shared_max);
517 518
    }

519
    if ((mask & OPTION_FILE_LIST) || mask & OPTION_FILE_LIST_DETAILED)
520
    {
521 522 523 524
        if(mask & OPTION_FILE_LIST_DETAILED)
            file_list(&job, file_hash, 1);
        else
            file_list(&job, file_hash, 0);
525 526
    }

527
    if(ret < 0)
528
    {
529
        fprintf(stderr, "Error: failed to parse log file.\n");
530
        fflush(stderr);
531 532 533
        return(-1);
    }

534 535 536 537 538
    for(i=0; i<mount_count; i++)
    {
        free(mnt_pts[i]);
        free(fs_types[i]);
    }
539 540 541 542 543 544
    if(mount_count > 0)
    {
        free(devs);
        free(mnt_pts);
        free(fs_types);
    }
545
 
546
    darshan_log_close(file);
547 548 549 550 551 552 553

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

554 555
    return(0);
}
556

557 558
void accum_file(struct darshan_job *job,
                struct darshan_file *dfile,
559 560 561 562 563 564 565
                hash_entry_t *hfile, 
                file_data_t *fdata)
{
    int i;

    hfile->procs += 1;

566 567 568 569 570 571 572 573 574 575 576 577 578 579 580 581 582 583 584 585 586 587 588 589 590 591 592 593 594 595 596 597 598 599 600 601 602
    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]));
        }
    }

603 604
    if (dfile->rank == -1)
    {
605
        hfile->procs = job->nprocs;
606
        hfile->type |= FILETYPE_SHARED;
607

608 609 610 611 612 613 614 615 616 617 618
    }
    else if (hfile->procs > 1)
    {
        hfile->type &= (~FILETYPE_UNIQUE);
        hfile->type |= FILETYPE_PARTSHARED;
    }
    else
    {
        hfile->type |= FILETYPE_UNIQUE;
    }

619 620 621 622 623 624 625 626 627 628 629 630 631
    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];
    }

632 633 634 635 636 637 638 639
    for (i = 0; i < CP_NUM_INDICES; i++)
    {
        switch(i)
        {
        case CP_DEVICE:
        case CP_MODE:
        case CP_MEM_ALIGNMENT:
        case CP_FILE_ALIGNMENT:
640 641
            if(CP_FILE_PARTIAL(hfile))
                hfile->counters[i] = dfile->counters[i];
642 643 644 645 646 647
            break;
        case CP_SIZE_AT_OPEN:
            if (hfile->counters[i] == -1)
            {
                hfile->counters[i] = dfile->counters[i];
            }
648
            if (hfile->counters[i] > dfile->counters[i] && !CP_FILE_PARTIAL(dfile))
649 650 651 652 653 654 655 656 657 658 659
            {
                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;
660 661 662 663 664 665 666 667 668 669 670 671 672 673 674

        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;
 
675 676 677 678 679 680 681 682 683 684 685 686 687 688 689 690 691 692 693 694 695 696 697 698 699 700 701 702 703 704 705 706 707
        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)
        {
708 709 710 711 712 713 714 715 716 717 718 719 720 721 722 723 724 725
            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;
726 727 728 729 730 731 732 733 734 735 736 737 738 739 740 741 742 743 744 745 746 747 748 749 750 751 752 753 754 755 756
            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;
}

757
void file_list(struct darshan_job *djob, hash_entry_t *file_hash, int detail_flag)
758 759 760
{
    hash_entry_t *curr = NULL;
    hash_entry_t *tmp = NULL;
761
    char* type;
762
    int i;
763

764 765 766 767 768 769 770 771 772 773 774 775 776 777 778 779 780 781 782 783 784 785 786 787 788 789 790 791 792
    /* 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
     * - r histogram (MPI or POSIX)
     * - w histogram (MPI or POSIX)
     */

    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");

793
    printf("# <hash>: hash of file name\n");
Philip Carns's avatar
Philip Carns committed
794
    printf("# <suffix>: last %d characters of file name\n", CP_NAME_SUFFIX_LEN);
795 796
    printf("# <type>: MPI or POSIX\n");
    printf("# <nprocs>: number of processes that opened the file\n");
797
    printf("# <slowest>: (estimated) time in seconds consumed in IO by slowest process.\n");
798
    printf("# <avg>: average time in seconds consumed in IO per process.\n");
799 800 801 802 803
    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");
    }
804
    
805 806 807 808 809 810 811 812 813 814
    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>");
        printf("\t<end_open>\t<end_read>\t<end_write>\n");
    }
    else
    {
        printf("\n");
    }
815 816
    HASH_ITER(hlink, file_hash, curr, tmp)
    {
817 818 819 820 821
        if(curr->counters[CP_INDEP_OPENS] || curr->counters[CP_COLL_OPENS])
            type = "MPI";
        else
            type = "POSIX";

822
        printf("%" PRIu64 "\t%s\t%s\t%" PRId64 "\t%f\t%f",
Philip Carns's avatar
Philip Carns committed
823
            curr->hash,
824 825
            curr->name_suffix,
            type,
826
            curr->procs,
827 828
            curr->slowest_time,
            curr->cumul_time/(double)curr->procs);
829 830 831 832 833 834 835 836
        if(detail_flag)
        {
            for(i=CP_F_OPEN_TIMESTAMP; i<=CP_F_WRITE_END_TIMESTAMP; i++)
            {
                printf("\t%f", curr->fcounters[i]);
            }
        }
        printf("\n");
837 838 839 840
    }

    return;
}
841 842 843 844 845 846 847 848 849 850 851 852 853 854 855 856 857 858 859 860 861 862 863 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

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) */
947 948 949 950 951 952 953
        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];
        }
954 955 956 957 958

        /* by_open_lastio (same for MPI or POSIX) */
        if (dfile->fcounters[CP_F_READ_END_TIMESTAMP] >
            dfile->fcounters[CP_F_WRITE_END_TIMESTAMP])
        {
959 960 961 962 963 964 965
            /* 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];
            }
966 967 968
        }
        else
        {
969 970 971 972 973 974 975
            /* 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];
            }
976 977 978 979 980 981 982 983 984 985 986 987 988 989 990 991 992 993 994 995 996 997 998 999 1000 1001 1002 1003 1004 1005 1006 1007 1008
        }

        /* 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)
        {
1009 1010 1011 1012
            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];
1013 1014 1015
        }
        else
        {
1016 1017 1018 1019 1020
            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];

1021 1022 1023 1024 1025 1026 1027 1028 1029 1030
        }
    }

    return;
}

void calc_perf(struct darshan_job *djob,
               hash_entry_t *hash_rank_uniq,
               perf_data_t *pdata)
{
1031
    int64_t i;
1032 1033 1034 1035 1036 1037

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

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

1038
    for (i=0; i<djob->nprocs; i++)
1039
    {
1040
        if (pdata->rank_cumul_io_time[i] > pdata->slowest_rank_time)
1041
        {
1042
            pdata->slowest_rank_time = pdata->rank_cumul_io_time[i];
1043
            pdata->slowest_rank_meta_time = pdata->rank_cumul_md_time[i];
1044 1045 1046
        }
    }

1047
    if (pdata->slowest_rank_time + pdata->shared_time_by_cumul)
1048
    pdata->agg_perf_by_cumul = ((double)pdata->total_bytes / 1048576.0) /
1049 1050 1051 1052
                                  (pdata->slowest_rank_time +
                                   pdata->shared_time_by_cumul);

    if (pdata->slowest_rank_time + pdata->shared_time_by_open)
1053
    pdata->agg_perf_by_open  = ((double)pdata->total_bytes / 1048576.0) / 
1054 1055 1056 1057
                                   (pdata->slowest_rank_time +
                                    pdata->shared_time_by_open);

    if (pdata->slowest_rank_time + pdata->shared_time_by_open_lastio)
1058 1059 1060
    pdata->agg_perf_by_open_lastio = ((double)pdata->total_bytes / 1048576.0) /
                                     (pdata->slowest_rank_time +
                                      pdata->shared_time_by_open_lastio);
1061

1062 1063
    if (pdata->slowest_rank_time + pdata->shared_time_by_slowest)
    pdata->agg_perf_by_slowest = ((double)pdata->total_bytes / 1048576.0) /
1064 1065
                                     (pdata->slowest_rank_time +
                                      pdata->shared_time_by_slowest);
1066 1067 1068

    return;
}