Profiling results ----------------- Total cpu time observed: 48360ms (out of 49044ms) Number of samples taken: 120 (once every 403ms) (Hiding functions with self<1.0% and local<2.0%: 2 of 90 hidden) ======================================================================== Caller Idx Total Self Name+src Local% ms(pct) ms(pct) Callee ======================================================================== ??? [15] 100.0% [1] 47716(98.7%) 0(0.0%) profile-thunk16 ...t/pkgs/profile-lib/main.rkt:9:0 run [8] 100.0% ------------------------------------------------------------------------ for-loop [88] 1.0% loop [46] 99.0% [2] 33430(69.1%) 1792(3.7%) ??? ...s/herbie/alt-testing/src/programs.rkt:156:4 ??? [9] 75.2% ??? [10] 19.4% ------------------------------------------------------------------------ ->flonum [54] 100.0% [3] 3464(7.2%) 0(0.0%) iterate-egraph!13 ...g/src/core/simplify.rkt:105:0 one-iter [11] 91.1% map-enodes [14] 8.9% ------------------------------------------------------------------------ hash-ref! [51] 100.0% [4] 1084(2.2%) 0(0.0%) ??? ...s/herbie/alt-testing/src/programs.rkt:194:5 loop [46] 100.0% ------------------------------------------------------------------------ match-e [28] 100.0% [5] 728(1.5%) 0(0.0%) for-loop .../alt-testing/src/core/ematch.rkt:59:11 for-loop [12] 100.0% ------------------------------------------------------------------------ loop [73] 100.0% [6] 316(0.7%) 0(0.0%) ??? ...bie/alt-testing/src/core/localize.rkt:43:32 ??? [47] 100.0% ------------------------------------------------------------------------ loop [46] 100.0% [7] 310(0.6%) 0(0.0%) for-loop ...lt-testing/src/core/simplify.rkt:195:2 eval-const-expr [13] 100.0% ------------------------------------------------------------------------ profile-thunk16 [1] 100.0% [8] 47716(98.7%) 0(0.0%) run ...share/racket/pkgs/profile-lib/main.rkt:39:2 ??? [15] 100.0% ------------------------------------------------------------------------ ??? [2] 100.0% [9] 25144(52.0%) 6728(13.9%) ??? ...acket/collects/racket/private/kw.rkt:444:14 ??? [16] 55.8% ...higher-order.rkt:346:33 [19] 7.9% parse-loop145 [21] 3.9% ??? [22] 2.7% ??? [23] 1.3% ------------------------------------------------------------------------ ??? [2] 100.0% [10] 6494(13.4%) 0(0.0%) ??? ...contract/private/../../private/kw.rkt:761:9 real->bigfloat [17] 100.0% ------------------------------------------------------------------------ iterate-egraph!13 [3] 100.0% [11] 3154(6.5%) 0(0.0%) one-iter ...lt-testing/src/core/simplify.rkt:116:0 for-loop [18] 66.7% for-loop [20] 33.3% ------------------------------------------------------------------------ for-loop [5] 100.0% [12] 728(1.5%) 0(0.0%) for-loop .../alt-testing/src/core/ematch.rkt:65:37 match-e [28] 100.0% ------------------------------------------------------------------------ for-loop [7] 100.0% [13] 310(0.6%) 0(0.0%) eval-const-expr ...-testing/src/programs.rkt:168:0 f137 [55] 100.0% ------------------------------------------------------------------------ iterate-egraph!13 [3] 100.0% [14] 310(0.6%) 0(0.0%) map-enodes ...lt-testing/src/core/egraph.rkt:140:0 loop [46] 100.0% ------------------------------------------------------------------------ for-loop [48] 1.9% run [8] 48.4% [15] 48360(100.0%) 0(0.0%) ??? ...lects/racket/private/more-scheme.rkt:261:28 profile-thunk16 [1] 48.4% loop [29] 33.0% prepare-points [30] 8.5% run-improve50 [24] 6.9% ->flonum [54] 3.3% ------------------------------------------------------------------------ ??? [9] 100.0% [16] 14026(29.0%) 3642(7.5%) ??? ...-racket/utils/simple-result-arrow.rkt:39:12 bfdiv [25] 46.9% bfneg [26] 27.1% ------------------------------------------------------------------------ ??? [10] 100.0% [17] 6494(13.4%) 4832(10.0%) real->bigfloat .../private/bigfloat/mpfr.rkt:451:0 ??? [69] 25.6% ------------------------------------------------------------------------ one-iter [11] 100.0% [18] 2104(4.4%) 0(0.0%) for-loop ...lt-testing/src/core/simplify.rkt:166:2 for-loop [27] 100.0% ------------------------------------------------------------------------ ??? [9] 100.0% [19] 1984(4.1%) 346(0.7%) ...higher-order.rkt:346:33 (unknown source) ??? [70] 82.6% ------------------------------------------------------------------------ for-loop [20] 50.0% one-iter [11] 50.0% [20] 1050(2.2%) 0(0.0%) for-loop ...t-testing/src/core/simplify.rkt:126:12 for-loop [20] 50.0% match-e [28] 50.0% ------------------------------------------------------------------------ ??? [9] 100.0% [21] 992(2.1%) 992(2.1%) parse-loop145 .../racket/match/compiler.rkt:418:15 ------------------------------------------------------------------------ ??? [9] 100.0% [22] 684(1.4%) 684(1.4%) ??? ...rivate/unconstrained-domain-arrow.rkt:40:13 ------------------------------------------------------------------------ ??? [9] 100.0% [23] 328(0.7%) 0(0.0%) ??? ...ie/alt-testing/src/syntax/syntax.rkt:156:17 ??? [65] 100.0% ------------------------------------------------------------------------ ??? [15] 100.0% [24] 7624(15.8%) 0(0.0%) run-improve50 ...lt-testing/src/mainloop.rkt:225:0 for-loop [31] 45.4% loop [29] 28.3% ??? [77] 18.0% prepare-points [30] 8.3% ------------------------------------------------------------------------ ??? [16] 100.0% [25] 6584(13.6%) 6584(13.6%) bfdiv ...-lib/math/private/bigfloat/mpfr.rkt:819:4 ------------------------------------------------------------------------ ??? [16] 100.0% [26] 3800(7.9%) 2444(5.1%) bfneg ...-lib/math/private/bigfloat/mpfr.rkt:616:4 ??? [69] 35.7% ------------------------------------------------------------------------ for-loop [18] 100.0% [27] 2104(4.4%) 0(0.0%) for-loop ...t-testing/src/core/simplify.rkt:148:10 substitute-e [32] 50.1% mk-enode! [36] 32.5% merge-egraph-nodes! [33] 17.4% ------------------------------------------------------------------------ for-loop [12] 40.5% for-loop [20] 59.5% [28] 1050(2.2%) 322(0.7%) match-e ...ie/alt-testing/src/core/ematch.rkt:46:0 for-loop [5] 40.5% ??? [77] 28.9% ------------------------------------------------------------------------ run-improve50 [24] 6.3% ??? [15] 93.7% [29] 34056(70.4%) 0(0.0%) loop ...es/herbie/alt-testing/src/points.rkt:238:2 loop [34] 37.8% loop [39] 35.9% make-exacts* [40] 23.0% for-loop [37] 3.2% ------------------------------------------------------------------------ run-improve50 [24] 7.2% ??? [15] 92.8% [30] 8826(18.3%) 0(0.0%) prepare-points ...alt-testing/src/points.rkt:214:0 make-exacts* [40] 36.5% loop [39] 33.2% loop [34] 30.3% ------------------------------------------------------------------------ run-improve50 [24] 100.0% [31] 3464(7.2%) 0(0.0%) for-loop ...ie/alt-testing/src/mainloop.rkt:240:10 run-iter! [35] 100.0% ------------------------------------------------------------------------ for-loop [27] 100.0% [32] 1054(2.2%) 0(0.0%) substitute-e ...t-testing/src/core/ematch.rkt:71:0 mk-enode! [36] 100.0% ------------------------------------------------------------------------ for-loop [27] 100.0% [33] 366(0.8%) 0(0.0%) merge-egraph-nodes! ...g/src/core/egraph.rkt:153:0 for-loop [38] 100.0% ------------------------------------------------------------------------ prepare-points [30] 17.2% loop [29] 82.8% [34] 15568(32.2%) 0(0.0%) loop ...es/herbie/alt-testing/src/points.rkt:158:2 loop [39] 57.9% make-exacts* [40] 40.2% ------------------------------------------------------------------------ for-loop [31] 100.0% [35] 3464(7.2%) 0(0.0%) run-iter! ...ie/alt-testing/src/mainloop.rkt:206:0 simplify! [41] 81.4% finalize-iter! [44] 9.5% localize-error [45] 9.1% ------------------------------------------------------------------------ for-loop [27] 39.4% substitute-e [32] 60.6% [36] 1738(3.6%) 0(0.0%) mk-enode! ...alt-testing/src/core/egraph.rkt:102:0 new-enode [42] 100.0% ------------------------------------------------------------------------ loop [29] 100.0% [37] 1100(2.3%) 0(0.0%) for-loop ...rbie/alt-testing/src/points.rkt:255:26 ??? [43] 100.0% ------------------------------------------------------------------------ merge-egraph-nodes! [33] 100.0% [38] 366(0.8%) 366(0.8%) for-loop .../alt-testing/src/core/egraph.rkt:233:6 ------------------------------------------------------------------------ prepare-points [30] 12.1% loop [34] 37.3% loop [29] 50.6% [39] 24172(50.0%) 326(0.7%) loop ...es/herbie/alt-testing/src/points.rkt:141:4 loop [46] 98.7% ------------------------------------------------------------------------ prepare-points [30] 18.6% loop [34] 36.1% loop [29] 45.3% [40] 17312(35.8%) 370(0.8%) make-exacts* ...e/alt-testing/src/points.rkt:138:0 loop [46] 81.9% eval-prog [49] 15.9% ------------------------------------------------------------------------ run-iter! [35] 100.0% [41] 2820(5.8%) 0(0.0%) simplify! ...ie/alt-testing/src/mainloop.rkt:146:0 for-loop [48] 100.0% ------------------------------------------------------------------------ mk-enode! [36] 100.0% [42] 1738(3.6%) 0(0.0%) new-enode ...e/alt-testing/src/core/enode.rkt:97:0 type-of-enode-expr [50] 100.0% ------------------------------------------------------------------------ for-loop [37] 100.0% [43] 1100(2.3%) 0(0.0%) ??? ...ies/herbie/alt-testing/src/points.rkt:230:7 ??? [47] 100.0% ------------------------------------------------------------------------ run-iter! [35] 100.0% [44] 328(0.7%) 0(0.0%) finalize-iter! ...t-testing/src/mainloop.rkt:160:0 ??? [77] 100.0% ------------------------------------------------------------------------ run-iter! [35] 100.0% [45] 316(0.7%) 0(0.0%) localize-error ...sting/src/core/localize.rkt:47:0 hash-ref! [51] 100.0% ------------------------------------------------------------------------ map-enodes [14] 0.4% make-exacts* [40] 0.7% ??? [4] 2.7% loop [39] 3.1% loop [46] 93.1% [46] 39422(81.5%) 1368(2.8%) loop ...cket/collects/racket/private/map.rkt:25:19 loop [46] 93.1% ??? [2] 3.5% hash-ref! [51] 2.7% for-loop [7] 0.4% ??? [47] 0.2% ------------------------------------------------------------------------ ??? [6] 5.6% f137 [55] 11.3% ??? [43] 19.6% loop [46] 63.4% [47] 5610(11.6%) 1434(3.0%) ??? ...tract/private/arrow-higher-order.rkt:342:33 ->flonum [54] 63.1% ??? [76] 11.3% ------------------------------------------------------------------------ simplify! [41] 100.0% [48] 2820(5.8%) 0(0.0%) for-loop ...bie/alt-testing/src/mainloop.rkt:150:6 ??? [15] 100.0% ------------------------------------------------------------------------ make-exacts* [40] 100.0% [49] 2760(5.7%) 688(1.4%) eval-prog ...ie/alt-testing/src/programs.rkt:150:0 hash-ref! [51] 39.3% f137 [55] 23.0% parse-lambda [53] 12.8% ------------------------------------------------------------------------ new-enode [42] 100.0% [50] 1738(3.6%) 350(0.7%) type-of-enode-expr ...ting/src/core/enode.rkt:68:0 get-sigs [52] 79.9% ------------------------------------------------------------------------ ??? [74] 11.3% localize-error [45] 11.3% eval-prog [49] 24.1% loop [46] 53.3% [51] 1400(2.9%) 0(0.0%) hash-ref! ...racket/private/more-scheme.rkt:373:13 ??? [4] 53.3% bigfloat-hash [56] 24.1% f137 [55] 22.6% ------------------------------------------------------------------------ type-of-enode-expr [50] 100.0% [52] 1388(2.9%) 0(0.0%) get-sigs ...bie/alt-testing/src/type-check.rkt:5:0 ??? [57] 50.7% ...sting/src/common.rkt:47:2 [64] 25.2% ->flonum [54] 24.1% ------------------------------------------------------------------------ eval-prog [49] 100.0% [53] 352(0.7%) 0(0.0%) parse-lambda ...llects/racket/private/kw.rkt:437:2 loop [58] 100.0% ------------------------------------------------------------------------ get-sigs [52] 1.6% ->flonum [54] 2.2% for-loop [59] 21.7% ??? [15] 23.9% ??? [47] 50.5% [54] 7004(14.5%) 1452(3.0%) ->flonum ...s/racket/private/norm-define.rkt:53:83 iterate-egraph!13 [3] 23.9% for-loop [59] 21.7% ??? [60] 10.3% return/no-unsupplied [63] 9.5% loop [67] 5.5% ??? [65] 4.5% ->flonum [54] 2.2% ??? [82] 1.6% ------------------------------------------------------------------------ eval-const-expr [13] 24.6% hash-ref! [51] 25.0% eval-prog [49] 50.4% [55] 1262(2.6%) 0(0.0%) f137 .../collects/racket/match/compiler.rkt:507:40 ??? [47] 50.4% map [68] 25.0% ...sting/src/common.rkt:47:2 [64] 24.6% ------------------------------------------------------------------------ hash-ref! [51] 100.0% [56] 1084(2.2%) 0(0.0%) bigfloat-hash ...h/private/bigfloat/mpfr.rkt:165:0 sig+exp->bigfloat [62] 64.0% bfcanonicalize [66] 36.0% ------------------------------------------------------------------------ get-sigs [52] 100.0% [57] 704(1.5%) 0(0.0%) ??? ...ts/racket/contract/private/arr-i.rkt:804:10 for-loop [61] 100.0% ------------------------------------------------------------------------ parse-lambda [53] 33.3% loop [58] 66.7% [58] 352(0.7%) 352(0.7%) loop .../collects/racket/private/stxcase.rkt:112:7 loop [58] 66.7% ------------------------------------------------------------------------ ->flonum [54] 100.0% [59] 3154(6.5%) 0(0.0%) for-loop ...lt-testing/src/core/simplify.rkt:66:12 ->flonum [54] 100.0% ------------------------------------------------------------------------ ->flonum [54] 100.0% [60] 722(1.5%) 0(0.0%) ??? ...-racket/utils/simple-result-arrow.rkt:60:15 ??? [69] 100.0% ------------------------------------------------------------------------ ??? [57] 100.0% [61] 704(1.5%) 0(0.0%) for-loop ...racket/contract/private/hash.rkt:239:6 ??? [70] 100.0% ------------------------------------------------------------------------ bigfloat-hash [56] 100.0% [62] 694(1.4%) 694(1.4%) sig+exp->bigfloat ...ivate/bigfloat/mpfr.rkt:385:0 ------------------------------------------------------------------------ ->flonum [54] 100.0% [63] 668(1.4%) 668(1.4%) return/no-unsupplied ...ct/private/arr-i.rkt:533:0 ------------------------------------------------------------------------ f137 [55] 47.0% get-sigs [52] 53.0% [64] 660(1.4%) 660(1.4%) ...sting/src/common.rkt:47:2 ...e/arr-i.rkt:906:19 ------------------------------------------------------------------------ ->flonum [54] 49.1% ??? [23] 50.9% [65] 644(1.3%) 328(0.7%) ??? ...racket/collects/racket/private/kw.rkt:761:9 ??? [72] 49.1% ------------------------------------------------------------------------ bigfloat-hash [56] 100.0% [66] 390(0.8%) 390(0.8%) bfcanonicalize .../private/bigfloat/mpfr.rkt:155:0 ------------------------------------------------------------------------ ->flonum [54] 100.0% [67] 382(0.8%) 0(0.0%) loop ...ies/herbie/alt-testing/src/points.rkt:66:6 random-exp [71] 100.0% ------------------------------------------------------------------------ f137 [55] 100.0% [68] 316(0.7%) 0(0.0%) map ...acket/collects/racket/private/map.rkt:20:13 ??? [74] 50.0% loop [73] 50.0% ------------------------------------------------------------------------ ??? [60] 19.3% bfneg [26] 36.3% real->bigfloat [17] 44.4% [69] 3740(7.7%) 3740(7.7%) ??? .../share/racket/collects/ffi/unsafe.rkt:861:4 ------------------------------------------------------------------------ for-loop [61] 30.1% ...higher-order.rkt:346:33 [19] 69.9% [70] 2342(4.8%) 1282(2.7%) ??? ...cts/racket/contract/private/list.rkt:187:10 ??? [75] 30.1% ??? [76] 15.2% ------------------------------------------------------------------------ loop [67] 100.0% [71] 382(0.8%) 382(0.8%) random-exp ...bie/alt-testing/src/common.rkt:253:0 ------------------------------------------------------------------------ ??? [65] 100.0% [72] 316(0.7%) 316(0.7%) ??? ...s/racket/contract/private/arr-i.rkt:1233:27 ------------------------------------------------------------------------ map [68] 12.5% loop [73] 87.5% [73] 316(0.7%) 0(0.0%) loop ...cket/collects/racket/private/map.rkt:36:19 loop [73] 87.5% ??? [6] 12.5% ------------------------------------------------------------------------ map [68] 100.0% [74] 316(0.7%) 0(0.0%) ??? ...ket/collects/racket/private/list.rkt:323:18 hash-ref! [51] 100.0% ------------------------------------------------------------------------ ??? [70] 100.0% [75] 704(1.5%) 0(0.0%) ??? ...ects/racket/contract/private/list.rkt:686:7 ??? [76] 100.0% ------------------------------------------------------------------------ ??? [70] 21.0% ??? [47] 37.5% ??? [75] 41.5% [76] 1696(3.5%) 1060(2.2%) ??? ...ects/racket/contract/private/guts.rkt:644:8 ??? [77] 37.5% ------------------------------------------------------------------------ finalize-iter! [44] 10.7% ??? [76] 20.8% match-e [28] 23.8% run-improve50 [24] 44.7% [77] 3062(6.3%) 728(1.5%) ??? ...contract/private/arrow-val-first.rkt:357:18 atab-add-altns [78] 44.7% hash-has-key? [79] 20.8% for-loop [80] 10.7% ------------------------------------------------------------------------ ??? [77] 100.0% [78] 1370(2.8%) 0(0.0%) atab-add-altns ...ting/src/core/alt-table.rkt:51:0 atab-add-altn [81] 100.0% ------------------------------------------------------------------------ ??? [77] 100.0% [79] 636(1.3%) 0(0.0%) hash-has-key? ...et/private/more-scheme.rkt:368:13 ??? [82] 100.0% ------------------------------------------------------------------------ ??? [77] 100.0% [80] 328(0.7%) 0(0.0%) for-loop ...lt-testing/src/core/alt-table.rkt:52:2 atab-add-altn [81] 100.0% ------------------------------------------------------------------------ for-loop [80] 19.3% atab-add-altns [78] 80.7% [81] 1698(3.5%) 0(0.0%) atab-add-altn ...ting/src/core/alt-table.rkt:243:0 best-and-tied-at-points [83] 100.0% ------------------------------------------------------------------------ ->flonum [54] 34.4% hash-has-key? [79] 65.6% [82] 970(2.0%) 0(0.0%) ??? ...ects/racket/contract/private/list.rkt:737:4 for-loop [84] 100.0% ------------------------------------------------------------------------ atab-add-altn [81] 100.0% [83] 1698(3.5%) 1370(2.8%) best-and-tied-at-points ...ore/alt-table.rkt:157:0 errors [86] 19.3% ------------------------------------------------------------------------ ??? [82] 100.0% [84] 970(2.0%) 334(0.7%) for-loop ...acket/contract/private/list.rkt:743:12 ??? [85] 65.6% ------------------------------------------------------------------------ for-loop [84] 100.0% [85] 636(1.3%) 0(0.0%) ??? ...ects/racket/contract/private/hash.rkt:222:6 check-hash/c [87] 100.0% ------------------------------------------------------------------------ best-and-tied-at-points [83] 100.0% [86] 328(0.7%) 0(0.0%) errors .../herbie/alt-testing/src/points.rkt:271:0 for-loop [88] 100.0% ------------------------------------------------------------------------ ??? [85] 100.0% [87] 636(1.3%) 636(1.3%) check-hash/c ...ket/contract/private/hash.rkt:83:0 ------------------------------------------------------------------------ errors [86] 100.0% [88] 328(0.7%) 0(0.0%) for-loop ...erbie/alt-testing/src/points.rkt:274:4 ??? [2] 100.0% ------------------------------------------------------------------------