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

Extract logging to a separate crate #12791

Merged
merged 5 commits into from
Mar 16, 2014
Merged

Conversation

alexcrichton
Copy link
Member

The rationale and modifications can be found in the first commit message.

This does make logging a bit more painful to use initially because it involves a feature gate and some phase attributes, but I think it may be reasonable to not require the phase attribute for loading macro_rules! macros because defining them will still be gated.


(addendum by pnkfelix: if you have found that your debug! invocations have stopped working, try adding this to your crate: #[phase(syntax, link)] extern crate log; Note that this requires #[feature(phase)];. More complete information is available by reading the docs for log)

## Useful Values

For convenience, if a value of `::help` is set for `RUST_LOG`, a program will
start, print out all modules registered for logging, and then exit.
Copy link
Member

Choose a reason for hiding this comment

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

Isn't this no longer true?

@sfackler
Copy link
Member

If externally loaded macros are un-feature-gated, we'll have to commit to finalizing how that process works by 1.0. I think we'll want some form of namespacing for sanity's sake, and full resolve support would be amazing (i.e. use std::macros::println!).

@sfackler
Copy link
Member

Hmm, I guess we'd need to do that even if it isn't un-feature-gated since we load std-macros that way.

@alexcrichton
Copy link
Member Author

Addressed some comments, will squash when good to go.

/// logging. This is the second layer of defense about determining whether a
/// module's log statement should be emitted or not.
#[doc(hidden)]
pub fn mod_enabled(level: u32, module: &str) -> bool {
Copy link
Member

Choose a reason for hiding this comment

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

Should/could this be designed to have the if level > LOG_LEVEL check inlined at call sites? (I guess you'd need to have the INIT.doit and the assert! etc. hidden behind a inline(never) inner function to avoid codebloat as much as possible.)

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 wanted this to specifically not get inlined at call sites. The if level > LOG_LEVEL is indeed inlined at all call sites, and it's done again here in case initialization happened recently.

Copy link
Member

Choose a reason for hiding this comment

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

Aha, it's in the macro invocation too; sounds good.

@huonw
Copy link
Member

huonw commented Mar 10, 2014

I'm sad about RUST_LOG=::help and the warning about mistyped RUST_LOG directives disappearing. I wonder if we could somehow (optionally) put a list of all the modules names into crates to restore this behaviour somewhat.

@@ -330,7 +330,12 @@ impl<'a> ExtCtxt<'a> {
pub fn backtrace(&self) -> Option<@ExpnInfo> { self.backtrace }
pub fn mod_push(&mut self, i: ast::Ident) { self.mod_path.push(i); }
pub fn mod_pop(&mut self) { self.mod_path.pop().unwrap(); }
pub fn mod_path(&self) -> Vec<ast::Ident> { self.mod_path.clone() }
pub fn mod_path(&self) -> Vec<ast::Ident> {
Copy link
Member

Choose a reason for hiding this comment

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

This change is just adding the crate name to the start of the return of module_path!()?

Copy link
Member Author

Choose a reason for hiding this comment

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

yes

@alexcrichton
Copy link
Member Author

I agree, I know that RUST_LOG=::help has helped me out more than once, especially the "no matching directives" warning.

I think the benefits of removing all this from the compiler outweigh the costs, however. It's becoming increasingly clear that we don't need a crate map and requiring one is a burden for all but rustc-generated programs

@alexcrichton
Copy link
Member Author

Updated with comments

@huonw
Copy link
Member

huonw commented Mar 10, 2014

r=me with a squash and rebase.

@alexcrichton
Copy link
Member Author

r? the last commit?

I'm still not entirely certain why it's necessary, but I did my best to document at least what I do understand.

This commit moves all logging out of the standard library into an external
crate. This crate is the new crate which is responsible for all logging macros
and logging implementation. A few reasons for this change are:

* The crate map has always been a bit of a code smell among rust programs. It
  has difficulty being loaded on almost all platforms, and it's used almost
  exclusively for logging and only logging. Removing the crate map is one of the
  end goals of this movement.

* The compiler has a fair bit of special support for logging. It has the
  __log_level() expression as well as generating a global word per module
  specifying the log level. This is unfairly favoring the built-in logging
  system, and is much better done purely in libraries instead of the compiler
  itself.

* Initialization of logging is much easier to do if there is no reliance on a
  magical crate map being available to set module log levels.

* If the logging library can be written outside of the standard library, there's
  no reason that it shouldn't be. It's likely that we're not going to build the
  highest quality logging library of all time, so third-party libraries should
  be able to provide just as high-quality logging systems as the default one
  provided in the rust distribution.

With a migration such as this, the change does not come for free. There are some
subtle changes in the behavior of liblog vs the previous logging macros:

* The core change of this migration is that there is no longer a physical
  log-level per module. This concept is still emulated (it is quite useful), but
  there is now only a global log level, not a local one. This global log level
  is a reflection of the maximum of all log levels specified. The previously
  generated logging code looked like:

    if specified_level <= __module_log_level() {
        println!(...)
    }

  The newly generated code looks like:

    if specified_level <= ::log::LOG_LEVEL {
        if ::log::module_enabled(module_path!()) {
            println!(...)
        }
    }

  Notably, the first layer of checking is still intended to be "super fast" in
  that it's just a load of a global word and a compare. The second layer of
  checking is executed to determine if the current module does indeed have
  logging turned on.

  This means that if any module has a debug log level turned on, all modules
  with debug log levels get a little bit slower (they all do more expensive
  dynamic checks to determine if they're turned on or not).

  Semantically, this migration brings no change in this respect, but
  runtime-wise, this will have a perf impact on some code.

* A `RUST_LOG=::help` directive will no longer print out a list of all modules
  that can be logged. This is because the crate map will no longer specify the
  log levels of all modules, so the list of modules is not known. Additionally,
  warnings can no longer be provided if a malformed logging directive was
  supplied.

The new "hello world" for logging looks like:

    #[phase(syntax, link)]
    extern crate log;

    fn main() {
        debug!("Hello, world!");
    }
This commit removes all internal support for the previously used __log_level()
expression. The logging subsystem was previously modified to not rely on this
magical expression. This also removes the only other function to use the
module_data map in trans, decl_gc_metadata. It appears that this is an ancient
function from a GC only used long ago.

This does not remove the crate map entirely, as libgreen still uses it to hook
in to the event loop provided by libgreen.
In removing many fields from the crate map, executables no longer always have an
explicit dependency on all upstream libraries. This means that the linker is no
longer picking them up as it used to.

To the best of my knowledge, the current situation is happening:

* On linux, we're passing the --as-needed flag to the linker, meaning that
  libraries are stripped out if there are no references to symbols in them.
* Executables may not reference libstd at all, such as "fn main() {}"
* When linking, the linker will discard libstd because there are no references
  to symbols in it. I presume that this means that all previous libs have had
  all their symbols resolved, so none of the libs are pulling in libstd as a
  dependency.
* The only real dependence on libstd comes from the rust_stack_exhausted symbol
  (which comes from libmorestack), but -lmorestack is at the end so by the time
  this comes up libstd is completely gone, leading to undefined references to
  rust_stack_exhausted

I'm not entirely convinced that this is what's happening, but it appears to be
along these lines. The one thing that I'm sure of is that removing the crate map
(and hence implicit dependency on all upstream libraries) has changed how
objects depend on upstream libraries.
This commit starts to topographically sort rust dependencies on the linker
command line. The reason for this is that linkers use right-hand libraries to
resolve left-hand libraries symbols, which is especially crucial for us because
we're using --as-needed on linux.
This commit switches over the backtrace infrastructure from piggy-backing off
the RUST_LOG environment variable to using the RUST_BACKTRACE environment
variable (logging is now disabled in libstd).
bors added a commit that referenced this pull request Mar 16, 2014
The rationale and modifications can be found in the first commit message.

This does make logging a bit more painful to use initially because it involves a feature gate and some `phase` attributes, but I think it may be reasonable to not require the `phase` attribute for loading `macro_rules!` macros because defining them will still be gated.
@bors bors closed this Mar 16, 2014
@bors bors merged commit 0015cab into rust-lang:master Mar 16, 2014
cadencemarseille added a commit to cadencemarseille/rust-pcre that referenced this pull request Mar 16, 2014
@alexcrichton alexcrichton deleted the liblog branch March 17, 2014 03:47
Kroisse added a commit to Kroisse/rust-mustache that referenced this pull request Mar 17, 2014
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants