1.. _profile: 2 3******************** 4The Python Profilers 5******************** 6 7**Source code:** :source:`Lib/profile.py` and :source:`Lib/pstats.py` 8 9-------------- 10 11.. _profiler-introduction: 12 13Introduction to the profilers 14============================= 15 16.. index:: 17 single: deterministic profiling 18 single: profiling, deterministic 19 20:mod:`cProfile` and :mod:`profile` provide :dfn:`deterministic profiling` of 21Python programs. A :dfn:`profile` is a set of statistics that describes how 22often and for how long various parts of the program executed. These statistics 23can be formatted into reports via the :mod:`pstats` module. 24 25The Python standard library provides two different implementations of the same 26profiling interface: 27 281. :mod:`cProfile` is recommended for most users; it's a C extension with 29 reasonable overhead that makes it suitable for profiling long-running 30 programs. Based on :mod:`lsprof`, contributed by Brett Rosen and Ted 31 Czotter. 32 332. :mod:`profile`, a pure Python module whose interface is imitated by 34 :mod:`cProfile`, but which adds significant overhead to profiled programs. 35 If you're trying to extend the profiler in some way, the task might be easier 36 with this module. Originally designed and written by Jim Roskind. 37 38.. note:: 39 40 The profiler modules are designed to provide an execution profile for a given 41 program, not for benchmarking purposes (for that, there is :mod:`timeit` for 42 reasonably accurate results). This particularly applies to benchmarking 43 Python code against C code: the profilers introduce overhead for Python code, 44 but not for C-level functions, and so the C code would seem faster than any 45 Python one. 46 47 48.. _profile-instant: 49 50Instant User's Manual 51===================== 52 53This section is provided for users that "don't want to read the manual." It 54provides a very brief overview, and allows a user to rapidly perform profiling 55on an existing application. 56 57To profile a function that takes a single argument, you can do:: 58 59 import cProfile 60 import re 61 cProfile.run('re.compile("foo|bar")') 62 63(Use :mod:`profile` instead of :mod:`cProfile` if the latter is not available on 64your system.) 65 66The above action would run :func:`re.compile` and print profile results like 67the following:: 68 69 214 function calls (207 primitive calls) in 0.002 seconds 70 71 Ordered by: cumulative time 72 73 ncalls tottime percall cumtime percall filename:lineno(function) 74 1 0.000 0.000 0.002 0.002 {built-in method builtins.exec} 75 1 0.000 0.000 0.001 0.001 <string>:1(<module>) 76 1 0.000 0.000 0.001 0.001 __init__.py:250(compile) 77 1 0.000 0.000 0.001 0.001 __init__.py:289(_compile) 78 1 0.000 0.000 0.000 0.000 _compiler.py:759(compile) 79 1 0.000 0.000 0.000 0.000 _parser.py:937(parse) 80 1 0.000 0.000 0.000 0.000 _compiler.py:598(_code) 81 1 0.000 0.000 0.000 0.000 _parser.py:435(_parse_sub) 82 83The first line indicates that 214 calls were monitored. Of those calls, 207 84were :dfn:`primitive`, meaning that the call was not induced via recursion. The 85next line: ``Ordered by: cumulative time`` indicates the output is sorted 86by the ``cumtime`` values. The column headings include: 87 88ncalls 89 for the number of calls. 90 91tottime 92 for the total time spent in the given function (and excluding time made in 93 calls to sub-functions) 94 95percall 96 is the quotient of ``tottime`` divided by ``ncalls`` 97 98cumtime 99 is the cumulative time spent in this and all subfunctions (from invocation 100 till exit). This figure is accurate *even* for recursive functions. 101 102percall 103 is the quotient of ``cumtime`` divided by primitive calls 104 105filename:lineno(function) 106 provides the respective data of each function 107 108When there are two numbers in the first column (for example ``3/1``), it means 109that the function recursed. The second value is the number of primitive calls 110and the former is the total number of calls. Note that when the function does 111not recurse, these two values are the same, and only the single figure is 112printed. 113 114Instead of printing the output at the end of the profile run, you can save the 115results to a file by specifying a filename to the :func:`run` function:: 116 117 import cProfile 118 import re 119 cProfile.run('re.compile("foo|bar")', 'restats') 120 121The :class:`pstats.Stats` class reads profile results from a file and formats 122them in various ways. 123 124.. _profile-cli: 125 126The files :mod:`cProfile` and :mod:`profile` can also be invoked as a script to 127profile another script. For example:: 128 129 python -m cProfile [-o output_file] [-s sort_order] (-m module | myscript.py) 130 131``-o`` writes the profile results to a file instead of to stdout 132 133``-s`` specifies one of the :func:`~pstats.Stats.sort_stats` sort values to sort 134the output by. This only applies when ``-o`` is not supplied. 135 136``-m`` specifies that a module is being profiled instead of a script. 137 138.. versionadded:: 3.7 139 Added the ``-m`` option to :mod:`cProfile`. 140 141.. versionadded:: 3.8 142 Added the ``-m`` option to :mod:`profile`. 143 144The :mod:`pstats` module's :class:`~pstats.Stats` class has a variety of methods 145for manipulating and printing the data saved into a profile results file:: 146 147 import pstats 148 from pstats import SortKey 149 p = pstats.Stats('restats') 150 p.strip_dirs().sort_stats(-1).print_stats() 151 152The :meth:`~pstats.Stats.strip_dirs` method removed the extraneous path from all 153the module names. The :meth:`~pstats.Stats.sort_stats` method sorted all the 154entries according to the standard module/line/name string that is printed. The 155:meth:`~pstats.Stats.print_stats` method printed out all the statistics. You 156might try the following sort calls:: 157 158 p.sort_stats(SortKey.NAME) 159 p.print_stats() 160 161The first call will actually sort the list by function name, and the second call 162will print out the statistics. The following are some interesting calls to 163experiment with:: 164 165 p.sort_stats(SortKey.CUMULATIVE).print_stats(10) 166 167This sorts the profile by cumulative time in a function, and then only prints 168the ten most significant lines. If you want to understand what algorithms are 169taking time, the above line is what you would use. 170 171If you were looking to see what functions were looping a lot, and taking a lot 172of time, you would do:: 173 174 p.sort_stats(SortKey.TIME).print_stats(10) 175 176to sort according to time spent within each function, and then print the 177statistics for the top ten functions. 178 179You might also try:: 180 181 p.sort_stats(SortKey.FILENAME).print_stats('__init__') 182 183This will sort all the statistics by file name, and then print out statistics 184for only the class init methods (since they are spelled with ``__init__`` in 185them). As one final example, you could try:: 186 187 p.sort_stats(SortKey.TIME, SortKey.CUMULATIVE).print_stats(.5, 'init') 188 189This line sorts statistics with a primary key of time, and a secondary key of 190cumulative time, and then prints out some of the statistics. To be specific, the 191list is first culled down to 50% (re: ``.5``) of its original size, then only 192lines containing ``init`` are maintained, and that sub-sub-list is printed. 193 194If you wondered what functions called the above functions, you could now (``p`` 195is still sorted according to the last criteria) do:: 196 197 p.print_callers(.5, 'init') 198 199and you would get a list of callers for each of the listed functions. 200 201If you want more functionality, you're going to have to read the manual, or 202guess what the following functions do:: 203 204 p.print_callees() 205 p.add('restats') 206 207Invoked as a script, the :mod:`pstats` module is a statistics browser for 208reading and examining profile dumps. It has a simple line-oriented interface 209(implemented using :mod:`cmd`) and interactive help. 210 211:mod:`profile` and :mod:`cProfile` Module Reference 212======================================================= 213 214.. module:: cProfile 215.. module:: profile 216 :synopsis: Python source profiler. 217 218Both the :mod:`profile` and :mod:`cProfile` modules provide the following 219functions: 220 221.. function:: run(command, filename=None, sort=-1) 222 223 This function takes a single argument that can be passed to the :func:`exec` 224 function, and an optional file name. In all cases this routine executes:: 225 226 exec(command, __main__.__dict__, __main__.__dict__) 227 228 and gathers profiling statistics from the execution. If no file name is 229 present, then this function automatically creates a :class:`~pstats.Stats` 230 instance and prints a simple profiling report. If the sort value is specified, 231 it is passed to this :class:`~pstats.Stats` instance to control how the 232 results are sorted. 233 234.. function:: runctx(command, globals, locals, filename=None, sort=-1) 235 236 This function is similar to :func:`run`, with added arguments to supply the 237 globals and locals mappings for the *command* string. This routine 238 executes:: 239 240 exec(command, globals, locals) 241 242 and gathers profiling statistics as in the :func:`run` function above. 243 244.. class:: Profile(timer=None, timeunit=0.0, subcalls=True, builtins=True) 245 246 This class is normally only used if more precise control over profiling is 247 needed than what the :func:`cProfile.run` function provides. 248 249 A custom timer can be supplied for measuring how long code takes to run via 250 the *timer* argument. This must be a function that returns a single number 251 representing the current time. If the number is an integer, the *timeunit* 252 specifies a multiplier that specifies the duration of each unit of time. For 253 example, if the timer returns times measured in thousands of seconds, the 254 time unit would be ``.001``. 255 256 Directly using the :class:`Profile` class allows formatting profile results 257 without writing the profile data to a file:: 258 259 import cProfile, pstats, io 260 from pstats import SortKey 261 pr = cProfile.Profile() 262 pr.enable() 263 # ... do something ... 264 pr.disable() 265 s = io.StringIO() 266 sortby = SortKey.CUMULATIVE 267 ps = pstats.Stats(pr, stream=s).sort_stats(sortby) 268 ps.print_stats() 269 print(s.getvalue()) 270 271 The :class:`Profile` class can also be used as a context manager (supported 272 only in :mod:`cProfile` module. see :ref:`typecontextmanager`):: 273 274 import cProfile 275 276 with cProfile.Profile() as pr: 277 # ... do something ... 278 279 pr.print_stats() 280 281 .. versionchanged:: 3.8 282 Added context manager support. 283 284 .. method:: enable() 285 286 Start collecting profiling data. Only in :mod:`cProfile`. 287 288 .. method:: disable() 289 290 Stop collecting profiling data. Only in :mod:`cProfile`. 291 292 .. method:: create_stats() 293 294 Stop collecting profiling data and record the results internally 295 as the current profile. 296 297 .. method:: print_stats(sort=-1) 298 299 Create a :class:`~pstats.Stats` object based on the current 300 profile and print the results to stdout. 301 302 The *sort* parameter specifies the sorting order of the displayed 303 statistics. It accepts a single key or a tuple of keys to enable 304 multi-level sorting, as in :func:`Stats.sort_stats <pstats.Stats.sort_stats>`. 305 306 .. versionadded:: 3.13 307 :meth:`~Profile.print_stats` now accepts a tuple of keys. 308 309 .. method:: dump_stats(filename) 310 311 Write the results of the current profile to *filename*. 312 313 .. method:: run(cmd) 314 315 Profile the cmd via :func:`exec`. 316 317 .. method:: runctx(cmd, globals, locals) 318 319 Profile the cmd via :func:`exec` with the specified global and 320 local environment. 321 322 .. method:: runcall(func, /, *args, **kwargs) 323 324 Profile ``func(*args, **kwargs)`` 325 326Note that profiling will only work if the called command/function actually 327returns. If the interpreter is terminated (e.g. via a :func:`sys.exit` call 328during the called command/function execution) no profiling results will be 329printed. 330 331.. _profile-stats: 332 333The :class:`Stats` Class 334======================== 335 336Analysis of the profiler data is done using the :class:`~pstats.Stats` class. 337 338.. module:: pstats 339 :synopsis: Statistics object for use with the profiler. 340 341.. class:: Stats(*filenames or profile, stream=sys.stdout) 342 343 This class constructor creates an instance of a "statistics object" from a 344 *filename* (or list of filenames) or from a :class:`Profile` instance. Output 345 will be printed to the stream specified by *stream*. 346 347 The file selected by the above constructor must have been created by the 348 corresponding version of :mod:`profile` or :mod:`cProfile`. To be specific, 349 there is *no* file compatibility guaranteed with future versions of this 350 profiler, and there is no compatibility with files produced by other 351 profilers, or the same profiler run on a different operating system. If 352 several files are provided, all the statistics for identical functions will 353 be coalesced, so that an overall view of several processes can be considered 354 in a single report. If additional files need to be combined with data in an 355 existing :class:`~pstats.Stats` object, the :meth:`~pstats.Stats.add` method 356 can be used. 357 358 Instead of reading the profile data from a file, a :class:`cProfile.Profile` 359 or :class:`profile.Profile` object can be used as the profile data source. 360 361 :class:`Stats` objects have the following methods: 362 363 .. method:: strip_dirs() 364 365 This method for the :class:`Stats` class removes all leading path 366 information from file names. It is very useful in reducing the size of 367 the printout to fit within (close to) 80 columns. This method modifies 368 the object, and the stripped information is lost. After performing a 369 strip operation, the object is considered to have its entries in a 370 "random" order, as it was just after object initialization and loading. 371 If :meth:`~pstats.Stats.strip_dirs` causes two function names to be 372 indistinguishable (they are on the same line of the same filename, and 373 have the same function name), then the statistics for these two entries 374 are accumulated into a single entry. 375 376 377 .. method:: add(*filenames) 378 379 This method of the :class:`Stats` class accumulates additional profiling 380 information into the current profiling object. Its arguments should refer 381 to filenames created by the corresponding version of :func:`profile.run` 382 or :func:`cProfile.run`. Statistics for identically named (re: file, line, 383 name) functions are automatically accumulated into single function 384 statistics. 385 386 387 .. method:: dump_stats(filename) 388 389 Save the data loaded into the :class:`Stats` object to a file named 390 *filename*. The file is created if it does not exist, and is overwritten 391 if it already exists. This is equivalent to the method of the same name 392 on the :class:`profile.Profile` and :class:`cProfile.Profile` classes. 393 394 395 .. method:: sort_stats(*keys) 396 397 This method modifies the :class:`Stats` object by sorting it according to 398 the supplied criteria. The argument can be either a string or a SortKey 399 enum identifying the basis of a sort (example: ``'time'``, ``'name'``, 400 ``SortKey.TIME`` or ``SortKey.NAME``). The SortKey enums argument have 401 advantage over the string argument in that it is more robust and less 402 error prone. 403 404 When more than one key is provided, then additional keys are used as 405 secondary criteria when there is equality in all keys selected before 406 them. For example, ``sort_stats(SortKey.NAME, SortKey.FILE)`` will sort 407 all the entries according to their function name, and resolve all ties 408 (identical function names) by sorting by file name. 409 410 For the string argument, abbreviations can be used for any key names, as 411 long as the abbreviation is unambiguous. 412 413 The following are the valid string and SortKey: 414 415 +------------------+---------------------+----------------------+ 416 | Valid String Arg | Valid enum Arg | Meaning | 417 +==================+=====================+======================+ 418 | ``'calls'`` | SortKey.CALLS | call count | 419 +------------------+---------------------+----------------------+ 420 | ``'cumulative'`` | SortKey.CUMULATIVE | cumulative time | 421 +------------------+---------------------+----------------------+ 422 | ``'cumtime'`` | N/A | cumulative time | 423 +------------------+---------------------+----------------------+ 424 | ``'file'`` | N/A | file name | 425 +------------------+---------------------+----------------------+ 426 | ``'filename'`` | SortKey.FILENAME | file name | 427 +------------------+---------------------+----------------------+ 428 | ``'module'`` | N/A | file name | 429 +------------------+---------------------+----------------------+ 430 | ``'ncalls'`` | N/A | call count | 431 +------------------+---------------------+----------------------+ 432 | ``'pcalls'`` | SortKey.PCALLS | primitive call count | 433 +------------------+---------------------+----------------------+ 434 | ``'line'`` | SortKey.LINE | line number | 435 +------------------+---------------------+----------------------+ 436 | ``'name'`` | SortKey.NAME | function name | 437 +------------------+---------------------+----------------------+ 438 | ``'nfl'`` | SortKey.NFL | name/file/line | 439 +------------------+---------------------+----------------------+ 440 | ``'stdname'`` | SortKey.STDNAME | standard name | 441 +------------------+---------------------+----------------------+ 442 | ``'time'`` | SortKey.TIME | internal time | 443 +------------------+---------------------+----------------------+ 444 | ``'tottime'`` | N/A | internal time | 445 +------------------+---------------------+----------------------+ 446 447 Note that all sorts on statistics are in descending order (placing most 448 time consuming items first), where as name, file, and line number searches 449 are in ascending order (alphabetical). The subtle distinction between 450 ``SortKey.NFL`` and ``SortKey.STDNAME`` is that the standard name is a 451 sort of the name as printed, which means that the embedded line numbers 452 get compared in an odd way. For example, lines 3, 20, and 40 would (if 453 the file names were the same) appear in the string order 20, 3 and 40. 454 In contrast, ``SortKey.NFL`` does a numeric compare of the line numbers. 455 In fact, ``sort_stats(SortKey.NFL)`` is the same as 456 ``sort_stats(SortKey.NAME, SortKey.FILENAME, SortKey.LINE)``. 457 458 For backward-compatibility reasons, the numeric arguments ``-1``, ``0``, 459 ``1``, and ``2`` are permitted. They are interpreted as ``'stdname'``, 460 ``'calls'``, ``'time'``, and ``'cumulative'`` respectively. If this old 461 style format (numeric) is used, only one sort key (the numeric key) will 462 be used, and additional arguments will be silently ignored. 463 464 .. For compatibility with the old profiler. 465 466 .. versionadded:: 3.7 467 Added the SortKey enum. 468 469 .. method:: reverse_order() 470 471 This method for the :class:`Stats` class reverses the ordering of the 472 basic list within the object. Note that by default ascending vs 473 descending order is properly selected based on the sort key of choice. 474 475 .. This method is provided primarily for compatibility with the old 476 profiler. 477 478 479 .. method:: print_stats(*restrictions) 480 481 This method for the :class:`Stats` class prints out a report as described 482 in the :func:`profile.run` definition. 483 484 The order of the printing is based on the last 485 :meth:`~pstats.Stats.sort_stats` operation done on the object (subject to 486 caveats in :meth:`~pstats.Stats.add` and 487 :meth:`~pstats.Stats.strip_dirs`). 488 489 The arguments provided (if any) can be used to limit the list down to the 490 significant entries. Initially, the list is taken to be the complete set 491 of profiled functions. Each restriction is either an integer (to select a 492 count of lines), or a decimal fraction between 0.0 and 1.0 inclusive (to 493 select a percentage of lines), or a string that will interpreted as a 494 regular expression (to pattern match the standard name that is printed). 495 If several restrictions are provided, then they are applied sequentially. 496 For example:: 497 498 print_stats(.1, 'foo:') 499 500 would first limit the printing to first 10% of list, and then only print 501 functions that were part of filename :file:`.\*foo:`. In contrast, the 502 command:: 503 504 print_stats('foo:', .1) 505 506 would limit the list to all functions having file names :file:`.\*foo:`, 507 and then proceed to only print the first 10% of them. 508 509 510 .. method:: print_callers(*restrictions) 511 512 This method for the :class:`Stats` class prints a list of all functions 513 that called each function in the profiled database. The ordering is 514 identical to that provided by :meth:`~pstats.Stats.print_stats`, and the 515 definition of the restricting argument is also identical. Each caller is 516 reported on its own line. The format differs slightly depending on the 517 profiler that produced the stats: 518 519 * With :mod:`profile`, a number is shown in parentheses after each caller 520 to show how many times this specific call was made. For convenience, a 521 second non-parenthesized number repeats the cumulative time spent in the 522 function at the right. 523 524 * With :mod:`cProfile`, each caller is preceded by three numbers: the 525 number of times this specific call was made, and the total and 526 cumulative times spent in the current function while it was invoked by 527 this specific caller. 528 529 530 .. method:: print_callees(*restrictions) 531 532 This method for the :class:`Stats` class prints a list of all function 533 that were called by the indicated function. Aside from this reversal of 534 direction of calls (re: called vs was called by), the arguments and 535 ordering are identical to the :meth:`~pstats.Stats.print_callers` method. 536 537 538 .. method:: get_stats_profile() 539 540 This method returns an instance of StatsProfile, which contains a mapping 541 of function names to instances of FunctionProfile. Each FunctionProfile 542 instance holds information related to the function's profile such as how 543 long the function took to run, how many times it was called, etc... 544 545 .. versionadded:: 3.9 546 Added the following dataclasses: StatsProfile, FunctionProfile. 547 Added the following function: get_stats_profile. 548 549.. _deterministic-profiling: 550 551What Is Deterministic Profiling? 552================================ 553 554:dfn:`Deterministic profiling` is meant to reflect the fact that all *function 555call*, *function return*, and *exception* events are monitored, and precise 556timings are made for the intervals between these events (during which time the 557user's code is executing). In contrast, :dfn:`statistical profiling` (which is 558not done by this module) randomly samples the effective instruction pointer, and 559deduces where time is being spent. The latter technique traditionally involves 560less overhead (as the code does not need to be instrumented), but provides only 561relative indications of where time is being spent. 562 563In Python, since there is an interpreter active during execution, the presence 564of instrumented code is not required in order to do deterministic profiling. 565Python automatically provides a :dfn:`hook` (optional callback) for each event. 566In addition, the interpreted nature of Python tends to add so much overhead to 567execution, that deterministic profiling tends to only add small processing 568overhead in typical applications. The result is that deterministic profiling is 569not that expensive, yet provides extensive run time statistics about the 570execution of a Python program. 571 572Call count statistics can be used to identify bugs in code (surprising counts), 573and to identify possible inline-expansion points (high call counts). Internal 574time statistics can be used to identify "hot loops" that should be carefully 575optimized. Cumulative time statistics should be used to identify high level 576errors in the selection of algorithms. Note that the unusual handling of 577cumulative times in this profiler allows statistics for recursive 578implementations of algorithms to be directly compared to iterative 579implementations. 580 581 582.. _profile-limitations: 583 584Limitations 585=========== 586 587One limitation has to do with accuracy of timing information. There is a 588fundamental problem with deterministic profilers involving accuracy. The most 589obvious restriction is that the underlying "clock" is only ticking at a rate 590(typically) of about .001 seconds. Hence no measurements will be more accurate 591than the underlying clock. If enough measurements are taken, then the "error" 592will tend to average out. Unfortunately, removing this first error induces a 593second source of error. 594 595The second problem is that it "takes a while" from when an event is dispatched 596until the profiler's call to get the time actually *gets* the state of the 597clock. Similarly, there is a certain lag when exiting the profiler event 598handler from the time that the clock's value was obtained (and then squirreled 599away), until the user's code is once again executing. As a result, functions 600that are called many times, or call many functions, will typically accumulate 601this error. The error that accumulates in this fashion is typically less than 602the accuracy of the clock (less than one clock tick), but it *can* accumulate 603and become very significant. 604 605The problem is more important with :mod:`profile` than with the lower-overhead 606:mod:`cProfile`. For this reason, :mod:`profile` provides a means of 607calibrating itself for a given platform so that this error can be 608probabilistically (on the average) removed. After the profiler is calibrated, it 609will be more accurate (in a least square sense), but it will sometimes produce 610negative numbers (when call counts are exceptionally low, and the gods of 611probability work against you :-). ) Do *not* be alarmed by negative numbers in 612the profile. They should *only* appear if you have calibrated your profiler, 613and the results are actually better than without calibration. 614 615 616.. _profile-calibration: 617 618Calibration 619=========== 620 621The profiler of the :mod:`profile` module subtracts a constant from each event 622handling time to compensate for the overhead of calling the time function, and 623socking away the results. By default, the constant is 0. The following 624procedure can be used to obtain a better constant for a given platform (see 625:ref:`profile-limitations`). :: 626 627 import profile 628 pr = profile.Profile() 629 for i in range(5): 630 print(pr.calibrate(10000)) 631 632The method executes the number of Python calls given by the argument, directly 633and again under the profiler, measuring the time for both. It then computes the 634hidden overhead per profiler event, and returns that as a float. For example, 635on a 1.8Ghz Intel Core i5 running macOS, and using Python's time.process_time() as 636the timer, the magical number is about 4.04e-6. 637 638The object of this exercise is to get a fairly consistent result. If your 639computer is *very* fast, or your timer function has poor resolution, you might 640have to pass 100000, or even 1000000, to get consistent results. 641 642When you have a consistent answer, there are three ways you can use it:: 643 644 import profile 645 646 # 1. Apply computed bias to all Profile instances created hereafter. 647 profile.Profile.bias = your_computed_bias 648 649 # 2. Apply computed bias to a specific Profile instance. 650 pr = profile.Profile() 651 pr.bias = your_computed_bias 652 653 # 3. Specify computed bias in instance constructor. 654 pr = profile.Profile(bias=your_computed_bias) 655 656If you have a choice, you are better off choosing a smaller constant, and then 657your results will "less often" show up as negative in profile statistics. 658 659.. _profile-timers: 660 661Using a custom timer 662==================== 663 664If you want to change how current time is determined (for example, to force use 665of wall-clock time or elapsed process time), pass the timing function you want 666to the :class:`Profile` class constructor:: 667 668 pr = profile.Profile(your_time_func) 669 670The resulting profiler will then call ``your_time_func``. Depending on whether 671you are using :class:`profile.Profile` or :class:`cProfile.Profile`, 672``your_time_func``'s return value will be interpreted differently: 673 674:class:`profile.Profile` 675 ``your_time_func`` should return a single number, or a list of numbers whose 676 sum is the current time (like what :func:`os.times` returns). If the 677 function returns a single time number, or the list of returned numbers has 678 length 2, then you will get an especially fast version of the dispatch 679 routine. 680 681 Be warned that you should calibrate the profiler class for the timer function 682 that you choose (see :ref:`profile-calibration`). For most machines, a timer 683 that returns a lone integer value will provide the best results in terms of 684 low overhead during profiling. (:func:`os.times` is *pretty* bad, as it 685 returns a tuple of floating-point values). If you want to substitute a 686 better timer in the cleanest fashion, derive a class and hardwire a 687 replacement dispatch method that best handles your timer call, along with the 688 appropriate calibration constant. 689 690:class:`cProfile.Profile` 691 ``your_time_func`` should return a single number. If it returns integers, 692 you can also invoke the class constructor with a second argument specifying 693 the real duration of one unit of time. For example, if 694 ``your_integer_time_func`` returns times measured in thousands of seconds, 695 you would construct the :class:`Profile` instance as follows:: 696 697 pr = cProfile.Profile(your_integer_time_func, 0.001) 698 699 As the :class:`cProfile.Profile` class cannot be calibrated, custom timer 700 functions should be used with care and should be as fast as possible. For 701 the best results with a custom timer, it might be necessary to hard-code it 702 in the C source of the internal :mod:`!_lsprof` module. 703 704Python 3.3 adds several new functions in :mod:`time` that can be used to make 705precise measurements of process or wall-clock time. For example, see 706:func:`time.perf_counter`. 707