]> arthur.barton.de Git - bup.git/commitdiff
Introduce BUP_DEBUG, --debug, and tone down the log messages a lot. bup-0.18
authorAvery Pennarun <apenwarr@gmail.com>
Tue, 7 Sep 2010 01:00:57 +0000 (18:00 -0700)
committerAvery Pennarun <apenwarr@gmail.com>
Tue, 7 Sep 2010 01:02:38 +0000 (18:02 -0700)
There's a new global bup option, --debug (-D) that increments BUP_DEBUG.  If
BUP_DEBUG >=1, debug1() prints; if >= 2, debug2() prints.

We change a bunch of formerly-always-printing log() messages to debug1 or
debug2, so now a typical bup session should be a lot less noisy.

This affects midx in particular, which was *way* too noisy now that 'bup
save' and 'bup server' were running it automatically every now and then.

Signed-off-by: Avery Pennarun <apenwarr@gmail.com>
cmd/midx-cmd.py
cmd/server-cmd.py
lib/bup/client.py
lib/bup/git.py
lib/bup/helpers.py
lib/bup/ssh.py
lib/bup/vfs.py
main.py

index eb66759a1d823f656a155dff4194d5aba9f339fd..f5e91e76de9371598ff45e928c4682325dbcf0b9 100755 (executable)
@@ -12,6 +12,7 @@ bup midx [options...] <idxnames...>
 o,output=  output midx filename (default: auto-generated)
 a,auto     automatically create .midx from any unindexed .idx files
 f,force    automatically create .midx from *all* .idx files
+p,print    print names of generated midx files
 max-files= maximum number of idx files to open at once [-1]
 dir=       directory containing idx/midx files
 """
@@ -32,14 +33,14 @@ def max_files():
 
 def merge(idxlist, bits, table):
     count = 0
-    for e in git.idxmerge(idxlist):
+    for e in git.idxmerge(idxlist, final_progress=False):
         count += 1
         prefix = git.extract_bits(e, bits)
         table[prefix] = count
         yield e
 
 
-def _do_midx(outdir, outfilename, infilenames):
+def _do_midx(outdir, outfilename, infilenames, prefixstr):
     if not outfilename:
         assert(outdir)
         sum = Sha1('\0'.join(infilenames)).hexdigest()
@@ -55,17 +56,18 @@ def _do_midx(outdir, outfilename, infilenames):
         inp.append(ix)
         total += len(ix)
 
-    log('Merging %d indexes (%d objects).\n' % (len(infilenames), total))
+    log('midx: %smerging %d indexes (%d objects).\n'
+        % (prefixstr, len(infilenames), total))
     if (not opt.force and (total < 1024 and len(infilenames) < 3)) \
        or len(infilenames) < 2 \
        or (opt.force and not total):
-        log('midx: nothing to do.\n')
+        debug1('midx: nothing to do.\n')
         return
 
     pages = int(total/SHA_PER_PAGE) or 1
     bits = int(math.ceil(math.log(pages, 2)))
     entries = 2**bits
-    log('Table size: %d (%d bits)\n' % (entries*4, bits))
+    debug1('midx: table size: %d (%d bits)\n' % (entries*4, bits))
     
     table = [0]*entries
 
@@ -103,9 +105,9 @@ def _do_midx(outdir, outfilename, infilenames):
     return total,outfilename
 
 
-def do_midx(outdir, outfilename, infilenames):
-    rv = _do_midx(outdir, outfilename, infilenames)
-    if rv:
+def do_midx(outdir, outfilename, infilenames, prefixstr):
+    rv = _do_midx(outdir, outfilename, infilenames, prefixstr)
+    if rv and opt['print']:
         print rv[1]
 
 
@@ -133,7 +135,7 @@ def do_midx_dir(path):
                     already[iname] = 1
                     any = 1
             if not any:
-                log('%r is redundant\n' % mname)
+                debug1('%r is redundant\n' % mname)
                 unlink(mname)
                 already[mname] = 1
 
@@ -150,30 +152,37 @@ def do_midx_dir(path):
     DESIRED_HWM = opt.force and 1 or 5
     DESIRED_LWM = opt.force and 1 or 2
     existed = dict((name,1) for sz,name in all)
-    log('midx: %d indexes; want no more than %d.\n' % (len(all), DESIRED_HWM))
+    debug1('midx: %d indexes; want no more than %d.\n' 
+           % (len(all), DESIRED_HWM))
     if len(all) <= DESIRED_HWM:
-        log('midx: nothing to do.\n')
+        debug1('midx: nothing to do.\n')
     while len(all) > DESIRED_HWM:
         all.sort()
         part1 = [name for sz,name in all[:len(all)-DESIRED_LWM+1]]
         part2 = all[len(all)-DESIRED_LWM+1:]
         all = list(do_midx_group(path, part1)) + part2
         if len(all) > DESIRED_HWM:
-            log('\nStill too many indexes (%d > %d).  Merging again.\n'
-                % (len(all), DESIRED_HWM))
+            debug1('\nStill too many indexes (%d > %d).  Merging again.\n'
+                   % (len(all), DESIRED_HWM))
 
-    for sz,name in all:
-        if not existed.get(name):
-            print name
+    if opt['print']:
+        for sz,name in all:
+            if not existed.get(name):
+                print name
 
 
 def do_midx_group(outdir, infiles):
-    for sublist in _group(infiles, opt.max_files):
-        rv = _do_midx(path, None, sublist)
+    groups = list(_group(infiles, opt.max_files))
+    gprefix = ''
+    for n,sublist in enumerate(groups):
+        if len(groups) != 1:
+            gprefix = 'Group %d: ' % (n+1)
+        rv = _do_midx(path, None, sublist, gprefix)
         if rv:
             yield rv
 
 
+handle_ctrl_c()
 
 o = options.Options('bup midx', optspec)
 (opt, flags, extra) = o.parse(sys.argv[1:])
@@ -188,7 +197,7 @@ if opt.max_files < 0:
 assert(opt.max_files >= 5)
 
 if extra:
-    do_midx(git.repo('objects/pack'), opt.output, extra)
+    do_midx(git.repo('objects/pack'), opt.output, extra, '')
 elif opt.auto or opt.force:
     if opt.dir:
         paths = [opt.dir]
@@ -196,8 +205,8 @@ elif opt.auto or opt.force:
         paths = [git.repo('objects/pack')]
         paths += glob.glob(git.repo('index-cache/*/.'))
     for path in paths:
-        log('midx: scanning %s\n' % path)
+        debug1('midx: scanning %s\n' % path)
         do_midx_dir(path)
-        log('\n')
+        debug1('\n')
 else:
     o.fatal("you must use -f or -a or provide input filenames")
index 5acc98a441c155c582fecd9ed9c506313265ee7f..8ea3a3728b84bac334b31333c830b0f2e198bb87 100755 (executable)
@@ -8,13 +8,13 @@ suspended_w = None
 
 def init_dir(conn, arg):
     git.init_repo(arg)
-    log('bup server: bupdir initialized: %r\n' % git.repodir)
+    debug1('bup server: bupdir initialized: %r\n' % git.repodir)
     conn.ok()
 
 
 def set_dir(conn, arg):
     git.check_repo_or_die(arg)
-    log('bup server: bupdir is %r\n' % git.repodir)
+    debug1('bup server: bupdir is %r\n' % git.repodir)
     conn.ok()
 
     
@@ -51,9 +51,9 @@ def receive_objects(conn, junk):
             w.abort()
             raise Exception('object read: expected length header, got EOF\n')
         n = struct.unpack('!I', ns)[0]
-        #log('expecting %d bytes\n' % n)
+        #debug2('expecting %d bytes\n' % n)
         if not n:
-            log('bup server: received %d object%s.\n' 
+            debug1('bup server: received %d object%s.\n' 
                 % (w.count, w.count!=1 and "s" or ''))
             fullpath = w.close()
             if fullpath:
@@ -62,13 +62,13 @@ def receive_objects(conn, junk):
             conn.ok()
             return
         elif n == 0xffffffff:
-            log('bup server: receive-objects suspended.\n')
+            debug2('bup server: receive-objects suspended.\n')
             suspended_w = w
             conn.ok()
             return
             
         buf = conn.read(n)  # object sizes in bup are reasonably small
-        #log('read %d bytes\n' % n)
+        #debug2('read %d bytes\n' % n)
         if len(buf) < n:
             w.abort()
             raise Exception('object read: expected %d bytes, got %d\n'
@@ -90,7 +90,7 @@ def receive_objects(conn, junk):
             # efficient.
             w.objcache.refresh(skip_midx = True)
             oldpack = w.objcache.exists(sha)
-            log('new suggestion: %r\n' % oldpack)
+            debug2('new suggestion: %r\n' % oldpack)
             assert(oldpack)
             assert(oldpack != True)
             assert(not oldpack.endswith('.midx'))
@@ -99,7 +99,7 @@ def receive_objects(conn, junk):
             assert(oldpack.endswith('.idx'))
             (dir,name) = os.path.split(oldpack)
             if not (name in suggested):
-                log("bup server: suggesting index %s\n" % name)
+                debug1("bup server: suggesting index %s\n" % name)
                 conn.write('index %s\n' % name)
                 suggested[name] = 1
         else:
@@ -150,7 +150,7 @@ o = options.Options('bup server', optspec)
 if extra:
     o.fatal('no arguments expected')
 
-log('bup server: reading from stdin.\n')
+debug2('bup server: reading from stdin.\n')
 
 commands = {
     'init-dir': init_dir,
@@ -171,7 +171,7 @@ for _line in lr:
     line = _line.strip()
     if not line:
         continue
-    log('bup server: command: %r\n' % line)
+    debug1('bup server: command: %r\n' % line)
     words = line.split(' ', 1)
     cmd = words[0]
     rest = len(words)>1 and words[1] or ''
@@ -184,4 +184,4 @@ for _line in lr:
         else:
             raise Exception('unknown server command: %r\n' % line)
 
-log('bup server: done\n')
+debug1('bup server: done\n')
index 8c6ef596b72304196d89f61a5df52e8f8ae1c365..d1fdbbe155851563f026fc03d83e990b20cf1f26 100644 (file)
@@ -134,11 +134,11 @@ class Client:
         mkdirp(self.cachedir)
         for f in os.listdir(self.cachedir):
             if f.endswith('.idx') and not f in all:
-                log('pruning old index: %r\n' % f)
+                debug1('client: pruning old index: %r\n' % f)
                 os.unlink(os.path.join(self.cachedir, f))
 
     def sync_index(self, name):
-        #log('requesting %r\n' % name)
+        #debug1('requesting %r\n' % name)
         self.check_busy()
         mkdirp(self.cachedir)
         self.conn.write('send-index %s\n' % name)
@@ -147,12 +147,12 @@ class Client:
         fn = os.path.join(self.cachedir, name)
         f = open(fn + '.tmp', 'w')
         count = 0
-        progress('Receiving index: %d/%d\r' % (count, n))
+        progress('Receiving index from server: %d/%d\r' % (count, n))
         for b in chunkyreader(self.conn, n):
             f.write(b)
             count += len(b)
-            progress('Receiving index: %d/%d\r' % (count, n))
-        progress('Receiving index: %d/%d, done.\n' % (count, n))
+            progress('Receiving index from server: %d/%d\r' % (count, n))
+        progress('Receiving index from server: %d/%d, done.\n' % (count, n))
         self.check_ok()
         f.close()
         os.rename(fn + '.tmp', fn)
@@ -166,7 +166,7 @@ class Client:
         return git.PackIdxList(self.cachedir)
 
     def _suggest_pack(self, indexname):
-        log('received index suggestion: %s\n' % indexname)
+        debug1('client: received index suggestion: %s\n' % indexname)
         ob = self._busy
         if ob:
             assert(ob == 'receive-objects')
index df1678afe56bdbe850958bf45ce51a05a7e0527f..af54a60d98c6a9340b69a58dcd502cf873bd1b97 100644 (file)
@@ -383,8 +383,8 @@ class PackIdxList:
                             any += 1
                             break
                     if not any and not ix.force_keep:
-                        log('midx: removing redundant: %s\n'
-                            % os.path.basename(ix.name))
+                        debug1('midx: removing redundant: %s\n'
+                               % os.path.basename(ix.name))
                         unlink(ix.name)
             for f in os.listdir(self.dir):
                 full = os.path.join(self.dir, f)
@@ -392,7 +392,7 @@ class PackIdxList:
                     ix = PackIdx(full)
                     d[full] = ix
             self.packs = list(set(d.values()))
-        log('PackIdxList: using %d index%s.\n'
+        debug1('PackIdxList: using %d index%s.\n'
             % (len(self.packs), len(self.packs)!=1 and 'es' or ''))
 
     def add(self, hash):
@@ -429,7 +429,7 @@ def open_idx(filename):
         raise GitError('idx filenames must end with .idx or .midx')
 
 
-def idxmerge(idxlist):
+def idxmerge(idxlist, final_progress=True):
     """Generate a list of all the objects reachable in a PackIdxList."""
     total = sum(len(i) for i in idxlist)
     iters = (iter(i) for i in idxlist)
@@ -451,7 +451,8 @@ def idxmerge(idxlist):
             heapq.heapreplace(heap, (e, it))
         else:
             heapq.heappop(heap)
-    log('Reading indexes: %.2f%% (%d/%d), done.\n' % (100, total, total))
+    if final_progress:
+        log('Reading indexes: %.2f%% (%d/%d), done.\n' % (100, total, total))
 
 
 class PackWriter:
index daaa0c4402aa605f55b304e4f84816983e6e382a..34067006f099b07695da943087cfc327d4702c2a 100644 (file)
@@ -3,6 +3,17 @@ import sys, os, pwd, subprocess, errno, socket, select, mmap, stat, re
 from bup import _version
 
 
+def atoi(s):
+    """Convert the string 's' to an integer. Return 0 if s is not a number."""
+    try:
+        return int(s or '0')
+    except ValueError:
+        return 0
+
+
+buglvl = atoi(os.environ.get('BUP_DEBUG', 0))
+
+
 # Write (blockingly) to sockets that may or may not be in blocking mode.
 # We need this because our stderr is sometimes eaten by subprocesses
 # (probably ssh) that sometimes make it nonblocking, if only temporarily,
@@ -26,6 +37,16 @@ def log(s):
     _hard_write(sys.stderr.fileno(), s)
 
 
+def debug1(s):
+    if buglvl >= 1:
+        log(s)
+
+
+def debug2(s):
+    if buglvl >= 2:
+        log(s)
+
+
 def mkdirp(d, mode=None):
     """Recursively create directories on path 'd'.
 
@@ -305,14 +326,6 @@ def count(l):
     return reduce(lambda x,y: x+1, l)
 
 
-def atoi(s):
-    """Convert the string 's' to an integer. Return 0 if s is not a number."""
-    try:
-        return int(s or '0')
-    except ValueError:
-        return 0
-
-
 saved_errors = []
 def add_error(e):
     """Append an error message to the list of saved errors.
index 99053ffdd523380070aada6fc0dee45847aaafb8..52ee03584c53171f9fa3407958d1b55fed71b2c1 100644 (file)
@@ -28,10 +28,11 @@ def connect(rhost, subcmd):
         # allow shellquoting.  So we end up having to double-shellquote
         # stuff here.
         escapedir = re.sub(r'([^\w/])', r'\\\\\\\1', nicedir)
+        buglvl = helpers.atoi(os.environ.get('BUP_DEBUG'))
         force_tty = helpers.atoi(os.environ.get('BUP_FORCE_TTY'))
         cmd = r"""
-                   sh -c PATH=%s:'$PATH BUP_FORCE_TTY=%s bup %s'
-               """ % (escapedir, force_tty, subcmd)
+                   sh -c PATH=%s:'$PATH BUP_DEBUG=%s BUP_FORCE_TTY=%s bup %s'
+               """ % (escapedir, buglvl, force_tty, subcmd)
         argv = ['ssh', rhost, '--', cmd.strip()]
         #helpers.log('argv is: %r\n' % argv)
     def setup():
index 1e61745ee8da6048afdd2241e4caa070665c8452..479a90534f863b51dfab88065b40893d1e6be98e 100644 (file)
@@ -120,7 +120,7 @@ class _ChunkReader(object):
                 self.blob = self.blob[want:]
             if not self.it:
                 break
-        log('next(%d) returned %d\n' % (size, len(out)))
+        debug2('next(%d) returned %d\n' % (size, len(out)))
         self.ofs += len(out)
         return out
 
@@ -220,7 +220,7 @@ class Node(object):
             return self
 
     def _lresolve(self, parts):
-        #log('_lresolve %r in %r\n' % (parts, self.name))
+        #debug2('_lresolve %r in %r\n' % (parts, self.name))
         if not parts:
             return self
         (first, rest) = (parts[0], parts[1:])
@@ -253,7 +253,7 @@ class Node(object):
         parts = re.split(r'/+', path or '.')
         if not parts[-1]:
             parts[-1] = '.'
-        #log('parts: %r %r\n' % (path, parts))
+        #debug2('parts: %r %r\n' % (path, parts))
         return start._lresolve(parts)
 
     def resolve(self, path = ''):
@@ -310,12 +310,12 @@ class File(Node):
     def size(self):
         """Get this file's size."""
         if self._cached_size == None:
-            log('<<<<File.size() is calculating...\n')
+            debug1('<<<<File.size() is calculating...\n')
             if self.bupmode == git.BUP_CHUNKED:
                 self._cached_size = _total_size(self.hash)
             else:
                 self._cached_size = _chunk_len(self.hash)
-            log('<<<<File.size() done.\n')
+            debug1('<<<<File.size() done.\n')
         return self._cached_size
 
 
diff --git a/main.py b/main.py
index c43978c7374a76233f8d105fa2aebfe3afa1641c..7a7e426ff8800ce5eba951beba9474d8191548ea 100755 (executable)
--- a/main.py
+++ b/main.py
@@ -23,12 +23,13 @@ os.environ['PYTHONPATH'] = libpath + ':' + os.environ.get('PYTHONPATH', '')
 os.environ['BUP_MAIN_EXE'] = os.path.abspath(exe)
 os.environ['BUP_RESOURCE_PATH'] = resourcepath
 
+from bup import helpers
 from bup.helpers import *
 
 
 def usage():
-    log('Usage: bup [-?|--help] [-d=BUP_DIR|--bup-dir=BUP_DIR] COMMAND [ARGS]'
-        + '\n\n')
+    log('Usage: bup [-?|--help] [-d BUP_DIR] [--debug] '
+        '<command> [options...]\n\n')
     common = dict(
         ftp = 'Browse backup sets using an ftp-like client',
         fsck = 'Check backup sets for damage and add redundancy information',
@@ -65,8 +66,8 @@ if len(argv) < 2:
 
 # Handle global options.
 try:
-    global_args, subcmd = getopt.getopt(argv[1:], '?Vd:',
-                                        ['help', 'version', 'bup-dir='])
+    global_args, subcmd = getopt.getopt(argv[1:], '?VDd:',
+                                    ['help', 'version', 'debug', 'bup-dir='])
 except getopt.GetoptError, ex:
     log('error: ' + ex.msg + '\n')
     usage()
@@ -75,11 +76,14 @@ help_requested = None
 dest_dir = None
 
 for opt in global_args:
-    if opt[0] == '-?' or opt[0] == '--help':
+    if opt[0] in ['-?', '--help']:
         help_requested = True
-    if opt[0] == '-V' or opt[0] == '--version':
+    elif opt[0] in ['-V', '--version']:
         subcmd = ['version']
-    elif opt[0] == '-d' or opt[0] == '--bup-dir':
+    elif opt[0] in ['-D', '--debug']:
+        helpers.buglvl += 1
+        os.environ['BUP_DEBUG'] = str(helpers.buglvl)
+    elif opt[0] in ['-d', '--bup-dir']:
         dest_dir = opt[1]
     else:
         log('error: unexpected option "%s"\n' % opt[0])