Creating a conditional log

Hi there!

TLDR: I want to make a logger for my code that outputs the unevaluated expressions and evaluated expression sometimes - like on one time step. It seems the only way to do this is with a macro, but I can’t figure out how to make a conditional macro that doesn’t cause world-age problems.

I am working on a code that simulates the forces on an object in water and I’d like to gut-check what’s going on using a calculation log. This calculation log should conditionally output the unevaluated expressions and evaluated expressions to stdout. The @show macro does this perfectly, but it either outputs every single calculation or none of them. There are a lottt of calculations, so I need a way to only use @show on one timestep. Here are the things I’ve tried:

  1. Creating my own macro that works just like show macro, but takes a bool argument as well → macro myshow(bool, expr). This works if I specify the bool at the moment of calling the macro (e.g. @myshow true z=x+y) but doesn’t work if I instantiate the bool variable beforehand and pass it in, e.g.

     bool=true
     @myshow bool z=x+y
    

because the bool hasn’t been assigned a value when the macro is defined during precompilation.

  1. I tried creating a global variable and referencing that when calling myshow, e.g.
const show_output = Ref(false)

function _myshow(expr)
    if show_output==true
        expr2 = QuoteNode(expr)
        :(println($expr2, " = ", $(esc(expr))))
    else
        :(println($(esc(expr))))
    end
end

macro myshow(expr)
    return _myshow(expr)
end

which works except it doesn’t when I simulate looping through timesteps and changing show_output to true or false during the runtime, like this:

function test(x, y)
for timestep in 1:10
        b =  0
        # Change show_output based on the timestep
        if timestep == 5
            show_output[] = true
        else
            show_output[]=false
        end
        @myshow(b = x + y)
end
end

I assume because the macro references show_output’s value exactly as it is when first instantiated, frozen in time.

  1. If I use @eval @myshow(b = x + y) it can access the changes in show_output throughout the loop, but can’t access the local variables passed in for x and y in the function. I’ve seen elsewhere that Base.invokelatest might be able to help, but that feels like a last resort option.

  2. I’ve messed around with composing macros and nesting macros in other functions but haven’t had any luck yet. My sense is that there’s some possibility in editing the first option by adding another layer of macros&functions to evaluate the log variable so it doesn’t just exist as syntax, e.g.

function _evaluatelog(bool)
    evaluates whether bool is true or false
end

macro evaluatelog(bool)
    return evaluatelog(bool)
end

function _myshow(bool, expr)
     bool2 = @evaluatelog bool
     if bool2==true
         expr2 = QuoteNode(expr)
         :(println($expr2, " = ", $(esc(expr))))
     else
         :(println($(esc(expr))))
     end
end

macro myshow(bool, expr)
    return _myshow(bool, expr)
end

If you only need one timestep, would warn and maxlog work?

julia> function do_stuff()
                  @warn "This warning only shows up once" maxlog = 1
                  @warn "But this appears twice" maxlog = 2
                  return 1
              end
do_stuff (generic function with 1 method)

julia> do_stuff()
┌ Warning: This warning only shows up once
└ @ Main REPL[76]:2
┌ Warning: But this appears twice
└ @ Main REPL[76]:3
1

julia> do_stuff()
┌ Warning: But this appears twice
└ @ Main REPL[76]:3
1

julia> do_stuff()
1
1 Like

there’s also always the straight forward option

should_log = true

for i in 1:10
     if should_log
         @show i
         should_log = false
     end
end

But +1 to using the logging system, it does seem like a good tool for the job. Though if performance is absolutely critical one should note that maxlog works by doing a dictionary lookup based on the log id, so could be slightly slower.

Thanks for the response! When using Logging, it messes with the integrity of the code:

@info y = 456

print(y) -> ERROR: UndefVarError: `y` not defined

but maybe it would be possible to implement something like the @show in Logging, or vice-versa with a maxlog in @show so it outputs the unevaluated & evaluated exprs but still assigns the value to the variable.

Thanks for the tip!

1 Like

This is for sure a solid implementation. I forgot to mention that another requirement for this task is that it doesn’t clutter up the code too much (this would require putting for loops in almost every function) but I might have to compromise on that if I can’t find another way.

Thanks for the note on maxlog, I’ll keep an eye on that!

Got it. In that case, I think something like this modified version of @show might work, and you should be able to modify the conditional logic to suit your case (e.g. set foo = (timestep == 5)).

julia> global foo = false
false

julia> macro show_if(exs...)
               if foo
                   blk = Expr(:block)
                   for ex in exs
                       push!(blk.args, :(println($(sprint(Base.show_unquoted,ex)*" = "),
                                                 repr(begin local value = $(esc(ex)) end))))
                   end
                   isempty(exs) || push!(blk.args, :value)
                   return blk
               else
                       return esc(exs...)
               end
       end
@show_if (macro with 1 method)

julia> @show_if 1 + 1
2

julia> foo = true
true

julia> @show_if 1 + 1
1 + 1 = 2
2

This works in the global environment, but when using @show_if in a function, like

function test_show_if(exs...)
for timestep in 1:10
        b =  0
        # Change show_output based on the timestep
        if timestep == 5
            foo = true
        else
            foo = false
        end
        @show_if(b = x + y)
end
end

the global variable foo doesn’t get updated because the macro @show_if seems to freeze the code at the first moment in time it’s called (during precompilation) and so even though we change the global variable in this function, @show_if always sees foo = false

because you don’t update it. You need to use global to write to globals. So write:

        if timestep == 5
            global foo = true
        else
            global foo = false
        end

this checks foo at macro-expansion time, rather than producing code which itself checks foo. I kinda thought the goal would be the latter, so that foo does not need to be defined/set lexically before the macro invocations.

1 Like

Oof, working with macros is tricky. Here’s a version that I think successfully checks foo at runtime:

global foo = false
macro show_if(exs...)
    blk = Expr(:block)
    for ex in exs
        push!(blk.args, :(foo && println($(sprint(Base.show_unquoted,ex)*" = "),
                                  repr(begin local value = $(esc(ex)) end))))
    end
    push!(blk.args, esc(exs...))
    return blk
end


julia> function test_show_if()
       for timestep in 4:6
               b =  0
               # Change show_output based on the timestep

               if timestep == 5
                   global foo = true
               else
                   global foo = false
               end
               println("b before show_if $b")
               @show_if(b = timestep)
               println("b after show_if $b")
       end
       end
test_show_if (generic function with 1 method)

julia> test_show_if()
b before show_if 0
b after show_if 4
b before show_if 0
b = timestep = 5
b after show_if 5
b before show_if 0
b after show_if 6

This executes the code inside @show_if either way, but only displays it when foo == true. Note that you need to use global foo inside the function.