From cf085da6ac3f0b0ef33ccc7e79f74961c120435f Mon Sep 17 00:00:00 2001 From: Matt Palmer Date: Fri, 7 Nov 2014 21:17:12 +1100 Subject: [PATCH] Now with debugging! In addition to refactoring the output formatting in general, there's now a separate --debug option that will provide you with even *more* obsessive detail about what's going on. --- bin/lvmsync | 88 ++++++++++++++++++++++++++++++++--------------------- 1 file changed, 53 insertions(+), 35 deletions(-) diff --git a/bin/lvmsync b/bin/lvmsync index 1f95abc..cc69159 100755 --- a/bin/lvmsync +++ b/bin/lvmsync @@ -43,10 +43,13 @@ def main() end opts.on("-v", "--[no-]verbose", - "Run verbosely") { |v| options[:verbose] = v } + "Run verbosely") { |v| $verbose = v } + + opts.on("-d", "--[no-]debug", + "Print debugging information") { |v| $debug = v } opts.on("-q", "--[no-]quiet", - "Run quietly") { |v| options[:quiet] = v } + "Run quietly") { |v| $quiet = v } opts.on("-b ", "--snapback ", "Make a backup snapshot file on the destination") do |v| @@ -75,49 +78,42 @@ def main() puts "lvmsync #{GVB.version}" exit 0 rescue GVB::VersionUnobtainable - $stderr.puts "Unable to determine lvmsync version." - $stderr.puts "Install lvmsync as a gem, or run it from within a git checkout" - exit 1 + fatal "Unable to determine lvmsync version.\n" + + "Install lvmsync as a gem, or run it from within a git checkout" end end end.parse! - if options[:quiet] and options[:verbose] - $stderr.puts "I can't run quietly *and* verbosely at the same time!" - exit 1 + if $quiet and ($verbose or $debug) + fatal "I can't run quietly *and* verbosely at the same time!" end if options[:apply] if ARGV[0].nil? - $stderr.puts "No destination device specified." - exit 1 + fatal "No destination device specified." end options[:device] = ARGV[0] run_apply(options) elsif options[:server] - $stderr.puts "--server is deprecated; please use '--apply -' instead" unless opts[:quiet] + info "--server is deprecated; please use '--apply -' instead" if (ARGV[0].nil?) - $stderr.puts "No destination block device specified. WTF?" - exit 1 + fatal "No destination block device specified. WTF?" end options[:apply] = '-' options[:device] = ARGV[0] run_apply(options) else if ARGV[0].nil? - $stderr.puts "ERROR: No snapshot specified. Exiting." - exit 1 + fatal "No snapshot specified. Exiting. Do you need --help?" end options[:snapdev] = ARGV[0] if options[:stdout] and options[:snapback] - $stderr.puts "--snapback cannot be used with --stdout" - exit 1 + fatal "--snapback cannot be used with --stdout" end if (options[:stdout].nil? and ARGV[1].nil?) - $stderr.puts "No destination specified." - exit 1 + fatal "No destination specified." end if options[:stdout].nil? dev, host = ARGV[1].split(':', 2).reverse @@ -143,18 +139,19 @@ end def process_dumpdata(instream, destdev, snapback = nil, opts = {}) handshake = instream.readline.chomp unless handshake == PROTOCOL_VERSION - $stderr.puts "Handshake failed; protocol mismatch? (saw '#{handshake}' expected '#{PROTOCOL_VERSION}'" - exit 1 + fatal "Handshake failed; protocol mismatch? (saw '#{handshake}' expected '#{PROTOCOL_VERSION}'" end snapback.puts handshake if snapback + verbose "Writing changed data to #{destdev.inspect}" File.open(destdev, 'w+') do |dest| while header = instream.read(12) offset, chunksize = header.unpack("QN") offset = ntohq(offset) begin + debug "Seeking to #{offset}" dest.seek offset rescue Errno::EINVAL # In certain rare circumstances, we want to transfer a block @@ -164,6 +161,8 @@ def process_dumpdata(instream, destdev, snapback = nil, opts = {}) # if you didn't notice that your dd shit itself, it's unlikely # you're going to notice now. + info "Write occured past end of device" + # Skip the chunk of data instream.read(chunksize) # Go to the next chunk @@ -173,9 +172,12 @@ def process_dumpdata(instream, destdev, snapback = nil, opts = {}) if snapback snapback.write(header) snapback.write dest.read(chunksize) + # Got to back to where we were before, since the read from dest + # has advanced the file pointer by `chunksize` dest.seek offset end dest.write instream.read(chunksize) + debug "Wrote #{chunksize} bytes at #{offset}" end end end @@ -189,13 +191,11 @@ def run_client(opts) lv = begin LVM::LogicalVolume.new(snapshot) rescue RuntimeError => e - $stderr.puts "#{snapshot}: could not find logical volume (#{e.message})" - exit 1 + fatal "#{snapshot}: could not find logical volume (#{e.message})" end unless lv.snapshot? - $stderr.puts "#{snapshot}: Not a snapshot device" - exit 1 + fatal "#{snapshot}: Not a snapshot device" end # Since, in principle, we're not supposed to be reading from snapshot @@ -208,14 +208,16 @@ def run_client(opts) snapback = opts[:snapback] ? "--snapback #{opts[:snapback]}" : '' source = opts[:source] || lv.origin.path - $stderr.puts "Data source: #{source}" if opts[:verbose] + verbose "Data source: #{source}" if opts[:stdout] dump_changes(lv, source, $stdout, opts) else - verbose = opts[:verbose] ? '-v' : '' + verbose = $verbose ? '-v' : '' + debug = $debug ? '-d' : '' + server_cmd = if desthost - "#{opts[:rsh]} #{desthost} lvmsync --apply - #{snapback} #{verbose} #{destdev}" + "#{opts[:rsh]} #{desthost} lvmsync --apply - #{snapback} #{verbose} #{debug} #{destdev}" else "#{$0} --apply - #{snapback} #{verbose} #{destdev}" end @@ -232,7 +234,7 @@ def run_client(opts) until (active_fds = IO.select(fds, [], [], 0)).nil? active_fds[0].each do |fd| begin - $stderr.puts "\e[2K\rremote:#{fd.readline}" unless opts[:quiet] + info "\e[2K\rremote:#{fd.readline}" rescue EOFError, Errno::EPIPE fd.close fds.delete(fd) @@ -251,7 +253,7 @@ def run_client(opts) until (active_fds = IO.select(fds, [], [], 0.1)).nil? active_fds[0].each do |fd| begin - $stderr.puts "\e[2K\rremote:#{fd.readline}" unless opts[:quiet] + info "\e[2K\rremote:#{fd.readline}" rescue EOFError, Errno::EPIPE fd.close fds.delete(fd) @@ -262,7 +264,7 @@ def run_client(opts) end if (exit_status or $?).exitstatus != 0 - $stderr.puts "APPLY FAILED." + fatal "APPLY FAILED." end end end @@ -282,8 +284,7 @@ def dump_changes(snapshot, source, outfd, opts) chunk_size = r.last - r.first + 1 xfer_size += chunk_size - $stderr.puts "Sending chunk #{r.to_s}..." if opts[:verbose] - $stderr.puts "Seeking to #{r.first} in #{source}" if opts[:verbose] + debug "Sending chunk #{r.to_s}..." origindev.seek(r.first, IO::SEEK_SET) @@ -297,7 +298,7 @@ def dump_changes(snapshot, source, outfd, opts) end # Progress bar! - if xfer_count % 100 == 50 and !opts[:quiet] + if xfer_count % 100 == 50 and !$quiet $stderr.printf "\e[2K\rSending chunk %i of %i, %.2fMB/s", xfer_count, change_count, @@ -311,7 +312,7 @@ def dump_changes(snapshot, source, outfd, opts) total_size = origindev.tell end - unless opts[:quiet] + unless $quiet $stderr.printf "\rTransferred %i bytes in %.2f seconds\n", xfer_size, Time.now - start_time @@ -336,4 +337,21 @@ def parse_snapshot_name(origname) end end +def debug(s) + $stderr.puts s if $debug +end + +def verbose(s) + $stderr.puts s if $verbose or $debug +end + +def info(s) + $stderr.puts s unless $quiet +end + +def fatal(s, status=1) + $stderr.puts "FATAL ERROR: #{s}" + exit status +end + main