Julia recompiles same code more than once

General Usage
1

I have a code that looks like

module M   # Actually a package
    struct Model ... end

    function stiffness(elem::T) # always return Matrix{FLoat64}
        # there are more stiffness functions
        # for different types T
        some work ..
    end

    function global_matrix(model::Model) # always return Matrix{FLoat64}
        for elem in model # two iterations
            time1 = time()
               K = stiffness(elem)
            @show time() - time1 # time spent by stiffness
        end
    end

    function solve(model::Model)
        G = global_matrix(model)
        more staff...
    end
end

As you can see I am doing some timing to the function stiffness. I also created a test:

# test.jl
using M
m = Model(2)

println("First run: model with 2 elems")
solve(m)

println("Second run: same model")
solve(m)

Results:

First run: model with 2 elems
time() - time1 = 0.13308095932006836
time() - time1 = 7.200241088867188e-5

Second run: same model
time() - time1 = 0.1240081787109375
time() - time1 = 7.295608520507812e-5

In this test there are four calls to the function stiffness:
(twice for each call to solve)

In the first call the function spends around 0.133 secs which includes the compilation time, ok.

In the second call it spends 7.2e-5 secs which is great.
But in the third time it spends 0.124 secs which is similar to the first call and it seems that Julia is compiling the function stiffness again even for the same argument.
In the fourth call, the time spent is small once more.

Does anybody experienced something like this before?
In which cases this may happen?
I tested with Julia 0.7 and 1.0 and the results were similar.

2

You should use BenchmarkTools for benchmarking your code.

Can you provide more detail about your stiffness function? Are the elements in the model the exact same?

3

Thanks Sukera for the feedback.
In this case I am not specifically trying to benchmark the code but to investigate why compilation is happening more than once.
The elements in the model are exact the same. Same objects.

4

It’s not really possible to reproduce the effect without having a minimal working example - can you provide one? It may be that it’s not really compiling twice but rather that the first call to stiffness does the actual compilation and the second call gets optimized out if the same function with the exact same object is called and the compiler can prove there are no sideeffects from stiffness. That information gets lost when you call solve more than once though, and thus the first run of stiffness of the second call to solve is “slow” again.

5

I am quite sure this does not happen but it would be interesting to have an example that is actually runnable.

6

It’s the only thing I could come up with - I agree that it’s probably not what is happening (even though I still believe it’s a possibility), but we’ll only know for sure with an example.

7

I will try to get a minimal working example asap and be back.

8

After some work I finally got a minimal working example.
It does not make too much sense because I removed a lot of code but I believe it shows the problem:


abstract type Element
end

mutable struct Model
    elems::Array{Element,1}
end

mutable struct Rod<:Element
    id::Int
    function Rod()
        return new() 
    end
end


function stiffness(elem::Element)
    K = zeros(4,4)

    keys = (1, 2, 3)[1:2]
    # WOW-1: By changing the line above by the one below, the problem dissapears
    #keys = [1, 2, 3][1:2]

    map = Int[ key for i=1:2 for key in keys ]
    return K, map
end
            

function global_matrix(model::Model, ndofs::Int) 
    # If the useless ndofs arg above is removed, the first call last a lot :O

    for elem in model.elems
        time1 = time()
            Ke, map = stiffness(elem)
        @show time() - time1
    end

end


function solve(model::Model)

    args = :(x, y)
    rhs  = :(x+y)
    fun = eval( :($args-> $rhs) )
    # WOW-2: Or, by changing the line above by the one below, the problem also dissapears
    # but the time spent in the first call is still large
    #fun = x -> x

    ndofs = 6
    global_matrix(model, ndofs)

    return
end

model = Model( [ Rod(), Rod(), Rod(), Rod() ] )

n=3

for i=1:n
    println("\nRun $i: Model with 4 elems")
    solve(model)
end

This time there are 12 calls to the function stiffness ( 4 for each call to the function solve )

See the results:

Run 1: Model with 4 elems
time() - time1 = 0.06474614143371582
time() - time1 = 1.0013580322265625e-5
time() - time1 = 7.152557373046875e-6
time() - time1 = 1.9073486328125e-6

Run 2: Model with 4 elems
time() - time1 = 0.057138919830322266
time() - time1 = 1.0967254638671875e-5
time() - time1 = 2.86102294921875e-6
time() - time1 = 2.1457672119140625e-6

Run 3: Model with 4 elems
time() - time1 = 0.055906057357788086
time() - time1 = 1.0967254638671875e-5
time() - time1 = 5.9604644775390625e-6
time() - time1 = 2.86102294921875e-6

What impresses me is that by changing a line in the function solve the time spent by the function stiffness reduces. May be some case of “spooky action at a distance…”

9

Just a guess- but what if you replace n=3 by const n=3. Without const, the compiler may not be able to prove that n, and therefore i, is always an Int.

10

I tried using const n=3 but had no effect.

11

I think it may have something to do with the use of tuples in list comprehension and the use of the eval function.

12

Indeed you’re close there. Instead it’s

That’s just a bad idea. You’re eval creating a new function every single time. Normal Julia usage will hoist out the type and function declaration so that way it’s only done once and the compilation is stored. Since you are essentially telling the compiler to dynamically create and compile a function every single time solve is used, it creates and compiles a new function each time.

I would recommend not using eval and instead just creating an anonymous function. If you are really utilizing function generation tools you should use @generated functions or a macro and do it once at compile time.

1 Like
13

You are right but in this case I need different expressions to be evaluated for each call to solve (It is related to some boundary conditions that may change). Also I do not get why this could affect the performance of the stiffness function that do not depend on that use of eval.

14

Take in a BC function dependent on space (and time), not an expression.

1 Like
15

Alright, that is one thing. Thanks a lot @ChrisRackauckas for the feedback. Now, how to explain that it is the cause of the possible ‘recompilation’ of the function stiffness?
Also, why the problem seems to disappear when the line

    keys = (1, 2, 3)[1:2]

is changed to

    keys = [1, 2, 3][1:2]

even when using the eval function?

In fact, I get the following results:

Run 1: Model with 4 elems
time() - time1 = 5.0067901611328125e-6
time() - time1 = 1.9073486328125e-6
time() - time1 = 0.0
time() - time1 = 0.0

Run 2: Model with 4 elems
time() - time1 = 9.5367431640625e-7
time() - time1 = 3.0994415283203125e-6
time() - time1 = 9.5367431640625e-7
time() - time1 = 9.5367431640625e-7

Run 3: Model with 4 elems
time() - time1 = 9.5367431640625e-7
time() - time1 = 5.0067901611328125e-6
time() - time1 = 1.1920928955078125e-6
time() - time1 = 9.5367431640625e-7