darshan-job-summary.pl.in 45.7 KB
Newer Older
1
#!/usr/bin/perl -w
2 3 4 5 6
#
#  (C) 2009 by Argonne National Laboratory.
#      See COPYRIGHT in top-level directory.
#

7
# Set via configure
8
my $PREFIX="@prefix@";
9

10
use lib "@prefix@/lib";
11 12
use TeX::Encode;
use Encode;
13
use File::Temp qw/ tempdir /;
14
use File::Basename;
15
use Cwd;
16 17
use Getopt::Long;
use English;
18
use Number::Bytes::Human qw(format_bytes);
19
use POSIX qw(strftime);
20

21 22 23 24 25 26 27 28
#
# system commands used
#
my $darshan_parser = "$PREFIX/bin/darshan-parser";
my $pdflatex       = "pdflatex";
my $epstopdf       = "epstopdf";
my $cp             = "cp";
my $mv             = "mv";
29 30 31 32 33 34 35 36 37 38
my $gnuplot;
# Prefer gnuplot installed with darshan, if present.
if(-x "$PREFIX/bin/gnuplot")
{
    $gnuplot       = "$PREFIX/bin/gnuplot";
}
else
{
    $gnuplot       = "gnuplot";
}
39

40
my $orig_dir = getcwd;
41
my $output_file = "summary.pdf";
42
my $verbose_flag = 0;
43
my $input_file = "";
44 45
my %access_hash = ();
my @access_size = ();
46
my %hash_files = ();
47
my $size_est_flag = 0;
48 49
my $read_interval_overflow_flag = 0;
my $write_interval_overflow_flag = 0;
50

51
# data structures for calculating performance
52 53
my %hash_unique_file_time = ();
my $shared_file_time = 0;
54
my $total_job_bytes = 0;
55

56 57
process_args();

58 59
check_prereqs();

60 61 62 63 64 65
my $tmp_dir = tempdir( CLEANUP => !$verbose_flag );
if ($verbose_flag)
{
    print "verbose: $tmp_dir\n";
}

66 67 68

open(TRACE, "$darshan_parser $input_file |") || die("Can't execute \"$darshan_parser $input_file\": $!\n");

69 70
open(FA_READ, ">$tmp_dir/file-access-read.dat") || die("error opening output file: $!\n");
open(FA_WRITE, ">$tmp_dir/file-access-write.dat") || die("error opening output file: $!\n");
71 72
open(FA_READ_SH, ">$tmp_dir/file-access-read-sh.dat") || die("error opening output file: $!\n");
open(FA_WRITE_SH, ">$tmp_dir/file-access-write-sh.dat") || die("error opening output file: $!\n");
73 74 75

my $last_read_start = 0;
my $last_write_start = 0;
76

77 78 79 80 81 82 83 84 85 86 87 88
my $cumul_read_indep = 0;
my $cumul_read_bytes_indep = 0;

my $cumul_write_indep = 0;
my $cumul_write_bytes_indep = 0;

my $cumul_read_shared = 0;
my $cumul_read_bytes_shared = 0;

my $cumul_write_shared = 0;
my $cumul_write_bytes_shared = 0;

89 90 91
my $cumul_meta_shared = 0;
my $cumul_meta_indep = 0;

92 93 94 95 96
my $first_data_line = 1;
my $current_rank = 0;
my $current_hash = 0;
my %file_record_hash = ();

97 98
my %fs_data = ();

99
while ($line = <TRACE>) {
100
    chomp($line);
101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124
    
    if ($line =~ /^\s*$/) {
        # ignore blank lines
    }
    elsif ($line =~ /^#/) {
	if ($line =~ /^# exe: /) {
	    ($junk, $cmdline) = split(':', $line, 2);
            # add escape characters if needed for special characters in
            # command line
            $cmdline = encode('latex', $cmdline);
	}
	if ($line =~ /^# nprocs: /) {
	    ($junk, $nprocs) = split(':', $line, 2);
	    $procreads[$nprocs] = 0;
	}
	if ($line =~ /^# run time: /) {
	    ($junk, $runtime) = split(':', $line, 2);
	}
	if ($line =~ /^# start_time: /) {
	    ($junk, $starttime) = split(':', $line, 2);
	}
	if ($line =~ /^# uid: /) {
	    ($junk, $uid) = split(':', $line, 2);
	}
125 126 127
        if ($line =~ /^# jobid: /) {
	    ($junk, $jobid) = split(':', $line, 2);
        }
128 129 130 131 132
        if ($line =~ /^# darshan log version: /) {
            ($junk, $version) = split(':', $line, 2);
            $version =~ s/^\s+//;
            ($major, $minor) = split(/\./, $version, 2);
        }
133 134
    }
    else {
135
        # parse line
136
	@fields = split(/[\t ]+/, $line);
137

138 139 140
        # encode the file system name to protect against special characters
        $fields[5] = encode('latex', $fields[5]);
        
141 142 143 144 145 146 147 148 149
        # is this our first piece of data?
        if($first_data_line)
        {
            $current_rank = $fields[0];
            $current_hash = $fields[1];
            $first_data_line = 0;
        }

        # is this a new file record?
150
        if($fields[0] != $current_rank || $fields[1] != $current_hash)
151 152
        {
            # process previous record
153
            process_file_record($current_rank, $current_hash, \%file_record_hash);
154 155 156 157 158

            # reset variables for next record 
            $current_rank = $fields[0];
            $current_hash = $fields[1];
            %file_record_hash = ();
159
            $file_record_hash{CP_NAME_SUFFIX} = $fields[4];
160 161 162 163
        }

        $file_record_hash{$fields[2]} = $fields[3];

164 165 166
	$summary{$fields[2]} += $fields[3];

	# record per-process POSIX read count
167
	if ($fields[2] eq "CP_POSIX_READS" || $fields[2] eq "CP_POSIX_FREADS") {
168 169 170 171 172 173 174 175 176
	    if ($fields[0] == -1) {
		$procreads[$nprocs] += $fields[3];
	    }
	    else {
		$procreads[$fields[0]] += $fields[3];
	    }
	}

	# record per-proces POSIX write count
177
	if ($fields[2] eq "CP_POSIX_WRITES" || $fields[2] eq "CP_POSIX_FWRITES") {
178 179 180 181 182 183 184 185
	    if ($fields[0] == -1) {
		$procwrites[$nprocs] += $fields[3];
	    }
	    else {
		$procwrites[$fields[0]] += $fields[3];
	    }
	}

186
        # seperate accumulators for independent and shared reads and writes
Philip Carns's avatar
Philip Carns committed
187
        if ($fields[2] eq "CP_F_POSIX_READ_TIME" && $fields[0] == -1){
188 189
            $cumul_read_shared += $fields[3];
        }
Philip Carns's avatar
Philip Carns committed
190
        if ($fields[2] eq "CP_F_POSIX_READ_TIME" && $fields[0] != -1){
191 192
            $cumul_read_indep += $fields[3];
        }
Philip Carns's avatar
Philip Carns committed
193
        if ($fields[2] eq "CP_F_POSIX_WRITE_TIME" && $fields[0] == -1){
194 195
            $cumul_write_shared += $fields[3];
        }
Philip Carns's avatar
Philip Carns committed
196
        if ($fields[2] eq "CP_F_POSIX_WRITE_TIME" && $fields[0] != -1){
197 198 199
            $cumul_write_indep += $fields[3];
        }

200 201 202 203 204 205 206
        if ($fields[2] eq "CP_F_POSIX_META_TIME" && $fields[0] == -1){
            $cumul_meta_shared += $fields[3];
        }
        if ($fields[2] eq "CP_F_POSIX_META_TIME" && $fields[0] != -1){
            $cumul_meta_indep += $fields[3];
        }

207 208
        if ((($fields[2] eq "CP_BYTES_READ") or
             ($fields[2] eq "CP_BYTES_WRITTEN")) and
209 210 211 212
            not defined($fs_data{$fields[5]}))
        {
            $fs_data{$fields[5]} = [0,0];
        }
213

Philip Carns's avatar
Philip Carns committed
214
        if ($fields[2] eq "CP_BYTES_READ" && $fields[0] == -1){
215
            $cumul_read_bytes_shared += $fields[3];
216
            $fs_data{$fields[5]}->[0] += $fields[3];
217
        }
Philip Carns's avatar
Philip Carns committed
218
        if ($fields[2] eq "CP_BYTES_READ" && $fields[0] != -1){
219
            $cumul_read_bytes_indep += $fields[3];
220
            $fs_data{$fields[5]}->[0] += $fields[3];
221
        }
Philip Carns's avatar
Philip Carns committed
222
        if ($fields[2] eq "CP_BYTES_WRITTEN" && $fields[0] == -1){
223
            $cumul_write_bytes_shared += $fields[3];
224
            $fs_data{$fields[5]}->[1] += $fields[3];
225
        }
Philip Carns's avatar
Philip Carns committed
226
        if ($fields[2] eq "CP_BYTES_WRITTEN" && $fields[0] != -1){
227
            $cumul_write_bytes_indep += $fields[3];
228
            $fs_data{$fields[5]}->[1] += $fields[3];
229 230
        }

231 232 233 234 235 236 237 238 239 240 241 242 243 244
        # record start and end of reads and writes

        if ($fields[2] eq "CP_F_READ_START_TIMESTAMP") {
            # store until we find the end
            # adjust for systems that give absolute time stamps
            $last_read_start = $fields[3];
        }
        if ($fields[2] eq "CP_F_READ_END_TIMESTAMP" && $fields[3] != 0) {
            # assume we got the read start already 
            my $xdelta = $fields[3] - $last_read_start;
            # adjust for systems that have absolute time stamps 
            if($last_read_start > $starttime) {
                $last_read_start -= $starttime;
            }
245
            if($fields[3] > $runtime && !$read_interval_overflow_flag)
246
            {
247
                $read_interval_overflow_flag = 1;
248 249
                print "Warning: detected read access at time $fields[3] but runtime is only $runtime seconds.\n";
            }
250 251 252 253 254 255
            if($fields[0] == -1){
                print FA_READ_SH "$last_read_start\t0\t$xdelta\t0\n";
            }
            else{
                print FA_READ "$last_read_start\t$fields[0]\t$xdelta\t0\n";
            }
256 257 258 259 260 261 262 263 264 265 266 267
        }
        if ($fields[2] eq "CP_F_WRITE_START_TIMESTAMP") {
            # store until we find the end
            $last_write_start = $fields[3];
        }
        if ($fields[2] eq "CP_F_WRITE_END_TIMESTAMP" && $fields[3] != 0) {
            # assume we got the write start already 
            my $xdelta = $fields[3] - $last_write_start;
            # adjust for systems that have absolute time stamps 
            if($last_write_start > $starttime) {
                $last_write_start -= $starttime;
            }
268
            if($fields[3] > $runtime && !$write_interval_overflow_flag)
269
            {
270
                $write_interval_overflow_flag = 1;
271 272
                print "Warning: detected write access at time $fields[3] but runtime is only $runtime seconds.\n";
            }
273 274 275 276 277 278
            if($fields[0] == -1){
                print FA_WRITE_SH "$last_write_start\t0\t$xdelta\t0\n";
            }
            else{
                print FA_WRITE "$last_write_start\t$fields[0]\t$xdelta\t0\n";
            }
279 280
        }

281 282
        if ($fields[2] =~ /^CP_ACCESS(.)_ACCESS/) {
            $access_size[$1] = $fields[3];
283
        }
284 285 286 287
        if ($fields[2] =~ /^CP_ACCESS(.)_COUNT/) {
            my $tmp_access_size = $access_size[$1];
            if(defined $access_hash{$tmp_access_size}){
                $access_hash{$tmp_access_size} += $fields[3];
288
            }
289 290
            else{
                $access_hash{$tmp_access_size} = $fields[3];
291 292 293 294 295
            }
        }
    }
}

296 297
close(TRACE) || die "darshan-parser failure: $! $?";

298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314
#
# Exit out if there are no actual file accesses
#
if ($first_data_line)
{
    $strtm = strftime("%a %b %e %H:%M:%S %Y", localtime($starttime));

    print "This darshan log has no file records. No summary was produced.\n";
    print "    jobid:$jobid\n";
    print "      uid:$uid\n";
    print "starttime: $strtm ($starttime )\n";
    print "  runtime:$runtime (seconds)\n";
    print "   nprocs:$nprocs\n";
    print "  version: $version\n";
    exit(1);
}

315
# process last file record
316
$file_record_hash{CP_NAME_SUFFIX} = $fields[4];
317
process_file_record($current_rank, $current_hash, \%file_record_hash);
318

319 320 321 322
# Fudge one point at the end to make xrange match in read and write plots.
# For some reason I can't get the xrange command to work.  -Phil
print FA_READ "$runtime\t-1\t0\t0\n";
print FA_WRITE "$runtime\t-1\t0\t0\n";
323 324
print FA_READ_SH "$runtime\t0\t0\t0\n";
print FA_WRITE_SH "$runtime\t0\t0\t0\n";
325 326
close(FA_READ);
close(FA_WRITE);
327 328
close(FA_READ_SH);
close(FA_WRITE_SH);
329

330
# counts of operations
331
open(COUNTS, ">$tmp_dir/counts.dat") || die("error opening output file: $!\n");
332 333
print COUNTS "# P=POSIX, MI=MPI-IO indep., MC=MPI-IO coll., R=read, W=write\n";
print COUNTS "# PR, MIR, MCR, PW, MIW, MCW, Popen, Pseek, Pstat\n";
334
my $total_posix_opens = $summary{CP_POSIX_OPENS} + $summary{CP_POSIX_FOPENS};
335
my $total_syncs = $summary{CP_POSIX_FSYNCS} + $summary{CP_POSIX_FDSYNCS};
336
print COUNTS "Read, ", $summary{CP_POSIX_READS} + $summary{CP_POSIX_FREADS}, ", ",
337
    $summary{CP_INDEP_READS}, ", ", $summary{CP_COLL_READS}, "\n",
338
    "Write, ", $summary{CP_POSIX_WRITES} + $summary{CP_POSIX_FWRITES}, ", ", 
339
    $summary{CP_INDEP_WRITES}, ", ", $summary{CP_COLL_WRITES}, "\n",
340
    "Open, ", $total_posix_opens, ", ", $summary{CP_INDEP_OPENS},", ",
341 342 343
    $summary{CP_COLL_OPENS}, "\n",
    "Stat, ", $summary{CP_POSIX_STATS}, ", 0, 0\n",
    "Seek, ", $summary{CP_POSIX_SEEKS}, ", 0, 0\n",
344 345
    "Mmap, ", $summary{CP_POSIX_MMAPS}, ", 0, 0\n",
    "Fsync, ", $total_syncs, ", 0, 0\n";
346 347 348
close COUNTS;

# histograms of reads and writes
349
open (HIST, ">$tmp_dir/hist.dat") || die("error opening output file: $!\n");
350 351 352 353 354 355 356 357 358 359 360 361 362 363 364 365 366 367 368 369 370 371 372 373
print HIST "# size_range read write\n";
print HIST "0-100, ", $summary{CP_SIZE_READ_0_100}, ", ",
                 $summary{CP_SIZE_WRITE_0_100}, "\n";
print HIST "101-1K, ", $summary{CP_SIZE_READ_100_1K}, ", ",
                 $summary{CP_SIZE_WRITE_100_1K}, "\n";
print HIST "1K-10K, ", $summary{CP_SIZE_READ_1K_10K}, ", ",
                 $summary{CP_SIZE_WRITE_1K_10K}, "\n";
print HIST "10K-100K, ", $summary{CP_SIZE_READ_10K_100K}, ", ",
                 $summary{CP_SIZE_WRITE_10K_100K}, "\n";
print HIST "100K-1M, ", $summary{CP_SIZE_READ_100K_1M}, ", ",
                 $summary{CP_SIZE_WRITE_100K_1M}, "\n";
print HIST "1M-4M, ", $summary{CP_SIZE_READ_1M_4M}, ", ",
                 $summary{CP_SIZE_WRITE_1M_4M}, "\n";
print HIST "4M-10M, ", $summary{CP_SIZE_READ_4M_10M}, ", ",
                 $summary{CP_SIZE_WRITE_4M_10M}, "\n";
print HIST "10M-100M, ", $summary{CP_SIZE_READ_10M_100M}, ", ",
                 $summary{CP_SIZE_WRITE_10M_100M}, "\n";
print HIST "100M-1G, ", $summary{CP_SIZE_READ_100M_1G}, ", ",
                 $summary{CP_SIZE_WRITE_100M_1G}, "\n";
print HIST "1G+, ", $summary{CP_SIZE_READ_1G_PLUS}, ", ",
                 $summary{CP_SIZE_WRITE_1G_PLUS}, "\n";
close HIST;

# sequential and consecutive accesses
374
open (PATTERN, ">$tmp_dir/pattern.dat") || die("error opening output file: $!\n");
375
print PATTERN "# op total sequential consecutive\n";
376
print PATTERN "Read, ", $summary{CP_POSIX_READS} + $summary{CP_POSIX_FREADS}, ", ",
377
    $summary{CP_SEQ_READS}, ", ", $summary{CP_CONSEC_READS}, "\n";
378
print PATTERN "Write, ", $summary{CP_POSIX_WRITES} + $summary{CP_POSIX_FWRITES}, ", ",
379 380 381 382
    $summary{CP_SEQ_WRITES}, ", ", $summary{CP_CONSEC_WRITES}, "\n";
close PATTERN;

# aligned I/O
383
open (ALIGN, ">$tmp_dir/align.dat") || die("error opening output file: $!\n");
384
print ALIGN "# total unaligned_mem unaligned_file align_mem align_file\n";
385 386
print ALIGN $summary{CP_POSIX_READS} + $summary{CP_POSIX_WRITES} + $summary{CP_POSIX_FREADS} + $summary{CP_POSIX_FWRITES}
, ", ",
387 388 389 390
    $summary{CP_MEM_NOT_ALIGNED}, ", ", $summary{CP_FILE_NOT_ALIGNED}, "\n";
close ALIGN;

# MPI types
391
open (TYPES, ">$tmp_dir/types.dat") || die("error opening output file: $!\n");
392 393 394 395 396 397 398 399 400 401 402 403 404 405 406 407 408 409 410 411 412 413 414 415 416 417 418 419 420 421 422 423 424 425 426 427 428 429 430 431 432 433 434 435 436 437 438
print TYPES "# type use_count\n";
print TYPES "Named, ", $summary{CP_COMBINER_NAMED}, "\n";
print TYPES "Dup, ", $summary{CP_COMBINER_DUP}, "\n";
print TYPES "Contig, ", $summary{CP_COMBINER_CONTIGUOUS}, "\n";
print TYPES "Vector, ", $summary{CP_COMBINER_VECTOR}, "\n";
print TYPES "HvecInt, ", $summary{CP_COMBINER_HVECTOR_INTEGER}, "\n";
print TYPES "Hvector, ", $summary{CP_COMBINER_HVECTOR}, "\n";
print TYPES "Indexed, ", $summary{CP_COMBINER_INDEXED}, "\n";
print TYPES "HindInt, ", $summary{CP_COMBINER_HINDEXED_INTEGER}, "\n";
print TYPES "Hindexed, ", $summary{CP_COMBINER_HINDEXED}, "\n";
print TYPES "IndBlk, ", $summary{CP_COMBINER_INDEXED_BLOCK}, "\n";
print TYPES "StructInt, ", $summary{CP_COMBINER_STRUCT_INTEGER}, "\n";
print TYPES "Struct, ", $summary{CP_COMBINER_STRUCT}, "\n";
print TYPES "Subarray, ", $summary{CP_COMBINER_SUBARRAY}, "\n";
print TYPES "Darray, ", $summary{CP_COMBINER_DARRAY}, "\n";
print TYPES "F90Real, ", $summary{CP_COMBINER_F90_REAL}, "\n";
print TYPES "F90Complex, ", $summary{CP_COMBINER_F90_COMPLEX}, "\n";
print TYPES "F90Int, ", $summary{CP_COMBINER_F90_INTEGER}, "\n";
print TYPES "Resized, ", $summary{CP_COMBINER_RESIZED}, "\n";
close TYPES;

# generate histogram of process I/O counts
#
# NOTE: NEED TO FILL IN ACTUAL WRITE DATA!!!
#
$minprocread = (defined $procreads[0]) ? $procreads[0] : 0;
$maxprocread = (defined $procreads[0]) ? $procreads[0] : 0;
for ($i=1; $i < $nprocs; $i++) {
    $rdi = (defined $procreads[$i]) ? $procreads[$i] : 0;
    $minprocread = ($rdi > $minprocread) ? $minprocread : $rdi;
    $maxprocread = ($rdi < $maxprocread) ? $maxprocread : $rdi;
}
$minprocread += $procreads[$nprocs];
$maxprocread += $procreads[$nprocs];
# print "$minprocread $maxprocread\n";

@bucket = ( 0, 0, 0, 0, 0, 0, 0, 0, 0, 0 );

for ($i=0; $i < $nprocs; $i++) {
    $mysize = ((defined $procreads[$i]) ? $procreads[$i] : 0) +
	$procreads[$nprocs];
    $mysize -= $minprocread;
    $mybucket = ($mysize > 0) ?
	(($mysize * 10) / ($maxprocread - $minprocread)) : 0;
    $bucket[$mybucket]++;
}

439
open(IODIST, ">$tmp_dir/iodist.dat") || die("error opening output file: $!\n");
440 441 442 443 444 445 446 447 448 449 450 451 452 453 454 455 456 457 458 459 460
print IODIST "# bucket n_procs_rd n_procs_wr\n";
print IODIST "# NOTE: WRITES ARE A COPY OF READS FOR NOW!!!\n";

$bucketsize = $maxprocread - $minprocread / 10;
# TODO: do writes also, is dropping a 0 in for now
for ($i=0; $i < 10; $i++) {
    print IODIST $bucketsize * $i + $minprocread, "-",
    $bucketsize * ($i+1) + $minprocread, ", ", $bucket[$i], ", 0\n";
}
close IODIST;

# generate title for summary
($executable, $junk) = split(' ', $cmdline, 2);
@parts = split('/', $executable);
$cmd = $parts[$#parts];

@timearray = localtime($starttime);
$year = $timearray[5] + 1900;
$mon = $timearray[4] + 1;
$mday = $timearray[3];

461
open(TITLE, ">$tmp_dir/title.tex") || die("error opening output file:$!\n");
462 463 464 465 466 467 468 469 470 471 472 473 474 475 476 477 478
print TITLE "
\\rhead{\\thepage\\ of \\pageref{LastPage}}
\\chead[
\\large $cmd ($mon/$mday/$year)
]
{
\\large $cmd ($mon/$mday/$year)
}
\\cfoot[
\\scriptsize{$cmdline}
]
{
\\scriptsize{$cmdline}
}
";
close TITLE;

479
open(TABLES, ">$tmp_dir/job-table.tex") || die("error opening output file:$!\n");
480
print TABLES "
481
\\begin{tabular}{|p{.47\\columnwidth}|p{.35\\columnwidth}|p{.47\\columnwidth}|p{.6\\columnwidth}|}
482
\\hline
483
jobid: $jobid \& uid: $uid \& nprocs: $nprocs \& runtime: $runtime seconds\\\\
484 485 486 487 488
\\hline
\\end{tabular}
";
close TABLES;

489
open(TABLES, ">$tmp_dir/access-table.tex") || die("error opening output file:$!\n");
490
print TABLES "
Philip Carns's avatar
Philip Carns committed
491
\\begin{tabular}{r|r}
492
\\multicolumn{2}{c}{ } \\\\
493
\\multicolumn{2}{c}{Most Common Access Sizes} \\\\
494 495 496
\\hline
access size \& count \\\\
\\hline
Philip Carns's avatar
Philip Carns committed
497
\\hline
498 499
";

500 501
# sort access sizes (descending)
my $i = 0;
502 503
foreach $value (sort {$access_hash{$b} <=> $access_hash{$a} } keys %access_hash) {
    if($i == 4) {
504 505 506 507 508 509 510 511 512
        last;
    }
    if($access_hash{$value} == 0) {
        last;
    }
    print TABLES "$value \& $access_hash{$value} \\\\\n";
    $i++;
}

513 514 515 516 517 518
print TABLES "
\\hline
\\end{tabular}
";
close TABLES;

Philip Carns's avatar
Philip Carns committed
519 520 521
open(TABLES, ">$tmp_dir/file-count-table.tex") || die("error opening output file:$!\n");
print TABLES "
\\begin{tabular}{r|r|r|r}
522
\\multicolumn{4}{c}{ } \\\\
Philip Carns's avatar
Philip Carns committed
523
\\multicolumn{4}{c}{File Count Summary} \\\\
524 525 526 527 528 529 530 531
";
if($size_est_flag == 1)
{
print TABLES "
\\multicolumn{4}{c}{(estimated by I/O access offsets)} \\\\
";
}
print TABLES "
Philip Carns's avatar
Philip Carns committed
532 533 534 535 536 537 538 539 540 541 542 543 544 545 546 547 548 549 550 551 552 553 554 555 556 557 558 559 560 561 562 563 564 565
\\hline
type \& number of files \& avg. size \& max size \\\\
\\hline
\\hline
";
my $counter;
my $sum;
my $max;
my $key;
my $avg;

$counter = 0;
$sum = 0;
$max = 0;
foreach $key (keys %hash_files) {
    $counter++;
    if($hash_files{$key}{'min_open_size'} >
        $hash_files{$key}{'max_size'})
    {
        $sum += $hash_files{$key}{'min_open_size'};
        if($hash_files{$key}{'min_open_size'} > $max)
        {
            $max = $hash_files{$key}{'min_open_size'};
        }
    }
    else
    {
        $sum += $hash_files{$key}{'max_size'};
        if($hash_files{$key}{'max_size'} > $max)
        {
            $max = $hash_files{$key}{'max_size'};
        }
    }
}
566 567
if($counter > 0) { $avg = $sum / $counter; }
else { $avg = 0; }
568 569
$avg = format_bytes($avg);
$max = format_bytes($max);
Philip Carns's avatar
Philip Carns committed
570 571
print TABLES "total opened \& $counter \& $avg \& $max \\\\\n";

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 603 604 605 606 607 608 609 610 611 612 613 614 615 616 617 618 619 620 621 622 623 624 625 626 627 628 629 630 631 632 633 634 635 636 637 638 639 640 641 642 643 644 645 646 647 648 649 650 651 652 653 654 655 656 657 658 659 660 661 662 663 664 665 666 667 668 669 670 671 672 673 674 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
$counter = 0;
$sum = 0;
$max = 0;
foreach $key (keys %hash_files) {
    if($hash_files{$key}{'was_read'} && !($hash_files{$key}{'was_written'}))
    {
        $counter++;
        if($hash_files{$key}{'min_open_size'} >
            $hash_files{$key}{'max_size'})
        {
            $sum += $hash_files{$key}{'min_open_size'};
            if($hash_files{$key}{'min_open_size'} > $max)
            {
                $max = $hash_files{$key}{'min_open_size'};
            }
        }
        else
        {
            $sum += $hash_files{$key}{'max_size'};
            if($hash_files{$key}{'max_size'} > $max)
            {
                $max = $hash_files{$key}{'max_size'};
            }
        }
    }
}
if($counter > 0) { $avg = $sum / $counter; }
else { $avg = 0; }
$avg = format_bytes($avg);
$max = format_bytes($max);
print TABLES "read-only files \& $counter \& $avg \& $max \\\\\n";

$counter = 0;
$sum = 0;
$max = 0;
foreach $key (keys %hash_files) {
    if(!($hash_files{$key}{'was_read'}) && $hash_files{$key}{'was_written'})
    {
        $counter++;
        if($hash_files{$key}{'min_open_size'} >
            $hash_files{$key}{'max_size'})
        {
            $sum += $hash_files{$key}{'min_open_size'};
            if($hash_files{$key}{'min_open_size'} > $max)
            {
                $max = $hash_files{$key}{'min_open_size'};
            }
        }
        else
        {
            $sum += $hash_files{$key}{'max_size'};
            if($hash_files{$key}{'max_size'} > $max)
            {
                $max = $hash_files{$key}{'max_size'};
            }
        }
    }
}
if($counter > 0) { $avg = $sum / $counter; }
else { $avg = 0; }
$avg = format_bytes($avg);
$max = format_bytes($max);
print TABLES "write-only files \& $counter \& $avg \& $max \\\\\n";

$counter = 0;
$sum = 0;
$max = 0;
foreach $key (keys %hash_files) {
    if($hash_files{$key}{'was_read'} && $hash_files{$key}{'was_written'})
    {
        $counter++;
        if($hash_files{$key}{'min_open_size'} >
            $hash_files{$key}{'max_size'})
        {
            $sum += $hash_files{$key}{'min_open_size'};
            if($hash_files{$key}{'min_open_size'} > $max)
            {
                $max = $hash_files{$key}{'min_open_size'};
            }
        }
        else
        {
            $sum += $hash_files{$key}{'max_size'};
            if($hash_files{$key}{'max_size'} > $max)
            {
                $max = $hash_files{$key}{'max_size'};
            }
        }
    }
}
if($counter > 0) { $avg = $sum / $counter; }
else { $avg = 0; }
$avg = format_bytes($avg);
$max = format_bytes($max);
print TABLES "read/write files \& $counter \& $avg \& $max \\\\\n";

$counter = 0;
$sum = 0;
$max = 0;
foreach $key (keys %hash_files) {
    if($hash_files{$key}{'was_written'} &&
        $hash_files{$key}{'min_open_size'} == 0 &&
        $hash_files{$key}{'max_size'} > 0)
    {
        $counter++;
        if($hash_files{$key}{'min_open_size'} >
            $hash_files{$key}{'max_size'})
        {
            $sum += $hash_files{$key}{'min_open_size'};
            if($hash_files{$key}{'min_open_size'} > $max)
            {
                $max = $hash_files{$key}{'min_open_size'};
            }
        }
        else
        {
            $sum += $hash_files{$key}{'max_size'};
            if($hash_files{$key}{'max_size'} > $max)
            {
                $max = $hash_files{$key}{'max_size'};
            }
        }
    }
}
if($counter > 0) { $avg = $sum / $counter; }
else { $avg = 0; }
$avg = format_bytes($avg);
$max = format_bytes($max);
print TABLES "created files \& $counter \& $avg \& $max \\\\\n";

Philip Carns's avatar
Philip Carns committed
702 703 704 705 706 707 708
print TABLES "
\\hline
\\end{tabular}
";
close(TABLES);


709 710 711 712
#
# Generate Per Filesystem Data
#
open(TABLES, ">$tmp_dir/fs-data-table.tex") || die("error opening output files:$!\n");
713
if (($major > 1) or ($minor > 23))
714
{
715 716 717 718 719 720 721 722 723 724 725 726
    print TABLES "
    \\begin{tabular}{c|r|r|r|r}
    \\multicolumn{5}{c}{ } \\\\
    \\multicolumn{5}{c}{Data Transfer Per Filesystem} \\\\
    \\hline
    \\multirow{2}{*}{File System} \& \\multicolumn{2}{c}{Write} \\vline \& \\multicolumn{2}{c}{Read} \\\\
    \\cline{2-5}
    \& MiB \& Ratio \& MiB \& Ratio \\\\\
    \\hline
    \\hline
    ";
    foreach $key (keys %fs_data)
727
    {
728 729 730
        my $wr_total_mb = ($fs_data{$key}->[1] / (1024*1024));
        my $rd_total_mb = ($fs_data{$key}->[0] / (1024*1024));
        my $wr_total_rt;
731

732
        if ($cumul_write_bytes_shared+$cumul_write_bytes_indep)
733 734 735 736 737 738 739 740 741 742 743 744 745 746 747 748 749
        {
            $wr_total_rt = ($fs_data{$key}->[1] / ($cumul_write_bytes_shared + $cumul_write_bytes_indep));
        }
        else
        {
            $wr_total_rt = 0;
        }

        my $rd_total_rt;
        if ($cumul_read_bytes_shared+$cumul_read_bytes_indep)
        {
            $rd_total_rt = ($fs_data{$key}->[0] / ($cumul_read_bytes_shared + $cumul_read_bytes_indep));
        }
        else
        {
            $rd_total_rt = 0;
        }
750

751 752
        printf TABLES "%s \& %.5f \& %.5f \& %.5f \& %.5f \\\\\n",
            $key, $wr_total_mb, $wr_total_rt, $rd_total_mb, $rd_total_rt;
753 754 755 756 757
}
print TABLES "
\\hline
\\end{tabular}
";
758 759 760 761 762 763 764 765
}
else
{
    print TABLES "
\\rule{0in}{1in}
\\parbox{5in}{Log versions prior to 1.24 do not support per-filesystem data.}
";
}
766 767 768
close(TABLES);


769
open(TIME, ">$tmp_dir/time-summary.dat") || die("error opening output file:$!\n");
770 771 772 773 774 775 776 777 778 779 780 781 782 783 784
print TIME "# <type>, <app time>, <read>, <write>, <meta>\n";
print TIME "POSIX, ", ((($runtime * $nprocs - $summary{CP_F_POSIX_READ_TIME} -
    $summary{CP_F_POSIX_WRITE_TIME} -
    $summary{CP_F_POSIX_META_TIME})/($runtime * $nprocs)) * 100);
print TIME ", ", (($summary{CP_F_POSIX_READ_TIME}/($runtime * $nprocs))*100);
print TIME ", ", (($summary{CP_F_POSIX_WRITE_TIME}/($runtime * $nprocs))*100);
print TIME ", ", (($summary{CP_F_POSIX_META_TIME}/($runtime * $nprocs))*100), "\n";
print TIME "MPI-IO, ", ((($runtime * $nprocs - $summary{CP_F_MPI_READ_TIME} -
    $summary{CP_F_MPI_WRITE_TIME} -
    $summary{CP_F_MPI_META_TIME})/($runtime * $nprocs)) * 100);
print TIME ", ", (($summary{CP_F_MPI_READ_TIME}/($runtime * $nprocs))*100);
print TIME ", ", (($summary{CP_F_MPI_WRITE_TIME}/($runtime * $nprocs))*100);
print TIME ", ", (($summary{CP_F_MPI_META_TIME}/($runtime * $nprocs))*100), "\n";
close TIME;

785
# copy template files to tmp tmp_dir
786 787
system "$cp $PREFIX/share/*.gplt $tmp_dir/";
system "$cp $PREFIX/share/*.tex $tmp_dir/";
788

789
# generate template for file access plot (we have to set range)
790 791 792 793
my $ymax = $nprocs;
my $yinc = int($nprocs / 8);
if($yinc == 0) {$yinc=1;}
my $ymaxtic = $nprocs-1;
794 795 796 797 798
open(FILEACC, ">$tmp_dir/file-access-read-eps.gplt") || die("error opening output file:$!\n");
print FILEACC "#!/usr/bin/gnuplot -persist

set terminal postscript eps color solid font \"Helvetica\" 18 size 10in,2.5in
set output \"file-access-read.eps\"
799 800
set ylabel \"MPI rank\"
set xlabel \"hours:minutes:seconds\"
801 802 803
set xdata time
set timefmt \"%s\"
set format x \"%H:%M:%S\"
804
set yrange [-1:$ymax]
Philip Carns's avatar
Philip Carns committed
805
set title \"Timespan from first to last read access on independent files\"
806
set xrange [\"0\":\"$runtime\"]
807
set ytics 0,$yinc,$ymaxtic
808
#set ytics -1,1
809
set lmargin 4
810 811 812 813 814 815 816 817 818 819 820 821 822 823 824 825 826 827 828

# color blindness work around
set style line 2 lc 3
set style line 3 lc 4
set style line 4 lc 5
set style line 5 lc 2
set style increment user

# lw 3 to make lines thicker...
# note that writes are slightly offset for better visibility
plot \"file-access-read.dat\" using 1:2:3:4 with vectors nohead filled notitle
";
close FILEACC;

open(FILEACC, ">$tmp_dir/file-access-write-eps.gplt") || die("error opening output file:$!\n");
print FILEACC "#!/usr/bin/gnuplot -persist

set terminal postscript eps color solid font \"Helvetica\" 18 size 10in,2.5in
set output \"file-access-write.eps\"
829 830
set ylabel \"MPI rank\"
set xlabel \"hours:minutes:seconds\"
831 832 833
set xdata time
set timefmt \"%s\"
set format x \"%H:%M:%S\"
Philip Carns's avatar
Philip Carns committed
834
set title \"Timespan from first to last write access on independent files\"
835
set yrange [-1:$ymax]
836
set xrange [\"0\":\"$runtime\"]
837
#set ytics -1,1
838
set ytics 0,$yinc,$ymaxtic
839
set lmargin 4
840 841 842 843 844 845 846 847 848 849 850 851 852

# color blindness work around
set style line 2 lc 3
set style line 3 lc 4
set style line 4 lc 5
set style line 5 lc 2
set style increment user

# lw 3 to make lines thicker...
plot \"file-access-write.dat\" using 1:2:3:4 with vectors nohead filled lt 2 notitle
";
close FILEACC;

853 854 855 856 857 858 859 860 861 862
open(FILEACC, ">$tmp_dir/file-access-shared-eps.gplt") || die("error opening output file:$!\n");
print FILEACC "#!/usr/bin/gnuplot -persist

set terminal postscript eps color solid font \"Helvetica\" 18 size 10in,2.5in
set output \"file-access-shared.eps\"
set xlabel \"hours:minutes:seconds\"
set xdata time
set timefmt \"%s\"
set format x \"%H:%M:%S\"
unset ytics
863
set ylabel \"All processes\"
864
set xrange [\"0\":\"$runtime\"]
865
set yrange [-1:1]
Philip Carns's avatar
Philip Carns committed
866
set title \"Timespan from first to last access on files shared by all processes\"
867
set lmargin 4
868 869 870 871 872 873 874 875 876 877 878 879 880

# color blindness work around
set style line 2 lc 3
set style line 3 lc 4
set style line 4 lc 5
set style line 5 lc 2
set style increment user

plot \"file-access-read-sh.dat\" using 1:2:3:4 with vectors nohead filled lw 10 title \"read\", \\
\"file-access-write-sh.dat\" using 1:((\$2)-.2):3:4 with vectors nohead filled lw 10 title \"write\"
";
close FILEACC;

881 882 883 884 885 886 887 888 889 890 891 892 893 894 895 896
$cumul_read_indep /= $nprocs;
$cumul_read_bytes_indep /= $nprocs;
$cumul_read_bytes_indep /= 1048576.0;

$cumul_write_indep /= $nprocs;
$cumul_write_bytes_indep /= $nprocs;
$cumul_write_bytes_indep /= 1048576.0;

$cumul_read_shared /= $nprocs;
$cumul_read_bytes_shared /= $nprocs;
$cumul_read_bytes_shared /= 1048576.0;

$cumul_write_shared /= $nprocs;
$cumul_write_bytes_shared /= $nprocs;
$cumul_write_bytes_shared /= 1048576.0;

897 898 899
$cumul_meta_shared /= $nprocs;
$cumul_meta_indep /= $nprocs;

900
open(FILEACC, ">$tmp_dir/file-access-table.tex") || die("error opening output file:$!\n");
901
print FILEACC "
Philip Carns's avatar
Philip Carns committed
902 903 904 905
\\begin{tabular}{l|p{1.7in}r}
\\multicolumn{3}{c}{Average I/O per process} \\\\
\\hline
 \& Cumulative time spent in I/O functions (seconds) \& Amount of I/O (MB) \\\\
906 907
\\hline
\\hline
Philip Carns's avatar
Philip Carns committed
908 909
";

Philip Carns's avatar
Philip Carns committed
910 911 912 913 914
# printf to get consistent precision in output
printf(FILEACC "Independent reads \& \\multicolumn{1}{r}{%f} \& \\multicolumn{1}{r}{%f} \\\\", 
    $cumul_read_indep, $cumul_read_bytes_indep);
printf(FILEACC "Independent writes \& \\multicolumn{1}{r}{%f} \& \\multicolumn{1}{r}{%f} \\\\", 
    $cumul_write_indep, $cumul_write_bytes_indep);
915 916
printf(FILEACC "Independent metadata \& \\multicolumn{1}{r}{%f} \& \\multicolumn{1}{r}{N/A} \\\\", 
    $cumul_meta_indep);
Philip Carns's avatar
Philip Carns committed
917 918 919 920
printf(FILEACC "Shared reads \& \\multicolumn{1}{r}{%f} \& \\multicolumn{1}{r}{%f} \\\\", 
    $cumul_read_shared, $cumul_read_bytes_shared);
printf(FILEACC "Shared writes \& \\multicolumn{1}{r}{%f} \& \\multicolumn{1}{r}{%f} \\\\", 
    $cumul_write_shared, $cumul_write_bytes_shared);
921 922
printf(FILEACC "Shared metadata \& \\multicolumn{1}{r}{%f} \& \\multicolumn{1}{r}{N/A} \\\\", 
    $cumul_meta_shared);
Philip Carns's avatar
Philip Carns committed
923 924

print FILEACC "
925 926 927
\\hline
\\end{tabular}
";
928 929
close(FILEACC);

930 931 932 933 934 935 936 937 938 939 940 941 942 943 944 945 946
#
# Variance Data
#
open(VARP, ">$tmp_dir/variance-table.tex") || die("error opening output file:$!\n");
print VARP "
\\begin{tabular}{c|r|r|r|r|r|r|r|r|r}
\\multicolumn{10}{c}{} \\\\
\\multicolumn{10}{c}{Variance in Shared Files} \\\\
\\hline
File \& Processes \& \\multicolumn{3}{c}{Fastest} \\vline \&
\\multicolumn{3}{c}{Slowest} \\vline \& \\multicolumn{2}{c}{\$\\sigma\$} \\\\
\\cline{3-10}
Suffix \&  \& Rank \& Time \& Bytes \& Rank \& Time \& Bytes \& Time \& Bytes \\\\
\\hline
\\hline
";

947 948 949 950 951
my $curcount = 1;
foreach $key (sort { $hash_files{$b}{'slowest_time'} <=> $hash_files{$a}{'slowest_time'} } keys %hash_files) {

    if ($curcount > 20) { last; }

952 953 954 955 956 957
    if ($hash_files{$key}{'procs'} > 1)
    {
        my $vt = sprintf("%.3g", sqrt($hash_files{$key}{'variance_time'}));
        my $vb = sprintf("%.3g", sqrt($hash_files{$key}{'variance_bytes'}));
        my $fast_bytes = format_bytes($hash_files{$key}{'fastest_bytes'});
        my $slow_bytes = format_bytes($hash_files{$key}{'slowest_bytes'});
958
        my $name = encode('latex', $hash_files{$key}{'name'});
959 960

        print VARP "
961
               $name \&
962 963 964 965 966 967 968 969 970 971
               $hash_files{$key}{'procs'} \&
               $hash_files{$key}{'fastest_rank'} \&
               $hash_files{$key}{'fastest_time'} \&
               $fast_bytes \&
               $hash_files{$key}{'slowest_rank'} \&
               $hash_files{$key}{'slowest_time'} \& 
               $slow_bytes \&
               $vt \&
               $vb \\\\
         ";
972
        $curcount++;
973 974 975 976 977 978 979 980 981
    }
}

print VARP "
\\hline
\\end{tabular}
";
close(VARP);

982 983 984 985 986 987 988 989 990 991
# calculate performance
##########################################################################

# what was the slowest time by any proc for unique file access?
my $slowest_uniq_time = 0;
if(keys %hash_unique_file_time > 0)
{
    $slowest_uniq_time < $_ and $slowest_uniq_time = $_ for values %hash_unique_file_time;
}
print("Slowest unique file time: $slowest_uniq_time\n");
992
print("Slowest shared file time: $shared_file_time\n");
993 994 995
print("Total bytes read and written by app (may be incorrect): $total_job_bytes\n");
my $tmp_total_time = $slowest_uniq_time+$shared_file_time;
print("Total absolute I/O time: $tmp_total_time\n");
996

997 998 999
# move to tmp_dir
chdir $tmp_dir;

1000
# execute gnuplot scripts
1001
system "$gnuplot counts-eps.gplt";
1002
system "$epstopdf counts.eps";
1003
system "$gnuplot hist-eps.gplt";
1004
system "$epstopdf hist.eps";
1005
system "$gnuplot pattern-eps.gplt";
1006
system "$epstopdf pattern.eps";
1007
system "$gnuplot time-summary-eps.gplt";
1008
system "$epstopdf time-summary.eps";
1009
system "$gnuplot file-access-read-eps.gplt";
1010
system "$epstopdf file-access-read.eps";
1011
system "$gnuplot file-access-write-eps.gplt";
1012
system "$epstopdf file-access-write.eps";
1013
system "$gnuplot file-access-shared-eps.gplt";
1014
system "$epstopdf file-access-shared.eps";
1015

1016 1017 1018 1019
#system "gnuplot align-pdf.gplt";
#system "gnuplot iodist-pdf.gplt";
#system "gnuplot types-pdf.gplt";

1020
# generate summary PDF
1021 1022 1023
# NOTE: an autoconf test determines if -halt-on-error is available and sets
# __CP_PDFLATEX_HALT_ON_ERROR accordingly
$system_rc = system "$pdflatex @__CP_PDFLATEX_HALT_ON_ERROR@ summary.tex > latex.output";
1024 1025 1026 1027 1028 1029 1030
if($system_rc)
{
    print("LaTeX generation (phase1) failed [$system_rc], aborting summary creation.\n");
    print("error log:\n");
    system("tail latex.output");
    exit(1);
}
1031
$system_rc = system "$pdflatex @__CP_PDFLATEX_HALT_ON_ERROR@ summary.tex > latex.output2";
1032 1033 1034 1035 1036 1037 1038
if($system_rc)
{
    print("LaTeX generation (phase2) failed [$system_rc], aborting summary creation.\n");
    print("error log:\n");
    system("tail latex.output2");
    exit(1);
}
1039

1040 1041
# get back out of tmp dir and grab results
chdir $orig_dir;
1042
system "$mv $tmp_dir/summary.pdf $output_file";
1043

1044

1045 1046
sub process_file_record
{
1047 1048 1049 1050 1051 1052
    my $rank = $_[0];
    my $hash = $_[1];
    my(%file_record) = %{$_[2]};

    if($file_record{'CP_INDEP_OPENS'} == 0 &&
        $file_record{'CP_COLL_OPENS'} == 0 &&
1053
        $file_record{'CP_POSIX_OPENS'} == 0 &&
1054
        $file_record{'CP_POSIX_FOPENS'} == 0)
1055 1056 1057 1058 1059 1060 1061 1062 1063 1064
    {
        # file wasn't really opened, just stat probably
        return;
    }

    # record smallest open time size reported by any rank
    if(!defined($hash_files{$hash}{'min_open_size'}) ||
        $hash_files{$hash}{'min_open_size'} > 
        $file_record{'CP_SIZE_AT_OPEN'})
    {
1065 1066 1067 1068 1069 1070 1071 1072 1073 1074 1075 1076 1077
        # size at open will be set to -1 if the darshan library was not
        # configured to stat files at open time
        if($file_record{'CP_SIZE_AT_OPEN'} < 0)
        {
            $hash_files{$hash}{'min_open_size'} = 0;
            # set flag indicating that file sizes are estimated 
            $size_est_flag = 1;
        }
        else
        {
            $hash_files{$hash}{'min_open_size'} = 
                $file_record{'CP_SIZE_AT_OPEN'};
        }
1078 1079 1080 1081 1082 1083 1084 1085 1086 1087 1088 1089 1090 1091 1092 1093 1094 1095 1096 1097 1098 1099 1100 1101 1102 1103 1104 1105 1106 1107 1108 1109 1110 1111 1112 1113 1114 1115 1116 1117 1118 1119 1120 1121 1122 1123 1124 1125 1126 1127 1128 1129