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 LaunchLogger class #145

Merged
merged 18 commits into from
Mar 14, 2019
Merged

Add LaunchLogger class #145

merged 18 commits into from
Mar 14, 2019

Conversation

jacobperron
Copy link
Member

Supports logging messages from multiple processes and modules to the screen, a common log file, or both.
LaunchLogger is a singleton and when it is first instantiated a log file is created of the form 'DATETIME-launch-HOSTNAME-PID.log'.
Messages sent to the screen or the log file will have the format 'TIME [LEVEL] NAME: MESSAGE'.

Connects to #104

Tests were added that capture and check stdout, but I could only get them working by supplying pytest with the -s option. I'm not sure why this is required.
E.g. colcon test --pytest-args -s --packages-select launch

  • Linux Build Status
  • Linux-aarch64 Build Status
  • macOS Build Status
  • Windows Build Status

@jacobperron jacobperron added in progress Actively being worked on (Kanban column) in review Waiting for review (Kanban column) and removed in progress Actively being worked on (Kanban column) labels Oct 5, 2018
@hidmic hidmic mentioned this pull request Jan 31, 2019
Copy link
Member

@wjwwood wjwwood left a comment

Choose a reason for hiding this comment

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

lgtm, other than some style comments.

@@ -81,23 +81,22 @@ def __init__(
:param: argv stored in the context for access by the entities, None results in []
:param: debug if True (not default), asyncio the logger are seutp for debug
"""
# Setup logging and debugging.
# TODO(hidmic): should be moved somewhere else maybe?
Copy link
Member

Choose a reason for hiding this comment

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

Like where? Generally, I'd like to avoid indeterminate TODO's, at best they have a "do X when Y is possible/occurs" type structure. So I'd like to resolve this TODO before merging.

This seems like a reasonable place to initialize the logging, was there a specific use case you have in mind where this might not work out?

return _decorator


@singleton(screen_handler=None, file_handlers={})
Copy link
Member

Choose a reason for hiding this comment

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

This isn't a great name for the decoration, imo. It's not making the function a singleton, it's adding attributes to the function. Maybe add_logging_attributed or just logging_attributes.


@singleton(screen_handler=None, file_handlers={})
def launchConfig(*, level=None, log_dir=None, screen_format=None,
log_format=None, screen_style=None, log_style=None):
Copy link
Member

Choose a reason for hiding this comment

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

Please wrap all arguments or none, and do not vertically align like this. All indentation should be a multiple of 4 and should only indent one level at a time.

Copy link
Member

Choose a reason for hiding this comment

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

def launchConfig(
    *, level=None, log_dir=None, screen_format=None,
    log_format=None, screen_style=None, log_style=None
):

or

def launchConfig(
    *,
    level=None,
    log_dir=None,
    screen_format=None,
    log_format=None,
    screen_style=None,
    log_style=None
):

the 'default' format.
:param: screen_style the screen format style. No style can be provided
if a format alias is given.
:param: log_format for logging to the main launch log file, as expected
Copy link
Member

Choose a reason for hiding this comment

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

This parameter comes before the previously documented on (screen_style) in the function declaration, please document them in the order they appear in the function declaration.

@hidmic
Copy link
Contributor

hidmic commented Feb 27, 2019

Running CI again:

  • Linux Build Status
  • Linux-aarch64 Build Status
  • macOS Build Status
  • Windows Build Status

@hidmic
Copy link
Contributor

hidmic commented Feb 27, 2019

@wjwwood ready for re-review and merge! :)

Copy link
Member

@wjwwood wjwwood left a comment

Choose a reason for hiding this comment

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

This lgtm, I went through and fixed some style issues, and some docs, and some style issues with the docs :D.

Also, I noticed the use of methodName rather than method_name, which is more common in launch itself. I guess you were trying to emulate the logging module from Python in some cases, to have launch.logging be a drop in replacement of sorts for it.

I'm not sure how I feel about that. I kind of prefer people to use Python's logging directly and the launch.logging module only be used for configuration and special cases. This is pretty much what's happening right now anyways, for instance the only place that launch.logging.getLogger() is being used instead of logging.getLogger appears to be in the launch service, even though there are numerous other cases throughout the code that get the logger directly from Python.

I opened a draft pr (#190) so we can discuss it, because I'd like to know what you think about.

Related to that, I can see the convenience of forwarding some of the logging module's contents via launch.logging, e.g. forwarding logging.DEBUG as launch.logging.DEBUG, but for most of the cases, it seems like having people just use logging directly might be better. Especially if the above draft pr is the direction we want to go in.

launch/test/launch/test_logging.py Outdated Show resolved Hide resolved
@hidmic
Copy link
Contributor

hidmic commented Feb 28, 2019

I guess you were trying to emulate the logging module from Python in some cases, to have launch.logging be a drop in replacement of sorts for it.

That's correct. As a result of providing all necessary functionality (e.g. a reset() to prevent successive LaunchService instances from interacting with each other, not the same as shutdown() as this one can only be called once per process) and keeping the API simple (e.g. no need to configure each logger every time to output to screen and the launch log file) without preventing full use of the logging module capabilities. It seemed to me it was the most sane way to do it considering that logging state is global (e.g. having code affecting logging.root verbosity in launch.logging and user code seemed awkward).

An alternative, though it wouldn't allow for some of the functionality added now, would be to turn launch.logging into a set of functions to configure loggers. And leave everything else to be set through the logging module.

This is pretty much what's happening right now anyways, for instance the only place that launch.logging.getLogger() is being used instead of logging.getLogger appears to be in the launch service, even though there are numerous other cases throughout the code that get the logger directly from Python.

I'm under the impression that you're not considering the changes added by #147 (which we should probably merge into this one). Using launch.logging.getLogger() instead of logging.getLogger() is a convenience to avoid having to explicitly attach screen and launch log file handlers to each and every logger instance. And no, we're not leveraging loggers' hierarchy for common handling because I was unable to use hierarchy relationships to correctly model process output configurations.

@hidmic
Copy link
Contributor

hidmic commented Feb 28, 2019

BTW thanks for the typing annotations :) Haven't had the time to setup mypy on Emacs yet.

@wjwwood
Copy link
Member

wjwwood commented Feb 28, 2019

I'm under the impression that you're not considering the changes added by #147 (which we should probably merge into this one).

Yup, that bit me again. I would support merging them.

So, you are using the custom getLogger in a few places, but I still think it's important for users to realize that this function is from launch and not python itself, so I stand by my request to make it launch.logging.getLogger everywhere in the other pr. Following that logic, I think the function doesn't need to look like the one from python's logging, and so I wouldn't change my proposal in #190, though could still be convinced to not go that way.

What do you want to do, leave it as is or make launch.logging conform to the rest of launch rather than emulate Python's logging module?

@hidmic
Copy link
Contributor

hidmic commented Mar 1, 2019

Ok, I think I see where you're going. To have launch.logging taking care of it's own subtree of loggers, right? I'll take your draft and move things around a bit.

@hidmic
Copy link
Contributor

hidmic commented Mar 6, 2019

@wjwwood Alright, done. I had to rebase to solve some merge conflicts.

There're two things I'm not very fond of though:

  1. To have launch_config() affecting logging.root verbosity.
  2. To have reset() affecting all loggers known to logging.

I'd be inclined to push all launch.logging loggers below a common namespace like launch.<logger-name> to scope the effect of the aforementioned functions. Thoughts?

@wjwwood
Copy link
Member

wjwwood commented Mar 6, 2019

I'm not sure why but there are still merge conflicts.

@hidmic
Copy link
Contributor

hidmic commented Mar 7, 2019

Uh. That's odd. I'll rebase again.

@hidmic
Copy link
Contributor

hidmic commented Mar 8, 2019

@wjwwood ping

Copy link
Member

@wjwwood wjwwood left a comment

Choose a reason for hiding this comment

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

lgtm


There're two things I'm not very fond of though:

  • To have launch_config() affecting logging.root verbosity.

Yeah, I guess so, but couldn't you instead store the requested log level and apply it only to the loggers as they're created using launch.logging.* functions? Effectively preventing them from inheriting from the root logger's settings or you could ensure the given log level is not less than the inherited log level, so that setting the root logger to debug would still affect all launch loggers even if the log level given was info, for example.

  • To have reset() affecting all loggers known to logging.

I don't understand the problem with this one.

I'd be inclined to push all launch.logging loggers below a common namespace like launch.<logger-name> to scope the effect of the aforementioned functions. Thoughts?

I'd prefer to not do that since it just makes all the names longer, though I could be convinced otherwise if there were example outputs which didn't look too bad. Instead I'd prefer to keep track of which "top level" loggers need to be affected without having a namespace for them all.

In the end, I think it won't matter that much as the default use case is running launch in it's own process by itself. The will be cases where that's not true, but I don't feel like this is going to be a big issue, but I could be underestimating it.

@hidmic
Copy link
Contributor

hidmic commented Mar 12, 2019

Yeah, I guess so, but couldn't you instead store the requested log level and apply it only to the loggers as they're created using launch.logging.* functions?

Hmm, the problem with that approach is that launch_config() may be called more than once with different levels or even coexist with levels set on a per logger basis by the user. Having a root logger helps implementing the fallback mechanism (i.e. if no level is set here, use the parent's).

I don't understand the problem with this one.

That it's counter-intuitive if you're using the raw logging module too. A launch.logging.reset() will affect loggers created/retrieved by logging.getLogger(). It seems to my like the kind of caveat/feature/bug one may lose an hour on if the documentation was not read thoroughly.

In the end, I think it won't matter that much as the default use case is running launch in it's own process by itself.

That's a fair argument. Though we'll have a testing framework using launch as a module in short.


Anyways, I'll rebase, test and merge this to get things going. We can revisit it later (even open issues if you think it's worth it). Thanks for the review @wjwwood !

jacobperron and others added 7 commits March 12, 2019 15:40
Supports logging messages from multiple processes and modules to the screen, a common log file, or both.
LaunchLogger is a singleton and when it is first instantiated a log file is created of the form 'DATETIME-launch-HOSTNAME-PID.log'.
Messages sent to the screen or the log file will have the format 'TIME [LEVEL] NAME: MESSAGE'.
The timestamp in the screen format is optional.
Also extends LaunchLogger interface.

Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
- Fix style and documentation issues.
- Removes dangling TODO.

Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
wjwwood and others added 11 commits March 12, 2019 15:40
Signed-off-by: William Woodall <william@osrfoundation.org>
Signed-off-by: William Woodall <william@osrfoundation.org>
Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
Replacing usage of the Python logging module with the new LaunchLogger.
Also, removed unecessary logging logic.
Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
Signed-off-by: Michel Hidalgo <michel@ekumenlabs.com>
@hidmic
Copy link
Contributor

hidmic commented Mar 14, 2019

Alright, CI passed. I'll merge this one, we can discuss outstanding issues/caveats in future PRs.

@hidmic hidmic merged commit 8f1ed68 into master Mar 14, 2019
@hidmic hidmic removed the in review Waiting for review (Kanban column) label Mar 14, 2019
@wjwwood wjwwood deleted the 104-launch-logger branch March 16, 2019 03:31
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.

None yet

3 participants