Ticket #13361: trac_12883_startuptime.patch

File trac_12883_startuptime.patch, 4.9 KB (added by vbraun, 9 years ago)

Initial patch

  • sage-startuptime.py

    # HG changeset patch
    # User Volker Braun <vbraun@stp.dias.ie>
    # Date 1344792900 14400
    # Node ID e65ef19166908d40aba8e859532d325bacc9d6bf
    # Parent  1dd3cffdc684fd86f93aa51b18672020b79cfb25
    Report startuptime exclusive children instead of inclusive
    
    diff --git a/sage-startuptime.py b/sage-startuptime.py
    a b  
    11#!/usr/bin/env python
    2 ###########################################################
    3 # Based on a script by Andrew Dalke:
     2
     3########################################################################
     4# Originally based on a script by Andrew Dalke:
    45#    http://projects.scipy.org/pipermail/numpy-discussion/2008-July/035415.html
    56#
    6 # From: Andrew Dalke <dalke@dalkescientific.com>
    7 # Date: Sun, Jul 6, 2008 at 10:07 AM
    8 # To: Mike Hansen <mhansen@gmail.com>
    9 # "This work written by Andrew Dalke and released into the public
    10 # domain in 2008.  No copyright protection is asserted."
    11 #   
    12 # Included in Sage by Mike Hansen and William Stein
    13 ###########################################################
     7# 2012: Total rewrite by Volker Braun
     8########################################################################
     9
     10
     11########################################################################
     12#       Copyright (C) 2012 Volker Braun <vbraun.name@gmail.com>
     13#
     14#  Distributed under the terms of the GNU General Public License (GPL)
     15#
     16#                  http://www.gnu.org/licenses/
     17########################################################################
    1418
    1519
    1620import time
    1721
    18 seen = set()
    19 import_order = []
    20 elapsed_times = {}
     22direct_children_time = 0
     23import_counter = 0
     24parent = None
     25index_to_parent = dict()
    2126global_level = 0
    22 parent = None
    23 children = {}
     27all_modules = dict()
    2428
    2529def new_import(name, globals={}, locals={}, fromlist=[], level=-1):
    26      global global_level, parent
    27      if name in seen:
    28          return old_import(name, globals, locals, fromlist)
    29      seen.add(name)
    30      import_order.append((name, global_level, parent))
     30     """"
     31     The new import function
     32
     33     Note that ``name`` is not unique, it can be `sage.foo.bar` or `bar`.
     34     """
     35     global global_level, all_modules, import_counter, parent, direct_children_time
     36     global_level += 1
     37     old_direct_children_time = direct_children_time
     38     direct_children_time = 0
     39     old_parent = parent
     40     parent = this_import_counter = import_counter
     41     import_counter += 1
    3142     t1 = time.time()
    32      old_parent = parent
    33      parent = name
    34      global_level += 1
    3543     module = old_import(name, globals, locals, fromlist, level)
     44     t2 = time.time()
     45     parent = old_parent
     46     elapsed_time = t2-t1
     47     module_time = elapsed_time - direct_children_time
     48     direct_children_time = old_direct_children_time + elapsed_time
    3649     global_level -= 1
    37      parent = old_parent
    38      t2 = time.time()
    39      elapsed_times[name] = t2-t1
     50     index_to_parent[this_import_counter] = module
     51     data = all_modules.get(module, None)
     52     if data is not None:
     53          data['parents'].append(parent)
     54          data['import_names'].add(name)
     55          data['cumulative_time'] += elapsed_time
     56          data['time'] += module_time
     57          return module
     58     data = {
     59          'cumulative_time': elapsed_time,
     60          'time': module_time,
     61          'level': level,
     62          'import_names': set([name]),
     63          'parents': [parent] }
     64     all_modules[module] = data
    4065     return module
    4166
    4267old_import = __builtins__.__import__
    43 
    4468__builtins__.__import__ = new_import
    45 
    4669from sage.all import *
    4770
    48 parents = {}
    49 for name, level, parent in import_order:
    50      parents[name] = parent
     71for data in all_modules.values():
     72     data['parents'] = set( index_to_parent.get(i,None) for i in data['parents'] )
    5173
    52 print "== Tree =="
    53 for name, level,parent in import_order:
    54      try:
    55           print "%s%s: %.3f (%s)" % (" "*level, name, elapsed_times[name], 
    56 parent)
    57      except KeyError:
    58           pass
     74module_by_speed = sorted([ (data['time'], module, data)
     75                           for module,data in all_modules.iteritems() ])
    5976
    60 print "\n"
    61 print "== Slowest (including children) =="
    62 slowest = sorted((t, name) for (name, t) in elapsed_times.items())[-50:]
    63 for elapsed_time, name in slowest[::-1]:
    64      print "%.3f %s (%s)" % (elapsed_time, name, parents[name])
     77print "== Slowest module imports (excluding / including children) =="
     78width = 10
     79fmt_header = '{0:>'+str(width)+   '} {1:>'+str(width)+   '} {2:>'+str(width)+'}  {3}'
     80fmt_number = '{0:>'+str(width)+'.3f} {1:>'+str(width)+'.3f} {2:>'+str(width)+'}  {3}'
     81print fmt_header.format('exclude/ms', 'include/ms', '#parents', 'module name')
     82for t, module, data in module_by_speed[-50:]:
     83     print fmt_number.format(1000*t, 1000*data['cumulative_time'], len(data['parents']), module.__name__)
    6584
     85print 'Total time (sum over exclusive time): {:.3f}ms'.format(1000*sum(data[0] for data in module_by_speed))
    6686
    6787