558 sorted by descending total execution time |
558 sorted by descending total execution time |
559 |
559 |
560 chances are the lines at the top are the ones that will bring the higher |
560 chances are the lines at the top are the ones that will bring the higher |
561 benefit after optimisation. Start there. |
561 benefit after optimisation. Start there. |
562 """ |
562 """ |
563 arguments = '< rql.log' |
563 arguments = 'rql.log' |
564 name = 'exlog' |
564 name = 'exlog' |
565 options = ( |
565 options = ( |
566 ) |
566 ) |
567 |
567 |
568 def run(self, args): |
568 def run(self, args): |
569 if args: |
|
570 raise BadCommandUsage("no argument expected") |
|
571 import re |
569 import re |
572 requests = {} |
570 requests = {} |
573 for lineno, line in enumerate(sys.stdin): |
571 for filepath in args: |
574 if not ' WHERE ' in line: |
|
575 continue |
|
576 #sys.stderr.write( line ) |
|
577 try: |
572 try: |
578 rql, time = line.split('--') |
573 stream = file(filepath) |
579 rql = re.sub("(\'\w+': \d*)", '', rql) |
574 except OSError, ex: |
580 if '{' in rql: |
575 raise BadCommandUsage("can't open rql log file %s: %s" |
581 rql = rql[:rql.index('{')] |
576 % (filepath, ex)) |
582 req = requests.setdefault(rql, []) |
577 for lineno, line in enumerate(file): |
583 time.strip() |
578 if not ' WHERE ' in line: |
584 chunks = time.split() |
579 continue |
585 clocktime = float(chunks[0][1:]) |
580 try: |
586 cputime = float(chunks[-3]) |
581 rql, time = line.split('--') |
587 req.append( (clocktime, cputime) ) |
582 rql = re.sub("(\'\w+': \d*)", '', rql) |
588 except Exception, exc: |
583 if '{' in rql: |
589 sys.stderr.write('Line %s: %s (%s)\n' % (lineno, exc, line)) |
584 rql = rql[:rql.index('{')] |
590 |
585 req = requests.setdefault(rql, []) |
|
586 time.strip() |
|
587 chunks = time.split() |
|
588 clocktime = float(chunks[0][1:]) |
|
589 cputime = float(chunks[-3]) |
|
590 req.append( (clocktime, cputime) ) |
|
591 except Exception, exc: |
|
592 sys.stderr.write('Line %s: %s (%s)\n' % (lineno, exc, line)) |
591 stat = [] |
593 stat = [] |
592 for rql, times in requests.items(): |
594 for rql, times in requests.iteritems(): |
593 stat.append( (sum(time[0] for time in times), |
595 stat.append( (sum(time[0] for time in times), |
594 sum(time[1] for time in times), |
596 sum(time[1] for time in times), |
595 len(times), rql) ) |
597 len(times), rql) ) |
596 |
|
597 stat.sort() |
598 stat.sort() |
598 stat.reverse() |
599 stat.reverse() |
599 |
600 total_time = sum(clocktime for clocktime, cputime, occ, rql in stat) * 0.01 |
600 total_time = sum(clocktime for clocktime, cputime, occ, rql in stat)*0.01 |
|
601 print 'Percentage;Cumulative Time (clock);Cumulative Time (CPU);Occurences;Query' |
601 print 'Percentage;Cumulative Time (clock);Cumulative Time (CPU);Occurences;Query' |
602 for clocktime, cputime, occ, rql in stat: |
602 for clocktime, cputime, occ, rql in stat: |
603 print '%.2f;%.2f;%.2f;%s;%s' % (clocktime/total_time, clocktime, cputime, occ, rql) |
603 print '%.2f;%.2f;%.2f;%s;%s' % (clocktime/total_time, clocktime, |
|
604 cputime, occ, rql) |
604 |
605 |
605 |
606 |
606 class GenerateSchema(Command): |
607 class GenerateSchema(Command): |
607 """Generate schema image for the given cube""" |
608 """Generate schema image for the given cube""" |
608 name = "schema" |
609 name = "schema" |