Profiling results ----------------- Total cpu time observed: 12694ms (out of 13100ms) Number of samples taken: 97 (once every 131ms) (Hiding functions with self<1.0% and local<2.0%: 2 of 60 hidden) ====================================================================== Caller Idx Total Self Name+src Local% ms(pct) ms(pct) Callee ====================================================================== ??? [5] 100.0% [1] 12694(100.0%) 0(0.0%) profile-thunk16 ...t/pkgs/profile-lib/main.rkt:9:0 run [3] 100.0% ---------------------------------------------------------------------- match-e [29] 100.0% [2] 74(0.6%) 0(0.0%) for-loop ...tlock/herbie/src/core/ematch.rkt:59:11 for-loop [4] 100.0% ---------------------------------------------------------------------- profile-thunk16 [1] 100.0% [3] 12694(100.0%) 0(0.0%) run ...share/racket/pkgs/profile-lib/main.rkt:39:2 ??? [5] 100.0% ---------------------------------------------------------------------- for-loop [2] 33.6% match-e [29] 66.4% [4] 220(1.7%) 0(0.0%) for-loop ...tlock/herbie/src/core/ematch.rkt:65:37 match-e [29] 100.0% ---------------------------------------------------------------------- run [3] 50.0% [5] 12694(100.0%) 0(0.0%) ??? ...lects/racket/private/more-scheme.rkt:261:28 profile-thunk16 [1] 50.0% loop [7] 46.4% run-improve50 [6] 3.6% ---------------------------------------------------------------------- ??? [5] 100.0% [6] 918(7.2%) 0(0.0%) run-improve50 ...ock/herbie/src/mainloop.rkt:234:0 setup-prog [8] 48.8% loop [7] 42.0% for-loop [9] 9.2% ---------------------------------------------------------------------- run-improve50 [6] 3.2% ??? [5] 96.8% [7] 12162(95.8%) 0(0.0%) loop /home/ztatlock/herbie/src/points.rkt:159:2 loop [10] 53.6% make-exacts* [14] 42.8% for-loop [12] 2.2% loop [15] 0.8% ---------------------------------------------------------------------- run-improve50 [6] 100.0% [8] 448(3.5%) 0(0.0%) setup-prog /home/ztatlock/herbie/src/glue.rkt:45:0 simplify-alt [11] 100.0% ---------------------------------------------------------------------- run-improve50 [6] 100.0% [9] 84(0.7%) 0(0.0%) for-loop ...ztatlock/herbie/src/mainloop.rkt:245:8 run-iter! [13] 100.0% ---------------------------------------------------------------------- loop [7] 100.0% [10] 6524(51.4%) 0(0.0%) loop /home/ztatlock/herbie/src/points.rkt:119:2 loop [15] 52.1% make-exacts* [14] 46.1% eval-prog [18] 1.8% ---------------------------------------------------------------------- setup-prog [8] 100.0% [11] 448(3.5%) 0(0.0%) simplify-alt .../ztatlock/herbie/src/glue.rkt:83:0 simplify [16] 100.0% ---------------------------------------------------------------------- loop [7] 100.0% [12] 262(2.1%) 0(0.0%) for-loop .../ztatlock/herbie/src/points.rkt:166:24 for-loop [17] 100.0% ---------------------------------------------------------------------- for-loop [9] 100.0% [13] 84(0.7%) 0(0.0%) run-iter! ...tatlock/herbie/src/mainloop.rkt:215:0 choose-best-alt! [19] 100.0% ---------------------------------------------------------------------- loop [10] 36.6% loop [7] 63.4% [14] 8214(64.7%) 0(0.0%) make-exacts* ...atlock/herbie/src/points.rkt:106:0 map [20] 64.7% loop [24] 35.3% ---------------------------------------------------------------------- loop [7] 2.7% loop [10] 97.3% [15] 3494(27.5%) 0(0.0%) loop /home/ztatlock/herbie/src/points.rkt:109:4 map [20] 97.5% loop [24] 2.5% ---------------------------------------------------------------------- simplify-alt [11] 100.0% [16] 448(3.5%) 0(0.0%) simplify ...lock/herbie/src/core/simplify.rkt:39:0 iterate-egraph!5 [21] 100.0% ---------------------------------------------------------------------- for-loop [12] 100.0% [17] 262(2.1%) 0(0.0%) for-loop .../ztatlock/herbie/src/points.rkt:167:26 ??? [22] 100.0% ---------------------------------------------------------------------- loop [10] 100.0% [18] 116(0.9%) 0(0.0%) eval-prog ...tatlock/herbie/src/programs.rkt:146:0 [running expand-time body] [23]100.0% ---------------------------------------------------------------------- run-iter! [13] 100.0% [19] 84(0.7%) 0(0.0%) choose-best-alt! .../herbie/src/mainloop.rkt:115:0 ??? [33] 100.0% ---------------------------------------------------------------------- loop [15] 39.1% make-exacts* [14] 60.9% [20] 8724(68.7%) 0(0.0%) map ...acket/collects/racket/private/map.rkt:20:13 loop [24] 100.0% ---------------------------------------------------------------------- simplify [16] 100.0% [21] 448(3.5%) 0(0.0%) iterate-egraph!5 ...bie/src/core/simplify.rkt:95:0 one-iter [25] 100.0% ---------------------------------------------------------------------- for-loop [17] 100.0% [22] 262(2.1%) 262(2.1%) ??? /home/ztatlock/herbie/src/points.rkt:156:9 ---------------------------------------------------------------------- eval-prog [18] 100.0% [23] 116(0.9%) 116(0.9%) [running expand-time body] ...ivate/unsafe.rkt:##f ---------------------------------------------------------------------- loop [15] 0.0% make-exacts* [14] 0.1% map [20] 1.3% loop [24] 98.6% [24] 11708(92.2%) 76(0.6%) loop ...cket/collects/racket/private/map.rkt:25:19 loop [24] 98.6% ??? [43] 1.3% ->flonum [46] 0.1% ---------------------------------------------------------------------- iterate-egraph!5 [21] 100.0% [25] 448(3.5%) 0(0.0%) one-iter ...ock/herbie/src/core/simplify.rkt:106:0 for-loop [26] 49.1% apply-match [28] 35.7% loop [27] 15.2% ---------------------------------------------------------------------- for-loop [26] 50.0% one-iter [25] 50.0% [26] 220(1.7%) 0(0.0%) for-loop ...ck/herbie/src/core/simplify.rkt:116:12 for-loop [26] 50.0% match-e [29] 50.0% ---------------------------------------------------------------------- one-iter [25] 100.0% [27] 68(0.5%) 0(0.0%) loop ...cket/collects/racket/private/map.rkt:52:19 apply-match [28] 100.0% ---------------------------------------------------------------------- loop [27] 29.8% one-iter [25] 70.2% [28] 228(1.8%) 0(0.0%) apply-match .../herbie/src/core/simplify.rkt:122:2 reduce-to-single! [30] 70.2% substitute-e [32] 29.8% ---------------------------------------------------------------------- for-loop [4] 50.0% for-loop [26] 50.0% [29] 220(1.7%) 0(0.0%) match-e ...tatlock/herbie/src/core/ematch.rkt:46:0 for-loop [4] 33.2% custom-in-set [31] 33.2% for-loop [2] 16.8% ??? [33] 16.8% ---------------------------------------------------------------------- apply-match [28] 100.0% [30] 160(1.3%) 0(0.0%) reduce-to-single! ...bie/src/core/egraph.rkt:324:0 filter-loop! [34] 100.0% ---------------------------------------------------------------------- match-e [29] 100.0% [31] 146(1.2%) 146(1.2%) custom-in-set ...acket/private/set-types.rkt:577:0 ---------------------------------------------------------------------- substitute-e [32] 50.0% apply-match [28] 50.0% [32] 68(0.5%) 0(0.0%) substitute-e ...ck/herbie/src/core/ematch.rkt:71:0 substitute-e [32] 50.0% ??? [33] 50.0% ---------------------------------------------------------------------- substitute-e [32] 30.1% match-e [29] 32.7% choose-best-alt! [19] 37.2% [33] 226(1.8%) 74(0.6%) ??? ...contract/private/arrow-val-first.rkt:357:18 ??? [35] 37.2% hash-has-key? [36] 30.1% ---------------------------------------------------------------------- reduce-to-single! [30] 100.0% [34] 160(1.3%) 160(1.3%) filter-loop! ...ck/herbie/src/core/enode.rkt:114:2 ---------------------------------------------------------------------- ??? [33] 100.0% [35] 84(0.7%) 0(0.0%) ??? ...ztatlock/herbie/src/core/alt-table.rkt:54:0 ??? [37] 100.0% ---------------------------------------------------------------------- ??? [33] 100.0% [36] 68(0.5%) 68(0.5%) hash-has-key? ...et/private/more-scheme.rkt:368:13 ---------------------------------------------------------------------- ??? [35] 100.0% [37] 84(0.7%) 0(0.0%) ??? ...tract/private/arrow-higher-order.rkt:342:33 best-alt [38] 100.0% ---------------------------------------------------------------------- ??? [37] 100.0% [38] 84(0.7%) 0(0.0%) best-alt /home/ztatlock/herbie/src/glue.rkt:78:0 argmins [39] 100.0% ---------------------------------------------------------------------- best-alt [38] 100.0% [39] 84(0.7%) 0(0.0%) argmins /home/ztatlock/herbie/src/common.rkt:134:0 composed [40] 100.0% ---------------------------------------------------------------------- argmins [39] 100.0% [40] 84(0.7%) 0(0.0%) composed ...ollects/racket/private/list.rkt:321:16 errors [41] 100.0% ---------------------------------------------------------------------- composed [40] 100.0% [41] 84(0.7%) 0(0.0%) errors /home/ztatlock/herbie/src/points.rkt:184:0 for-loop [42] 100.0% ---------------------------------------------------------------------- errors [41] 100.0% [42] 84(0.7%) 0(0.0%) for-loop ...e/ztatlock/herbie/src/points.rkt:187:4 ??? [43] 100.0% ---------------------------------------------------------------------- for-loop [42] 0.7% loop [24] 99.3% [43] 11478(90.4%) 626(4.9%) ??? /home/ztatlock/herbie/src/programs.rkt:152:4 ??? [44] 59.4% ??? [45] 33.6% ->flonum [46] 0.7% ---------------------------------------------------------------------- ??? [43] 100.0% [44] 6818(53.7%) 1324(10.4%) ??? ...contract/private/../../private/kw.rkt:761:9 real->bigfloat [47] 80.6% ---------------------------------------------------------------------- ??? [43] 100.0% [45] 3858(30.4%) 826(6.5%) ??? ...acket/collects/racket/private/kw.rkt:444:14 ??? [48] 70.1% ...higher-order.rkt:346:33 [49] 5.9% ??? [51] 2.6% ---------------------------------------------------------------------- ??? [43] 26.1% loop [24] 73.9% [46] 322(2.5%) 62(0.5%) ->flonum .../ztatlock/herbie/src/programs.rkt:34:0 ??? [50] 54.0% ??? [52] 26.7% ---------------------------------------------------------------------- ??? [44] 100.0% [47] 5494(43.3%) 4628(36.5%) real->bigfloat .../private/bigfloat/mpfr.rkt:451:0 ??? [56] 15.8% ---------------------------------------------------------------------- ??? [45] 100.0% [48] 2704(21.3%) 174(1.4%) ??? ...-racket/utils/simple-result-arrow.rkt:39:12 bfadd [53] 93.6% ---------------------------------------------------------------------- ??? [45] 100.0% [49] 226(1.8%) 0(0.0%) ...higher-order.rkt:346:33 (unknown source) ??? [54] 100.0% ---------------------------------------------------------------------- ->flonum [46] 100.0% [50] 174(1.4%) 84(0.7%) ??? /home/ztatlock/herbie/src/config.rkt:48:0 return/no-unsupplied [55] 51.7% ---------------------------------------------------------------------- ??? [45] 100.0% [51] 102(0.8%) 102(0.8%) ??? ...rivate/unconstrained-domain-arrow.rkt:40:13 ---------------------------------------------------------------------- ->flonum [46] 100.0% [52] 86(0.7%) 0(0.0%) ??? ...-racket/utils/simple-result-arrow.rkt:60:15 ??? [56] 100.0% ---------------------------------------------------------------------- ??? [48] 100.0% [53] 2530(19.9%) 1706(13.4%) bfadd ...-lib/math/private/bigfloat/mpfr.rkt:819:4 ??? [56] 32.6% ---------------------------------------------------------------------- ...higher-order.rkt:346:33 [49]100.0% [54] 226(1.8%) 150(1.2%) ??? ...cts/racket/contract/private/list.rkt:187:10 ??? [58] 33.6% ---------------------------------------------------------------------- ??? [50] 100.0% [55] 90(0.7%) 0(0.0%) return/no-unsupplied ...ct/private/arr-i.rkt:533:0 filter [57] 100.0% ---------------------------------------------------------------------- ??? [52] 4.8% bfadd [53] 46.4% real->bigfloat [47] 48.8% [56] 1776(14.0%) 1776(14.0%) ??? .../share/racket/collects/ffi/unsafe.rkt:861:4 ---------------------------------------------------------------------- return/no-unsupplied [55] 100.0% [57] 90(0.7%) 90(0.7%) filter ...t/collects/racket/private/list.rkt:256:2 ---------------------------------------------------------------------- ??? [54] 100.0% [58] 76(0.6%) 76(0.6%) ??? ...ects/racket/contract/private/guts.rkt:644:8 ----------------------------------------------------------------------