From 8cf1a515ddbb11cb872e12e86cca305c164ffc33 Mon Sep 17 00:00:00 2001 From: Matthew Bloch Date: Thu, 7 Jun 2012 00:01:11 +0100 Subject: [PATCH 1/7] Missing break; in switch statement (verbose was setting default deny!) --- src/flexnbd.c | 1 + 1 file changed, 1 insertion(+) diff --git a/src/flexnbd.c b/src/flexnbd.c index f0ae799..dbfc1b6 100644 --- a/src/flexnbd.c +++ b/src/flexnbd.c @@ -192,6 +192,7 @@ void read_serve_param( int c, char **ip_addr, char **ip_port, char **file, char break; case 'v': set_debug(1); + break; case 'd': *default_deny = 1; break; From 9fc3c061f84ff427c80d22867d5100d2bb820710 Mon Sep 17 00:00:00 2001 From: Matthew Bloch Date: Thu, 7 Jun 2012 01:15:29 +0100 Subject: [PATCH 2/7] Fixed arguments to debug function. --- src/util.c | 20 ++++++++++++-------- 1 file changed, 12 insertions(+), 8 deletions(-) diff --git a/src/util.c b/src/util.c index 05be379..32c33b1 100644 --- a/src/util.c +++ b/src/util.c @@ -66,17 +66,21 @@ void set_debug(int value) { } #ifdef DEBUG + # include # include -void debug(const char *msg, ...) { - va_list argp; - - if ( global_debug ) { - fprintf(stderr, "%08x %4d: ", (int) pthread_self(), (int) clock() ); - fprintf(stderr, msg, argp); - fprintf(stderr, "\n"); - } +void debug(const char *format, ...) { + va_list argptr; + + if (!global_debug) + return; + + fprintf(stderr, "%08x %4d: ", (int) pthread_self(), (int) clock() ); + va_start(argptr, format); + vfprintf(stderr, format, argptr); + va_end(argptr); + fprintf(stderr, "\n"); } #endif From 08f3d42b34453fedb7b8f2169a162adc23077847 Mon Sep 17 00:00:00 2001 From: Matthew Bloch Date: Thu, 7 Jun 2012 02:06:08 +0100 Subject: [PATCH 3/7] Improved fuzz test to find an actual code bug (previous bug was in the test ). --- tests/flexnbd.rb | 13 ++++++++----- tests/fuzz | 17 ++++++++++++----- 2 files changed, 20 insertions(+), 10 deletions(-) diff --git a/tests/flexnbd.rb b/tests/flexnbd.rb index 66801cb..b2adef5 100644 --- a/tests/flexnbd.rb +++ b/tests/flexnbd.rb @@ -7,7 +7,7 @@ class FlexNBD def initialize(bin, ip, port) @bin = bin - @debug = `#{@bin} serve --help` =~ /--debug/ ? "--debug" : "" + @debug = "--verbose" # tests always run in debug mode! @valgrind = ENV['VALGRIND'] ? "valgrind " : "" @bin = "#{@valgrind}#{@bin}" raise "#{bin} not executable" unless File.executable?(bin) @@ -25,6 +25,7 @@ class FlexNBD "--sock #{ctrl} "\ "#{@debug} "\ "#{acl.join(' ')}" + #STDERR.print "#{cmd}\n" @pid = fork do exec(cmd) end @@ -42,15 +43,17 @@ class FlexNBD end def read(offset, length) - IO.popen("#{@bin} read "\ + + out = IO.popen("#{@bin} read "\ "--addr #{ip} "\ "--port #{port} "\ "--from #{offset} "\ "#{@debug} "\ "--size #{length}","r") do |fh| - return fh.read + fh.read end - raise "read failed" unless $?.success? + raise IOError.new "NBD read failed" unless $?.success? + out end def write(offset, data) @@ -62,7 +65,7 @@ class FlexNBD "--size #{data.length}","w") do |fh| fh.write(data) end - raise "write failed" unless $?.success? + raise IOError.new "NBD write failed" unless $?.success? nil end diff --git a/tests/fuzz b/tests/fuzz index e3e3558..e4fb8a6 100644 --- a/tests/fuzz +++ b/tests/fuzz @@ -22,7 +22,7 @@ end testname_local = "#{$0}.test.#{$$}.local" testname_serve = "#{$0}.test.#{$$}.serve" [testname_local, testname_serve].each do |name| - File.open(name, "w+") { |fh| fh.seek(test_size-1, IO::SEEK_SET); fh.write("0") } + File.open(name, "w+") { |fh| fh.seek(test_size-1, IO::SEEK_SET); fh.write("\0") } end @local = File.open(testname_local, "r+") @@ -55,15 +55,22 @@ repetitions.times do |n| length &= 0xfffff000 if CHEAT_AND_ROUND_DOWN offset = rand(test_size - length) offset &= 0xfffff000 if CHEAT_AND_ROUND_DOWN - content = (n%2 == 1) ? ("x" * length) : ("\0" * length) - + + content = (n%2 == 0) ? ("\0" * length) : ( ((n/2)&255).chr * length) + @local.seek(offset, IO::SEEK_SET) @local.write(content) + @local.fsync @serve.write(offset, content) - if @serve.read(offset, length) != content - STDERR.print "After pass #{n}: Didn't read back what we wrote!" + check_read = @serve.read(offset, length) + if check_read != content + STDERR.print "After pass #{n}: Didn't read back what we wrote!\n" + STDERR.print "*** We wrote these #{content.length} bytes...\n" + IO.popen("hexdump", "w") { |io| io.print(content) } + STDERR.print "*** But we got back these #{check_read.length} bytes...\n" + IO.popen("hexdump", "w") { |io| io.print(check_read) } exit 1 end From 57104317802de221e678e9462983c41274019223 Mon Sep 17 00:00:00 2001 From: Matthew Bloch Date: Thu, 7 Jun 2012 11:17:02 +0100 Subject: [PATCH 4/7] Refactored write_not_zeroes to use struct bitset_mapping instead of repeating all that code (has not fixed earlier bug yet, but lots of repetition cut). --- src/client.c | 34 +++++++++++++--------------------- src/ioutil.c | 35 ++++++++++++++++------------------- src/serve.c | 4 ++-- src/serve.h | 2 +- 4 files changed, 32 insertions(+), 43 deletions(-) diff --git a/src/client.c b/src/client.c index 20e6468..3aa9bd7 100644 --- a/src/client.c +++ b/src/client.c @@ -26,7 +26,7 @@ */ void write_not_zeroes(struct client* client, off64_t from, int len) { - char *map = client->serve->block_allocation_map; + struct bitset_mapping *map = client->serve->allocation_map; while (len > 0) { /* so we have to calculate how much of our input to consider @@ -36,17 +36,15 @@ void write_not_zeroes(struct client* client, off64_t from, int len) * how many blocks our write covers, then cut off the start * and end to get the exact number of bytes. */ - int first_bit = from/block_allocation_resolution; - int last_bit = (from+len+block_allocation_resolution-1) / - block_allocation_resolution; - int run = bit_run_count(map, first_bit, last_bit-first_bit) * - block_allocation_resolution; + + int run = bitset_run_count(map, from, len); - if (run > len) + debug("write_not_zeroes: from=%ld, len=%d, run=%d", from, len, run); + + if (run > len) { run = len; - - debug("write_not_zeroes: %ld+%d, first_bit=%d, last_bit=%d, run=%d", - from, len, first_bit, last_bit, run); + debug("(run adjusted to %d)", run); + } #define DO_READ(dst, len) CLIENT_ERROR_ON_FAILURE( \ readloop( \ @@ -57,8 +55,8 @@ void write_not_zeroes(struct client* client, off64_t from, int len) "read failed %ld+%d", from, (len) \ ) - if (bit_is_set(map, from/block_allocation_resolution)) { - debug("writing the lot"); + if (bitset_is_set_at(map, from)) { + debug("writing the lot: from=%ld, run=%d", from, run); /* already allocated, just write it all */ DO_READ(client->mapped + from, run); server_dirty(client->serve, from, run); @@ -69,16 +67,11 @@ void write_not_zeroes(struct client* client, off64_t from, int len) char zerobuffer[block_allocation_resolution]; /* not allocated, read in block_allocation_resoution */ while (run > 0) { - char *dst = client->mapped+from; - int bit = from/block_allocation_resolution; int blockrun = block_allocation_resolution - (from % block_allocation_resolution); if (blockrun > run) blockrun = run; - debug("writing partial: bit=%d, blockrun=%d (run=%d)", - bit, blockrun, run); - DO_READ(zerobuffer, blockrun); /* This reads the buffer twice in the worst case @@ -88,10 +81,9 @@ void write_not_zeroes(struct client* client, off64_t from, int len) */ if (zerobuffer[0] != 0 || memcmp(zerobuffer, zerobuffer + 1, blockrun - 1)) { - memcpy(dst, zerobuffer, blockrun); - bit_set(map, bit); + memcpy(client->mapped+from, zerobuffer, blockrun); + bitset_set_range(map, from, blockrun); server_dirty(client->serve, from, blockrun); - debug("non-zero, copied and set bit %d", bit); /* at this point we could choose to * short-cut the rest of the write for * faster I/O but by continuing to do it @@ -247,7 +239,7 @@ void client_reply_to_read( struct client* client, struct nbd_request request ) void client_reply_to_write( struct client* client, struct nbd_request request ) { debug("request write %ld+%d", request.from, request.len); - if (client->serve->block_allocation_map) { + if (client->serve->allocation_map) { write_not_zeroes( client, request.from, request.len ); } else { diff --git a/src/ioutil.c b/src/ioutil.c index f61ff12..159d6b9 100644 --- a/src/ioutil.c +++ b/src/ioutil.c @@ -14,10 +14,10 @@ #include "util.h" #include "bitset.h" -char* build_allocation_map(int fd, off64_t size, int resolution) +struct bitset_mapping* build_allocation_map(int fd, off64_t size, int resolution) { int i; - char *allocation_map = xmalloc((size+resolution)/resolution); + struct bitset_mapping* allocation_map = bitset_alloc(size, resolution); struct fiemap *fiemap_count, *fiemap; fiemap_count = (struct fiemap*) xmalloc(sizeof(struct fiemap)); @@ -49,27 +49,24 @@ char* build_allocation_map(int fd, off64_t size, int resolution) if (ioctl(fd, FS_IOC_FIEMAP, fiemap) < 0) return NULL; - for (i=0;ifm_mapped_extents;i++) { - int first_bit = fiemap->fm_extents[i].fe_logical / resolution; - int last_bit = (fiemap->fm_extents[i].fe_logical + - fiemap->fm_extents[i].fe_length + resolution - 1) / - resolution; - int run = last_bit - first_bit; - - bit_set_range(allocation_map, first_bit, run); - } + for (i=0;ifm_mapped_extents;i++) + bitset_set_range( + allocation_map, + fiemap->fm_extents[i].fe_logical, + fiemap->fm_extents[i].fe_length + ); for (i=0; i<16; i++) { debug("map[%d] = %d%d%d%d%d%d%d%d", i, - (allocation_map[i] & 1) == 1, - (allocation_map[i] & 2) == 2, - (allocation_map[i] & 4) == 4, - (allocation_map[i] & 8) == 8, - (allocation_map[i] & 16) == 16, - (allocation_map[i] & 32) == 32, - (allocation_map[i] & 64) == 64, - (allocation_map[i] & 128) == 128 + (allocation_map->bits[i] & 1) == 1, + (allocation_map->bits[i] & 2) == 2, + (allocation_map->bits[i] & 4) == 4, + (allocation_map->bits[i] & 8) == 8, + (allocation_map->bits[i] & 16) == 16, + (allocation_map->bits[i] & 32) == 32, + (allocation_map->bits[i] & 64) == 64, + (allocation_map->bits[i] & 128) == 128 ); } diff --git a/src/serve.c b/src/serve.c index f45dfaa..d211d8f 100644 --- a/src/serve.c +++ b/src/serve.c @@ -305,7 +305,7 @@ void serve_init_allocation_map(struct server* params) params->size = size; SERVER_ERROR_ON_FAILURE(size, "Couldn't find size of %s", params->filename); - params->block_allocation_map = + params->allocation_map = build_allocation_map(fd, size, block_allocation_resolution); close(fd); } @@ -336,7 +336,7 @@ void serve_cleanup(struct server* params) self_pipe_destroy( params->close_signal ); - free(params->block_allocation_map); + free(params->allocation_map); if (params->mirror) debug("mirror thread running! this should not happen!"); diff --git a/src/serve.h b/src/serve.h index 9cb4b48..9ec711a 100644 --- a/src/serve.h +++ b/src/serve.h @@ -69,7 +69,7 @@ struct server { int server_fd; int control_fd; - char* block_allocation_map; + struct bitset_mapping* allocation_map; struct { pthread_t thread; union mysockaddr address; } nbd_client[MAX_NBD_CLIENTS]; From 3810a8210f2a89c63eace3d71c0d4e475b24ba5c Mon Sep 17 00:00:00 2001 From: Matthew Bloch Date: Thu, 7 Jun 2012 12:25:56 +0100 Subject: [PATCH 5/7] Added some record-keeping / printing to fuzzer to assist with backtracking. --- tests/fuzz | 16 ++++++++++++++-- 1 file changed, 14 insertions(+), 2 deletions(-) diff --git a/tests/fuzz b/tests/fuzz index e4fb8a6..4749986 100644 --- a/tests/fuzz +++ b/tests/fuzz @@ -30,6 +30,13 @@ end @serve = FlexNBD.new(binary, "127.0.0.1", 41234) @serve.serve(testname_serve) +$record = [] +def print_record + $record.each do |offset, length, byte| + STDERR.print " wrote #{byte} to #{offset}+#{length}\n" + end +end + repetitions.times do |n| begin @@ -44,6 +51,7 @@ repetitions.times do |n| if md5_local != md5_serve STDERR.print "Before pass #{n}: MD5 error: local=#{md5_local} serve=#{md5_serve}\n" + print_record STDERR.print "**** Local contents:\n" system("hexdump #{testname_local}") STDERR.print "**** Serve contents:\n" @@ -51,12 +59,14 @@ repetitions.times do |n| exit 1 end - length = rand(max_length) + length = rand(max_length/8) length &= 0xfffff000 if CHEAT_AND_ROUND_DOWN offset = rand(test_size - length) offset &= 0xfffff000 if CHEAT_AND_ROUND_DOWN - content = (n%2 == 0) ? ("\0" * length) : ( ((n/2)&255).chr * length) + content = (n%2 == 0) ? ("\0" * length) : ( (n&255).chr * length) + + $record << [offset, length, content[0]] @local.seek(offset, IO::SEEK_SET) @local.write(content) @@ -67,6 +77,7 @@ repetitions.times do |n| check_read = @serve.read(offset, length) if check_read != content STDERR.print "After pass #{n}: Didn't read back what we wrote!\n" + print_record STDERR.print "*** We wrote these #{content.length} bytes...\n" IO.popen("hexdump", "w") { |io| io.print(content) } STDERR.print "*** But we got back these #{check_read.length} bytes...\n" @@ -76,6 +87,7 @@ repetitions.times do |n| rescue StandardError => ex STDERR.print "During pass #{n}: Exception: #{ex}" + print_record STDERR.print ex.backtrace.join("\n") + "\n" exit 2 end From d763ab4e74aeb0307f743425753ffbf076e8daf4 Mon Sep 17 00:00:00 2001 From: Matthew Bloch Date: Thu, 7 Jun 2012 12:27:46 +0100 Subject: [PATCH 6/7] Fixed bug in bitset_run_count which was causing data corruptionn writing around sparse boundaries. --- src/bitset.h | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/bitset.h b/src/bitset.h index 9c081af..ee0f8fb 100644 --- a/src/bitset.h +++ b/src/bitset.h @@ -147,7 +147,8 @@ static inline int bitset_run_count( uint64_t len) { INT_FIRST_AND_LAST; - return bit_run_count(set->bits, first, bitlen) * set->resolution; + return (bit_run_count(set->bits, first, bitlen) * set->resolution) - + (from % set->resolution); } /** Tests whether the bit field is clear for the given file offset. From 40f0f9fab6f48223bdea84a91feab66ffeb47419 Mon Sep 17 00:00:00 2001 From: Matthew Bloch Date: Thu, 7 Jun 2012 12:28:21 +0100 Subject: [PATCH 7/7] Big bit of debug output in write_not_zeroes (disabled). --- src/client.c | 17 +++++++++++++++++ 1 file changed, 17 insertions(+) diff --git a/src/client.c b/src/client.c index 3aa9bd7..86df1e7 100644 --- a/src/client.c +++ b/src/client.c @@ -46,6 +46,22 @@ void write_not_zeroes(struct client* client, off64_t from, int len) debug("(run adjusted to %d)", run); } + if (0) /* useful but expensive */ + { + int i; + fprintf(stderr, "full map resolution=%d: ", map->resolution); + for (i=0; iserve->size; i+=map->resolution) { + int here = (from >= i && from < i+map->resolution); + + if (here) + fprintf(stderr, ">"); + fprintf(stderr, bitset_is_set_at(map, i) ? "1" : "0"); + if (here) + fprintf(stderr, "<"); + } + fprintf(stderr, "\n"); + } + #define DO_READ(dst, len) CLIENT_ERROR_ON_FAILURE( \ readloop( \ client->socket, \ @@ -81,6 +97,7 @@ void write_not_zeroes(struct client* client, off64_t from, int len) */ if (zerobuffer[0] != 0 || memcmp(zerobuffer, zerobuffer + 1, blockrun - 1)) { + debug("non-zero, writing from=%ld, blockrun=%d", from, blockrun); memcpy(client->mapped+from, zerobuffer, blockrun); bitset_set_range(map, from, blockrun); server_dirty(client->serve, from, blockrun);