benchmarking formula creating compile time in StatsModels.jl

formula.jl

using StatsModels

macro echotime(ex)
    println(ex)
    esc(:(@time $ex))
end

@formula(y ~ 1+x)

exs = [
    :(y ~ 1+x)
    :(y ~ a+b)
    :(y ~ a+b+c)
    :(y ~ a+b+c+d)
    :(y ~ a+b+c+d+e)
    :(y ~ a+b+c+d+e+f)
    :(y ~ log(a))
    :(y ~ log(a) + log(b))
    :(y ~ log(a) + log(b) + log(c))
    :(y ~ log(a) + log(b) + log(c) + log(d))
    :(y ~ log(a) + log(b) + log(c) + log(d) + log(e))
    :(y ~ log(a) + log(b) + log(c) + log(d) + log(e) + log(f))
    :(y ~ exp(a))
    :(y ~ exp(a) + exp(b))
    :(y ~ exp(a) + exp(b) + exp(c))
    :(y ~ exp(a) + exp(b) + exp(c) + exp(d))
    :(y ~ exp(a) + exp(b) + exp(c) + exp(d) + exp(e))
    :(y ~ exp(a) + exp(b) + exp(c) + exp(d) + exp(e) + exp(f))
]

function time_exs(exs)

    for ex in exs
        println(ex)
        @eval @time @formula($ex)
        @eval @time @formula($ex)
    end

end

time_exs(exs)

results-257bbeb25d07c7e755cf44ca98e3a0af6c305e75

# dfk/vector
# manages to avoid SOME of the extra compilation  from dfk/syntax, but still some there.

y ~ 1 + x
  0.000030 seconds (22 allocations: 1024 bytes)
  0.000026 seconds (22 allocations: 1024 bytes)
y ~ a + b
  0.000762 seconds (3.25 k allocations: 209.406 KiB)
  0.000040 seconds (23 allocations: 1.016 KiB)
y ~ a + b + c
  0.202089 seconds (416.45 k allocations: 21.792 MiB)
  0.000077 seconds (50 allocations: 1.953 KiB)
y ~ a + b + c + d
  0.019078 seconds (26.52 k allocations: 1.357 MiB)
  0.000080 seconds (85 allocations: 2.766 KiB)
y ~ a + b + c + d + e
  0.000108 seconds (121 allocations: 3.672 KiB)
  0.000084 seconds (121 allocations: 3.672 KiB)
y ~ a + b + c + d + e + f
  0.000088 seconds (136 allocations: 4.094 KiB)
  0.000085 seconds (136 allocations: 4.094 KiB)
y ~ log(a)
  0.033081 seconds (55.29 k allocations: 3.267 MiB)
  0.000011 seconds (11 allocations: 480 bytes)
y ~ log(a) + log(b)
  0.250338 seconds (362.76 k allocations: 18.099 MiB, 9.33% gc time)
  0.000042 seconds (86 allocations: 2.812 KiB)
y ~ log(a) + log(b) + log(c)
  0.231030 seconds (457.14 k allocations: 23.988 MiB)
  0.000090 seconds (230 allocations: 6.578 KiB)
y ~ log(a) + log(b) + log(c) + log(d)
  0.033108 seconds (40.08 k allocations: 2.058 MiB)
  0.000067 seconds (314 allocations: 8.625 KiB)
y ~ log(a) + log(b) + log(c) + log(d) + log(e)
  0.032818 seconds (37.30 k allocations: 1.968 MiB)
  0.000078 seconds (399 allocations: 10.766 KiB)
y ~ log(a) + log(b) + log(c) + log(d) + log(e) + log(f)
  0.038049 seconds (42.55 k allocations: 2.149 MiB)
  0.000081 seconds (483 allocations: 12.859 KiB)
y ~ exp(a)
  0.013761 seconds (6.69 k allocations: 411.746 KiB)
  0.000011 seconds (11 allocations: 480 bytes)
y ~ exp(a) + exp(b)
  0.195103 seconds (154.94 k allocations: 7.918 MiB)
  0.000049 seconds (110 allocations: 3.562 KiB)
y ~ exp(a) + exp(b) + exp(c)
  0.298317 seconds (457.18 k allocations: 23.984 MiB, 23.80% gc time)
  0.000091 seconds (278 allocations: 8.078 KiB)
y ~ exp(a) + exp(b) + exp(c) + exp(d)
  0.032561 seconds (40.12 k allocations: 2.060 MiB)
  0.000073 seconds (362 allocations: 10.125 KiB)
y ~ exp(a) + exp(b) + exp(c) + exp(d) + exp(e)
  0.031980 seconds (37.35 k allocations: 1.971 MiB)
  0.000078 seconds (447 allocations: 12.266 KiB)
y ~ exp(a) + exp(b) + exp(c) + exp(d) + exp(e) + exp(f)
  0.037132 seconds (42.60 k allocations: 2.150 MiB)
  0.000106 seconds (531 allocations: 14.359 KiB)

results-a7d1534407656830ac10bd2899bfd171cc047279

# master

y ~ 1 + x
  0.000030 seconds (24 allocations: 1.453 KiB)
  0.000026 seconds (24 allocations: 1.453 KiB)
y ~ a + b
  0.007479 seconds (3.57 k allocations: 222.652 KiB)
  0.000017 seconds (11 allocations: 720 bytes)
y ~ a + b + c
  0.008335 seconds (3.58 k allocations: 223.059 KiB)
  0.000017 seconds (12 allocations: 752 bytes)
y ~ a + b + c + d
  0.008023 seconds (3.58 k allocations: 222.840 KiB)
  0.000017 seconds (13 allocations: 784 bytes)
y ~ a + b + c + d + e
  0.009069 seconds (3.58 k allocations: 223.012 KiB)
  0.000018 seconds (15 allocations: 896 bytes)
y ~ a + b + c + d + e + f
  0.008347 seconds (3.58 k allocations: 223.105 KiB)
  0.000018 seconds (16 allocations: 928 bytes)
y ~ log(a)
  0.054569 seconds (96.08 k allocations: 5.497 MiB)
  0.024602 seconds (9.05 k allocations: 520.583 KiB)
y ~ log(a) + log(b)
  0.716022 seconds (1.19 M allocations: 59.931 MiB, 1.62% gc time)
  0.607828 seconds (1.02 M allocations: 51.087 MiB, 1.51% gc time)
y ~ log(a) + log(b) + log(c)
  0.764320 seconds (1.43 M allocations: 72.044 MiB, 2.28% gc time)
  0.652638 seconds (901.80 k allocations: 45.116 MiB, 1.53% gc time)
y ~ log(a) + log(b) + log(c) + log(d)
  0.720986 seconds (1.01 M allocations: 50.068 MiB, 1.25% gc time)
  0.704896 seconds (1.01 M allocations: 50.090 MiB, 1.23% gc time)
y ~ log(a) + log(b) + log(c) + log(d) + log(e)
  0.824501 seconds (1.11 M allocations: 55.013 MiB, 2.04% gc time)
  0.810598 seconds (1.11 M allocations: 55.035 MiB, 0.98% gc time)
y ~ log(a) + log(b) + log(c) + log(d) + log(e) + log(f)
  0.908695 seconds (1.21 M allocations: 59.970 MiB, 0.89% gc time)
  0.920887 seconds (1.21 M allocations: 59.957 MiB, 1.85% gc time)
y ~ exp(a)
  0.023846 seconds (9.39 k allocations: 546.286 KiB)
  0.024243 seconds (9.05 k allocations: 520.177 KiB)
y ~ exp(a) + exp(b)
  0.690605 seconds (1.20 M allocations: 59.978 MiB, 1.22% gc time)
  0.615599 seconds (1.02 M allocations: 51.110 MiB, 1.58% gc time)
y ~ exp(a) + exp(b) + exp(c)
  0.707121 seconds (1.24 M allocations: 62.348 MiB, 2.68% gc time)
  0.611217 seconds (901.80 k allocations: 45.128 MiB, 1.39% gc time)
y ~ exp(a) + exp(b) + exp(c) + exp(d)
  0.721166 seconds (1.01 M allocations: 50.072 MiB, 1.17% gc time)
  0.738193 seconds (1.01 M allocations: 50.066 MiB, 1.25% gc time)
y ~ exp(a) + exp(b) + exp(c) + exp(d) + exp(e)
  0.836975 seconds (1.11 M allocations: 55.030 MiB, 1.03% gc time)
  0.812385 seconds (1.11 M allocations: 55.008 MiB, 1.19% gc time)
y ~ exp(a) + exp(b) + exp(c) + exp(d) + exp(e) + exp(f)
  0.926991 seconds (1.21 M allocations: 59.965 MiB, 1.89% gc time)
  0.919655 seconds (1.21 M allocations: 59.990 MiB, 0.96% gc time)

results-b230147730538a0650bb01657f023d80349ede25

# dfk/syntax

y ~ 1 + x
  0.000101 seconds (25 allocations: 1.406 KiB)
  0.000100 seconds (25 allocations: 1.406 KiB)
y ~ a + b
  0.006183 seconds (2.17 k allocations: 135.030 KiB)
  0.000013 seconds (11 allocations: 768 bytes)
y ~ a + b + c
  0.034697 seconds (53.78 k allocations: 3.048 MiB)
  0.000016 seconds (23 allocations: 1.484 KiB)
y ~ a + b + c + d
  0.035098 seconds (53.91 k allocations: 3.052 MiB)
  0.000021 seconds (25 allocations: 1.547 KiB)
y ~ a + b + c + d + e
  0.036862 seconds (54.05 k allocations: 3.059 MiB)
  0.000017 seconds (28 allocations: 1.688 KiB)
y ~ a + b + c + d + e + f
  0.067935 seconds (54.18 k allocations: 3.064 MiB, 41.10% gc time)
  0.000024 seconds (30 allocations: 1.750 KiB)
y ~ log(a)
  0.026196 seconds (44.74 k allocations: 2.699 MiB)
  0.000011 seconds (11 allocations: 480 bytes)
y ~ log(a) + log(b)
  0.239399 seconds (332.92 k allocations: 17.049 MiB)
  0.000021 seconds (27 allocations: 1.703 KiB)
y ~ log(a) + log(b) + log(c)
  0.074463 seconds (121.33 k allocations: 6.717 MiB)
  0.000021 seconds (42 allocations: 2.906 KiB)
y ~ log(a) + log(b) + log(c) + log(d)
  0.080705 seconds (114.74 k allocations: 6.304 MiB)
  0.000026 seconds (49 allocations: 3.297 KiB)
y ~ log(a) + log(b) + log(c) + log(d) + log(e)
  0.142023 seconds (118.20 k allocations: 6.460 MiB, 48.90% gc time)
  0.000026 seconds (57 allocations: 3.828 KiB)
y ~ log(a) + log(b) + log(c) + log(d) + log(e) + log(f)
  0.074193 seconds (121.95 k allocations: 6.627 MiB)
  0.000032 seconds (64 allocations: 4.219 KiB)
y ~ exp(a)
  0.014050 seconds (6.69 k allocations: 411.762 KiB)
  0.000011 seconds (11 allocations: 480 bytes)
y ~ exp(a) + exp(b)
  0.244727 seconds (332.97 k allocations: 17.036 MiB)
  0.000024 seconds (27 allocations: 1.703 KiB)
y ~ exp(a) + exp(b) + exp(c)
  0.074187 seconds (121.34 k allocations: 6.717 MiB)
  0.000030 seconds (42 allocations: 2.906 KiB)
y ~ exp(a) + exp(b) + exp(c) + exp(d)
  0.080867 seconds (114.75 k allocations: 6.310 MiB)
  0.000026 seconds (49 allocations: 3.297 KiB)
y ~ exp(a) + exp(b) + exp(c) + exp(d) + exp(e)
  0.132146 seconds (118.21 k allocations: 6.462 MiB, 45.12% gc time)
  0.000029 seconds (57 allocations: 3.828 KiB)
y ~ exp(a) + exp(b) + exp(c) + exp(d) + exp(e) + exp(f)
  0.073608 seconds (121.96 k allocations: 6.633 MiB)
  0.000026 seconds (64 allocations: 4.219 KiB)