# @time is off by at least 10x

**URL:** https://discourse.julialang.org/t/time-is-off-by-at-least-10x/44896
**Category:** New to Julia
**Tags:** question
**Created:** [August 13, 2020, 9:22pm UTC](https://discourse.julialang.org/t/time-is-off-by-at-least-10x/44896 "2020-08-13T21:22:53Z")
**Posts on this page:** 8
**Page:** 1

<div class="post-metadata">

### Author: ![mkarikom](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/mkarikom/32/7096_2.png) [@mkarikom](https://discourse.julialang.org/u/mkarikom)
#### Post date: [August 13, 2020, 9:22pm UTC](https://discourse.julialang.org/t/time-is-off-by-at-least-10x/44896/1 "2020-08-13T21:22:53Z")

</div>

`f1` calls `f2` and `f3`. (this trivial logic will help with parallelization later)

`f2` and `f3` both mutate `struct1` and `struct2`.

```julia
function f1!(int1,int2,struct1,struct2)
 println("\n running f2: ")
   @time f2!(int1,struct1,struct2) 
 println("\n running f3")
   @time f3!(int2,struct1,struct2)
end

for i in 1:n
println("\n running f1")
@time f1()
end

```

This is a sample from one iteration:

```julia
 running f1: 
 running f2: 
  0.000006 seconds (30 allocations: 4.688 KiB)
 running f3: 
  0.000005 seconds (1 allocation: 160 bytes)
  0.000170 seconds (111 allocations: 8.297 KiB)

```

---

<div class="post-metadata">

### Author: ![Oscar\_Smith](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/oscar_smith/32/25343_2.png) [@Oscar\_Smith](https://discourse.julialang.org/u/Oscar_Smith)
#### Post date: [August 13, 2020, 9:26pm UTC](https://discourse.julialang.org/t/time-is-off-by-at-least-10x/44896/2 "2020-08-13T21:26:19Z")

</div>

What’s unintuitive here?

---

<div class="post-metadata">

### Author: ![fredrikekre](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/fredrikekre/32/1688_2.png) [@fredrikekre](https://discourse.julialang.org/u/fredrikekre)
#### Post date: [August 13, 2020, 9:27pm UTC](https://discourse.julialang.org/t/time-is-off-by-at-least-10x/44896/3 "2020-08-13T21:27:24Z")

</div>

Please include all code necessary to reproduce the data (see e.g. [Please read: make it easier to help you](https://discourse.julialang.org/t/psa-make-it-easier-to-help-you/14757)). Note also that for microbenchmarking you probably want to use the [BenchmarkTools.jl](https://github.com/JuliaCI/BenchmarkTools.jl) package and not `@time`.

---

<div class="post-metadata">

### Author: ![mkarikom](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/mkarikom/32/7096_2.png) [@mkarikom](https://discourse.julialang.org/u/mkarikom)
#### Post date: [August 13, 2020, 9:29pm UTC](https://discourse.julialang.org/t/time-is-off-by-at-least-10x/44896/4 "2020-08-13T21:29:08Z")

</div>

I just don’t know how `f1` can take 1.7e-4 sec when it’s constituents only take 0.1e-4 sec.

---

<div class="post-metadata">

### Author: ![Oscar\_Smith](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/oscar_smith/32/25343_2.png) [@Oscar\_Smith](https://discourse.julialang.org/u/Oscar_Smith)
#### Post date: [August 13, 2020, 9:30pm UTC](https://discourse.julialang.org/t/time-is-off-by-at-least-10x/44896/5 "2020-08-13T21:30:34Z")

</div>

You’re measuring printing also. Depending on the terminal, that can be surprisingly slow. You may also be measuring compilation time.

---

<div class="post-metadata">

### Author: ![mkarikom](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/mkarikom/32/7096_2.png) [@mkarikom](https://discourse.julialang.org/u/mkarikom)
#### Post date: [August 13, 2020, 9:32pm UTC](https://discourse.julialang.org/t/time-is-off-by-at-least-10x/44896/6 "2020-08-13T21:32:04Z")

</div>

Thanks, I’ll try BenchmarkTools.  
I’m not claiming @time is in any way broken, just confused.

I’ll see what I can do as far as an MWE, it’s just that `f2` and `f3` are both many lines, the structs are very complicated, etc.

---

<div class="post-metadata">

### Author: ![mkarikom](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/mkarikom/32/7096_2.png) [@mkarikom](https://discourse.julialang.org/u/mkarikom)
#### Post date: [August 13, 2020, 9:35pm UTC](https://discourse.julialang.org/t/time-is-off-by-at-least-10x/44896/7 "2020-08-13T21:35:22Z")

</div>

Ok, I guess printing could be the culprit. Compilation time unlikely `f1` is getting executed repeatedly in a loop.  
Sorry, just realized that the loop structure was excluded, now fixed.  
Again I’ll see what I can do about adding MWE

---

<div class="post-metadata">

### Author: ![anon37204545](https://avatars.discourse-cdn.com/v4/letter/a/439d5e/32.png) [@anon37204545](https://discourse.julialang.org/u/anon37204545)
#### Post date: [August 13, 2020, 9:53pm UTC](https://discourse.julialang.org/t/time-is-off-by-at-least-10x/44896/8 "2020-08-13T21:53:11Z")

</div>

As a side note, you probably want to benchmark this instead of measuring the times only once. You can do that with `using BenchmarkTools` and `@btime` instead of `@time`.
