588 sorted by descending total execution time |
588 sorted by descending total execution time |
589 |
589 |
590 chances are the lines at the top are the ones that will bring the higher |
590 chances are the lines at the top are the ones that will bring the higher |
591 benefit after optimisation. Start there. |
591 benefit after optimisation. Start there. |
592 """ |
592 """ |
593 arguments = '< rql.log' |
593 arguments = 'rql.log' |
594 name = 'exlog' |
594 name = 'exlog' |
595 options = ( |
595 options = ( |
596 ) |
596 ) |
597 |
597 |
598 def run(self, args): |
598 def run(self, args): |
599 if args: |
|
600 raise BadCommandUsage("no argument expected") |
|
601 import re |
599 import re |
602 requests = {} |
600 requests = {} |
603 for lineno, line in enumerate(sys.stdin): |
601 for filepath in args: |
604 if not ' WHERE ' in line: |
|
605 continue |
|
606 #sys.stderr.write( line ) |
|
607 try: |
602 try: |
608 rql, time = line.split('--') |
603 stream = file(filepath) |
609 rql = re.sub("(\'\w+': \d*)", '', rql) |
604 except OSError, ex: |
610 if '{' in rql: |
605 raise BadCommandUsage("can't open rql log file %s: %s" |
611 rql = rql[:rql.index('{')] |
606 % (filepath, ex)) |
612 req = requests.setdefault(rql, []) |
607 for lineno, line in enumerate(file): |
613 time.strip() |
608 if not ' WHERE ' in line: |
614 chunks = time.split() |
609 continue |
615 clocktime = float(chunks[0][1:]) |
610 try: |
616 cputime = float(chunks[-3]) |
611 rql, time = line.split('--') |
617 req.append( (clocktime, cputime) ) |
612 rql = re.sub("(\'\w+': \d*)", '', rql) |
618 except Exception, exc: |
613 if '{' in rql: |
619 sys.stderr.write('Line %s: %s (%s)\n' % (lineno, exc, line)) |
614 rql = rql[:rql.index('{')] |
620 |
615 req = requests.setdefault(rql, []) |
|
616 time.strip() |
|
617 chunks = time.split() |
|
618 clocktime = float(chunks[0][1:]) |
|
619 cputime = float(chunks[-3]) |
|
620 req.append( (clocktime, cputime) ) |
|
621 except Exception, exc: |
|
622 sys.stderr.write('Line %s: %s (%s)\n' % (lineno, exc, line)) |
621 stat = [] |
623 stat = [] |
622 for rql, times in requests.items(): |
624 for rql, times in requests.iteritems(): |
623 stat.append( (sum(time[0] for time in times), |
625 stat.append( (sum(time[0] for time in times), |
624 sum(time[1] for time in times), |
626 sum(time[1] for time in times), |
625 len(times), rql) ) |
627 len(times), rql) ) |
626 |
|
627 stat.sort() |
628 stat.sort() |
628 stat.reverse() |
629 stat.reverse() |
629 |
630 total_time = sum(clocktime for clocktime, cputime, occ, rql in stat) * 0.01 |
630 total_time = sum(clocktime for clocktime, cputime, occ, rql in stat)*0.01 |
|
631 print 'Percentage;Cumulative Time (clock);Cumulative Time (CPU);Occurences;Query' |
631 print 'Percentage;Cumulative Time (clock);Cumulative Time (CPU);Occurences;Query' |
632 for clocktime, cputime, occ, rql in stat: |
632 for clocktime, cputime, occ, rql in stat: |
633 print '%.2f;%.2f;%.2f;%s;%s' % (clocktime/total_time, clocktime, cputime, occ, rql) |
633 print '%.2f;%.2f;%.2f;%s;%s' % (clocktime/total_time, clocktime, |
|
634 cputime, occ, rql) |
634 |
635 |
635 |
636 |
636 class GenerateSchema(Command): |
637 class GenerateSchema(Command): |
637 """Generate schema image for the given cube""" |
638 """Generate schema image for the given cube""" |
638 name = "schema" |
639 name = "schema" |