Profiling results ----------------- Total cpu time observed: 136358ms (out of 141048ms) Number of samples taken: 317 (once every 430ms) (Hiding functions with self<1.0% and local<2.0%: 3 of 101 hidden) ========================================================================== Caller Idx Total Self Name+src Local% ms(pct) ms(pct) Callee ========================================================================== run [12] 49.8% [1] 135034(99.0%) 0(0.0%) ??? ...lects/racket/private/more-scheme.rkt:261:28 profile-thunk16 [7] 49.8% loop [13] 43.3% run-improve50 [9] 6.9% -------------------------------------------------------------------------- map [40] 0.6% for-loop [87] 1.5% loop [57] 98.0% [2] 115646(84.8%) 0(0.0%) ??? ...bie/sampling-logging/src/programs.rkt:154:4 ??? [8] 100.0% -------------------------------------------------------------------------- ??? [63] 100.0% [3] 8874(6.5%) 0(0.0%) iterate-egraph!13 ...g/src/core/simplify.rkt:102:0 one-iter [10] 100.0% -------------------------------------------------------------------------- hash-ref! [49] 100.0% [4] 2184(1.6%) 0(0.0%) f6 ...et/collects/racket/match/compiler.rkt:507:40 map [40] 100.0% -------------------------------------------------------------------------- ??? [63] 100.0% [5] 1692(1.2%) 0(0.0%) loop ...mpling-logging/src/core/simplify.rkt:215:2 pass [11] 100.0% -------------------------------------------------------------------------- parse-loop12 [54] 1.3% loop [6] 98.7% [6] 364(0.3%) 0(0.0%) loop ...cket/collects/racket/private/map.rkt:36:19 loop [6] 98.7% ??? [17] 1.3% -------------------------------------------------------------------------- ??? [1] 100.0% [7] 134416(98.6%) 0(0.0%) profile-thunk16 ...t/pkgs/profile-lib/main.rkt:9:0 run [12] 100.0% -------------------------------------------------------------------------- ??? [2] 100.0% [8] 115646(84.8%) 8540(6.3%) ??? ...acket/collects/racket/private/kw.rkt:444:14 bf-complex-mult [62] 80.8% bf-complex-add [15] 7.8% ??? [19] 2.2% ??? [17] 0.8% parse-loop12 [54] 0.7% -------------------------------------------------------------------------- ??? [1] 100.0% [9] 17994(13.2%) 0(0.0%) run-improve50 ...ng-logging/src/mainloop.rkt:234:0 setup-alt-simplified [14] 53.3% loop [13] 23.2% for-loop [20] 14.0% setup-prog [22] 7.7% get-final-combination [23] 1.8% -------------------------------------------------------------------------- iterate-egraph!13 [3] 100.0% [10] 8874(6.5%) 0(0.0%) one-iter ...ng-logging/src/core/simplify.rkt:113:0 for-loop [16] 57.1% loop [18] 42.9% -------------------------------------------------------------------------- loop [5] 100.0% [11] 1692(1.2%) 0(0.0%) pass ...mpling-logging/src/core/simplify.rkt:205:2 for-loop [21] 100.0% -------------------------------------------------------------------------- profile-thunk16 [7] 100.0% [12] 134416(98.6%) 0(0.0%) run ...share/racket/pkgs/profile-lib/main.rkt:39:2 ??? [1] 100.0% -------------------------------------------------------------------------- run-improve50 [9] 3.4% ??? [1] 96.6% [13] 121220(88.9%) 0(0.0%) loop ...rbie/sampling-logging/src/points.rkt:193:2 make-exacts* [32] 54.0% loop [24] 46.0% -------------------------------------------------------------------------- run-improve50 [9] 100.0% [14] 9594(7.0%) 0(0.0%) setup-alt-simplified ...-logging/src/glue.rkt:49:0 simplify-alt [25] 100.0% -------------------------------------------------------------------------- ??? [8] 100.0% [15] 8972(6.6%) 402(0.3%) bf-complex-add ...-logging/src/bigcomplex.rkt:22:0 ??? [80] 87.0% ...higher-order.rkt:346:33 [70] 8.5% -------------------------------------------------------------------------- for-loop [16] 50.0% one-iter [10] 50.0% [16] 5066(3.7%) 0(0.0%) for-loop ...g-logging/src/core/simplify.rkt:123:12 for-loop [16] 50.0% rule-valid-at-type? [26] 50.0% -------------------------------------------------------------------------- get-final-combination [23] 8.3% ??? [78] 8.5% loop [6] 9.4% loop [57] 21.0% ??? [8] 24.7% map [40] 28.1% [17] 3884(2.8%) 500(0.4%) ??? ...tract/private/arrow-higher-order.rkt:342:33 ??? [63] 66.8% ??? [98] 11.8% best-alt [31] 8.5% -------------------------------------------------------------------------- one-iter [10] 100.0% [18] 3808(2.8%) 0(0.0%) loop ...cket/collects/racket/private/map.rkt:52:19 apply-match [27] 100.0% -------------------------------------------------------------------------- ??? [8] 100.0% [19] 2588(1.9%) 2588(1.9%) ??? ...rivate/unconstrained-domain-arrow.rkt:40:13 -------------------------------------------------------------------------- run-improve50 [9] 100.0% [20] 2514(1.8%) 0(0.0%) for-loop ...mpling-logging/src/mainloop.rkt:249:10 run-iter! [28] 100.0% -------------------------------------------------------------------------- pass [11] 100.0% [21] 1692(1.2%) 334(0.2%) for-loop ...g-logging/src/core/simplify.rkt:208:29 argmin [29] 59.1% for-loop [30] 21.2% -------------------------------------------------------------------------- run-improve50 [9] 100.0% [22] 1382(1.0%) 0(0.0%) setup-prog ...e/sampling-logging/src/glue.rkt:40:0 ??? [64] 100.0% -------------------------------------------------------------------------- run-improve50 [9] 100.0% [23] 324(0.2%) 0(0.0%) get-final-combination ...ng/src/mainloop.rkt:264:0 ??? [17] 100.0% -------------------------------------------------------------------------- loop [13] 100.0% [24] 55772(40.9%) 0(0.0%) loop ...rbie/sampling-logging/src/points.rkt:152:2 make-exacts* [32] 99.2% -------------------------------------------------------------------------- setup-alt-simplified [14] 100.0% [25] 9594(7.0%) 0(0.0%) simplify-alt ...sampling-logging/src/glue.rkt:76:0 ??? [63] 100.0% -------------------------------------------------------------------------- for-loop [16] 100.0% [26] 5066(3.7%) 3354(2.5%) rule-valid-at-type? .../src/syntax/rules.rkt:487:0 for-loop [35] 33.8% -------------------------------------------------------------------------- loop [18] 100.0% [27] 3808(2.8%) 0(0.0%) apply-match ...logging/src/core/simplify.rkt:130:2 for-loop [33] 67.9% update-leader! [48] 23.6% match-e [39] 8.5% -------------------------------------------------------------------------- for-loop [20] 100.0% [28] 2514(1.8%) 0(0.0%) run-iter! ...mpling-logging/src/mainloop.rkt:215:0 localize-error [34] 86.9% choose-best-alt! [38] 13.1% -------------------------------------------------------------------------- for-loop [21] 100.0% [29] 1000(0.7%) 0(0.0%) argmin ...re/racket/collects/racket/list.rkt:743:0 for-loop [36] 100.0% -------------------------------------------------------------------------- for-loop [21] 100.0% [30] 358(0.3%) 358(0.3%) for-loop ...g-logging/src/core/simplify.rkt:195:13 -------------------------------------------------------------------------- ??? [17] 100.0% [31] 330(0.2%) 0(0.0%) best-alt ...bie/sampling-logging/src/glue.rkt:71:0 argmins [37] 100.0% -------------------------------------------------------------------------- loop [24] 45.8% loop [13] 54.2% [32] 120764(88.6%) 0(0.0%) make-exacts* ...pling-logging/src/points.rkt:138:0 map [40] 48.5% loop [57] 45.8% eval-prog [41] 5.7% -------------------------------------------------------------------------- apply-match [27] 100.0% [33] 2586(1.9%) 0(0.0%) for-loop ...g-logging/src/core/simplify.rkt:145:10 substitute-e [42] 62.9% merge-egraph-nodes! [43] 23.4% mk-enode! [47] 13.8% -------------------------------------------------------------------------- run-iter! [28] 100.0% [34] 2184(1.6%) 0(0.0%) localize-error ...gging/src/core/localize.rkt:47:0 hash-ref! [49] 100.0% -------------------------------------------------------------------------- rule-valid-at-type? [26] 100.0% [35] 1712(1.3%) 1712(1.3%) for-loop ...e/sampling-logging/src/common.rkt:99:9 -------------------------------------------------------------------------- argmin [29] 100.0% [36] 1000(0.7%) 0(0.0%) for-loop ...ampling-logging/src/programs.rkt:199:2 ??? [63] 67.0% ??? [66] 33.0% -------------------------------------------------------------------------- best-alt [31] 100.0% [37] 330(0.2%) 0(0.0%) argmins ...e/sampling-logging/src/common.rkt:150:0 composed [44] 100.0% -------------------------------------------------------------------------- run-iter! [28] 100.0% [38] 330(0.2%) 0(0.0%) choose-best-alt! ...logging/src/mainloop.rkt:115:0 ??? [64] 100.0% -------------------------------------------------------------------------- for-loop [45] 50.0% apply-match [27] 50.0% [39] 324(0.2%) 0(0.0%) match-e ...mpling-logging/src/core/ematch.rkt:46:0 for-loop [45] 50.0% loop [57] 50.0% -------------------------------------------------------------------------- ??? [46] 0.9% f6 [4] 2.7% make-exacts* [32] 96.4% [40] 60802(44.6%) 0(0.0%) map ...acket/collects/racket/private/map.rkt:20:13 loop [57] 95.3% ??? [46] 2.7% ??? [2] 1.1% ??? [17] 0.9% -------------------------------------------------------------------------- make-exacts* [32] 100.0% [41] 6830(5.0%) 0(0.0%) eval-prog ...mpling-logging/src/programs.rkt:148:0 hash-ref! [49] 100.0% -------------------------------------------------------------------------- substitute-e [42] 9.9% for-loop [33] 90.1% [42] 1626(1.2%) 0(0.0%) substitute-e ...g-logging/src/core/ematch.rkt:71:0 mk-enode! [47] 90.1% substitute-e [42] 9.9% -------------------------------------------------------------------------- merge-egraph-nodes! [43] 24.7% for-loop [33] 75.3% [43] 604(0.4%) 0(0.0%) merge-egraph-nodes! ...g/src/core/egraph.rkt:152:0 update-leader! [48] 75.3% merge-egraph-nodes! [43] 24.7% -------------------------------------------------------------------------- argmins [37] 100.0% [44] 330(0.2%) 0(0.0%) composed ...ollects/racket/private/list.rkt:321:16 errors [81] 100.0% -------------------------------------------------------------------------- match-e [39] 100.0% [45] 324(0.2%) 0(0.0%) for-loop ...ling-logging/src/core/ematch.rkt:65:37 match-e [39] 100.0% -------------------------------------------------------------------------- map [40] 15.1% loop [57] 84.9% [46] 2184(1.6%) 0(0.0%) ??? ...ket/collects/racket/private/list.rkt:323:18 hash-ref! [49] 94.8% map [40] 5.2% -------------------------------------------------------------------------- for-loop [33] 18.0% substitute-e [42] 82.0% [47] 1982(1.5%) 294(0.2%) mk-enode! ...ing-logging/src/core/egraph.rkt:101:0 new-enode [50] 85.2% -------------------------------------------------------------------------- merge-egraph-nodes! [43] 40.2% apply-match [27] 59.8% [48] 1502(1.1%) 0(0.0%) update-leader! ...ogging/src/core/egraph.rkt:217:0 for-loop [51] 100.0% -------------------------------------------------------------------------- localize-error [34] 3.2% ??? [46] 21.0% eval-prog [41] 22.5% loop [57] 53.3% [49] 9014(6.6%) 292(0.2%) hash-ref! ...racket/private/more-scheme.rkt:373:13 ??? [53] 53.3% bigfloat-hash [52] 21.7% parse-loop12 [54] 21.0% f6 [4] 3.2% -------------------------------------------------------------------------- mk-enode! [47] 100.0% [50] 1688(1.2%) 0(0.0%) new-enode ...pling-logging/src/core/enode.rkt:97:0 type-of-enode-expr [55] 100.0% -------------------------------------------------------------------------- update-leader! [48] 100.0% [51] 1502(1.1%) 0(0.0%) for-loop ...ling-logging/src/core/egraph.rkt:222:6 for-loop [56] 100.0% -------------------------------------------------------------------------- hash-ref! [49] 100.0% [52] 6538(4.8%) 0(0.0%) bigfloat-hash ...h/private/bigfloat/mpfr.rkt:165:0 bfcanonicalize [58] 64.2% sig+exp->bigfloat [59] 35.8% -------------------------------------------------------------------------- hash-ref! [49] 100.0% [53] 6134(4.5%) 0(0.0%) ??? ...bie/sampling-logging/src/programs.rkt:183:5 loop [57] 100.0% -------------------------------------------------------------------------- ??? [8] 27.1% hash-ref! [49] 72.9% [54] 2996(2.2%) 812(0.6%) parse-loop12 ...s/racket/match/compiler.rkt:418:15 loop [57] 71.4% loop [6] 1.5% -------------------------------------------------------------------------- new-enode [50] 100.0% [55] 1688(1.2%) 0(0.0%) type-of-enode-expr ...ging/src/core/enode.rkt:68:0 get-sigs [60] 100.0% -------------------------------------------------------------------------- for-loop [51] 100.0% [56] 1502(1.1%) 0(0.0%) for-loop ...ling-logging/src/core/egraph.rkt:223:8 hash-update! [61] 100.0% -------------------------------------------------------------------------- make-exacts* [32] 0.2% match-e [39] 0.3% parse-loop12 [54] 0.6% map [40] 0.6% ??? [53] 5.0% loop [57] 93.0% [57] 122738(90.0%) 348(0.3%) loop ...cket/collects/racket/private/map.rkt:25:19 loop [57] 93.0% hash-ref! [49] 5.0% ??? [2] 1.2% ??? [46] 0.6% bf-complex-mult [62] 0.0% ??? [17] 0.0% -------------------------------------------------------------------------- bigfloat-hash [52] 100.0% [58] 4200(3.1%) 3858(2.8%) bfcanonicalize .../private/bigfloat/mpfr.rkt:155:0 bigfloat->sig+exp [67] 8.1% -------------------------------------------------------------------------- bigfloat-hash [52] 100.0% [59] 2338(1.7%) 2338(1.7%) sig+exp->bigfloat ...ivate/bigfloat/mpfr.rkt:385:0 -------------------------------------------------------------------------- type-of-enode-expr [55] 100.0% [60] 1688(1.2%) 0(0.0%) get-sigs ...ampling-logging/src/type-check.rkt:5:0 ??? [66] 40.5% ??? [64] 21.1% ...gging/src/common.rkt:47:2 [68] 19.3% ??? [63] 19.1% -------------------------------------------------------------------------- for-loop [56] 100.0% [61] 1502(1.1%) 0(0.0%) hash-update! ...ket/private/more-scheme.rkt:362:13 ??? [65] 100.0% -------------------------------------------------------------------------- loop [57] 0.4% ??? [8] 99.6% [62] 93806(68.8%) 4436(3.3%) bf-complex-mult ...logging/src/bigcomplex.rkt:33:0 bf* [69] 56.5% ??? [80] 36.5% ...higher-order.rkt:346:33 [70] 2.3% -------------------------------------------------------------------------- get-sigs [60] 0.8% for-loop [36] 1.7% ??? [17] 18.9% simplify-alt [25] 36.5% ??? [63] 39.9% [63] 12836(9.4%) 1438(1.1%) ??? ...llects/racket/private/norm-define.rkt:53:83 ??? [63] 39.9% iterate-egraph!13 [3] 34.1% ??? [73] 6.3% loop [5] 5.7% return/no-unsupplied [74] 3.0% ??? [82] 1.6% -------------------------------------------------------------------------- choose-best-alt! [38] 16.0% get-sigs [60] 17.2% setup-prog [22] 66.8% [64] 2068(1.5%) 0(0.0%) ??? ...contract/private/arrow-val-first.rkt:357:18 make-alt-table [72] 66.8% hash-has-key? [76] 17.2% ??? [78] 16.0% -------------------------------------------------------------------------- hash-update! [61] 100.0% [65] 1502(1.1%) 0(0.0%) ??? ...sampling-logging/src/core/egraph.rkt:225:24 for-loop [71] 100.0% -------------------------------------------------------------------------- for-loop [36] 32.5% get-sigs [60] 67.5% [66] 1014(0.7%) 330(0.2%) ??? ...ts/racket/contract/private/arr-i.rkt:804:10 ??? [75] 35.5% for-loop [91] 32.0% -------------------------------------------------------------------------- bfcanonicalize [58] 100.0% [67] 342(0.3%) 0(0.0%) bigfloat->sig+exp ...ivate/bigfloat/mpfr.rkt:370:0 new-mpz [77] 100.0% -------------------------------------------------------------------------- get-sigs [60] 100.0% [68] 326(0.2%) 0(0.0%) ...gging/src/common.rkt:47:2 ...e/arr-i.rkt:906:19 ??? [79] 100.0% -------------------------------------------------------------------------- bf-complex-mult [62] 100.0% [69] 53044(38.9%) 336(0.2%) bf* ...ath/private/bigfloat/bigfloat-mpfr.rkt:95:0 ??? [80] 99.4% -------------------------------------------------------------------------- bf-complex-add [15] 26.5% bf-complex-mult [62] 73.5% [70] 2878(2.1%) 428(0.3%) ...higher-order.rkt:346:33 (unknown source) ??? [94] 85.1% -------------------------------------------------------------------------- ??? [65] 100.0% [71] 1502(1.1%) 896(0.7%) for-loop ...ing-logging/src/core/egraph.rkt:226:26 update-en-expr [83] 40.3% -------------------------------------------------------------------------- ??? [64] 100.0% [72] 1382(1.0%) 0(0.0%) make-alt-table ...ging/src/core/alt-table.rkt:32:0 errors [81] 100.0% -------------------------------------------------------------------------- ??? [63] 100.0% [73] 808(0.6%) 808(0.6%) ??? ...-racket/utils/simple-result-arrow.rkt:60:15 -------------------------------------------------------------------------- ??? [63] 100.0% [74] 382(0.3%) 382(0.3%) return/no-unsupplied ...ct/private/arr-i.rkt:533:0 -------------------------------------------------------------------------- ??? [66] 100.0% [75] 360(0.3%) 0(0.0%) ??? ...ects/racket/contract/private/hash.rkt:217:4 ??? [84] 100.0% -------------------------------------------------------------------------- ??? [64] 100.0% [76] 356(0.3%) 0(0.0%) hash-has-key? ...et/private/more-scheme.rkt:368:13 ??? [82] 100.0% -------------------------------------------------------------------------- bigfloat->sig+exp [67] 100.0% [77] 342(0.3%) 342(0.3%) new-mpz ...-lib/math/private/bigfloat/gmp.rkt:73:0 -------------------------------------------------------------------------- ??? [64] 100.0% [78] 330(0.2%) 0(0.0%) ??? ...ampling-logging/src/core/alt-table.rkt:54:0 ??? [17] 100.0% -------------------------------------------------------------------------- ...gging/src/common.rkt:47:2 [68] 100.0% [79] 326(0.2%) 326(0.2%) ??? ...s/racket/contract/private/arr-i.rkt:1268:39 -------------------------------------------------------------------------- bf-complex-add [15] 8.2% bf-complex-mult [62] 36.1% bf* [69] 55.6% [80] 94726(69.5%) 6372(4.7%) ??? ...-racket/utils/simple-result-arrow.rkt:39:12 bfmul [85] 84.9% bfneg [86] 8.4% -------------------------------------------------------------------------- composed [44] 19.3% make-alt-table [72] 80.7% [81] 1712(1.3%) 0(0.0%) errors ...ie/sampling-logging/src/points.rkt:228:0 for-loop [87] 100.0% -------------------------------------------------------------------------- hash-has-key? [76] 36.0% ??? [63] 64.0% [82] 990(0.7%) 312(0.2%) ??? ...ects/racket/contract/private/list.rkt:737:4 for-loop [88] 68.5% -------------------------------------------------------------------------- for-loop [71] 100.0% [83] 606(0.4%) 606(0.4%) update-en-expr ...ogging/src/core/egraph.rkt:211:0 -------------------------------------------------------------------------- ??? [75] 100.0% [84] 360(0.3%) 0(0.0%) ??? ...ects/racket/contract/private/list.rkt:169:2 ??? [89] 100.0% -------------------------------------------------------------------------- ??? [80] 100.0% [85] 80410(59.0%) 52650(38.6%) bfmul ...-lib/math/private/bigfloat/mpfr.rkt:819:4 ??? [90] 34.5% -------------------------------------------------------------------------- ??? [80] 100.0% [86] 7944(5.8%) 5668(4.2%) bfneg ...-lib/math/private/bigfloat/mpfr.rkt:616:4 ??? [90] 28.7% -------------------------------------------------------------------------- errors [81] 100.0% [87] 1712(1.3%) 0(0.0%) for-loop .../sampling-logging/src/points.rkt:231:4 ??? [2] 100.0% -------------------------------------------------------------------------- ??? [82] 100.0% [88] 678(0.5%) 0(0.0%) for-loop ...acket/contract/private/list.rkt:743:12 for-loop [91] 52.5% ??? [93] 47.5% -------------------------------------------------------------------------- ??? [84] 100.0% [89] 360(0.3%) 0(0.0%) ??? ...ects/racket/contract/private/list.rkt:678:5 for-loop [92] 100.0% -------------------------------------------------------------------------- bfneg [86] 7.6% bfmul [85] 92.4% [90] 30036(22.0%) 30036(22.0%) ??? .../share/racket/collects/ffi/unsafe.rkt:861:4 -------------------------------------------------------------------------- ??? [66] 47.6% for-loop [88] 52.4% [91] 680(0.5%) 0(0.0%) for-loop ...racket/contract/private/hash.rkt:239:6 ??? [94] 100.0% -------------------------------------------------------------------------- ??? [89] 100.0% [92] 360(0.3%) 0(0.0%) for-loop ...racket/contract/private/list.rkt:680:9 get/build-late-neg-projection [95]100.0% -------------------------------------------------------------------------- for-loop [88] 100.0% [93] 322(0.2%) 322(0.2%) ??? ...private/unconstrained-domain-arrow.rkt:74:4 -------------------------------------------------------------------------- for-loop [91] 21.7% ...higher-order.rkt:346:33 [70] 78.3% [94] 3130(2.3%) 2472(1.8%) ??? ...cts/racket/contract/private/list.rkt:187:10 ??? [98] 10.7% ??? [97] 10.4% -------------------------------------------------------------------------- for-loop [92] 100.0% [95] 360(0.3%) 0(0.0%) get/build-late-neg-projection ...te/guts.rkt:691:0 ??? [96] 100.0% -------------------------------------------------------------------------- get/build-late-neg-projection [95]100.0% [96] 360(0.3%) 360(0.3%) ??? ...cts/racket/contract/private/prop.rkt:314:12 -------------------------------------------------------------------------- ??? [94] 100.0% [97] 324(0.2%) 0(0.0%) ??? ...ects/racket/contract/private/list.rkt:686:7 ??? [98] 100.0% -------------------------------------------------------------------------- ??? [97] 29.0% ??? [94] 29.9% ??? [17] 41.1% [98] 1118(0.8%) 1118(0.8%) ??? ...ects/racket/contract/private/guts.rkt:644:8 --------------------------------------------------------------------------