Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add @create_log_macro for making custom styled logging macros #52196

Merged
merged 9 commits into from
Jan 2, 2024

Conversation

IanButterworth
Copy link
Member

@IanButterworth IanButterworth commented Nov 16, 2023

Makes it easier to create custom logging macros

julia> @create_log_macro MyLog 1500 :light_cyan
@mylog (macro with 1 method)

julia> @mylog "hello"
┌ MyLog: hello
└ @ Main REPL[2]:1
Screen.Recording.2023-12-29.at.7.45.22.PM.mov

@IanButterworth IanButterworth added logging The logging framework needs tests Unit tests are required for this change labels Nov 16, 2023
@IanButterworth IanButterworth added backport 1.10 Change should be backported to the 1.10 release and removed needs tests Unit tests are required for this change labels Nov 20, 2023
@DilumAluthge
Copy link
Member

DilumAluthge commented Nov 20, 2023

I think that fixing the UndefVarError: _min_enabled_level not defined error would be a bugfix, but it seems to me that the ability to customize the printing is a new feature.

@IanButterworth IanButterworth added the don't squash Don't squash merge label Nov 20, 2023
@KristofferC KristofferC mentioned this pull request Nov 27, 2023
39 tasks
@IanButterworth IanButterworth removed don't squash Don't squash merge backport 1.10 Change should be backported to the 1.10 release labels Nov 30, 2023
@IanButterworth IanButterworth marked this pull request as draft November 30, 2023 21:26
@IanButterworth IanButterworth changed the title Fix creating custom log level macros Support naming custom log levels Nov 30, 2023
@IanButterworth
Copy link
Member Author

I'm leaving this as a draft as I think this needs a nicer way to make a custom macro than

macro mylog(exs...) Base.CoreLogging.logmsg_code((Base.CoreLogging.@_sourceinfo)..., LogLevel(-500), exs...) end

KristofferC added a commit that referenced this pull request Dec 2, 2023
Backported PRs:
- [x] #51213 <!-- Wait for other threads to finish compiling before
exiting -->
- [x] #51520 <!-- Make allocopt respect the GC verifier rules with non
usual address spaces -->
- [x] #51598 <!-- Use a simple error when reporting sysimg load
failures. -->
- [x] #51757 <!-- fix parallel peakflop usage -->
- [x] #51781 <!-- Don't make pkgimages global editable -->
- [x] #51848 <!-- allow finalizers to take any locks and yield during
exit -->
- [x] #51847 <!-- add missing wait during Timer and AsyncCondition close
-->
- [x] #50824 <!-- Add some aliasing warnings to docstrings for mutating
functions in Base -->
- [x] #51885 <!-- remove chmodding the pkgimages -->
- [x] #50207 <!-- [devdocs] Improve documentation about building
external forks of LLVM -->
- [x] #51967 <!-- further fix to the new promoting method for
AbstractDateTime subtraction -->
- [x] #51980 <!-- macroexpand: handle const/atomic struct fields
correctly -->
- [x] #51995 <!-- [Artifacts] Pass artifacts dictionary to
`ensure_artifact_installed` dispatch -->
- [x] #52098 <!-- Fix errors in `sort` docstring -->
- [x] #52136 <!-- Bump JuliaSyntax to 0.4.7 -->
- [x] #52140 <!-- Make c func `abspath` consistent on Windows. Fix
tracking path conversion. -->
- [x] #52009 <!-- fix completion that resulted in startpos of 0 for `\\
-->
- [x] #52192 <!-- cap the number of GC threads to number of cpu cores
-->
- [x] #52206 <!-- Make have_fma consistent between interpreter and
compiled -->
- [x] #52027 <!-- fix Unicode.julia_chartransform for Julia 1.10 -->
- [x] #52217 <!-- More helpful error message for empty `cpu_target` in
`Base.julia_cmd` -->
- [x] #51371 <!-- Memoize `cwstring` when used for env lookup /
modification on Windows -->
- [x] #52214 <!-- Turn Method Overwritten Error into a PrecompileError
-- turning off caching -->
- [x] #51895 <!-- Devdocs on fixing precompile hangs, take 2 -->
- [x] #51596 <!-- Reland "Don't mark nonlocal symbols as hidden"" -->
- [x] #51834 <!-- [REPLCompletions] allow symbol completions within
incomplete macrocall expression -->
- [x] #52010 <!-- Revert "Support sorting iterators (#46104)" -->
- [x] #51430 <!-- add support for async backtraces of Tasks on any
thread -->
- [x] #51471 <!-- Fix segfault if root task is NULL -->
- [x] #52194 <!-- Fix multiversioning issues caused by the parallel llvm
work -->
- [x] #51035 <!-- refactor GC scanning code to reflect jl_binding_t are
now first class -->
- [x] #52030 <!-- Bump Statistics -->
- [x] #52189 <!-- codegen: ensure i1 bool is widened to i8 before
storing -->
- [x] #52228 <!-- Widen diagonal var during `Type` unwrapping in
`instanceof_tfunc` -->
- [x] #52182 <!-- jitlayers: replace sharedbytes intern pool with one
that respects alignment -->

Contains multiple commits, manual intervention needed:
- [ ] #51092 <!-- inference: fix bad effects for recursion -->

Non-merged PRs with backport label:
- [ ] #52196 <!-- Fix creating custom log level macros -->
- [ ] #52170 <!-- fix invalidations related to `ismutable` -->
- [ ] #51479 <!-- prevent code loading from lookin in the versioned
environment when building Julia -->
@IanButterworth

This comment has been minimized.

@IanButterworth IanButterworth marked this pull request as ready for review December 29, 2023 17:28
@IanButterworth IanButterworth changed the title Support naming custom log levels Add @create_log_macro for making custom styled logging macros Dec 29, 2023
@IanButterworth
Copy link
Member Author

@oxinabox does this look reasonable to you?

@DilumAluthge
Copy link
Member

It seems like @create_log_macro should live in the Logging stdlib, right?

@DilumAluthge DilumAluthge added the feature Indicates new feature / enhancement requests label Dec 30, 2023
base/logging.jl Outdated Show resolved Hide resolved
Co-authored-by: Jacob Quinn <[email protected]>
end
if haskey(custom_log_levels, loglevel)
throw(ArgumentError("Custom log macro already exists for given log level"))
end
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I guess we're ok with reusing existing colors? Maybe it would be helpful to at least note the colors the builtin log levels are already using?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think it's ok to leave that up to the user. They can see the colors of existing logs and figure out what they want from that I think

@quinnj
Copy link
Member

quinnj commented Jan 1, 2024

Would it make sense to define the builtin levels using the new macro? Just curious if there's anything preventing that.

Copy link
Member

@quinnj quinnj left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Love this

@IanButterworth
Copy link
Member Author

Would it make sense to define the builtin levels using the new macro? Just curious if there's anything preventing that.

I'm not sure. The built-in log methods have some > type logic on printing that would require keeping some special handling.

The macro is now defined in Logging, the defaults are defined in CoreLogging. We could move the macro back though.

Also we'd probably want to expand the macro arg handling so that this works

Info = LogLevel(0)
@create_log_macro Info Base.info_color()

because Info is used for printing logic.

Perhaps a follow-on PR?

@IanButterworth IanButterworth merged commit 7baa577 into JuliaLang:master Jan 2, 2024
7 checks passed
@IanButterworth IanButterworth deleted the ib/custom_log_level branch January 2, 2024 01:57
@oxinabox
Copy link
Contributor

oxinabox commented Jan 2, 2024

I guess the way to define the existing levels with the the color printing would be to make the color of the log defaults
orthogonal to default log types.
That just happened to put the default log levels into the right color region (I have argued before that the default logs should actually be in the middle, not the edge of their color regions).

Along the way we could also make the color optional for custom log levels and have it default to that for that color region. (by e.g. storing nothing for the color)

Other problem though is those levels are defined in Base.CoreLogging and the macro for defining log levels is in the logging stdlib, though i guess we could just define it without the macro, but using the same parts.

@quinnj
Copy link
Member

quinnj commented Jan 2, 2024

(I have argued before that the default logs should actually be in the middle, not the edge of their color regions).

Yes, I've wanted this as well.

@fredrikekre
Copy link
Member

I find this a bit weird because:

  1. It couples the log event creation with an expectation/promise how the message will be rendered. It particular it will only hold true for ConsoleLogger. Will it now be required from the API to query the color when rendering messages? What should the color be used for? Many contexts don't even allow color (e.g. JSON logs) so there it has to be ignored regardless.
  2. It modifies a global variable. What happens when there is a conflict? I think that if this is kept it has be disallowed or heavily discouraged to use in packages. It is also a bit strange that this reserves a global resource for something that is local to the namespace where the mew macro is defined.

@IanButterworth
Copy link
Member Author

I think that if this is kept it has be disallowed or heavily discouraged to use in packages

Indeed. That could be noted in the docs. I guess short of some General automerge check there isn't a way to enforce disallowing that though?

It is also a bit strange that this reserves a global resource for something that is local to the namespace where the mew macro is defined.

I did wonder if this could create the macro in Logging and export it.. but that seems more prone to issues.

Re. ConsoleLogger & color specificity, that is a good point. I guess this needs some more thought, but not revert-worthy?

@inkydragon inkydragon removed the merge me PR is reviewed. Merge when all tests are passing label Jan 4, 2024
@fredrikekre
Copy link
Member

I didn't quite follow why this is needed at all. Why can't people just define something like the following pseudo code:

macro mylog(args...)
    return @logmsg LogLevel(1500) args...
end

?

@IanButterworth
Copy link
Member Author

julia> @logmsg LogLevel(1500) "foo"
┌ LogLevel(1500): foo
└ @ Main REPL[9]:1

No customization of the meaning of a log level in the printing.

@IanButterworth
Copy link
Member Author

IanButterworth commented Jan 8, 2024

Also because getting the macro correct by manually constructing it while maintaining the call site info is a little tricky

@fredrikekre
Copy link
Member

Right, but as mentioned above, the rendering is really part of the logger sink that is in use so printing is something that should be registered with the logger instead.. It is pretty easy to do this already with LoggingExtras.jl.

A related thought I had some time ago; perhaps ConsoleLogger should print all info levels as Info: ? Perhaps with the number if it is non-standard.

@IanButterworth
Copy link
Member Author

I do think you have a point about this not working in terms of all the different logger types that would need to plug into it.

I've never thought about the log levels as

Debug 
Debug -999
...
Debug -1
Info
Info 1
....
Info 999
Warn
Warn 1001
...
Warn 1999
Error
Error 2001
...

I always thought of the other numbers as semantically undefined. But that does kind of make sense.

For my specific desires I just want:

  1. a way to easily have a level between @debug and @info that has a simple log macro (simpler than @logmsg MyLog ...)
  2. For that to show in logs more tidily and meaningfully than LogLevel(-500): foo

If we stick to the standard semantic log categories covering the ranges above, then:
Re. 1) I'm not sure it would be possible to make @debug -500 "foo" backwards compatible, and it's a bit untidy. I guess a simple way to make a custom named @debug2 which would effectively @logmsg LogLevel(-500)
Re. 2) Printing off-standard numbers as Debug(-500): foo etc. seems like an improvement

@tecosaur
Copy link
Contributor

@IanButterworth you might be interested in looking at #51829, and how I've resolved the merge conflict introduced by these changes: instead of using a colour name with @create_log_macro you'll want to use a Face or face name (e.g. :tip, :blue, etc.).

The log colour being a Face now could make display in other mime types easier now though, with StyledString's htmlcolor function for instance (though it is private API at the moment).

@IanButterworth
Copy link
Member Author

Thanks. This may end up getting reverted though, but don't let that hold your PR up.

@oxinabox @quinnj what do you think about reverting this and instead doing what's discussed above?

@quinnj
Copy link
Member

quinnj commented Jan 26, 2024

Yeah, that SGTM.

IanButterworth added a commit to IanButterworth/julia that referenced this pull request Mar 2, 2024
KristofferC pushed a commit that referenced this pull request Mar 6, 2024
@KristofferC KristofferC mentioned this pull request Mar 6, 2024
60 tasks
KristofferC added a commit that referenced this pull request Mar 17, 2024
Backported PRs:
- [x] #39071 <!-- Add a lazy `logrange` function and `LogRange` type -->
- [x] #51802 <!-- Allow AnnotatedStrings in log messages -->
- [x] #53369 <!-- Orthogonalize re-indexing for FastSubArrays -->
- [x] #48050 <!-- improve `--heap-size-hint` arg handling -->
- [x] #53482 <!-- add IR encoding for EnterNode -->
- [x] #53499 <!-- Avoid compiler warning about redefining jl_globalref_t
-->
- [x] #53507 <!-- update staled `Core.Compiler.Effects` documentation
-->
- [x] #53408 <!-- task splitting: change additive accumulation to
multiplicative -->
- [x] #53523 <!-- add back an alias for `check_top_bit` -->
- [x] #53377 <!-- add _readdirx for returning more object info gathered
during dir scan -->
- [x] #53525 <!-- fix InteractiveUtils call in Base.runtests on failure
-->
- [x] #53540 <!-- use more efficient `_readdirx` for tab completion -->
- [x] #53545 <!-- use `_readdirx` for `walkdir` -->
- [x] #53551 <!-- revert "Add @create_log_macro for making custom styled
logging macros (#52196)" -->
- [x] #53554 <!-- Always return a value in 1-d circshift! of
abstractarray.jl -->
- [x] #53424 <!-- yet more atomics & cache-line fixes on work-stealing
queue -->
- [x] #53571 <!-- Update Documenter to v1.3 for inventory writing -->
- [x] #53403 <!-- Move parallel precompilation to Base -->
- [x] #53589 <!-- add back `unsafe_convert` to pointer for arrays -->
- [x] #53596 <!-- build: remove extra .a file -->
- [x] #53606 <!-- fix error path in `precompilepkgs` -->
- [x] #53004 <!-- Unexport with, at_with, and ScopedValue from Base -->
- [x] #53629 <!-- typo fix in scoped values docs -->
- [x] #53630 <!-- sroa: Fix incorrect scope counting -->
- [x] #53598 <!-- Use Base parallel precompilation to build stdlibs -->
- [x] #53649 <!-- precompilepkgs: package in boths deps and weakdeps are
in fact only weak -->
- [x] #53671 <!-- Fix bootstrap Base precompile in cross compile
configuration -->
- [x] #52125 <!-- Load Pkg if not already to reinstate missing package
add prompt -->
- [x] #53602 <!-- Handle zero on arrays of unions of number types and
missings -->
- [x] #53516 <!-- permit NamedTuple{<:Any, Union{}} to be created -->
- [x] #53643 <!-- Bump CSL to 1.1.1 to fix libgomp bug -->
- [x] #53679 <!-- move precompile workload back from Base -->
- [x] #53663 <!-- add isassigned methods for reinterpretarray -->
- [x] #53662 <!-- [REPL] fix incorrectly cleared line after completions
accepted -->
- [x] #53611 <!-- Linalg: matprod_dest for Diagonal and adjvec -->
- [x] #53659 <!-- fix #52025, re-allow all implicit pointer casts in
cconvert for Array -->
- [x] #53631 <!-- LAPACK: validate input parameters to throw informative
errors -->
- [x] #53628 <!-- Make some improvements to the Scoped Values
documentation. -->
- [x] #53655 <!-- Change tbaa of ptr_phi to tbaa_value  -->
- [x] #53391 <!-- Default to the medium code model in x86 linux -->
- [x] #53699 <!-- Move `isexecutable, isreadable, iswritable` to
`filesystem.jl` -->
- [x] #41232 <!-- Fix linear indexing for ReshapedArray if the parent
has offset axes -->
- [x] #53527 <!-- Enable analyzegc checks for try catch and fix found
issues -->
- [x] #52092 
- [x] #53682 <!-- Increase build precompilation -->
- [x] #53720 
- [x] #53553 <!-- typeintersect: fix `UnionAll` unaliasing bug caused by
innervars. -->

Contains multiple commits, manual intervention needed:
- [ ] #53305 <!-- Propagate inbounds in isassigned with CartesianIndex
indices -->

Non-merged PRs with backport label:
- [ ] #53736 <!-- fix literal-pow to return the right type when the base
is -1 -->
- [ ] #53707 <!-- Make ScopedValue public -->
- [ ] #53696 <!-- add invokelatest to on_done callback in bracketed
paste -->
- [ ] #53660 <!-- put Logging back in default sysimage -->
- [ ] #53509 <!-- revert moving "creating packages" from Pkg.jl -->
- [ ] #53452 <!-- RFC: allow Tuple{Union{}}, returning Union{} -->
- [ ] #53402 <!-- Add `jl_getaffinity` and `jl_setaffinity` -->
- [ ] #52694 <!-- Reinstate similar for AbstractQ for backward
compatibility -->
- [ ] #51928 <!-- Styled markdown, with a few tweaks -->
- [ ] #51816 <!-- User-themable stacktraces -->
- [ ] #51811 <!-- Make banner size depend on terminal size -->
- [ ] #51479 <!-- prevent code loading from lookin in the versioned
environment when building Julia -->
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
feature Indicates new feature / enhancement requests logging The logging framework
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants