Memory allocations are not very understandable

General Usage Performance
21

I tried adding a variable to collect values returned by winsMilestone but .mem file still is the same.

22

Well if @time says there are no allocations it probably all got elided.

23

@time says there were 6 allocations of 320 bytes. This is why this seems strange.

24

When you put it in a function it didn’t show any allocations.

For me it shows:

f() = @time test(1000)

julia> @time test(1000)
  0.000013 seconds (5 allocations: 304 bytes)

julia> f()
  0.000013 seconds (1 allocation: 144 bytes)

which I guess is the allocation of the array.

25

I just run this code:

using Profile

@inline function winsMilestone(topSide, bottomSide)
    a = 0

    if (count(!iszero, topSide) < 3  ||  count(!iszero, bottomSide) < 3)
         return 1
    end

    return 2
end

function test(n_iter)
    A = zeros(UInt8,(7, 9))
    sum = 0
    for i=1:n_iter
        for j=1:9
            sum += @views winsMilestone(A[1:3, j], A[4:7, j])
        end
    end
    return sum
end

@time test(1)

Profile.clear_malloc_data()
@time test(1000)

In console:

> julia --track-allocation=user alloc-test.jl
  0.117380 seconds (135.18 k allocations: 7.587 MiB)
  0.016712 seconds (6 allocations: 320 bytes)

It generates the following mem:

        - using Profile
        - 
        - @inline function winsMilestone(topSide, bottomSide)
        -     a = 0
        - 
        0     if (count(!iszero, topSide) < 3  ||  count(!iszero, bottomSide) < 3)
        0          return 1
        -     end
        - 
        0     return 2
        - end
        - 
        - function test(n_iter)
        0     A = zeros(UInt8,(7, 9))
        0     sum = 0
        0     for i=1:n_iter
        0         for j=1:9
        0             sum += @views winsMilestone(A[1:3, j], A[4:7, j])
        -         end
        -     end
        0     return sum
        - end
        - 
        - @time test(1)
        - 
        - Profile.clear_malloc_data()
        - @time test(1000)

As you can see, the reported figures do not match.

26

And I have told you why.

and also to put the @time call in a function to avoid this.

julia> @macroexpand @time time(1000)
quote
    #= util.jl:167 =#
    local #21#stats = (Base.gc_num)()
    #= util.jl:168 =#
    local #23#elapsedtime = (Base.time_ns)()
    #= util.jl:169 =#
    local #22#val = time(1000)
    #= util.jl:170 =#
    #23#elapsedtime = (Base.time_ns)() - #23#elapsedtime
    #= util.jl:171 =#
    local #24#diff = (Base.GC_Diff)((Base.gc_num)(), #21#stats)
    #= util.jl:172 =#
    (Base.time_print)(#23#elapsedtime, #24#diff.allocd, #24#diff.total_time, (Base.gc_alloc_count)(#24#diff))
    #= util.jl:174 =#
    #22#val
end

These variables are in global scope and will likely cause allocations.

1 Like
27

Thanks. I guess we can say the initial question has been solved.