[Zodb-checkins] CVS: StandaloneZODB/Tools - timeiter.py:1.1.2.2

Barry Warsaw barry@wooz.org
Wed, 9 Jan 2002 13:21:41 -0500


Update of /cvs-repository/StandaloneZODB/Tools
In directory cvs.zope.org:/tmp/cvs-serv18940

Modified Files:
      Tag: Standby-branch
	timeiter.py 
Log Message:
Get rid of the log file which was only used for the traceback printing
on KeyError.   We've gotten rid of the KeyError catch anyway, since
that was just needed for some bogus data long since cleared.

Use multiple -v flags instead of a -q flag for setting the verbosity
level.

Added a -D and a -S flag for specifying the storage name, defaulting
to FileStorage.  Also try to open the source read_only=1 and retrying
with no argument if that fails because the storage doesn't support it.



=== StandaloneZODB/Tools/timeiter.py 1.1.2.1 => 1.1.2.2 ===
 
-"""Time transaction commits and normalize vs. pickle size and #objects.
+"""A script to gather statistics while doing a storage migration.
+
+This is very similar to a standard storage's copyTransactionsFrom() method,
+except that it's geared to run as a script, and it collects useful pieces of
+information as it's working.  This script can be used to stress test a storage
+since it blasts transactions at it as fast as possible.  You can get a good
+sense of the performance of a storage by running this script.
+
+
 
 Actually just counts the size of pickles in the transaction via the iterator
 protocol, so storage overheads aren't counted.
 
 Usage: %(PROGRAM)s [options]
 Options:
-    -h/--help
-        Print this message and exit.
-
     -s filename
     --source=filename
         Use database in filename as the source.
@@ -43,8 +48,11 @@
     -p/--profile
         Turn on specialized profiling.
 
-    -q/--quiet
-        Be quite.
+    -v/--verbose
+        Turns on verbose output.  Multiple -v options increase the verbosity.
+
+    -h/--help
+        Print this message and exit.
 """
 
 import sys
@@ -56,6 +64,7 @@
 import traceback
 import marshal
 
+import ZODB
 from ZODB import utils
 from ZODB.TimeStamp import TimeStamp
 
@@ -74,9 +83,9 @@
 
 def main():
     try:
-        opts, args = getopt.getopt(sys.argv[1:], 'hs:d:qo:l:pm:k:D:S:',
-                                   ['help', 'source=', 'dest=', 'quiet',
-                                    'output=', 'logfile=', 'profile',
+        opts, args = getopt.getopt(sys.argv[1:], 'hvs:d:o:pm:k:D:S:',
+                                   ['help', 'verbose', 'source=', 'dest=',
+                                    'output=', 'profile',
                                     'max=', 'skip=', 'dtype=', 'stype='])
     except getopt.error, msg:
         usage(1, msg)
@@ -86,9 +95,8 @@
         dest = None
         stype = 'ZODB.FileStorage.FileStorage'
         dtype = 'ZODB.FileStorage.FileStorage'
-        verbose = 1
+        verbose = 0
         outfile = None
-        logfile = None
         profilep = 0
         maxtxn = -1
         skiptxn = -1
@@ -98,6 +106,8 @@
     for opt, arg in opts:
         if opt in ('-h', '--help'):
             usage(0)
+        elif opt in ('-v', '--verbose'):
+            options.verbose += 1
         elif opt in ('-s', '--source'):
             options.source = arg
         elif opt in ('-d', '--dest'):
@@ -106,12 +116,8 @@
             options.stype = arg
         elif opt in ('-D', '--dtype'):
             options.dtype = arg
-        elif opt in ('-q', '--quiet'):
-            options.verbose = 0
         elif opt in ('-o', '--output'):
             options.outfile = arg
-        elif opt in ('-l', '--logfile'):
-            options.logfile = arg
         elif opt in ('-p', '--profile'):
             options.profilep = 1
         elif opt in ('-m', '--max'):
@@ -133,26 +139,21 @@
         options.outfp = open(options.outfile, 'w')
         options.outclosep = 1
 
-    # Open the logfile
-    if options.logfile is None:
-        options.logfp = sys.stdout
-        options.logclosep = 0
-    else:
-        options.logfp = open(options.logfile, 'w')
-        options.logclosep = 1
-
-    # Print a comment, this is a hack
-    print >> options.outfp, '# FS->BDB 3.3.11'
-    print >> options.outfp, '#', time.ctime()
-
     # Import the storage classes
-    __import__(options.stype)
-    Source = sys.modules[options.stype]
+    parts = options.stype.split('.')
+    modname = '.'.join(parts[:-1])
+    classname = parts[-1]
+    __import__(modname)
+    Source = getattr(sys.modules[modname], classname)
+
+    parts = options.dtype.split('.')
+    modname = '.'.join(parts[:-1])
+    classname = parts[-1]
+    __import__(modname)
+    Dest = getattr(sys.modules[modname], classname)
 
-    __import__(options.dtype)
-    Dest = sys.modules[options.dtype]
-
-    print >> sys.stderr, 'Opening source %s...' % Source.__class__.__name__
+    if options.verbose > 0:
+        print 'Opening source %s on %s...' % (Source.__name__, options.source)
     t0 = time.time()
     # Try to open this storage read-only, but fall back to normal open if
     # that fails
@@ -161,33 +162,35 @@
     except TypeError:
         srcdb = Source(options.source)
     t1 = time.time()
-    print >> sys.stderr, 'Opening source done in %s seconds' % (t1-t0)
+    if options.verbose > 0:
+        print 'Opening source done in %s seconds' % (t1-t0)
+    #srcdb._save_index()    
 
-    print >> sys.stderr, 'Opening destination %s...' % Dest.__class__.__name__
+    if options.verbose > 0:
+        print 'Opening dest %s on %s...' % (Dest.__name__, options.source)
     t0 = time.time()
     dstdb = Dest(options.dest)
     t1 = time.time()
-    print >> sys.stderr, 'Opening destination done in  %s seconds' % (t1-t0)
+    if options.verbose > 0:
+        print 'Opening destination done in  %s seconds' % (t1-t0)
 
     try:
         t0 = time.time()
         doit(srcdb, dstdb, options)
         t1 = time.time()
-        print 'Total time:', t1-t0
+        if options.verbose > 0:
+            print 'Total time:', t1-t0
     finally:
         # Done
         srcdb.close()
         dstdb.close()
         if options.outclosep:
             options.outfp.close()
-        if options.logclosep:
-            options.logfp.close()
 
 
 
 def doit(srcdb, dstdb, options):
     outfp = options.outfp
-    logfp = options.logfp
     profilep = options.profilep
     verbose = options.verbose
     # some global information
@@ -214,16 +217,18 @@
             t = TimeStamp(tid)
             if t <= ts:
                 if ok:
-                    print 'Time stamps are out of order %s, %s' % (ts, t)
+                    print >> sys.stderr, \
+                          'Time stamps are out of order %s, %s' % (ts, t)
                     ok = 0
                     ts = t.laterThan(ts)
                     tid = `ts`
                 else:
                     ts = t
                     if not ok:
-                        print 'Time stamps are back in order %s' % t
+                        print >> sys.stderr, \
+                              'Time stamps are back in order %s' % t
                         ok = 1
-        if verbose:
+        if verbose > 1:
             print ts
 
         prof = None
@@ -234,34 +239,31 @@
         t0 = time.time()
         dstdb.tpc_begin(txn, tid, txn.status)
         t1 = time.time()
-        try:
-            for r in txn:
-                oid = r.oid
-                objects += 1
-		thissize = len(r.data)
-                size += thissize
-		if thissize > largest_pickle:
-		    largest_pickle = thissize
-                if verbose:
-                    if not r.version:
-                        vstr = 'norev'
-                    else:
-                        vstr = r.version
-                    print utils.U64(oid), vstr, len(r.data)
-                oldrevid = prevrevids.get(oid, ZERO)
-                newrevid = dstdb.store(oid, oldrevid, r.data, r.version, txn)
-                prevrevids[oid] = newrevid
-            t2 = time.time()
-            dstdb.tpc_vote(txn)
-            t3 = time.time()
-            # Profile every 100 transactions
-            if prof:
-                prof.runcall(dstdb.tpc_finish, txn)
-            else:
-                dstdb.tpc_finish(txn)
-            t4 = time.time()
-        except KeyError, e:
-            traceback.print_exc(file=logfp)
+        for r in txn:
+            oid = r.oid
+            objects += 1
+            thissize = len(r.data)
+            size += thissize
+            if thissize > largest_pickle:
+                largest_pickle = thissize
+            if verbose > 1:
+                if not r.version:
+                    vstr = 'norev'
+                else:
+                    vstr = r.version
+                print utils.U64(oid), vstr, len(r.data)
+            oldrevid = prevrevids.get(oid, ZERO)
+            newrevid = dstdb.store(oid, oldrevid, r.data, r.version, txn)
+            prevrevids[oid] = newrevid
+        t2 = time.time()
+        dstdb.tpc_vote(txn)
+        t3 = time.time()
+        # Profile every 100 transactions
+        if prof:
+            prof.runcall(dstdb.tpc_finish, txn)
+        else:
+            dstdb.tpc_finish(txn)
+        t4 = time.time()
 
         # record the results
 	if objects > largest_txn_in_objects: