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

Fixes for logging during bootstrap #25722

Merged
merged 5 commits into from
Jan 25, 2018
Merged

Fixes for logging during bootstrap #25722

merged 5 commits into from
Jan 25, 2018

Conversation

c42f
Copy link
Member

@c42f c42f commented Jan 24, 2018

Here's some fixes to make logging reliable while building the sysimg.

  • Install SimpleLogger during sysimg build instead of NullLogger so that build warnings will be reported - see fix "Deprecated syntax "begin" inside indexing expression" warning. #25699 (comment)
  • For now, move the inclusion of logging.jl later in the sysimg, as it requires current_task() to be defined. With extra effort this could be defined further up but this seems simplest for now.
  • Use simpler formatting for SimpleLogger so it can be relied on earlier during bootstrap (don't rely on color printing or path manipulation). User friendly formatting is now provided by ConsoleLogger instead.
  • Don't catch logging exceptions inside SimpleLogger; let them propagate out as obvious errors instead.

This ensures bootstrap messages will be visible.
* Remove uses of print_with_color
* Remove use of basename() - just print the whole path
* Remove special case single line log formatting - always print metadata
  on a new line.
current_task() is used to discover the logger, so this must come after
task.jl
A logging exception during bootstrap is probably an error - propagate
this through instead of catching it.
test/logging.jl Outdated
"""

# Multiline message
@test genmsg(Warn, "line1\nline2", Main, "some/path.jl", 101) ==
"""
Warning: line1
Warn: line1
Copy link
Sponsor Member

Choose a reason for hiding this comment

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

It'd be better if this also used the full word, for consistency if nothing else.

Copy link
Member Author

Choose a reason for hiding this comment

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

What I did here was remove the special case when formatting the log level as part of the effort to do the least amount of formatting in SimpleLogger while keeping it fairly readable.

I'm leaning toward just renaming CoreLogging.Warn to CoreLogging.Warning because it seems really kind of bad to have to special case the printing of LogLevel every time you want to print it! How about I add the special case back in here, and make a separate PR for the renaming.

Copy link
Member Author

Choose a reason for hiding this comment

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

By the way, removing the special casing was more about simplicity and making custom log levels print correctly rather than changing Warn. The printing in ConsoleLogger is unaffected, which is what users will see by default.

@JeffBezanson
Copy link
Sponsor Member

Great, thanks!

@ararslan ararslan added the logging The logging framework label Jan 24, 2018
Copy link
Sponsor Member

@vtjnash vtjnash left a comment

Choose a reason for hiding this comment

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

Will be good to have this fixed. Looks likes some deprecation warnings may have been getting lost.

# Logging
include("logging.jl")
using .CoreLogging
global_logger(SimpleLogger(Core.STDERR, CoreLogging.Info))
Copy link
Sponsor Member

Choose a reason for hiding this comment

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

I think the assignment to _global_logstate can just be done at the end of the logging.jl file, and then also drop the using statement

Copy link
Member Author

Choose a reason for hiding this comment

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

The using (or an import) is required to bring the logging macro names into Base for later use in the sysimg, for example in loading.jl. So I'll leave this here unless there's a particular preference to do that with an import.

I set the logger here in sysimg because the value we're setting for the global logger is entirely related to bootstrap, not to the logging system per se. So I'd rather leave it in sysimg.jl because that's the place where the bootstrap ordering is defined.

@c42f
Copy link
Member Author

c42f commented Jan 25, 2018

Right, I've reverted the change to the Warn printing (let's discuss that separately). Good to go now from my perspective.

base/logging.jl Outdated
@@ -490,7 +490,7 @@ function handle_message(logger::SimpleLogger, level, message, _module, group, id
end
buf = IOBuffer()
iob = IOContext(buf, logger.stream)
levelstr = string(level)
levelstr = level == Warn ? "Warning" : string(level)
Copy link
Sponsor Member

Choose a reason for hiding this comment

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

My thought to make this less exceptional was that one might be able to specify a levelstr for each kind of message instead of just hacking this in there. Not important though since extension points can always be added in the future.

@JeffBezanson JeffBezanson merged commit e23b2ab into master Jan 25, 2018
@JeffBezanson JeffBezanson deleted the cjf/bootstrap-logging branch January 25, 2018 17:20
@vtjnash
Copy link
Sponsor Member

vtjnash commented Jan 26, 2018

It looks like there were two more instances of this missed in the Meta.parse functionality

@vtjnash
Copy link
Sponsor Member

vtjnash commented Jan 26, 2018

Oh, wait, I see you're trying to respect the depwarn boolean – I hadn't seen #25257 that flisp code is now attempting to act as if it is re-entrant and as if it is safe to call back into Julia code. Usually the user doesn't need to use these functions at runtime, but the existence of generated functions makes that assumption pretty bad.

@c42f
Copy link
Member Author

c42f commented Jan 27, 2018

flisp code is now attempting to act as if it is re-entrant and as if it is safe to call back into Julia code

Oh darn. So logging from the parser can be problematic if a generated function constructs a string and sends it through Meta.parse(), which further happens to have a syntax deprecation. Makes sense I suppose.

I'm sure there's a way out of this conundrum without going back to spamming STDERR (probably something task-related as you've previously suggested, or another related way of deferring messages). So far the response on #25413 didn't look promising but I've got some more ideas I can pursue.

@vtjnash
Copy link
Sponsor Member

vtjnash commented Jan 27, 2018

Or just if the generator returns an ast with deprecated syntax.

Oh well, this is all going away in a few months after we cut the v0.7 release, so maybe not a big deal to spend too much time on. Better to get the logging infrastructure working well and ready for release.

@c42f
Copy link
Member Author

c42f commented Jan 27, 2018

Oh right, hitting the problem in lowering generated ASTs is a lot more likely.

@c42f
Copy link
Member Author

c42f commented Jan 27, 2018

By the way, which parts are going away? It would be nice to have some idea so I can avoid wasting time on those.

@vtjnash
Copy link
Sponsor Member

vtjnash commented Jan 27, 2018

Sorry, I meant deprecations are going away (so the flisp code in Julia v1.0 won't need to deal with them anyways & not much point in wasting your time on them now)

@c42f
Copy link
Member Author

c42f commented Jan 27, 2018

Oh sure, no problem.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
logging The logging framework
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants