| 487 | self.bias = saved_bias |
| 488 | |
| 489 | def _calibrate_inner(self, m, verbose): |
| 490 | get_time = self.get_time |
| 491 | |
| 492 | # Set up a test case to be run with and without profiling. Include |
| 493 | # lots of calls, because we're trying to quantify stopwatch overhead. |
| 494 | # Do not raise any exceptions, though, because we want to know |
| 495 | # exactly how many profile events are generated (one call event, + |
| 496 | # one return event, per Python-level call). |
| 497 | |
| 498 | def f1(n): |
| 499 | for i in range(n): |
| 500 | x = 1 |
| 501 | |
| 502 | def f(m, f1=f1): |
| 503 | for i in range(m): |
| 504 | f1(100) |
| 505 | |
| 506 | f(m) # warm up the cache |
| 507 | |
| 508 | # elapsed_noprofile <- time f(m) takes without profiling. |
| 509 | t0 = get_time() |
| 510 | f(m) |
| 511 | t1 = get_time() |
| 512 | elapsed_noprofile = t1 - t0 |
| 513 | if verbose: |
| 514 | print("elapsed time without profiling =", elapsed_noprofile) |
| 515 | |
| 516 | # elapsed_profile <- time f(m) takes with profiling. The difference |
| 517 | # is profiling overhead, only some of which the profiler subtracts |
| 518 | # out on its own. |
| 519 | p = Profile() |
| 520 | t0 = get_time() |
| 521 | p.runctx('f(m)', globals(), locals()) |
| 522 | t1 = get_time() |
| 523 | elapsed_profile = t1 - t0 |
| 524 | if verbose: |
| 525 | print("elapsed time with profiling =", elapsed_profile) |
| 526 | |
| 527 | # reported_time <- "CPU seconds" the profiler charged to f and f1. |
| 528 | total_calls = 0.0 |
| 529 | reported_time = 0.0 |
| 530 | for (filename, line, funcname), (cc, ns, tt, ct, callers) in \ |
| 531 | p.timings.items(): |
| 532 | if funcname in ("f", "f1"): |
| 533 | total_calls += cc |
| 534 | reported_time += tt |
| 535 | |
| 536 | if verbose: |
| 537 | print("'CPU seconds' profiler reported =", reported_time) |
| 538 | print("total # calls =", total_calls) |
| 539 | if total_calls != m + 1: |
| 540 | raise ValueError("internal error: total calls = %d" % total_calls) |
| 541 | |
| 542 | # reported_time - elapsed_noprofile = overhead the profiler wasn't |
| 543 | # able to measure. Divide by twice the number of calls (since there |
| 544 | # are two profiler events per call in this test) to get the hidden |
| 545 | # overhead per event. |
| 546 | mean = (reported_time - elapsed_noprofile) / 2.0 / total_calls |