From 46a7f246388e23f740376ad60dd90469b033be4e Mon Sep 17 00:00:00 2001 From: Michel Machado Date: Thu, 25 Sep 2014 14:33:02 -0400 Subject: [PATCH] f3probe: add option --time-ops In order to reduce probing time, one needs to time reads, writes, and resets to evaluate how to change the probing algorithm. This patch adds these measurements. A good 256MB drive produced the following measurements: Probe time: 47.57 seconds Probe read op: count=2014, total time=1.72s, avg op time=0.85ms Probe write op: count=2003, total time=45.32s, avg op time=22.62ms Probe reset op: count=3, total time=0.53s, avg op time=175.66ms --- f3probe.c | 47 +++++++++++++++++++- libprobe.c | 128 +++++++++++++++++++++++++++++++++++++++++++++++++++++ libprobe.h | 6 +++ 3 files changed, 179 insertions(+), 2 deletions(-) diff --git a/f3probe.c b/f3probe.c index 1397657..ec18f55 100644 --- a/f3probe.c +++ b/f3probe.c @@ -47,6 +47,8 @@ static struct argp_option options[] = { "Trade speed for less use of memory", 0}, {"manual-reset", 'm', NULL, 0, "Ask user to manually reset the drive", 0}, + {"time-ops", 't', NULL, 0, + "Time reads, writes, and resets", 0}, { 0 } }; @@ -62,7 +64,8 @@ struct args { bool save; bool min_mem; bool manual_reset; - /* 2 free bytes. */ + bool time_ops; + /* 1 free bytes. */ /* Geometry. */ uint64_t real_size_byte; @@ -150,6 +153,10 @@ static error_t parse_opt(int key, char *arg, struct argp_state *state) args->manual_reset = true; break; + case 't': + args->time_ops = true; + break; + case ARGP_KEY_INIT: args->filename = NULL; break; @@ -294,14 +301,24 @@ static void report_order(const char *prefix, int order) printf("%s %.2f %s (2^%i Byte)\n", prefix, f, unit, order); } +static void report_ops(const char *op, uint64_t count, uint64_t time_us) +{ + printf("Probe %s op: count=%" PRIu64 + ", total time=%.2fs, avg op time=%.2fms\n", + op, count, time_us / 1e6, (time_us / count) / 1e3); +} + static int test_device(struct args *args) { struct timeval t1, t2; double time_s; - struct device *dev; + struct device *dev, *pdev; enum fake_type fake_type; uint64_t real_size_byte, announced_size_byte; int wrap, block_order; + uint64_t read_count, read_time_us; + uint64_t write_count, write_time_us; + uint64_t reset_count, reset_time_us; dev = args->debug ? create_file_device(args->filename, args->real_size_byte, @@ -310,6 +327,14 @@ static int test_device(struct args *args) : create_block_device(args->filename, args->manual_reset); assert(dev); + if (args->time_ops) { + pdev = create_perf_device(dev); + assert(pdev); + dev = pdev; + } else { + pdev = NULL; + } + if (args->save) { dev = create_safe_device(dev, probe_device_max_blocks(dev), args->min_mem); @@ -333,7 +358,18 @@ static int test_device(struct args *args) * make sure that the written blocks are recovered when * @args->save is true. */ + if (args->time_ops) + perf_device_sample(pdev, + &read_count, &read_time_us, + &write_count, &write_time_us, + &reset_count, &reset_time_us); + if (args->save) { + printf("Probe finished, recovering blocks..."); + fflush(stdout); + } free_device(dev); + if (args->save) + printf(" Done\n\n"); fake_type = dev_param_to_type(real_size_byte, announced_size_byte, wrap, block_order); @@ -363,6 +399,12 @@ static int test_device(struct args *args) report_order("\t Module:", wrap); report_order("\t Block size:", block_order); printf("\nProbe time: %.2f seconds\n", time_s); + + if (args->time_ops) { + report_ops("read", read_count, read_time_us); + report_ops("write", write_count, write_time_us); + report_ops("reset", reset_count, reset_time_us); + } return 0; } @@ -376,6 +418,7 @@ int main(int argc, char **argv) .save = true, .min_mem = false, .manual_reset = false, + .time_ops = false, .real_size_byte = 1ULL << 31, .fake_size_byte = 1ULL << 34, .wrap = 31, diff --git a/libprobe.c b/libprobe.c index 8e241ce..2f9f978 100644 --- a/libprobe.c +++ b/libprobe.c @@ -10,6 +10,7 @@ #include #include #include +#include #include #include #include @@ -536,6 +537,133 @@ error: return NULL; } +struct perf_device { + /* This must be the first field. See dev_pdev() for details. */ + struct device dev; + + struct device *shadow_dev; + + uint64_t read_count; + uint64_t read_time_us; + uint64_t write_count; + uint64_t write_time_us; + uint64_t reset_count; + uint64_t reset_time_us; +}; + +static inline struct perf_device *dev_pdev(struct device *dev) +{ + return (struct perf_device *)dev; +} + +static inline uint64_t diff_timeval_us(const struct timeval *t1, + const struct timeval *t2) +{ + return (t2->tv_sec - t1->tv_sec) * 1000000ULL + + t2->tv_usec - t1->tv_usec; +} + +static int pdev_read_block(struct device *dev, char *buf, int length, + uint64_t offset) +{ + struct perf_device *pdev = dev_pdev(dev); + struct timeval t1, t2; + int rc; + + assert(!gettimeofday(&t1, NULL)); + rc = pdev->shadow_dev->read_block(pdev->shadow_dev, buf, + length, offset); + assert(!gettimeofday(&t2, NULL)); + pdev->read_count++; + pdev->read_time_us += diff_timeval_us(&t1, &t2); + return rc; +} + +static int pdev_write_block(struct device *dev, const char *buf, int length, + uint64_t offset) +{ + struct perf_device *pdev = dev_pdev(dev); + struct timeval t1, t2; + int rc; + + assert(!gettimeofday(&t1, NULL)); + rc = pdev->shadow_dev->write_block(pdev->shadow_dev, buf, + length, offset); + assert(!gettimeofday(&t2, NULL)); + pdev->write_count++; + pdev->write_time_us += diff_timeval_us(&t1, &t2); + return rc; +} + +static int pdev_reset(struct device *dev) +{ + struct perf_device *pdev = dev_pdev(dev); + struct timeval t1, t2; + int rc; + + assert(!gettimeofday(&t1, NULL)); + rc = dev_reset(pdev->shadow_dev); + assert(!gettimeofday(&t2, NULL)); + pdev->reset_count++; + pdev->reset_time_us += diff_timeval_us(&t1, &t2); + return rc; +} + +static void pdev_free(struct device *dev) +{ + struct perf_device *pdev = dev_pdev(dev); + free_device(pdev->shadow_dev); +} + +struct device *create_perf_device(struct device *dev) +{ + struct perf_device *pdev; + + pdev = malloc(sizeof(*pdev)); + if (!pdev) + return NULL; + + pdev->shadow_dev = dev; + pdev->read_count = 0; + pdev->read_time_us = 0; + pdev->write_count = 0; + pdev->write_time_us = 0; + pdev->reset_count = 0; + pdev->reset_time_us = 0; + + pdev->dev.size_byte = dev->size_byte; + pdev->dev.block_order = dev->block_order; + pdev->dev.read_block = pdev_read_block; + pdev->dev.write_block = pdev_write_block; + pdev->dev.reset = pdev_reset; + pdev->dev.free = pdev_free; + + return &pdev->dev; +} + +void perf_device_sample(struct device *dev, + uint64_t *pread_count, uint64_t *pread_time_us, + uint64_t *pwrite_count, uint64_t *pwrite_time_us, + uint64_t *preset_count, uint64_t *preset_time_us) +{ + struct perf_device *pdev = dev_pdev(dev); + + if (pread_count) + *pread_count = pdev->read_count; + if (pread_time_us) + *pread_time_us = pdev->read_time_us; + + if (pwrite_count) + *pwrite_count = pdev->write_count; + if (pwrite_time_us) + *pwrite_time_us = pdev->write_time_us; + + if (preset_count) + *preset_count = pdev->reset_count; + if (preset_time_us) + *preset_time_us = pdev->reset_time_us; +} + #define SDEV_BITMAP_WORD long #define SDEV_BITMAP_BITS_PER_WORD (8*sizeof(SDEV_BITMAP_WORD)) struct safe_device { diff --git a/libprobe.h b/libprobe.h index b524a5a..7186001 100644 --- a/libprobe.h +++ b/libprobe.h @@ -38,6 +38,12 @@ struct device *create_file_device(const char *filename, struct device *create_block_device(const char *filename, int manual_reset); +struct device *create_perf_device(struct device *dev); +void perf_device_sample(struct device *dev, + uint64_t *pread_count, uint64_t *pread_time_us, + uint64_t *pwrite_count, uint64_t *pwrite_time_us, + uint64_t *preset_count, uint64_t *preset_time_us); + struct device *create_safe_device(struct device *dev, int max_blocks, int min_memory);