Profiling results ----------------- Total cpu time observed: 166462ms (out of 167020ms) Number of samples taken: 541 (once every 308ms) (Hiding functions with self<1.0% and local<2.0%: 4 of 92 hidden) ===================================================================== Caller Idx Total Self Name+src Local% ms(pct) ms(pct) Callee ===================================================================== ??? [4] 100.0% [1] 166462(100.0%) 0(0.0%) profile-thunk16 ...e/pkgs/profile-lib/main.rkt:9:0 run [3] 100.0% --------------------------------------------------------------------- substitute-e [35] 14.8% match-e [31] 85.2% [2] 2450(1.5%) 0(0.0%) variable? .../develop/src/syntax/syntax.rkt:1159:0 ??? [40] 100.0% --------------------------------------------------------------------- profile-thunk16 [1] 100.0% [3] 166462(100.0%) 0(0.0%) run ...et-7.0/share/pkgs/profile-lib/main.rkt:39:2 ??? [4] 100.0% --------------------------------------------------------------------- for-loop [88] 0.1% run [3] 49.9% [4] 166462(100.0%) 0(0.0%) ??? ...lects/racket/private/more-scheme.rkt:261:28 profile-thunk16 [1] 49.9% run-improve40 [5] 49.0% prepare-points-intervals [6] 0.7% oracle-error [7] 0.1% eval-errors [8] 0.1% ulp-difference [70] 0.1% errors [87] 0.1% ??? [18] 0.1% --------------------------------------------------------------------- ??? [4] 100.0% [5] 163320(98.1%) 0(0.0%) run-improve40 ...ie/develop/src/mainloop.rkt:336:0 simplify! [9] 99.8% for-loop [11] 0.2% --------------------------------------------------------------------- ??? [4] 100.0% [6] 2204(1.3%) 0(0.0%) prepare-points-intervals ...p/src/points.rkt:133:0 loop [10] 100.0% --------------------------------------------------------------------- ??? [4] 100.0% [7] 312(0.2%) 0(0.0%) oracle-error ...erbie/develop/src/points.rkt:212:0 for-loop [12] 100.0% --------------------------------------------------------------------- ??? [4] 100.0% [8] 306(0.2%) 0(0.0%) eval-errors ...herbie/develop/src/points.rkt:203:0 for-loop [13] 100.0% --------------------------------------------------------------------- run-improve40 [5] 100.0% [9] 162968(97.9%) 0(0.0%) simplify! ...herbie/develop/src/mainloop.rkt:213:0 ??? [14] 100.0% --------------------------------------------------------------------- prepare-points-intervals [6]100.0% [10] 2204(1.3%) 0(0.0%) loop ...htlies/herbie/develop/src/points.rkt:145:4 loop [15] 100.0% --------------------------------------------------------------------- run-improve40 [5] 100.0% [11] 352(0.2%) 0(0.0%) for-loop .../herbie/develop/src/mainloop.rkt:351:4 run-iter! [16] 100.0% --------------------------------------------------------------------- oracle-error [7] 100.0% [12] 312(0.2%) 0(0.0%) for-loop ...es/herbie/develop/src/points.rkt:213:2 loop [46] 100.0% --------------------------------------------------------------------- eval-errors [8] 100.0% [13] 306(0.2%) 0(0.0%) for-loop ...es/herbie/develop/src/points.rkt:205:2 ??? [60] 100.0% --------------------------------------------------------------------- simplify! [9] 100.0% [14] 162968(97.9%) 0(0.0%) ??? ...s/herbie/develop/src/core/simplify.rkt:26:0 for-loop [17] 100.0% --------------------------------------------------------------------- loop [10] 100.0% [15] 2204(1.3%) 0(0.0%) loop ...htlies/herbie/develop/src/points.rkt:104:2 ??? [18] 100.0% --------------------------------------------------------------------- for-loop [11] 100.0% [16] 352(0.2%) 0(0.0%) run-iter! ...herbie/develop/src/mainloop.rkt:317:0 choose-best-alt! [19] 100.0% --------------------------------------------------------------------- ??? [14] 100.0% [17] 162968(97.9%) 302(0.2%) for-loop ...bie/develop/src/core/simplify.rkt:33:2 one-iter [20] 99.8% --------------------------------------------------------------------- ??? [4] 12.7% loop [15] 87.3% [18] 2524(1.5%) 288(0.2%) ??? ...tlies/herbie/develop/src/programs.rkt:146:2 ??? [21] 51.1% ??? [60] 37.5% --------------------------------------------------------------------- run-iter! [16] 100.0% [19] 352(0.2%) 0(0.0%) choose-best-alt! ...develop/src/mainloop.rkt:107:0 ??? [40] 100.0% --------------------------------------------------------------------- for-loop [17] 100.0% [20] 162666(97.7%) 0(0.0%) one-iter ...bie/develop/src/core/simplify.rkt:86:0 for-loop [22] 88.0% find-matches [23] 12.0% --------------------------------------------------------------------- ??? [18] 100.0% [21] 1290(0.8%) 0(0.0%) ??? ...t-7.0/collects/racket/private/kw.rkt:592:14 ??? [24] 100.0% --------------------------------------------------------------------- one-iter [20] 100.0% [22] 143222(86.0%) 0(0.0%) for-loop ...bie/develop/src/core/simplify.rkt:95:2 loop [25] 100.0% --------------------------------------------------------------------- one-iter [20] 100.0% [23] 19444(11.7%) 0(0.0%) find-matches ...develop/src/core/simplify.rkt:56:0 for-loop [26] 100.0% --------------------------------------------------------------------- ??? [21] 100.0% [24] 1290(0.8%) 0(0.0%) ??? ...tract/private/arrow-higher-order.rkt:361:33 ival-add [27] 100.0% --------------------------------------------------------------------- loop [25] 0.5% for-loop [22] 99.5% [25] 143222(86.0%) 0(0.0%) loop ...herbie/develop/src/core/simplify.rkt:100:4 apply-match [28] 99.5% loop [25] 0.5% --------------------------------------------------------------------- for-loop [26] 50.0% find-matches [23] 50.0% [26] 19444(11.7%) 2702(1.6%) for-loop ...bie/develop/src/core/simplify.rkt:58:8 for-loop [26] 50.0% match-e [31] 43.1% --------------------------------------------------------------------- ??? [24] 100.0% [27] 1290(0.8%) 0(0.0%) ival-add ...erbie/develop/src/biginterval.rkt:96:0 bfadd [29] 100.0% --------------------------------------------------------------------- loop [25] 100.0% [28] 143222(86.0%) 0(0.0%) apply-match .../develop/src/core/simplify.rkt:65:0 for-loop [30] 91.8% match-e [31] 6.5% set [49] 1.5% --------------------------------------------------------------------- ival-add [27] 100.0% [29] 1290(0.8%) 332(0.2%) bfadd ...-lib/math/private/bigfloat/mpfr.rkt:821:4 ??? [32] 51.2% new-mpfr [82] 23.1% --------------------------------------------------------------------- apply-match [28] 100.0% [30] 131436(79.0%) 322(0.2%) for-loop ...bie/develop/src/core/simplify.rkt:78:2 merge-egraph-nodes! [33] 63.0% dedup-children! [38] 34.5% substitute-e [35] 2.1% mk-enode! [51] 0.3% --------------------------------------------------------------------- apply-match [28] 24.7% for-loop [39] 24.9% for-loop [26] 50.4% [31] 26082(15.7%) 4888(2.9%) match-e ...herbie/develop/src/core/ematch.rkt:39:0 for-loop [34] 77.5% variable? [2] 3.5% make-sequence [36] 2.3% ??? [40] 1.8% --------------------------------------------------------------------- bfadd [29] 100.0% [32] 660(0.4%) 660(0.4%) ??? /opt/racket-7.0/collects/ffi/unsafe.rkt:898:4 --------------------------------------------------------------------- merge-egraph-nodes! [33] 2.2% for-loop [30] 97.6% [33] 82748(49.7%) 276(0.2%) merge-egraph-nodes! ...p/src/core/egraph.rkt:145:0 loop! [37] 91.6% update-leader! [42] 2.7% dedup-children! [38] 2.3% merge-egraph-nodes! [33] 2.2% enode-merge! [44] 0.7% --------------------------------------------------------------------- match-e [31] 100.0% [34] 22474(13.5%) 12746(7.7%) for-loop ...rbie/develop/src/core/ematch.rkt:52:11 for-loop [39] 43.8% cartesian-product [43] 3.4% loop [46] 2.7% foldr [45] 2.0% foldl [62] 1.3% --------------------------------------------------------------------- for-loop [41] 27.0% for-loop [30] 73.0% [35] 2724(1.6%) 306(0.2%) substitute-e ...e/develop/src/core/ematch.rkt:64:0 for-loop [41] 80.5% ??? [40] 9.1% variable? [2] 6.6% --------------------------------------------------------------------- match-e [31] 100.0% [36] 600(0.4%) 600(0.4%) make-sequence ...ects/racket/private/for.rkt:528:2 --------------------------------------------------------------------- loop [46] 34.3% merge-egraph-nodes! [33] 65.7% [37] 77774(46.7%) 13894(8.3%) loop! ...s/herbie/develop/src/core/enode.rkt:191:2 custom-set-union [48] 39.0% loop [46] 38.3% set [49] 11.2% update-en-expr [86] 2.8% --------------------------------------------------------------------- merge-egraph-nodes! [33] 4.0% for-loop [30] 96.0% [38] 47182(28.3%) 0(0.0%) dedup-children! ...evelop/src/core/enode.rkt:199:0 loop [47] 100.0% --------------------------------------------------------------------- for-loop [34] 100.0% [39] 12926(7.8%) 1228(0.7%) for-loop ...rbie/develop/src/core/ematch.rkt:58:37 match-e [31] 91.8% ??? [56] 2.2% --------------------------------------------------------------------- choose-best-alt! [19] 7.6% substitute-e [35] 12.8% match-e [31] 27.1% variable? [2] 52.6% [40] 4662(2.8%) 4310(2.6%) ??? ...contract/private/arrow-val-first.rkt:388:18 ??? [53] 7.6% --------------------------------------------------------------------- substitute-e [35] 100.0% [41] 2724(1.6%) 302(0.2%) for-loop ...rbie/develop/src/core/ematch.rkt:73:24 substitute-e [35] 46.5% mk-enode! [51] 42.4% --------------------------------------------------------------------- merge-egraph-nodes! [33] 100.0% [42] 2222(1.3%) 330(0.2%) update-leader! ...evelop/src/core/egraph.rkt:213:0 for-loop [50] 71.4% for-loop [54] 13.8% --------------------------------------------------------------------- for-loop [34] 100.0% [43] 924(0.6%) 924(0.6%) cartesian-product ...ollects/racket/list.rkt:822:0 --------------------------------------------------------------------- merge-egraph-nodes! [33] 100.0% [44] 600(0.4%) 300(0.2%) enode-merge! ...e/develop/src/core/enode.rkt:128:0 adopt-enode! [55] 50.0% --------------------------------------------------------------------- for-loop [34] 100.0% [45] 584(0.4%) 0(0.0%) foldr ....0/collects/racket/private/list.rkt:242:4 cp-2 [52] 100.0% --------------------------------------------------------------------- for-loop [34] 0.4% for-loop [12] 0.6% loop! [37] 5.7% loop [46] 93.3% [46] 53202(32.0%) 3486(2.1%) loop ...-7.0/collects/racket/private/map.rkt:40:19 loop [46] 93.3% loop! [37] 5.5% point-error [64] 0.6% foldl [62] 0.1% --------------------------------------------------------------------- dedup-children! [38] 9.1% loop [47] 90.9% [47] 47182(28.3%) 47182(28.3%) loop ...racket-7.0/collects/racket/list.rkt:434:17 loop [47] 90.9% --------------------------------------------------------------------- loop! [37] 100.0% [48] 36636(22.0%) 12060(7.2%) custom-set-union ...et/private/set-types.rkt:168:0 for-loop [57] 56.4% for-loop [58] 10.6% --------------------------------------------------------------------- apply-match [28] 9.8% loop! [37] 90.2% [49] 21608(13.0%) 19822(11.9%) set ...collects/racket/private/set-types.rkt:981:0 for-loop [59] 8.3% --------------------------------------------------------------------- update-leader! [42] 100.0% [50] 1586(1.0%) 0(0.0%) for-loop ...rbie/develop/src/core/egraph.rkt:218:6 hash-update! [69] 80.2% for-loop [63] 19.8% --------------------------------------------------------------------- for-loop [30] 22.5% for-loop [41] 77.5% [51] 1492(0.9%) 900(0.5%) mk-enode! ...rbie/develop/src/core/egraph.rkt:99:0 hash-has-key? [65] 20.1% new-enode [66] 19.6% --------------------------------------------------------------------- foldr [45] 100.0% [52] 584(0.4%) 0(0.0%) cp-2 .../racket-7.0/collects/racket/list.rkt:826:2 for-loop [61] 100.0% --------------------------------------------------------------------- ??? [40] 100.0% [53] 352(0.2%) 0(0.0%) ??? .../herbie/develop/src/core/alt-table.rkt:59:0 ??? [60] 100.0% --------------------------------------------------------------------- update-leader! [42] 100.0% [54] 306(0.2%) 306(0.2%) for-loop ...rbie/develop/src/core/egraph.rkt:228:6 --------------------------------------------------------------------- enode-merge! [44] 100.0% [55] 300(0.2%) 300(0.2%) adopt-enode! ...e/develop/src/core/enode.rkt:104:0 --------------------------------------------------------------------- for-loop [39] 100.0% [56] 282(0.2%) 0(0.0%) ??? ...ies/herbie/develop/src/core/ematch.rkt:43:5 for-loop [67] 100.0% --------------------------------------------------------------------- custom-set-union [48] 100.0% [57] 20680(12.4%) 4170(2.5%) for-loop ...cts/racket/private/set-types.rkt:174:3 for-loop [68] 79.8% --------------------------------------------------------------------- custom-set-union [48] 100.0% [58] 3896(2.3%) 3896(2.3%) for-loop ...cts/racket/private/set-types.rkt:152:2 --------------------------------------------------------------------- set [49] 100.0% [59] 1786(1.1%) 1786(1.1%) for-loop ...cts/racket/private/set-types.rkt:937:4 --------------------------------------------------------------------- for-loop [13] 19.1% ??? [53] 21.9% ??? [18] 59.0% [60] 1604(1.0%) 320(0.2%) ??? ...tract/private/arrow-higher-order.rkt:357:33 mk-ival [71] 39.0% best-alt [72] 21.9% ->flonum [73] 19.1% --------------------------------------------------------------------- cp-2 [52] 100.0% [61] 584(0.4%) 584(0.4%) for-loop ...ket-7.0/collects/racket/list.rkt:827:4 --------------------------------------------------------------------- loop [46] 45.6% for-loop [34] 54.4% [62] 540(0.3%) 294(0.2%) foldl ....0/collects/racket/private/list.rkt:229:4 merge2 [75] 45.6% --------------------------------------------------------------------- for-loop [50] 100.0% [63] 314(0.2%) 0(0.0%) for-loop ...rbie/develop/src/core/egraph.rkt:219:8 hash-update! [69] 100.0% --------------------------------------------------------------------- loop [46] 100.0% [64] 312(0.2%) 0(0.0%) point-error ...herbie/develop/src/points.rkt:195:0 ulp-difference [70] 100.0% --------------------------------------------------------------------- mk-enode! [51] 100.0% [65] 300(0.2%) 300(0.2%) hash-has-key? ...ket/private/more-scheme.rkt:371:2 --------------------------------------------------------------------- mk-enode! [51] 100.0% [66] 292(0.2%) 0(0.0%) new-enode ...erbie/develop/src/core/enode.rkt:96:0 type-of-enode-expr [74] 100.0% --------------------------------------------------------------------- ??? [56] 100.0% [67] 282(0.2%) 282(0.2%) for-loop ...erbie/develop/src/core/ematch.rkt:44:7 --------------------------------------------------------------------- for-loop [57] 100.0% [68] 16510(9.9%) 16510(9.9%) for-loop ...cts/racket/private/set-types.rkt:178:5 --------------------------------------------------------------------- for-loop [63] 19.8% for-loop [50] 80.2% [69] 1586(1.0%) 0(0.0%) hash-update! ...cket/private/more-scheme.rkt:365:4 ??? [76] 100.0% --------------------------------------------------------------------- point-error [64] 47.0% ??? [4] 53.0% [70] 664(0.4%) 312(0.2%) ulp-difference ...erbie/develop/src/float.rkt:14:0 return/no-unsupplied [78] 53.0% --------------------------------------------------------------------- ??? [60] 100.0% [71] 626(0.4%) 0(0.0%) mk-ival ...herbie/develop/src/biginterval.rkt:59:0 bf [77] 100.0% --------------------------------------------------------------------- ??? [60] 100.0% [72] 352(0.2%) 0(0.0%) best-alt .../herbie/develop/src/mainloop.rkt:102:0 argmins [79] 100.0% --------------------------------------------------------------------- ??? [60] 100.0% [73] 306(0.2%) 306(0.2%) ->flonum ...s/herbie/develop/src/programs.rkt:38:0 --------------------------------------------------------------------- new-enode [66] 100.0% [74] 292(0.2%) 0(0.0%) type-of-enode-expr ...elop/src/core/enode.rkt:69:0 table-ref [80] 100.0% --------------------------------------------------------------------- foldl [62] 100.0% [75] 246(0.1%) 246(0.1%) merge2 .../herbie/develop/src/core/ematch.rkt:24:0 --------------------------------------------------------------------- hash-update! [69] 100.0% [76] 1586(1.0%) 0(0.0%) ??? ...s/herbie/develop/src/core/egraph.rkt:221:24 for-loop [81] 100.0% --------------------------------------------------------------------- mk-ival [71] 100.0% [77] 626(0.4%) 0(0.0%) bf ...ath-lib/math/private/bigfloat/mpfr.rkt:601:2 new-mpfr [82] 100.0% --------------------------------------------------------------------- ulp-difference [70] 100.0% [78] 352(0.2%) 0(0.0%) return/no-unsupplied ...ct/private/arr-i.rkt:534:0 filter [83] 100.0% --------------------------------------------------------------------- best-alt [72] 100.0% [79] 352(0.2%) 0(0.0%) argmins ...lies/herbie/develop/src/common.rkt:93:0 ??? [84] 100.0% --------------------------------------------------------------------- type-of-enode-expr [74] 100.0% [80] 292(0.2%) 0(0.0%) table-ref ...es/herbie/develop/src/common.rkt:42:0 dict? [85] 100.0% --------------------------------------------------------------------- ??? [76] 100.0% [81] 1586(1.0%) 1292(0.8%) for-loop ...bie/develop/src/core/egraph.rkt:222:26 update-en-expr [86] 18.5% --------------------------------------------------------------------- bfadd [29] 32.3% bf [77] 67.7% [82] 924(0.6%) 924(0.6%) new-mpfr ...b/math/private/bigfloat/mpfr.rkt:335:0 --------------------------------------------------------------------- return/no-unsupplied [78] 100.0% [83] 352(0.2%) 352(0.2%) filter ...0/collects/racket/private/list.rkt:256:2 --------------------------------------------------------------------- argmins [79] 100.0% [84] 352(0.2%) 0(0.0%) ??? ...lies/herbie/develop/src/mainloop.rkt:104:19 errors [87] 100.0% --------------------------------------------------------------------- table-ref [80] 100.0% [85] 292(0.2%) 292(0.2%) dict? ...ollects/racket/private/generic.rkt:146:11 --------------------------------------------------------------------- for-loop [81] 6.0% loop! [37] 94.0% [86] 4914(3.0%) 4914(3.0%) update-en-expr ...evelop/src/core/egraph.rkt:207:0 --------------------------------------------------------------------- ??? [4] 47.6% ??? [84] 52.4% [87] 672(0.4%) 0(0.0%) errors ...lies/herbie/develop/src/points.rkt:228:0 for-loop [88] 100.0% --------------------------------------------------------------------- errors [87] 100.0% [88] 672(0.4%) 0(0.0%) for-loop ...es/herbie/develop/src/points.rkt:230:2 ??? [4] 100.0% ---------------------------------------------------------------------