In order to turn verbosity on or off, I used to write functions in the old-fashioned style
julia> using Printf julia> function do_something(verbose=false) for i in 1:10000 verbose && @printf("print some info") end end
and I’m considering rewriting such functions as
julia> using Logging julia> function do_something_with_logger() for i in 1:10000 @debug("print some info") end end
I was under the impression that logging should essentially be free unless the log level instructs that something should indeed be logged (that’s what the MicroLogging.jl README seems to say). But in Julia 0.7 and 1.0 I observe the following:
julia> using BenchmarkTools julia> @btime do_something() 4.849 ns (0 allocations: 0 bytes) julia> my_null_logger = Logging.NullLogger(); julia> @btime with_logger(my_null_logger) do do_something_with_logger() end 976.781 μs (1 allocation: 32 bytes) julia> my_custom_logger = Logging.ConsoleLogger(stderr, Logging.Error); julia> @btime with_logger(my_custom_logger) do do_something_with_logger() end 974.228 μs (1 allocation: 32 bytes)
So it turns out that the difference is pretty stark. Is this expected? Adding a second
@debug in the loop basically adds another millisecond to the time. Am I doing something wrong?