I write physics simulations in Julia. Quite often when building the functions that run these, I effectively ‘debug with printf’.
These introspections are useful to keep around after the initial effort to get the code working, but I was wondering what the recommended way to make the code permanent would be. Obviously for production runs of a code, you would want these suppressed, ideally with no overhead cost.
In C, this is often by done by a #define DEBUG 1, and then #ifdefs wrapping the printf functions. The equivalent in Julia would be to have a const VERBOSE=true in the global scope, and then if VERBOSE wrapping the print functions. I guess you could also use a @macro to compact away the if/end boilerplate.
Alternatively, you could add a function foo(...;verbose::Bool=false) keyword argument to the function. This looks to me much nicer, except for the fact that the function signature has this bit tacked on. But are there any hidden performance gremlins? Is there a way to tell Julia in the function signature, that the variable is const, so that the compiler can avoid even touching the verbose printing code unless it’s being used?
I guess this is heading in the direction where a full-blown logging package would be sensible (with differing levels of verbosity, warn/error/info levels), but it is also nice to know what to do on a smaller scale.
based on some static constant, adds or doesn’t add a debugging line of code
the debugging line, if it is compiled in, can check a mask to see if it will actually print anything or not
(or log anything)
for ease of getting formatted output (nice when debugging), I’d recommend my https://github.com/ScottPJones/StringUtils.jl (unregistered) package ;-), it’s a lot easier to use than trying to the @printf working inside of a macro with all the escaping rules.
You can skip the if/end text by using &&, like so:
const DEBUG = false
function test()
DEBUG && println("out")
2+2
end
julia> @code_llvm test()
define i64 @julia_test_62881() #0 !dbg !5 {
top:
ret i64 4
}
Since DEBUG is const, the printing doesn’t get compiled into the function and there is no overhead. I’m not sure if there’s any advantage to a macro approach, but this is easier for me since I still haven’t figured out metaprogramming.
For this current project, I’ve found the function foo(...;verbose=true) option the most nice to use.
I haven’t yet checked to see how time is wasted (or looked for any type instability gremlins), but it’s a definite benefit when using these functions in the REPL to have a ‘verbose’ option, much like a unix program on the command line.
Based on my understanding, if you define the parameter to have a default value, 2 versions of the function gets compiled: One with the default and another with the parameter as a variable. I was hoping that for the case where the value is not specified and it used the default, it would see the default as a constant and optimise like in a slightly modified version of @aaowens ’ example, however it doesn’t seem to be the case:
julia> @inline function test(verbose=false)
verbose && println("out")
2+2
end
test (generic function with 2 methods)
julia> @code_llvm test()
julia> @code_warntype test()
...
unless false goto 8
...
julia> @code_warntype test(true)
...
unless verbose::Bool goto 7
...
Without the @inline it just sets the value and calls the other version which now takes a value. With @inline macro, it half propagates through into the specific version of the function now generated for the case of test(), but the branch still remains.
i would probably think toward adding a log receiver parameter of type ::IO. to provide the default nolog behavior, i would create a type
immutable Discard <: IO end
@inline print(::Discard, etc...) = nothing
and also whatever other methods needed, and then having
function myfunc(params; log::IO = Discard())
if your only problem is not polluting production code with log, this does that. the only drawback is that you can’t turn on logging with some global flag, but have to actually pass a parameter, and then pass it further down the line as functions call each other.
I doubt the overhead is a big deal in any reasonable application, but I looked into it. It turns out that the overhead disappears with a specialization to unsafe_write and a small optimization to write which aids inlining. See https://github.com/JuliaLang/julia/pull/20830 for details.
Say you don’t want to stop your long running process, but you want some temporary verbose output.
With the example below, the penalty seems to be 7%. Those are not type instability gremlins, just added functionalty gremlins.
module globalslowdown
export changeable, preset, setverbose
global verbose = false
const presetverbose = false
const loops = 80000000
function changeable()
global verbose
a=1.0
for i = 1:loops
a=sin(a)
verbose && isinteger(i/10000000) && print(a," ")
end
end
function preset()
a=1.0
for i = 1:loops
a=sin(a)
presetverbose && isinteger(i/10000000) && print(a," ")
end
end
setverbose(v::Bool) = global verbose = v
end # module
@time globalslowdown.changeable()
@time globalslowdown.changeable()
@time globalslowdown.preset()
@time globalslowdown.preset()
globalslowdown.setverbose(true)
@time globalslowdown.changeable()
println()
@time globalslowdown.changeable()
Do any of the logging packages allow for a message to be printed only once? In my use case I want some functions to announce which method was called and for what parameters, but these functions are called thousands of times. I only want to log the first call.
Something like
function test(x)
@debug_once "$x"
...
end
This macro could define a const d1 = Ref(false) and then update the value if the debug is logged. Maybe this would be a performance issue, but it seems to be the same concept as the deprecation warnings and I don’t think they cause much issue.