Show timing and allocations for tests (#48)

* Show timing and allocations for tests

* Revert removal of newline

* Apply suggestions from code review

Co-authored-by: Jose Storopoli <[email protected]>

Co-authored-by: Jose Storopoli <[email protected]>

Author: rikhuijzer

test/Project.toml

@@ -5,8 +5,10 @@ DataFrames = "a93c6f00-e57d-5684-b7b6-d8193f3e46c0"
 Random = "9a3f8284-a2c9-5f02-9a11-845980a1fd5c"
 Statistics = "10745b16-79ce-11e8-11f9-7d13ad32a3b2"
 Test = "8dfed614-e22c-5e08-85e1-65c5234f0b40"
+TimerOutputs = "a759f4b9-e2f1-59dc-863e-4aeb61b1ea8f"
 
 [compat]
 CSV = "0.9, 1"
 CategoricalArrays = "0.10"
 DataFrames = "1"
+TimerOutputs = "0.5"

test/data_constructors.jl

@@ -1,4 +1,4 @@
-@testset "data_constructors.jl" begin
+@timed_testset "data_constructors" begin
     @testset "data_response" begin
         @testset "NamedTuples" begin
             expected = [2, 3, 4, 5]

test/priors.jl

@@ -1,4 +1,4 @@
-@testset "prior.jl" begin
+@timed_testset "priors" begin
     @testset "types" begin
         @test DefaultPrior() isa T.Prior
 

test/runtests.jl

@@ -5,6 +5,7 @@ using DataFrames
 using CategoricalArrays: CategoricalValue
 using CategoricalArrays: categorical, levels
 using Statistics: mean, std
+using TimerOutputs: TimerOutputs, @timeit
 using Random: seed!
 
 const T = TuringGLM
@@ -29,9 +30,23 @@ df_str = DataFrame(nt_str)
 
 df_cat = DataFrame(nt_cat)
 
-@testset "TuringGLM.jl" begin
+# To capture time and allocation information.
+const TIMEROUTPUT = TimerOutputs.TimerOutput()
+macro timed_testset(str, block)
+    return quote
+        @timeit TIMEROUTPUT "$($(esc(str)))" begin
+            @testset "$($(esc(str)))" begin
+                $(esc(block))
+            end
+        end
+    end
+end
+
+@testset "TuringGLM" begin
     include("data_constructors.jl")
     include("utils.jl")
     include("priors.jl")
     include("turing_model.jl")
 end
+
+show(TIMEROUTPUT; compact=true, sortby=:firstexec)

test/turing_model.jl

@@ -1,10 +1,10 @@
-@testset "turing_model.jl" begin
+@timed_testset "turing_model" begin
     DATA_DIR = joinpath("..", "data")
     kidiq = CSV.read(joinpath(DATA_DIR, "kidiq.csv"), DataFrame)
     wells = CSV.read(joinpath(DATA_DIR, "wells.csv"), DataFrame)
     roaches = CSV.read(joinpath(DATA_DIR, "roaches.csv"), DataFrame)
     cheese = CSV.read(joinpath(DATA_DIR, "cheese.csv"), DataFrame)
-    @testset "Gaussian Model" begin
+    @timed_testset "Gaussian Model" begin
         f = @formula(kid_score ~ mom_iq * mom_hs)
         @testset "standardize=false" begin
             m = turing_model(f, kidiq)
@@ -38,7 +38,7 @@
             @test quantile(chn)[Symbol("β[2]"), Symbol("50.0%")] ≈ 0.593 atol = 0.2
         end
     end
-    @testset "Student Model" begin
+    @timed_testset "TDist Model" begin
         f = @formula(kid_score ~ mom_iq * mom_hs)
         @testset "standardize=false" begin
             m = turing_model(f, kidiq; model=TDist)
@@ -59,7 +59,7 @@
             @test quantile(chn)[:ν, Symbol("50.0%")] ≈ 1.178 atol = 0.5
         end
     end
-    @testset "Logistic Model" begin
+    @timed_testset "Bernoulli Model" begin
         f = @formula(switch ~ arsenic + dist + assoc + educ)
         @testset "standardize=false" begin
             m = turing_model(f, wells; model=Bernoulli)
@@ -78,7 +78,7 @@
             @test quantile(chn)[Symbol("β[2]"), Symbol("50.0%")] ≈ -0.009 atol = 0.2
         end
     end
-    @testset "Pois Model" begin
+    @timed_testset "Poisson Model" begin
         f = @formula(y ~ roach1 + treatment + senior + exposure2)
         @testset "standardize=false" begin
             m = turing_model(f, roaches; model=Poisson)
@@ -97,7 +97,7 @@
             @test quantile(chn)[Symbol("β[2]"), Symbol("50.0%")] ≈ -0.5145 atol = 0.2
         end
     end
-    @testset "NegBin Model" begin
+    @timed_testset "NegativeBinomial Model" begin
         f = @formula(y ~ roach1 + treatment + senior + exposure2)
         @testset "standardize=false" begin
             m = turing_model(f, roaches; model=NegativeBinomial)
@@ -118,7 +118,7 @@
             @test quantile(chn)[:ϕ⁻, Symbol("50.0%")] ≈ 3.56 atol = 0.2
         end
     end
-    @testset "Hierarchical Model" begin
+    @timed_testset "Hierarchical Model" begin
         f = @formula(y ~ (1 | cheese) + background)
         m = turing_model(f, cheese)
         chn = sample(seed!(123), m, NUTS(), MCMCThreads(), 2_000, 2)

test/utils.jl

@@ -1,5 +1,5 @@
-@testset "utils" begin
-    @testset "center_predictors" begin
+@timed_testset "utils" begin
+    @timed_testset "center_predictors" begin
         @testset "NamedTuples" begin
             f = @formula(y_int ~ x_float + x_cat)
             X = T.data_fixed_effects(f, nt_str)
@@ -29,7 +29,7 @@
         end
     end
 
-    @testset "standardize_predictors" begin
+    @timed_testset "standardize_predictors" begin
         @testset "NamedTuples" begin
             f = @formula(y_int ~ x_float + x_cat)
             y = T.data_response(f, nt_str)