# Is @time not tracking the full evaluation time?

**URL:** <https://discourse.julialang.org/t/is-time-not-tracking-the-full-evaluation-time/46327>\
**Category:** General Usage\
**Created:** [September 9, 2020, 12:38pm UTC](https://discourse.julialang.org/t/is-time-not-tracking-the-full-evaluation-time/46327 "2020-09-09T12:38:10Z")\
**Posts on this page:** 7\
**Page:** 1

<div class="post-metadata">

**Author:** ![johnmyleswhite](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/johnmyleswhite/32/31_2.png) [@johnmyleswhite](https://discourse.julialang.org/u/johnmyleswhite)\
**Post date:** [September 9, 2020, 12:38pm UTC](https://discourse.julialang.org/t/is-time-not-tracking-the-full-evaluation-time/46327/1 "2020-09-09T12:38:10Z")

</div>

If I type something like the following into the 1.5.1 REPL, I find the results very surprising:

```julia
julia> @time NTuple{10000, Int}[]
  0.000001 seconds (1 allocation: 80 bytes)
NTuple{10000,Int64}[]

```

`@time` reports a very small time, but the REPL hangs for a long period before anything is printed to the terminal if this expression is evaluated for the first time in a new REPL session.

---

<div class="post-metadata">

**Author:** ![Keno](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/keno/32/285_2.png) [@Keno](https://discourse.julialang.org/u/Keno)\
**Post date:** [September 9, 2020, 12:49pm UTC](https://discourse.julialang.org/t/is-time-not-tracking-the-full-evaluation-time/46327/2 "2020-09-09T12:49:38Z")

</div>

It times the evaluation, but doesn’t time how long it takes to print the thing (or compile the functions necessary to print it).

---

<div class="post-metadata">

**Author:** ![ianshmean](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/ianshmean/32/216042_2.png) [@ianshmean](https://discourse.julialang.org/u/ianshmean)\
**Post date:** [September 9, 2020, 12:55pm UTC](https://discourse.julialang.org/t/is-time-not-tracking-the-full-evaluation-time/46327/3 "2020-09-09T12:55:13Z")

</div>

You can `@time @time foo()`. The outer time gets closer to user experience.

---

<div class="post-metadata">

**Author:** ![nilshg](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/nilshg/32/2283_2.png) [@nilshg](https://discourse.julialang.org/u/nilshg)\
**Post date:** [September 9, 2020, 12:59pm UTC](https://discourse.julialang.org/t/is-time-not-tracking-the-full-evaluation-time/46327/4 "2020-09-09T12:59:58Z")

</div>

That doesn’t solve this case unfortunately. I see:

```julia
julia> @time @time NTuple{10_000, Int}[]
  0.000001 seconds (1 allocation: 80 bytes)
  0.021888 seconds (20.72 k allocations: 1.085 MiB)
NTuple{10000,Int64}[]

```

But the lag before `NTuple{10000,Int64}[]` is actually printed is something like 20 seconds.

---

<div class="post-metadata">

**Author:** ![johnmyleswhite](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/johnmyleswhite/32/31_2.png) [@johnmyleswhite](https://discourse.julialang.org/u/johnmyleswhite)\
**Post date:** [September 9, 2020, 1:04pm UTC](https://discourse.julialang.org/t/is-time-not-tracking-the-full-evaluation-time/46327/5 "2020-09-09T13:04:01Z")

</div>

This is very helpful. Essentially one needs to do something like,

```julia
julia> @time show(stdout, NTuple{10000, Int}[])
NTuple{10000,Int64}[] 53.567039 seconds (1.52 M allocations: 54.703 MiB, 0.02% gc time)

```

to get a time that matches what a user would expect.

---

<div class="post-metadata">

**Author:** ![kristoffer.carlsson](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/kristoffer.carlsson/32/22_2.png) [@kristoffer.carlsson](https://discourse.julialang.org/u/kristoffer.carlsson)\
**Post date:** [September 9, 2020, 1:07pm UTC](https://discourse.julialang.org/t/is-time-not-tracking-the-full-evaluation-time/46327/6 "2020-09-09T13:07:20Z")

</div>

This is similar to measuring plotting time. Instead of `@time plot(rand(3,3))` you do `@time (p = plot(rand(3,3)); display(p))`

---

<div class="post-metadata">

**Author:** ![Henrique\_Becker](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/henrique_becker/32/15443_2.png) [@Henrique\_Becker](https://discourse.julialang.org/u/Henrique_Becker)\
**Post date:** [September 9, 2020, 1:13pm UTC](https://discourse.julialang.org/t/is-time-not-tracking-the-full-evaluation-time/46327/7 "2020-09-09T13:13:40Z")

</div>

Just to give an explanation instead of just examples: the time to build the object is being measured, but as printing was not explicitly called and is done by the REPL after it evaluated `@time ...` (because a `@time ...` expression just returns the value of `...`, and the REPL prints the value of each line by default), this implicit REPL method call is not being measured.

One way of avoiding this delay would be never compiling such methods, by placing a `;` at the end of the line, and suppressing the default printing by the REPL.