[rhmessaging-commits] rhmessaging commits: r2267 - store/trunk/cpp/tests/jrnl/jtt.

Author: kpvdr Date: 2008-08-08 06:58:59 -0400 (Fri, 08 Aug 2008) New Revision: 2267 Modified: store/trunk/cpp/tests/jrnl/jtt/jfile_chk.py Log: Minor bugfix to Python journal file analysis program jfile_chk.py; also added -a/--analysis flags which perform transactional analysis of journal content. Modified: store/trunk/cpp/tests/jrnl/jtt/jfile_chk.py =================================================================== --- store/trunk/cpp/tests/jrnl/jtt/jfile_chk.py 2008-08-07 19:49:37 UTC (rev 2266) +++ store/trunk/cpp/tests/jrnl/jtt/jfile_chk.py 2008-08-08 10:58:59 UTC (rev 2267) @@ -210,7 +210,7 @@ f.read(rem_in_blk(f, dblk_size)) def check(self): - if self.empty() or self.magic[:3] != 'RHM' or self.magic[-1] not in ['a', 'c', 'd', 'e', 'f', 'x']: + if self.empty() or self.magic[:3] != 'RHM' or self.magic[3] not in ['a', 'c', 'd', 'e', 'f', 'x']: return True if self.ver != hdr_ver and self.magic[-1] != 'x': raise Exception('%s: Invalid header version: found %d, expected %d.' % (self, self.ver, hdr_ver)) @@ -420,6 +420,7 @@ self.bfn = None self.csvfn = None self.jdir = None + self.aflag = False self.hflag = False self.qflag = False self.tnum = None @@ -434,9 +435,11 @@ self.file_start = 0 self.file_num = 0 self.fro = 0x200 - self.enqueued = {} + self.emap = {} + self.tmap = {} self.rec_cnt = 0 self.msg_cnt = 0 + self.txn_msg_cnt = 0 self.fhdr = None self.f = None self.first_rec = False @@ -471,75 +474,118 @@ stop = True; else: self.rec_cnt += 1 - if self.first_rec: - if self.fhdr.fro != hdr.foffs: - raise Exception('File header first record offset mismatch: fro=0x%08x; rec_offs=0x%08x' % (self.fhdr.fro, hdr.foffs)) - else: - if not self.qflag: print ' * fro ok: 0x%08x' % self.fhdr.fro - self.first_rec = False - if isinstance(hdr, EnqRec) and not stop: - while not hdr.complete(): - stop = self.advance_file() - if stop: - break - hdr.load(self.f) - if self.extern != None: - if hdr.extern: - if hdr.data != None: - raise Exception('Message data found on external record') + if self.first_rec: + if self.fhdr.fro != hdr.foffs: + raise Exception('File header first record offset mismatch: fro=0x%08x; rec_offs=0x%08x' % (self.fhdr.fro, hdr.foffs)) else: + if not self.qflag: print ' * fro ok: 0x%08x' % self.fhdr.fro + self.first_rec = False + if isinstance(hdr, EnqRec) and not stop: + while not hdr.complete(): + stop = self.advance_file() + if stop: + break + hdr.load(self.f) + if self.extern != None: + if hdr.extern: + if hdr.data != None: + raise Exception('Message data found on external record') + else: + if self.msg_len > 0 and len(hdr.data) != self.msg_len: + raise Exception('Message length (%d) incorrect; expected %d' % (len(hdr.data), self.msg_len)) + else: if self.msg_len > 0 and len(hdr.data) != self.msg_len: raise Exception('Message length (%d) incorrect; expected %d' % (len(hdr.data), self.msg_len)) - else: - if self.msg_len > 0 and len(hdr.data) != self.msg_len: - raise Exception('Message length (%d) incorrect; expected %d' % (len(hdr.data), self.msg_len)) - if self.xid_len > 0 and len(hdr.xid) != self.xid_len: - print ' ERROR: XID length (%d) incorrect; expected %d' % (len(hdr.xid), self.xid_len) - sys.exit(1) - #raise Exception('XID length (%d) incorrect; expected %d' % (len(hdr.xid), self.xid_len)) - if self.transient != None: - if self.transient: - if not hdr.transient: - raise Exception('Expected transient record, found persistent') + if self.xid_len > 0 and len(hdr.xid) != self.xid_len: + print ' ERROR: XID length (%d) incorrect; expected %d' % (len(hdr.xid), self.xid_len) + sys.exit(1) + #raise Exception('XID length (%d) incorrect; expected %d' % (len(hdr.xid), self.xid_len)) + if self.transient != None: + if self.transient: + if not hdr.transient: + raise Exception('Expected transient record, found persistent') + else: + if hdr.transient: + raise Exception('Expected persistent record, found transient') + stop = not self.check_owi(hdr) + if stop: + warn = ' (WARNING: OWI mismatch - could be overwrite boundary.)' else: - if hdr.transient: - raise Exception('Expected persistent record, found transient') - stop = not self.check_rid(hdr) - if stop: - warn = ' (WARNING: rid out of order, rid = %d; last rid = %d - could be overwrite boundary.)' % (hdr.rid, self.last_rid) - else: - self.msg_cnt += 1 - if self.auto_deq: - self.enqueued[hdr.rid] = hdr - elif isinstance(hdr, DeqHdr) and not stop: - while not hdr.complete(): - stop = self.advance_file() + self.msg_cnt += 1 + if self.aflag or self.auto_deq: + if hdr.xid == None: + self.emap[hdr.rid] = (self.fhdr.fid, hdr, False) + else: + self.txn_msg_cnt += 1 + if hdr.xid in self.tmap: + self.tmap[hdr.xid].append((self.fhdr.fid, hdr)) #Append tuple to existing list + else: + self.tmap[hdr.xid] = [(self.fhdr.fid, hdr)] # Create new list + elif isinstance(hdr, DeqHdr) and not stop: + while not hdr.complete(): + stop = self.advance_file() + if stop: + break + hdr.load(self.f) + stop = not self.check_owi(hdr) if stop: - break - hdr.load(self.f) - if self.auto_deq: - if hdr.deq_rid in self.enqueued: - del self.enqueued[hdr.deq_rid] + warn = ' (WARNING: OWI mismatch - could be overwrite boundary.)' else: - warn = ' (WARNING: dequeue rid %d not found in enqueued records)' % hdr.deq_rid - stop = not self.check_rid(hdr) - if stop: - warn = ' (WARNING: rid out of order, rid = %d; last rid = %d - could be overwrite boundary.)' % (hdr.rid, self.last_rid) - elif self.auto_deq != None: - if not self.auto_deq: - warn = ' WARNING: Dequeue record rid=%d found in non-dequeue test - ignoring.' % hdr.rid - elif isinstance(hdr, TxnHdr) and not stop: - while not hdr.complete(): - stop = self.advance_file() + if self.auto_deq != None: + if not self.auto_deq: + warn = ' WARNING: Dequeue record rid=%d found in non-dequeue test - ignoring.' % hdr.rid + if self.aflag or self.auto_deq: + if hdr.xid == None: + if hdr.deq_rid in self.emap: + if self.emap[hdr.deq_rid][2]: + warn = ' (WARNING: dequeue rid %d dequeues locked enqueue records %d)' % (hdr.rid, hdr.deq_rid) + del self.emap[hdr.deq_rid] + else: + warn = ' (WARNING: rid being dequeued %d not found in enqueued records)' % hdr.deq_rid + else: + if hdr.deq_rid in self.emap: + t = self.emap[hdr.deq_rid] + self.emap[hdr.deq_rid] = (t[0], t[1], True) # Lock enq record + if hdr.xid in self.tmap: + self.tmap[hdr.xid].append((self.fhdr.fid, hdr)) #Append to existing list + else: + self.tmap[hdr.xid] = [(self.fhdr.fid, hdr)] # Create new list + elif isinstance(hdr, TxnHdr) and not stop: + while not hdr.complete(): + stop = self.advance_file() + if stop: + break + hdr.load(self.f) + stop = not self.check_owi(hdr) if stop: - break - hdr.load(self.f) - stop = not self.check_rid(hdr) - if stop: - warn = ' (WARNING: rid out of order, rid = %d; last rid = %d - could be overwrite boundary.)' % (hdr.rid, self.last_rid) - if not self.qflag: print ' > %s%s' % (hdr, warn) - if not stop: - stop = (self.last_file and hdr.check()) or hdr.empty() or self.fhdr.empty() + warn = ' (WARNING: OWI mismatch - could be overwrite boundary.)' + else: + if hdr.xid in self.tmap: + mismatched_rids = [] + if hdr.magic[-1] == 'c': # commit + for rec in self.tmap[hdr.xid]: + if isinstance(rec[1], EnqRec): + self.emap[rec[1].rid] = (rec[0], rec[1], False) # Transfer enq to emap + elif isinstance(rec[1], DeqHdr): + if rec[1].deq_rid in self.emap: + del self.emap[rec[1].deq_rid] # Delete from emap + else: + mismatched_rids.append('0x%x' % rec[1].deq_rid) + else: + raise Exception('Unknown header found in txn map: %s' % rec[1]) + elif hdr.magic[-1] == 'a': # abort + for rec in self.tmap[hdr.xid]: + if isinstance(rec[1], DeqHdr): + if self.emap[rec[1].deq_rid] != None: + self.emap[rec[1].deq_rid][2] = False # Unlock enq record + del self.tmap[hdr.xid] + if len(mismatched_rids) > 0: + warn = ' (WARNING: transactional dequeues not found in enqueue map; rids=%s)' % mismatched_rids + else: + warn = ' (WARNING: xid %s not found in transaction map)' % hdr.xid + if not self.qflag: print ' > %s%s' % (hdr, warn) + if not stop: + stop = (self.last_file and hdr.check()) or hdr.empty() or self.fhdr.empty() def analyze_files(self): fname = '' @@ -609,6 +655,9 @@ self.file_num = 0; return self.file_num + def check_owi(self, hdr): + return self.fhdr.owi() == hdr.owi() + def check_rid(self, hdr): if self.last_rid != -1 and hdr.rid <= self.last_rid: return False @@ -690,7 +739,7 @@ def proc_args(self, argv): try: - opts, args = getopt.getopt(sys.argv[1:], "b:c:d:hqt:", ["base-filename=", "csv-filename=", "dir=", "help", "quiet", "test-num="]) + opts, args = getopt.getopt(sys.argv[1:], "ab:c:d:hqt:", ["analyse", "base-filename=", "csv-filename=", "dir=", "help", "quiet", "test-num="]) except getopt.GetoptError: self.usage() sys.exit(2) @@ -698,6 +747,8 @@ if o in ("-h", "--help"): self.usage() sys.exit() + if o in ("-a", "--analyze"): + self.aflag = True if o in ("-b", "--base-filename"): self.bfn = a if o in ("-c", "--csv-filename"): @@ -723,6 +774,7 @@ def usage(self): print 'Usage: %s opts' % sys.argv[0] print ' where opts are in either short or long format (*=req\'d):' + print ' -a --analyze Analyze enqueue/dequeue records' print ' -b --base-filename [string] * Base filename for journal files' print ' -c --csv-filename [string] CSV filename containing test parameters' print ' -d --dir [string] * Journal directory containing journal files' @@ -732,13 +784,31 @@ def report(self): if not self.qflag: + print + print ' === REPORT ====' if self.num_msgs > 0 and self.msg_cnt != self.num_msgs: print 'WARNING: Found %d messages; %d expected.' % (self.msg_cnt, self.num_msgs) - if len(self.enqueued) > 0: - print 'Remaining enqueued records: ', len(self.enqueued) - for h in self.enqueued: - print self.enqueued[h] - print 'WARNING: Enqueue-Dequeue mismatch, %d enqueued records remain.' % len(self.enqueued) + if len(self.emap) > 0: + print + print 'Remaining enqueued records: ' + for h in self.emap: + if self.emap[h][2] == True: # locked + locked = ' (locked)' + else: + locked = '' + print " fid=%d %s%s" % (self.emap[h][0], self.emap[h][1], locked) + print 'WARNING: Enqueue-Dequeue mismatch, %d enqueued records remain.' % len(self.emap) + if len(self.tmap) > 0: + txn_rec_cnt = 0 + print + print 'Remaining transactions: ' + for t in self.tmap: + print "xid=%s:" % t + for r in self.tmap[t]: + print " fid=%d %s" % (r[0], r[1]) + print " Total: %d records for xid %s" % (len(self.tmap[t]), t) + txn_rec_cnt += len(self.tmap[t]) + print 'WARNING: Incomplete transactions, %d xids remain containing %d records.' % (len(self.tmap), txn_rec_cnt) print '%d enqueues, %d journal records processed.' % (self.msg_cnt, self.rec_cnt)