Using @sprintf inside a macro

I need to prefix my log lines with a timestamp. so I was thinking overloading @printf along those lines

import Printf.@printf
macro printf(args...)
    tmp_str =  @sprintf(args...)
    return :(print(now(), " : ", tmp_str))
end

However @sprintf complains that it can’t take expression in. Wonder if there is a way to make it stop complaining.

Alternatively, maybe there are simpler ways to overload @printf so a desired timestamp is added?

You are misunderstanding how macros actually work.

When you call a macro, it is an abstract syntax tree transformation, so the input is treated as an expression instead of as a value.

In your example, you are inputting the expression into the macro of @sprintf which will never work.

You can do it like this (edited) (and edited again :slight_smile:)

julia> import Printf.@sprintf; import Dates.now;

julia> macro myprintf(x, y...)
         quote
           let tmp_str = @sprintf($x, $(esc(y))...)
           print(now(), " : ", tmp_str);
         end; end
       end

julia> @myprintf "%.2f" 1.111
2020-08-20T19:15:25.331 : 1.11

Edit: Thanks @chakravala. I could reproduce your error and then was really confused. I edited it again. Thanks @dlakelan for the hygiene help.

Edit: Still not quite right. See Using @sprintf inside a macro - #17 by simeonschaub for a correct solution by @simeonschaub.

3 Likes

@thofma no that is incorrect (also you have an extra begin which needs to be taken out).

I edited my post. Seems to work. I don’t understand why this should not be possible. The call to @printf is just a transformation at parse time, so why not do the same with the additional now() call? Of course the new macro has the same restrictions as @sprintf.

It doesn’t work for me, so I dont’t know?

julia> @myprintf("%.2f",1/9)
ERROR: LoadError: ArgumentError: @sprintf: first argument must be a format string
Stacktrace:
 [1] @sprintf(::LineNumberNode, ::Module, ::Vararg{Any,N} where N) at /build/julia/src/julia-1.5.0/usr/share/julia/stdlib/v1.5/Printf/src/Printf.jl:1291
 [2] run_repl(::REPL.AbstractREPL, ::Any; backend_on_current_task::Bool) at /build/julia/src/julia-1.5.0/usr/share/julia/stdlib/v1.5/REPL/src/REPL.jl:292
 [3] run_repl(::REPL.AbstractREPL, ::Any) at /build/julia/src/julia-1.5.0/usr/share/julia/stdlib/v1.5/REPL/src/REPL.jl:288
in expression starting at REPL[42]:3

I edited it. Seems to work fine for me:

julia> @myprintf("%.2f",1/9)
2020-08-20T19:19:09.447 : 0.11

I’d suggest

quote
   let tmp_str = ...
...
  end
end

Otherwise if a user uses this macro in the context where they already have a variable called tmp_str it will be overwritten ! In my code it is bound to a new variable inside the let.

3 Likes

Thanks. I secretly hoped that the macro hygiene police would show up :slight_smile:

1 Like

Thanks everyone! The solution works perfectly!

Since temp_str is not escaped you do not need the let. Local variables get renamed by default, and since temp_str is assigned to and not explicitly marked as global it is a local variable.

https://docs.julialang.org/en/v1/manual/metaprogramming/#Hygiene-1

1 Like

Nice. I have to read more about metaprogramming!

I would do it like this

macro myprintf(x, y...)
    :(print(now(),":",@sprintf($x, $(esc(y))...)))
end

having an extra variabl name is unecessary, and my preferred style is to not assign a variable unless it is needed more than once

@chakravala, thanks! In fact, this is exactly how I implemented it now in production code, for all the reasons you mentioned. Initially, I put a variable just to be more explicit where the problem is. Now it is of course time to clean up.

1 Like

Actually looks like I still run into a problem as above solution is not working in some very common scenario. Namely passing a variable into the macro (passing a number directly works)

import Printf.@sprintf; 
import Dates.now;
macro myprintf(x, y...)
    :(print(now(),":",@sprintf($x, $(esc(y))...)))
end

@myprintf("working %.f", 0.42)

#below fails with ERROR: MethodError: no method matching isfinite(::Symbol)
result  = 0.43
@myprintf("failing %.f", result)
1 Like

Splatting doesn’t quite work like this in macro calls. Try:

macro myprintf(x, y...)
    :(print(now(), ":", @sprintf($x, $(esc.(y)...))))
end

instead. You need to do the splatting inside the interpolation, for y to be spliced correctly into the expression.

Edit: I don’t think you even need the esc.

2 Likes

Thanks @simeonschaub! that indeed works as expected.

I wish somebody with a deep knowledge of macros would have written a bit deeper on the topic with tips and tricks, going into tricky situations like those

Yet, one more problem in this solution. using this macro inside a function seems to be not working

import Printf.@sprintf; 
import Dates.now;
macro myprintf(x, y...)
    :(print(now(), ":", @sprintf($x, $(esc.(y)...))))
end

function t()
    r = 21
    @myprintf("failing %.f\n", r * 2)
end

#calling function t is failing with unknown r
t()

I came up with this solution:

julia> macro myprintf(x,y...)
       :(print(now(),":",@sprintf($x,($(y...),)...)))
       end

after reading this post

But I don’t know why it works :rofl:

Does it work for you, if you just leave out the esc in the above example? This might be a macro expansion issue in Julia.