From 5dfc67ec18f8c9cbe8ea9b19628844f8f64f22a5 Mon Sep 17 00:00:00 2001 From: Andrea Mazzoleni Date: Wed, 25 Jun 2014 22:32:36 +0200 Subject: [PATCH] Keeps stats about usage time of disk and cpu. --- HISTORY | 2 ++ TODO | 11 ++----- cmdline/elem.c | 1 + cmdline/elem.h | 2 ++ cmdline/mingw.c | 10 +++++++ cmdline/portable.h | 8 ++++++ cmdline/state.c | 62 ++++++++++++++++++++++++++++++++++++++++ cmdline/state.h | 71 ++++++++++++++++++++++++++++++++++++++++++++++ cmdline/sync.c | 36 +++++++++++++++++++++++ cmdline/unix.c | 32 +++++++++++++++++++++ configure.ac | 3 ++ 11 files changed, 230 insertions(+), 8 deletions(-) diff --git a/HISTORY b/HISTORY index 2d659f3e..9714c186 100644 --- a/HISTORY +++ b/HISTORY @@ -14,6 +14,8 @@ SnapRAID HISTORY * Auto exclude the lock file. * Don't prints the 'UUID set' message anymore because it's the normal condition for empty disks. + * In 'sync' keeps stats about the amount of time spent waiting for + each disk and what is spent in CPU computation. * In Windows, if the disk doesn't support reading physical offsets, allows SnapRAID to continue anyway. diff --git a/TODO b/TODO index 7e8c72e2..7e480e3f 100644 --- a/TODO +++ b/TODO @@ -3,16 +3,11 @@ SnapRAID TODO This is the list of TODO items for SnapRAID. +/* close the last file in the disk */ +in sync.c + - Next -* Recognize if the content file is older than parity, -and in case make a full sync after asking for configuration -with a --force option. - -* Measures the time waited in blocking syscall for each disk, -and prints stats of the disk speeds when the command finish, -or when it's running. - * In status prints the allocated parity in each data disk. In case, also takes into account the extra available space in the parity disks. diff --git a/cmdline/elem.c b/cmdline/elem.c index e272435a..46acb0d1 100644 --- a/cmdline/elem.c +++ b/cmdline/elem.c @@ -644,6 +644,7 @@ struct snapraid_disk* disk_alloc(const char* name, const char* dir, uint64_t dev pathslash(disk->dir, sizeof(disk->dir)); disk->device = dev; + disk->tick = 0; disk->first_free_block = 0; disk->has_volatile_inodes = 0; disk->has_unreliable_physical = 0; diff --git a/cmdline/elem.h b/cmdline/elem.h index b9291006..ef9aa6c5 100644 --- a/cmdline/elem.h +++ b/cmdline/elem.h @@ -293,6 +293,8 @@ struct snapraid_disk { char dir[PATH_MAX]; /**< Mount point of the disk. It always terminates with /. */ uint64_t device; /**< Device identifier. */ + uint64_t tick; /**< Usage time of the disk. */ + /** * First free searching block. * Note that it doesn't necessarely point at the first free block, diff --git a/cmdline/mingw.c b/cmdline/mingw.c index cf0b6850..b45411bd 100644 --- a/cmdline/mingw.c +++ b/cmdline/mingw.c @@ -1370,5 +1370,15 @@ retry: return count; } +uint64_t tick(void) +{ + LARGE_INTEGER t; + + if (!QueryPerformanceCounter(&t)) + return 0; + + return t.QuadPart; +} + #endif diff --git a/cmdline/portable.h b/cmdline/portable.h index 6bb2a385..3c61125f 100644 --- a/cmdline/portable.h +++ b/cmdline/portable.h @@ -236,6 +236,14 @@ int filephy(const char* path, struct stat* st, uint64_t* physical); */ int fsinfo(const char* path, int* has_persistent_inode); +/** + * Get the tick counter value. + * + * Note that the frequency is unspecified, becasue the time measure + * is meant to be used to compare the ratio between usage times. + */ +uint64_t tick(void); + /** * Initializes the system. */ diff --git a/cmdline/state.c b/cmdline/state.c index 3e3e0807..fe228260 100644 --- a/cmdline/state.c +++ b/cmdline/state.c @@ -84,7 +84,10 @@ void state_init(struct snapraid_state* state) for(l=0;lparity_path[l][0] = 0; state->parity_device[l] = 0; + state->tick[l] = 0; } + state->tick_cpu = 0; + state->tick_last = tick(); state->share[0] = 0; state->pool[0] = 0; state->pool_device = 0; @@ -4309,10 +4312,13 @@ int state_progress(struct snapraid_state* state, block_off_t blockpos, block_off fflush(stdlog); } else { time_t now; + tommy_node* i; + unsigned l; now = time(0); if (state->progress_last != now) { + uint64_t tick_total; time_t delta = now - state->progress_start - state->progress_subtract; printf("%u%%, %u MiB", countpos * 100 / countmax, (unsigned)(countsize / (1024*1024))); @@ -4321,6 +4327,16 @@ int state_progress(struct snapraid_state* state, block_off_t blockpos, block_off printf(", %u MiB/s", (unsigned)(countsize / (1024*1024) / delta)); } + tick_total = state->tick_cpu; + for(i=state->disklist;i!=0;i=i->next) { + struct snapraid_disk* disk = i->data; + tick_total += disk->tick; + } + for(l=0;llevel;++l) + tick_total += state->tick[l]; + if (tick_total) + printf(", CPU %"PRIu64"%%", state->tick_cpu * 100ULL / tick_total); + if (delta > 5 && countpos > 0) { unsigned m, h; data_off_t to_do = countmax - countpos; @@ -4352,6 +4368,52 @@ int state_progress(struct snapraid_state* state, block_off_t blockpos, block_off return 0; } +void state_usage_print(struct snapraid_state* state) +{ + uint64_t tick_total; + uint64_t tick_max; + tommy_node* i; + unsigned l; + + tick_max = 0; + tick_total = 0; + for(i=state->disklist;i!=0;i=i->next) { + struct snapraid_disk* disk = i->data; + tick_total += disk->tick; + if (disk->tick > tick_max) + tick_max = disk->tick; + } + for(l=0;llevel;++l) { + tick_total += state->tick[l]; + if (state->tick[l] > tick_max) + tick_max = state->tick[l]; + } + + if (!tick_total) + return; + + printf("Time for disk:"); + for(i=state->disklist;i!=0;i=i->next) { + struct snapraid_disk* disk = i->data; + if (disk->tick == tick_max) + printf(" %s:", disk->name); + else + printf(" "); + printf("%"PRIu64"%%", disk->tick * 100ULL / tick_total); + } + printf("\n"); + + printf("Time for parity:"); + for(l=0;llevel;++l) { + if (state->tick[l] == tick_max) + printf(" %s:", lev_config_name(l)); + else + printf(" "); + printf("%"PRIu64"%%", state->tick[l] * 100ULL / tick_total); + } + printf("\n"); +} + void generate_configuration(const char* path) { struct snapraid_state state; diff --git a/cmdline/state.h b/cmdline/state.h index 6ef557ab..9b8ebf7e 100644 --- a/cmdline/state.h +++ b/cmdline/state.h @@ -117,6 +117,21 @@ struct snapraid_state { tommy_hashdyn previmportset; /**< Hashtable by prevhash of all the import blocks. Valid only if we are in a rehash state. */ tommy_arrayblkof infoarr; /**< Block information array. */ + /** + * Cumulative time used for parity disks. + */ + uint64_t tick[LEV_MAX]; + + /** + * Cumulative time used for computations. + */ + uint64_t tick_cpu; + + /** + * Last time used for time measure. + */ + uint64_t tick_last; + /** * Required size of the parity file, computed from the loaded state. * @@ -251,6 +266,62 @@ void state_progress_stop(struct snapraid_state* state); */ void state_progress_restart(struct snapraid_state* state); +/** + * Set the usage time as wasted one not counted. + */ +static inline void state_usage_waste(struct snapraid_state* state) +{ + uint64_t now = tick(); + + state->tick_last = now; +} + +/** + * Set the usage time for CPU. + */ +static inline void state_usage_cpu(struct snapraid_state* state) +{ + uint64_t now = tick(); + + /* increment the time spent in computations */ + state->tick_cpu += now - state->tick_last; + + state->tick_last = now; +} + +/** + * Set the usage time for data disk. + */ +static inline void state_usage_disk(struct snapraid_state* state, struct snapraid_disk* disk) +{ + uint64_t now = tick(); + + /* increment the time spent in the data disk */ + disk->tick += now - state->tick_last; + + state->tick_last = now; +} + +/** + * Set the usage time for parity disk. + */ +static inline void state_usage_parity(struct snapraid_state* state, unsigned level) +{ + uint64_t now = tick(); + + assert(level < LEV_MAX); + + /* increment the time spent in the parity disk */ + state->tick[level] += now - state->tick_last; + + state->tick_last = now; +} + +/** + * Prints the stats of the usage time. + */ +void state_usage_print(struct snapraid_state* state); + /****************************************************************************/ /* misc */ diff --git a/cmdline/sync.c b/cmdline/sync.c index b4545c40..2c87e25f 100644 --- a/cmdline/sync.c +++ b/cmdline/sync.c @@ -77,6 +77,9 @@ static int state_hash_process(struct snapraid_state* state, block_off_t blocksta } } + /* drop until now */ + state_usage_waste(state); + countsize = 0; countpos = 0; if (state_progress_begin(state, blockstart, blockmax, countmax)) @@ -113,6 +116,9 @@ static int state_hash_process(struct snapraid_state* state, block_off_t blocksta /* if we have to use the old hash */ rehash = info_get_rehash(info); + /* until now is CPU */ + state_usage_cpu(state); + /* if the file is different than the current one, close it */ if (handle[j].file != 0 && handle[j].file != block_file_get(block)) { /* file we are processing for error reporting */ @@ -212,6 +218,9 @@ static int state_hash_process(struct snapraid_state* state, block_off_t blocksta /* LCOV_EXCL_STOP */ } + /* until now is disk */ + state_usage_disk(state, disk); + countsize += read_size; /* now compute the hash */ @@ -406,6 +415,9 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari autosavemissing = countmax; /* blocks to do */ autosavedone = 0; /* blocks done */ + /* drop until now */ + state_usage_waste(state); + countsize = 0; countpos = 0; if (state_progress_begin(state, blockstart, blockmax, countmax)) @@ -528,6 +540,9 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari continue; } + /* until now is CPU */ + state_usage_cpu(state); + /* if the file is different than the current one, close it */ if (handle[j].file != 0 && handle[j].file != block_file_get(block)) { /* file we are processing for error reporting */ @@ -630,6 +645,9 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari /* LCOV_EXCL_STOP */ } + /* until now is disk */ + state_usage_disk(state, disk); + countsize += read_size; /* now compute the hash */ @@ -758,10 +776,14 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari /* if we have something to recover and enough parity */ if (something_to_recover && j == failed_count) { + /* until now is CPU */ + state_usage_cpu(state); + /* read the parity */ /* we are sure that parity exists because */ /* we have at least one BLK block */ for(l=0;llevel;++l) { + ret = parity_read(parity[l], i, buffer[diskmax+l], state->block_size, stdlog); if (ret == -1) { /* LCOV_EXCL_START */ @@ -773,6 +795,9 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari goto bail; /* LCOV_EXCL_STOP */ } + + /* until now is parity */ + state_usage_parity(state, l); } /* try to fix the data */ @@ -827,6 +852,9 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari /* compute the parity */ raid_gen(diskmax, state->level, state->block_size, buffer); + /* until now is CPU */ + state_usage_cpu(state); + /* write the parity */ for(l=0;llevel;++l) { ret = parity_write(parity[l], i, buffer[diskmax+l], state->block_size); @@ -840,6 +868,9 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari goto bail; /* LCOV_EXCL_STOP */ } + + /* until now is parity */ + state_usage_parity(state, l); } } @@ -922,11 +953,16 @@ static int state_sync_process(struct snapraid_state* state, struct snapraid_pari state_write(state); state_progress_restart(state); + + /* drop until now */ + state_usage_waste(state); } } state_progress_end(state, countpos, countmax, countsize); + state_usage_print(state); + if (error || silent_error) { printf("\n"); printf("%8u read/write errors\n", error); diff --git a/cmdline/unix.c b/cmdline/unix.c index 38216b92..be077775 100644 --- a/cmdline/unix.c +++ b/cmdline/unix.c @@ -235,6 +235,38 @@ int fsinfo(const char* path, int* has_persistent_inode) return 0; } +uint64_t tick(void) +{ +#if HAVE_MACH_ABSOLUTE_TIME + /* for Mac OS X */ + return match_absolute_time(); +#elif HAVE_CLOCK_GETTIME && (defined(CLOCK_MONOTONIC) || defined(CLOCK_MONOTONIC_RAW)) + /* for Linux */ + struct timespec tv; + + /* nanosecond precision with clock_gettime() */ +#if defined(CLOCK_MONOTONIC_RAW) + if (clock_gettime(CLOCK_MONOTONIC_RAW, &tv) != 0) { +#else + if (clock_gettime(CLOCK_MONOTONIC, &tv) != 0) { +#endif + return 0; + } + + return tv.tv_sec * 1000000000ULL + tv.tv_nsec; +#else + /* other platforms */ + struct timeval tv; + + /* microsecond precision with gettimeofday() */ + if (gettimeofday(&tv, 0) != 0) { + return 0; + } + + return tv.tv_sec * 1000000ULL + tv.tv_usec; +#endif +} + void os_init(void) { } diff --git a/configure.ac b/configure.ac index 0f4e7ba4..f42c4f66 100644 --- a/configure.ac +++ b/configure.ac @@ -76,6 +76,9 @@ AC_CHECK_FUNCS([ftruncate fallocate fsync access posix_fallocate posix_fadvise]) AC_CHECK_FUNCS([pread pwrite getc_unlocked ferror_unlocked fnmatch]) AC_CHECK_FUNCS([futimes futimens futimesat localtime_r]) AC_CHECK_FUNCS([fstatat flock statfs]) +AC_CHECK_FUNCS([mach_absolute_time]) +AC_SEARCH_LIBS([clock_gettime], [rt]) +AC_CHECK_FUNCS([clock_gettime]) dnl Checks for architecture AC_C_BIGENDIAN