Mac で Julia #9 Profiling

前回に引き続きJuliaについてです。

ドキュメントに沿って試していきます。

Basic usage

julia> function myfunc()
                  A = rand(200, 200, 400)
                  maximum(A)
              end
myfunc (generic function with 1 method)

julia> myfunc()
0.9999996886669018

まず、関数定義します、これって200x200x400個の乱数つくってるんですね！

julia> using Profile

julia> @profile myfunc()
0.9999999768449566

using Profile で宣言して @profileで測定します。

julia> Profile.print()
1  ./client.jl:421; _start()
 1 ./client.jl:242; exec_options(::Base.JLOptions)
  1 ./client.jl:330; run_main_repl(::Bool, ::Bool, ::Bool, ::Bool, ::Bool)
   1 ./logging.jl:308; macro expansion
    1 ./essentials.jl:685; invokelatest
     1 ./essentials.jl:686; #invokelatest#1
      1 ./logging.jl:311; (::getfield(Base, Symbol("##720#722")){Bool,Bool,Bool,Bool})(::Module)
       1 ...usr/share/julia/stdlib/v1.0/REPL/src/REPL.jl:191; run_repl(::REPL.AbstractREPL, ::Any)
        1 ...sr/share/julia/stdlib/v1.0/REPL/src/REPL.jl:1029; run_frontend(::REPL.LineEditREPL, ::REPL.REPLBackendRef)
         1 ...hare/julia/stdlib/v1.0/REPL/src/LineEdit.jl:2261; run_interface(::REPL.Terminals.TextTerminal, ::REPL.LineEdit.Modal...
          1 ./essentials.jl:685; invokelatest
           1 ./essentials.jl:686; #invokelatest#1
            1 ...r/share/julia/stdlib/v1.0/REPL/src/REPL.jl:713; (::getfield(REPL, Symbol("#do_respond#40")){Bool,getfield(REPL, ...
             1 ...re/julia/stdlib/v1.0/REPL/src/LineEdit.jl:2201; transition
              1 ...re/julia/stdlib/v1.0/REPL/src/LineEdit.jl:2194; transition(::Function, ::REPL.LineEdit.MIState, ::Any)
               1 ...e/julia/stdlib/v1.0/REPL/src/LineEdit.jl:2159; deactivate(::REPL.LineEdit.TextInterface, ::REPL.LineEdit.Mode...
                1 ...e/julia/stdlib/v1.0/REPL/src/LineEdit.jl:343; clear_input_area(::Any, ::Any)
                 1 ./sysimg.jl:18; getproperty(::Any, ::Symbol)
82 ./task.jl:259; (::getfield(REPL, Symbol("##28#29")){REPL.REPLBackend})()
 82 ...d/usr/share/julia/stdlib/v1.0/REPL/src/REPL.jl:117; macro expansion
  82 ...d/usr/share/julia/stdlib/v1.0/REPL/src/REPL.jl:85; eval_user_input(::Any, ::REPL.REPLBackend)
   82 ./boot.jl:319; eval(::Module, ::Any)
    82 ...hare/julia/stdlib/v1.0/Profile/src/Profile.jl:25; top-level scope
     55 ./REPL[7]:2; myfunc
      55 ...share/julia/stdlib/v1.0/Random/src/Random.jl:243; rand
       55 ...hare/julia/stdlib/v1.0/Random/src/Random.jl:258; rand
        55 ...hare/julia/stdlib/v1.0/Random/src/Random.jl:257; rand
         39 ./boot.jl:411; Type
          39 ./boot.jl:405; Type
           39 ./boot.jl:398; Type
         16 ...hare/julia/stdlib/v1.0/Random/src/Random.jl:233; rand!
          16 ...share/julia/stdlib/v1.0/Random/src/RNGs.jl:456; rand!
           16 ...share/julia/stdlib/v1.0/Random/src/RNGs.jl:450; _rand!
            16 ./gcutils.jl:87; macro expansion
             16 ...hare/julia/stdlib/v1.0/Random/src/RNGs.jl:438; rand!(::Random.MersenneTwister, ::Random.UnsafeView{Float64}, :...
              16 ...hare/julia/stdlib/v1.0/Random/src/RNGs.jl:412; fill_array!
               16 ...are/julia/stdlib/v1.0/Random/src/DSFMT.jl:95; dsfmt_fill_array_close_open!(::Random.DSFMT.DSFMT_state, ::Ptr{...
     27 ./REPL[7]:3; myfunc
      27 ./reducedim.jl:645; maximum
       27 ./reducedim.jl:645; #maximum#544
        27 ./reducedim.jl:649; _maximum
         27 ./reducedim.jl:650; _maximum
          27 ./reducedim.jl:301; mapreduce
           27 ./reducedim.jl:301; #mapreduce#538
            27 ./reducedim.jl:305; _mapreduce_dim
             25 ./reduce.jl:318; _mapreduce(::typeof(identity), ::typeof(max), ::IndexLinear, ::...
              2  ./reduce.jl:0; mapreduce_impl
              1  ./reduce.jl:460; mapreduce_impl
               1 ./float.jl:448; ==
              15 ./reduce.jl:461; mapreduce_impl
               15 ./array.jl:731; getindex
              7  ./reduce.jl:462; mapreduce_impl
               7 ./math.jl:562; max
             2  ./reduce.jl:460; _mapreduce(::typeof(identity), ::typeof(max), ::IndexLinear, ::...

julia>

うむ、内容がわかりませんw

時間を測定するマクロ @time

julia> @time myfunc()
  0.130843 seconds (128.59 k allocations: 128.612 MiB, 9.05% gc time)
0.9999998200636164

julia> @time myfunc()
  0.147341 seconds (7 allocations: 122.071 MiB, 38.25% gc time)
0.9999999568833762

処理時間がわかります。

正式（？）にはBase.@timeのようです。他にも@timev,@elapsed,@allocatedがあるようです。

時間(秒)が@elapsed、メモリ使用量(bytes)が@allocatedですね。

julia> Base.@timev myfunc()
  0.068951 seconds (7 allocations: 122.071 MiB, 11.95% gc time)
elapsed time (ns): 68951243
gc time (ns):      8240878
bytes allocated:   128000256
pool allocs:       6
malloc() calls:    1
GC pauses:         1
0.999999998727283

julia> Base.@elapsed myfunc()
0.066033414

julia> Base.@allocated myfunc()
128000080

今日はこの辺で。