# Error while using @time on a Multi-threaded Julia function!

**URL:** <https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189>\
**Category:** General Usage\
**Tags:** question, multithreading, benchmark\
**Created:** [June 11, 2020, 9:04am UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189 "2020-06-11T09:04:25Z")\
**Posts on this page:** 10\
**Page:** 1

<div class="post-metadata">

**Author:** ![Saad\_Mahmud](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/saad_mahmud/32/15518_2.png) [@Saad\_Mahmud](https://discourse.julialang.org/u/Saad_Mahmud)\
**Post date:** [June 11, 2020, 9:04am UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189/1 "2020-06-11T09:04:25Z")

</div>

I am trying to time a Julia function and inside that function, I am using Multiple threads. Example of the code is given below:

```julia
function function1(input)
@threads for i in 1:N
#does something with the input
end
end

for i in 1:M
@time function1(i)
end

```

When I do not use @time the code runs. When I don’t use @threads the code also runs fine. But whenever I use both it times properly at the beginning but after some iterations, it throws the following errors:

```julia
log will only return a complex result if called with a complex argument. Try log(Complex(x)).
Stacktrace:
 [1] throw_complex_domainerror(::Symbol, ::Float64) at ./math.jl:31
 [2] log(::Float64) at ./special/log.jl:285
 [3] log at ./special/log.jl:395 [inlined]
 [4] prettyprint_getunits at ./util.jl:74 [inlined]
 [5] format_bytes(::Int64) at ./util.jl:88
 [6] time_print(::UInt64, ::Int64, ::Int64, ::Int64) at ./util.jl:105
 [7] macro expansion at ./util.jl:159 [inlined]
 [8] main(::Array{SubString{String},1}) at /home/saadmahmud/Documents/Halite/testjulia/Runer.jl:21
 [9] top-level scope at /home/saadmahmud/Documents/Halite/testjulia/Runer.jl:33 [inlined]
 [10] top-level scope at ./none:0
 [11] include at ./boot.jl:317 [inlined]
 [12] include_relative(::Module, ::String) at ./loading.jl:1044
 [13] include(::Module, ::String) at ./sysimg.jl:29
 [14] exec_options(::Base.JLOptions) at ./client.jl:266
 [15] _start() at ./client.jl:425

```

What am I doing wrong and how can I time it properly?

---

<div class="post-metadata">

**Author:** ![ettersi](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/ettersi/32/6829_2.png) [@ettersi](https://discourse.julialang.org/u/ettersi)\
**Post date:** [June 11, 2020, 9:13am UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189/2 "2020-06-11T09:13:31Z")

</div>

The error message indicates that you call `log` with a negative argument. I highly doubt this has anything to do with `@threads` or `@time`, except perhaps that the negative argument only occurs if your code is executed in a particular order which only happens every once in a while when parallelised.

---

<div class="post-metadata">

**Author:** ![Saad\_Mahmud](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/saad_mahmud/32/15518_2.png) [@Saad\_Mahmud](https://discourse.julialang.org/u/Saad_Mahmud)\
**Post date:** [June 11, 2020, 9:18am UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189/3 "2020-06-11T09:18:29Z")

</div>

I am sure that @threads is not causing any problem because it produces results it suppose to and runs fine when I use it with out @time.

---

<div class="post-metadata">

**Author:** ![ettersi](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/ettersi/32/6829_2.png) [@ettersi](https://discourse.julialang.org/u/ettersi)\
**Post date:** [June 11, 2020, 9:41am UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189/4 "2020-06-11T09:41:14Z")

</div>

You are right. The stacktrace reveals that the error occurs inside the `@time` macro when figuring out the correct unit (`byte`, `KiB`, `MiB`, etc.), to print the amount of memory allocated. So my next guess would be that the `@threads` somehow messes up the allocation counter which makes `@time` believe that a negative amount of memory has been allocated.

I’m afraid it is hard to help you any further without an MWE which reproduces the error. Also, which version of Julia are you on?

---

<div class="post-metadata">

**Author:** ![antoine-levitt](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/antoine-levitt/32/4008_2.png) [@antoine-levitt](https://discourse.julialang.org/u/antoine-levitt)\
**Post date:** [June 11, 2020, 9:48am UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189/5 "2020-06-11T09:48:42Z")

</div>

Yeah, either the number of allocs or the RAM allocated gets negative. That could be an overflow, but overflowing an Int64 is pretty hard. What does `@allocated` instead of `@time` give?

---

<div class="post-metadata">

**Author:** ![Saad\_Mahmud](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/saad_mahmud/32/15518_2.png) [@Saad\_Mahmud](https://discourse.julialang.org/u/Saad_Mahmud)\
**Post date:** [June 11, 2020, 10:02am UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189/6 "2020-06-11T10:02:23Z")

</div>

1.0.4

---

<div class="post-metadata">

**Author:** ![Saad\_Mahmud](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/saad_mahmud/32/15518_2.png) [@Saad\_Mahmud](https://discourse.julialang.org/u/Saad_Mahmud)\
**Post date:** [June 11, 2020, 10:08am UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189/7 "2020-06-11T10:08:08Z")

</div>

@allocated does not create any error.  
Here is an example of @time output before creating error: 0.372356 seconds (3.74 M allocations: 200.172 MiB, 6.00% gc time)  
Few iterations later his occurs: 0.376349 seconds (3.70 M allocations: ERROR: LoadError: DomainError with -4.08709942e9:  
log will only return a complex result if called with a complex argument. Try log(Complex(x)).

FYI: It is not even that any particular input to functions1() creates the error. Same input some times works fine with @time and some time does not.

---

<div class="post-metadata">

**Author:** ![antoine-levitt](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/antoine-levitt/32/4008_2.png) [@antoine-levitt](https://discourse.julialang.org/u/antoine-levitt)\
**Post date:** [June 11, 2020, 10:16am UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189/8 "2020-06-11T10:16:31Z")

</div>

Yeah that looks like an Int32 overflow. Try if you can reproduce that with a more recent version of julia (1.5beta) and if you can please report it as a bug at [Issues · JuliaLang/julia · GitHub](https://github.com/JuliaLang/julia/issues)

---

<div class="post-metadata">

**Author:** ![Saad\_Mahmud](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/saad_mahmud/32/15518_2.png) [@Saad\_Mahmud](https://discourse.julialang.org/u/Saad_Mahmud)\
**Post date:** [June 11, 2020, 1:30pm UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189/9 "2020-06-11T13:30:26Z")

</div>

I tested julia 1.5.0 beta 64bit. This error does not occur. It seems like it is either a 32bit specific problem or 1.0.4 32bit specific problem.

---

<div class="post-metadata">

**Author:** ![ettersi](https://sea2.discourse-cdn.com/julialang/user_avatar/discourse.julialang.org/ettersi/32/6829_2.png) [@ettersi](https://discourse.julialang.org/u/ettersi)\
**Post date:** [June 12, 2020, 12:51am UTC](https://discourse.julialang.org/t/error-while-using-time-on-a-multi-threaded-julia-function/41189/10 "2020-06-12T00:51:05Z")

</div>

Actually, it looks like the relevant variables are all hard-coded to be `Int64`:

> <https://github.com/JuliaLang/julia/blob/38e9fb7f809621e27c9a650be473e26b4c871465/base/util.jl#L25>

So either there is some variable that was missed here, or there must be something race-condition-like going on with the threads.