Commit 2276d929 authored by Shane Snyder's avatar Shane Snyder

modify posix open and close counters

POSIX_F_OPEN_TIMESTAMP is now POSIX_F_OPEN_START_TIMESTAMP
POSIX_F_CLOSE_TIMESTAMP is now POSIX_F_CLOSE_END_TIMESTAMP

I also added POSIX_F_OPEN_END_TIMESTAMP and
POSIX_F_CLOSE_START_TIMESTAMP, so we can better understand how
long open and close phases are for some applications.
parent 557e586c
...@@ -108,17 +108,21 @@ ...@@ -108,17 +108,21 @@
#define POSIX_F_COUNTERS \ #define POSIX_F_COUNTERS \
/* timestamp of first open */\ /* timestamp of first open */\
X(POSIX_F_OPEN_TIMESTAMP) \ X(POSIX_F_OPEN_START_TIMESTAMP) \
/* timestamp of first read */\ /* timestamp of first read */\
X(POSIX_F_READ_START_TIMESTAMP) \ X(POSIX_F_READ_START_TIMESTAMP) \
/* timestamp of first write */\ /* timestamp of first write */\
X(POSIX_F_WRITE_START_TIMESTAMP) \ X(POSIX_F_WRITE_START_TIMESTAMP) \
/* timestamp of first close */\
X(POSIX_F_CLOSE_START_TIMESTAMP) \
/* timestamp of last open */\
X(POSIX_F_OPEN_END_TIMESTAMP) \
/* timestamp of last read */\ /* timestamp of last read */\
X(POSIX_F_READ_END_TIMESTAMP) \ X(POSIX_F_READ_END_TIMESTAMP) \
/* timestamp of last write */\ /* timestamp of last write */\
X(POSIX_F_WRITE_END_TIMESTAMP) \ X(POSIX_F_WRITE_END_TIMESTAMP) \
/* timestamp of last close */\ /* timestamp of last close */\
X(POSIX_F_CLOSE_TIMESTAMP) \ X(POSIX_F_CLOSE_END_TIMESTAMP) \
/* cumulative posix read time */\ /* cumulative posix read time */\
X(POSIX_F_READ_TIME) \ X(POSIX_F_READ_TIME) \
/* cumulative posix write time */\ /* cumulative posix write time */\
......
...@@ -204,9 +204,10 @@ static int darshan_mem_alignment = 1; ...@@ -204,9 +204,10 @@ static int darshan_mem_alignment = 1;
rec_ref->last_byte_written = 0; \ rec_ref->last_byte_written = 0; \
rec_ref->last_byte_read = 0; \ rec_ref->last_byte_read = 0; \
rec_ref->file_rec->counters[POSIX_OPENS] += 1; \ rec_ref->file_rec->counters[POSIX_OPENS] += 1; \
if(rec_ref->file_rec->fcounters[POSIX_F_OPEN_TIMESTAMP] == 0 || \ if(rec_ref->file_rec->fcounters[POSIX_F_OPEN_START_TIMESTAMP] == 0 || \
rec_ref->file_rec->fcounters[POSIX_F_OPEN_TIMESTAMP] > __tm1) \ rec_ref->file_rec->fcounters[POSIX_F_OPEN_START_TIMESTAMP] > __tm1) \
rec_ref->file_rec->fcounters[POSIX_F_OPEN_TIMESTAMP] = __tm1; \ rec_ref->file_rec->fcounters[POSIX_F_OPEN_START_TIMESTAMP] = __tm1; \
rec_ref->file_rec->fcounters[POSIX_F_OPEN_END_TIMESTAMP] = __tm2; \
DARSHAN_TIMER_INC_NO_OVERLAP(rec_ref->file_rec->fcounters[POSIX_F_META_TIME], \ DARSHAN_TIMER_INC_NO_OVERLAP(rec_ref->file_rec->fcounters[POSIX_F_META_TIME], \
__tm1, __tm2, rec_ref->last_meta_end); \ __tm1, __tm2, rec_ref->last_meta_end); \
darshan_add_record_ref(&(posix_runtime->fd_hash), &__ret, sizeof(int), rec_ref); \ darshan_add_record_ref(&(posix_runtime->fd_hash), &__ret, sizeof(int), rec_ref); \
...@@ -1021,8 +1022,10 @@ int DARSHAN_DECL(close)(int fd) ...@@ -1021,8 +1022,10 @@ int DARSHAN_DECL(close)(int fd)
{ {
rec_ref->last_byte_written = 0; rec_ref->last_byte_written = 0;
rec_ref->last_byte_read = 0; rec_ref->last_byte_read = 0;
rec_ref->file_rec->fcounters[POSIX_F_CLOSE_TIMESTAMP] = if(rec_ref->file_rec->fcounters[POSIX_F_CLOSE_START_TIMESTAMP] == 0 ||
darshan_core_wtime(); rec_ref->file_rec->fcounters[POSIX_F_CLOSE_START_TIMESTAMP] > tm1)
rec_ref->file_rec->fcounters[POSIX_F_CLOSE_START_TIMESTAMP] = tm1;
rec_ref->file_rec->fcounters[POSIX_F_CLOSE_END_TIMESTAMP] = tm2;
DARSHAN_TIMER_INC_NO_OVERLAP( DARSHAN_TIMER_INC_NO_OVERLAP(
rec_ref->file_rec->fcounters[POSIX_F_META_TIME], rec_ref->file_rec->fcounters[POSIX_F_META_TIME],
tm1, tm2, rec_ref->last_meta_end); tm1, tm2, rec_ref->last_meta_end);
...@@ -1488,7 +1491,7 @@ static void posix_record_reduction_op(void* infile_v, void* inoutfile_v, ...@@ -1488,7 +1491,7 @@ static void posix_record_reduction_op(void* infile_v, void* inoutfile_v,
} }
/* min non-zero (if available) value */ /* min non-zero (if available) value */
for(j=POSIX_F_OPEN_TIMESTAMP; j<=POSIX_F_WRITE_START_TIMESTAMP; j++) for(j=POSIX_F_OPEN_START_TIMESTAMP; j<=POSIX_F_CLOSE_START_TIMESTAMP; j++)
{ {
if((infile->fcounters[j] < inoutfile->fcounters[j] && if((infile->fcounters[j] < inoutfile->fcounters[j] &&
infile->fcounters[j] > 0) || inoutfile->fcounters[j] == 0) infile->fcounters[j] > 0) || inoutfile->fcounters[j] == 0)
...@@ -1498,7 +1501,7 @@ static void posix_record_reduction_op(void* infile_v, void* inoutfile_v, ...@@ -1498,7 +1501,7 @@ static void posix_record_reduction_op(void* infile_v, void* inoutfile_v,
} }
/* max */ /* max */
for(j=POSIX_F_READ_END_TIMESTAMP; j<=POSIX_F_CLOSE_TIMESTAMP; j++) for(j=POSIX_F_OPEN_END_TIMESTAMP; j<=POSIX_F_CLOSE_END_TIMESTAMP; j++)
{ {
if(infile->fcounters[j] > inoutfile->fcounters[j]) if(infile->fcounters[j] > inoutfile->fcounters[j])
tmp_file.fcounters[j] = infile->fcounters[j]; tmp_file.fcounters[j] = infile->fcounters[j];
......
...@@ -969,18 +969,20 @@ void posix_accum_file(struct darshan_posix_file *pfile, ...@@ -969,18 +969,20 @@ void posix_accum_file(struct darshan_posix_file *pfile,
{ {
switch(i) switch(i)
{ {
case POSIX_F_OPEN_TIMESTAMP: case POSIX_F_OPEN_START_TIMESTAMP:
case POSIX_F_READ_START_TIMESTAMP: case POSIX_F_READ_START_TIMESTAMP:
case POSIX_F_WRITE_START_TIMESTAMP: case POSIX_F_WRITE_START_TIMESTAMP:
case POSIX_F_CLOSE_START_TIMESTAMP:
if(tmp->fcounters[i] == 0 || if(tmp->fcounters[i] == 0 ||
tmp->fcounters[i] > pfile->fcounters[i]) tmp->fcounters[i] > pfile->fcounters[i])
{ {
tmp->fcounters[i] = pfile->fcounters[i]; tmp->fcounters[i] = pfile->fcounters[i];
} }
break; break;
case POSIX_F_OPEN_END_TIMESTAMP:
case POSIX_F_READ_END_TIMESTAMP: case POSIX_F_READ_END_TIMESTAMP:
case POSIX_F_WRITE_END_TIMESTAMP: case POSIX_F_WRITE_END_TIMESTAMP:
case POSIX_F_CLOSE_TIMESTAMP: case POSIX_F_CLOSE_END_TIMESTAMP:
if(tmp->fcounters[i] == 0 || if(tmp->fcounters[i] == 0 ||
tmp->fcounters[i] < pfile->fcounters[i]) tmp->fcounters[i] < pfile->fcounters[i])
{ {
...@@ -1287,12 +1289,12 @@ void posix_accum_perf(struct darshan_posix_file *pfile, ...@@ -1287,12 +1289,12 @@ void posix_accum_perf(struct darshan_posix_file *pfile,
if(pfile->base_rec.rank == -1) if(pfile->base_rec.rank == -1)
{ {
/* by_open */ /* by_open */
if(pfile->fcounters[POSIX_F_CLOSE_TIMESTAMP] > if(pfile->fcounters[POSIX_F_CLOSE_END_TIMESTAMP] >
pfile->fcounters[POSIX_F_OPEN_TIMESTAMP]) pfile->fcounters[POSIX_F_OPEN_START_TIMESTAMP])
{ {
pdata->shared_time_by_open += pdata->shared_time_by_open +=
pfile->fcounters[POSIX_F_CLOSE_TIMESTAMP] - pfile->fcounters[POSIX_F_CLOSE_END_TIMESTAMP] -
pfile->fcounters[POSIX_F_OPEN_TIMESTAMP]; pfile->fcounters[POSIX_F_OPEN_START_TIMESTAMP];
} }
/* by_open_lastio */ /* by_open_lastio */
...@@ -1300,21 +1302,21 @@ void posix_accum_perf(struct darshan_posix_file *pfile, ...@@ -1300,21 +1302,21 @@ void posix_accum_perf(struct darshan_posix_file *pfile,
pfile->fcounters[POSIX_F_WRITE_END_TIMESTAMP]) pfile->fcounters[POSIX_F_WRITE_END_TIMESTAMP])
{ {
/* be careful: file may have been opened but not read or written */ /* be careful: file may have been opened but not read or written */
if(pfile->fcounters[POSIX_F_READ_END_TIMESTAMP] > pfile->fcounters[POSIX_F_OPEN_TIMESTAMP]) if(pfile->fcounters[POSIX_F_READ_END_TIMESTAMP] > pfile->fcounters[POSIX_F_OPEN_START_TIMESTAMP])
{ {
pdata->shared_time_by_open_lastio += pdata->shared_time_by_open_lastio +=
pfile->fcounters[POSIX_F_READ_END_TIMESTAMP] - pfile->fcounters[POSIX_F_READ_END_TIMESTAMP] -
pfile->fcounters[POSIX_F_OPEN_TIMESTAMP]; pfile->fcounters[POSIX_F_OPEN_START_TIMESTAMP];
} }
} }
else else
{ {
/* be careful: file may have been opened but not read or written */ /* be careful: file may have been opened but not read or written */
if(pfile->fcounters[POSIX_F_WRITE_END_TIMESTAMP] > pfile->fcounters[POSIX_F_OPEN_TIMESTAMP]) if(pfile->fcounters[POSIX_F_WRITE_END_TIMESTAMP] > pfile->fcounters[POSIX_F_OPEN_START_TIMESTAMP])
{ {
pdata->shared_time_by_open_lastio += pdata->shared_time_by_open_lastio +=
pfile->fcounters[POSIX_F_WRITE_END_TIMESTAMP] - pfile->fcounters[POSIX_F_WRITE_END_TIMESTAMP] -
pfile->fcounters[POSIX_F_OPEN_TIMESTAMP]; pfile->fcounters[POSIX_F_OPEN_START_TIMESTAMP];
} }
} }
...@@ -1867,8 +1869,8 @@ void posix_file_list(hash_entry_t *file_hash, ...@@ -1867,8 +1869,8 @@ void posix_file_list(hash_entry_t *file_hash,
printf("\n# <record_id>\t<file_name>\t<nprocs>\t<slowest>\t<avg>"); printf("\n# <record_id>\t<file_name>\t<nprocs>\t<slowest>\t<avg>");
if(detail_flag) if(detail_flag)
{ {
printf("\t<start_open>\t<start_read>\t<start_write>"); printf("\t<start_open>\t<start_read>\t<start_write>\t<start_close>");
printf("\t<end_read>\t<end_write>\t<end_close>\t<posix_opens>"); printf("\t<end_open>\t<end_read>\t<end_write>\t<end_close>\t<posix_opens>");
for(i=POSIX_SIZE_READ_0_100; i<= POSIX_SIZE_WRITE_1G_PLUS; i++) for(i=POSIX_SIZE_READ_0_100; i<= POSIX_SIZE_WRITE_1G_PLUS; i++)
printf("\t<%s>", posix_counter_names[i]); printf("\t<%s>", posix_counter_names[i]);
} }
...@@ -1891,7 +1893,7 @@ void posix_file_list(hash_entry_t *file_hash, ...@@ -1891,7 +1893,7 @@ void posix_file_list(hash_entry_t *file_hash,
if(detail_flag) if(detail_flag)
{ {
for(i=POSIX_F_OPEN_TIMESTAMP; i<=POSIX_F_CLOSE_TIMESTAMP; i++) for(i=POSIX_F_OPEN_START_TIMESTAMP; i<=POSIX_F_CLOSE_END_TIMESTAMP; i++)
{ {
printf("\t%f", file_rec->fcounters[i]); printf("\t%f", file_rec->fcounters[i]);
} }
......
...@@ -196,10 +196,8 @@ static void darshan_log_print_posix_description() ...@@ -196,10 +196,8 @@ static void darshan_log_print_posix_description()
printf("# POSIX_ACCESS*_COUNT: count of the four most common access sizes.\n"); printf("# POSIX_ACCESS*_COUNT: count of the four most common access sizes.\n");
printf("# POSIX_*_RANK: rank of the processes that were the fastest and slowest at I/O (for shared files).\n"); printf("# POSIX_*_RANK: rank of the processes that were the fastest and slowest at I/O (for shared files).\n");
printf("# POSIX_*_RANK_BYTES: bytes transferred by the fastest and slowest ranks (for shared files).\n"); printf("# POSIX_*_RANK_BYTES: bytes transferred by the fastest and slowest ranks (for shared files).\n");
printf("# POSIX_F_OPEN_TIMESTAMP: timestamp of first open.\n"); printf("# POSIX_F_*_START_TIMESTAMP: timestamp of first open/read/write/close.\n");
printf("# POSIX_F_*_START_TIMESTAMP: timestamp of first read/write.\n"); printf("# POSIX_F_*_END_TIMESTAMP: timestamp of last open/read/write/close.\n");
printf("# POSIX_F_*_END_TIMESTAMP: timestamp of last read/write.\n");
printf("# POSIX_F_CLOSE_TIMESTAMP: timestamp of last close.\n");
printf("# POSIX_F_READ/WRITE/META_TIME: cumulative time spent in read, write, or metadata operations.\n"); printf("# POSIX_F_READ/WRITE/META_TIME: cumulative time spent in read, write, or metadata operations.\n");
printf("# POSIX_F_MAX_*_TIME: duration of the slowest read and write operations.\n"); printf("# POSIX_F_MAX_*_TIME: duration of the slowest read and write operations.\n");
printf("# POSIX_F_*_RANK_TIME: fastest and slowest I/O time for a single rank (for shared files).\n"); printf("# POSIX_F_*_RANK_TIME: fastest and slowest I/O time for a single rank (for shared files).\n");
...@@ -476,9 +474,10 @@ static void darshan_log_agg_posix_files(void *rec, void *agg_rec, int init_flag) ...@@ -476,9 +474,10 @@ static void darshan_log_agg_posix_files(void *rec, void *agg_rec, int init_flag)
/* sum */ /* sum */
agg_psx_rec->fcounters[i] += psx_rec->fcounters[i]; agg_psx_rec->fcounters[i] += psx_rec->fcounters[i];
break; break;
case POSIX_F_OPEN_TIMESTAMP: case POSIX_F_OPEN_START_TIMESTAMP:
case POSIX_F_READ_START_TIMESTAMP: case POSIX_F_READ_START_TIMESTAMP:
case POSIX_F_WRITE_START_TIMESTAMP: case POSIX_F_WRITE_START_TIMESTAMP:
case POSIX_F_CLOSE_START_TIMESTAMP:
/* minimum non-zero */ /* minimum non-zero */
if((psx_rec->fcounters[i] > 0) && if((psx_rec->fcounters[i] > 0) &&
((agg_psx_rec->fcounters[i] == 0) || ((agg_psx_rec->fcounters[i] == 0) ||
...@@ -487,9 +486,10 @@ static void darshan_log_agg_posix_files(void *rec, void *agg_rec, int init_flag) ...@@ -487,9 +486,10 @@ static void darshan_log_agg_posix_files(void *rec, void *agg_rec, int init_flag)
agg_psx_rec->fcounters[i] = psx_rec->fcounters[i]; agg_psx_rec->fcounters[i] = psx_rec->fcounters[i];
} }
break; break;
case POSIX_F_OPEN_END_TIMESTAMP:
case POSIX_F_READ_END_TIMESTAMP: case POSIX_F_READ_END_TIMESTAMP:
case POSIX_F_WRITE_END_TIMESTAMP: case POSIX_F_WRITE_END_TIMESTAMP:
case POSIX_F_CLOSE_TIMESTAMP: case POSIX_F_CLOSE_END_TIMESTAMP:
/* maximum */ /* maximum */
if(psx_rec->fcounters[i] > agg_psx_rec->fcounters[i]) if(psx_rec->fcounters[i] > agg_psx_rec->fcounters[i])
{ {
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment