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

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

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:

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?

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.

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.

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?

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?

1.0.4

@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.

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 https://github.com/JuliaLang/julia/issues

1 Like

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.

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

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