in warn macro the maxlog keyword is not effective

[piever]

I'm trying reproducing the old behavior of warn(msg, once = true). From the documentation I assumed that was done with the @warn macro and the maxlog keyword but it doesn't seem to work:

julia> function f(x)
           @warn "Test" maxlog=1
           return
       end
f (generic function with 1 method)

julia> f(1)
┌ Warning: Test
└ @ Main REPL[35]:2

julia> f(1)
┌ Warning: Test
└ @ Main REPL[35]:2

I'm on Julia 1.0:

julia> versioninfo()
Julia Version 1.0.0
Commit 5d4eaca0c9 (2018-08-08 20:58 UTC)
Platform Info:
  OS: Linux (x86_64-pc-linux-gnu)
  CPU: Intel(R) Core(TM) i7-7700HQ CPU @ 2.80GHz
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-6.0.0 (ORCJIT, skylake)

[B4rtDC]

I believe the option to limit the output of a logger to only x times is not working in general. The example below is a slightly modified copy (limited i to 15 instead of 10000) of the Logging package documentation.

using Logging
for i=1:15
    @info "With the default backend, you will only see (i = $i) ten times"  maxlog=10
    @debug "Algorithm1" i progress=i/10000
end

┌ Info: With the default backend, you will only see (i = 1) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 2) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 3) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 4) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 5) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 6) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 7) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 8) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 9) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 10) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 11) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 12) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 13) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 14) ten times
└ @ Main In[128]:5
┌ Info: With the default backend, you will only see (i = 15) ten times
└ @ Main In[128]:5

I'm also on Julia 1.0:

julia> versioninfo()
Julia Version 1.0.0
Commit 5d4eaca0c9 (2018-08-08 20:58 UTC)
Platform Info:
  OS: macOS (x86_64-apple-darwin14.5.0)
  CPU: Intel(R) Core(TM)2 Duo CPU     T9600  @ 2.80GHz
  WORD_SIZE: 64
  LIBM: libopenlibm
  LLVM: libLLVM-6.0.0 (ORCJIT, penryn)

[ExpandingMan]

I seem to be seeing this also in 1.0.

[IainNZ]

jump-dev/JuMP.jl#1432 seems to have encountered this problem too

[IainNZ]

Could someone with the power to do so add this to the 1.1 milestone?

[Seelengrab]

julia/base/logging.jl

Lines 231 to 248 in 3ab56f1

	function log_record_id(_module, level, message_ex)
	modname = _module === nothing ? "" : join(fullname(_module), "_")
	# Use (1<<31) to fit well within an (arbitriraly chosen) eight hex digits,
	# as we increment h to resolve any collisions.
	h = hash(string(modname, level, message_ex)) % (1<<31)
	while true
	id = Symbol(modname, '_', string(h, base = 16, pad = 8))
	# _log_record_ids is a registry of log record ids for use during
	# compilation, to ensure uniqueness of ids. Note that this state will
	# only persist during module compilation so it will be empty when a
	# precompiled module is loaded.
	if !(id in _log_record_ids)
	push!(_log_record_ids, id)
	return id
	end
	h += 1
	end
	end

Looks like the id generation doesn't return the old value if one exists. Should be a simple fix.

[oxinabox]

What I can't work out is why this worked fine in Julia 0.7-beta.

See my demo in #29227

This is the diff of logging.jl from 0.7-beta.197 to master

diff --git a/base/logging.jl b/base/logging.jl
index 9034460a4d..1d54aab3d2 100644
--- a/base/logging.jl
+++ b/base/logging.jl
@@ -208,11 +208,11 @@ macro _sourceinfo()
     end)
 end
 
-macro logmsg(level, exs...) logmsg_code((@_sourceinfo)..., esc(level), exs...) end
-macro debug(exs...) logmsg_code((@_sourceinfo)..., :Debug, exs...) end
-macro  info(exs...) logmsg_code((@_sourceinfo)..., :Info,  exs...) end
-macro  warn(exs...) logmsg_code((@_sourceinfo)..., :Warn,  exs...) end
-macro error(exs...) logmsg_code((@_sourceinfo)..., :Error, exs...) end
+macro logmsg(level, message, exs...) logmsg_code((@_sourceinfo)..., esc(level), message, exs...) end
+macro debug(message, exs...) logmsg_code((@_sourceinfo)..., :Debug, message, exs...) end
+macro  info(message, exs...) logmsg_code((@_sourceinfo)..., :Info,  message, exs...) end
+macro  warn(message, exs...) logmsg_code((@_sourceinfo)..., :Warn,  message, exs...) end
+macro error(message, exs...) logmsg_code((@_sourceinfo)..., :Error, message, exs...) end
 
 # Logging macros share documentation
 @eval @doc $_logmsg_docs :(@logmsg)
@@ -229,7 +229,7 @@ _log_record_ids = Set{Symbol}()
 # versions of the originating module, provided the log generating statement
 # itself doesn't change.
 function log_record_id(_module, level, message_ex)
-    modname = _module === nothing ?  "" : join(fullname(_module), "_")
+    modname = join(fullname(_module), "_")
     # Use (1<<31) to fit well within an (arbitriraly chosen) eight hex digits,
     # as we increment h to resolve any collisions.
     h = hash(string(modname, level, message_ex)) % (1<<31)
@@ -288,21 +288,9 @@ function logmsg_code(_module, file, line, level, message, exs...)
             push!(kwargs, Expr(:kw, Symbol(ex), esc(ex)))
         end
     end
-
     # Note that it may be necessary to set `id` and `group` manually during bootstrap
-    id = something(id, :(log_record_id(_module, level, $exs)))
-    if group == nothing
-        group = if isdefined(Base, :basename) && isa(file, String)
-            # precompute if we can
-            QuoteNode(splitext(basename(file))[1])
-        else
-            # memoized run-time execution
-            ref = Ref{Symbol}()
-            :(isassigned($ref) ? $ref[]
-                               : $ref[] = Symbol(splitext(basename(something($file, "")))[1]))
-        end
-    end
-
+    id !== nothing || (id = Expr(:quote, log_record_id(_module, level, exs)))
+    group !== nothing || (group = Expr(:quote, Symbol(splitext(basename(file))[1])))
     quote
         level = $level
         std_level = convert(LogLevel, level)
@@ -341,7 +329,7 @@ end
         handle_message(logger, Error, msg, _module, :logevent_error, id, filepath, line; exception=(err,catch_backtrace()))
     catch err2
         try
-            # Give up and write to stderr, in three independent calls to
+            # Give up and write to STDERR, in three independent calls to
             # increase the odds of it getting through.
             print(stderr, "Exception handling log message: ")
             println(stderr, err)
@@ -496,7 +484,7 @@ with_logger(f::Function, logger::AbstractLogger) = with_logstate(f, LogState(log
     current_logger()
 
 Return the logger for the current task, or the global logger if none is
-attached to the task.
+is attached to the task.
 """
 current_logger() = current_logstate().logger
 
@@ -541,8 +529,8 @@ function handle_message(logger::SimpleLogger, level, message, _module, group, id
     for (key, val) in kwargs
         println(iob, "│   ", key, " = ", val)
     end
-    println(iob, "â”” @ ", something(_module, "nothing"), " ",
-            something(filepath, "nothing"), ":", something(line, "nothing"))
+    mod = _module === nothing ? "" : "$(_module) "
+    println(iob, "â”” @ ", mod, filepath, ":", line)
     write(logger.stream, take!(buf))
     nothing
 end

[c42f]

Root cause is the same as #28400 (bug introduced in #28017)

Analysis: #29355 (comment)