Intended behavior?

[dpo]

I'm finding this confusing and unexpected:

julia> using Logging
julia> Logging.configure(level=DEBUG)
julia> @debug(y)
15-May 15:24:45:DEBUG:root:y

even though there's nothing called y in my name space. This is because of the way the arguments to @debug are escaped in the macro definition. On the other hand, if we define

julia> macro mydebug(msg...)
           if Logging.DEBUG < Logging._root.level
               :nothing
           else
               :(Logging.debug($(msg...)))   # <-- here's the change.
           end
       end

then @mydebug(y) throws an error, which I find much more intuitive. In addition, it allows me to define

debug_formatted(fmt, args...) = @eval @mydebug(@sprintf($fmt, $(args...)))

so that I can type

julia> debug_formatted("a = %d", 3)
15-May 15:24:31:DEBUG:root:a = 3

This lets me log dynamically-generated messages. I'm not sure how the overhead of @eval compares to that of debug(), but it shouldn't be as high because debug() itself starts with an @eval.

[kmsquire]

Thanks for this issue--that behavior is definitely not intentional! Unfortunately, the situation seems to be slightly more complicated. I have a set of fixes that I think will address your concerns and make the macros actually usable. I will try to push them later this evening.

BTW, @eval in a function call will always cause the function to be slow. The evals that are happening in Debug.jl only happen once, in order to define the functions. After the functions are defined, they're simply called, with no additional calls to eval.

I'll write a little more later.

[kmsquire]

Okay, I pushed some fixes. I should have let you push your original idea--sorry about that! That formed the first part of the fix.

The other issue was that, after your fix, any passed variables were evaluated in the context of the Logging module, i.e.,

julia> using Logging

julia> @debug(x)
ERROR: x not defined

julia> x = 5
5

julia> @debug(x)
ERROR: x not defined

julia> macroexpand(:(@debug(x)))
:(Logging.Logging.debug(Logging.x))

That Logging.x is clearly a problem! I think I (vaguely) remember @JeffBezanson changing this a while back, but never updated things here. (Actually, I'm not sure the macros ever worked beyond displaying simple text.)

Anyway, the user is now required to call the (new) @configure macro to use the logging macros, which calls the configure function, and then loads (includes) the macros in the calling context, so they can be used.

julia> using Logging

julia> @Logging.configure(level=DEBUG)
Logger(root,DEBUG,TTY(open, 0 bytes waiting),root)

julia> @debug(x)
ERROR: x not defined

julia> x=5
5

julia> @debug(x)
16-May 07:46:35:DEBUG:root:5

A limitation of this is that it is no longer possible to prefix the macro with Logging., so the current namespace will always be "polluted" with the logging macro names:

julia> @Logging.debug(x)
ERROR: @debug not defined

julia> @debug(x)
16-May 07:49:28:DEBUG:root:5

But at least it's useful now.

[kmsquire]

Fixed by 55a53fcf3449aec353e1e29938c29e816608e4c4

[dpo]

Excellent, thank you! I realize my macro definition lacked hygiene, so you did well to not pull it :). I was just trying to illustrate what I wanted to achieve. Now this works too

@debug(@sprintf("x=%d",x))

which is the real deal in my opinion.

Now, there's a namespace clash with Debug.jl (there may already have been before):

julia> using Logging

julia> @Logging.configure(level=INFO)
Logger(root,INFO,TTY(open, 0 bytes waiting),root)

julia> using Debug
Warning: using Debug.@debug in module Main conflicts with an existing identifier.

[kmsquire]

Sigh. Well, I thought it was a useful workaround. Can you open up another issue for this?

Thanks, Kevin

On Friday, May 16, 2014, Dominique notifications@github.com wrote:

Excellent, thank you! I realize my macro definition lacked hygiene, so you did well to not pull it :). I was just trying to illustrate what I wanted to achieve. Now this works too

@debug(@sprintf("x=%d",x))

which is the real deal in my opinion.

Now, there's a namespace clash with Debug.jl (there may already have been before):

julia> using Logging

julia> @Logging.configure(level=INFO) Logger(root,INFO,TTY(open, 0 bytes waiting),root)

julia> using Debug Warning: using Debug.@debug in module Main conflicts with an existing identifier.

— Reply to this email directly or view it on GitHubhttps://github.com/kmsquire/Logging.jl/issues/11#issuecomment-43355953 .