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

Problem when use coloredlogs with other libraries. #18

Closed
lightless233 opened this issue Jul 26, 2016 · 7 comments
Closed

Problem when use coloredlogs with other libraries. #18

lightless233 opened this issue Jul 26, 2016 · 7 comments

Comments

@lightless233
Copy link

When I use selenium+phantomjs and coloredlogs, I found all log will output to the console, include selenuim's log. I just want show my log. How can I close the other logs?

This is my code:

FIELD_STYLES = dict(
    asctime=dict(color='green'),
    hostname=dict(color='magenta'),
    levelname=dict(color='green', bold=coloredlogs.CAN_USE_BOLD_FONT),
    filename=dict(color='magenta'),
    name=dict(color='blue'),
    threadName=dict(color='green')
)

LEVEL_STYLES = dict(
    debug=dict(color='green'),
    info=dict(color='cyan'),
    verbose=dict(color='blue'),
    warning=dict(color='yellow'),
    error=dict(color='red'),
    critical=dict(color='red', bold=coloredlogs.CAN_USE_BOLD_FONT)
)
logger = logging.getLogger("ProjectName")

cf = ConfigParser.ConfigParser()
cf.read("config.ini")
if cf.has_option("ProjectName", "debug") and cf.get("ProjectName", "debug") == "On":
    level = "DEBUG"
else:
    level = "INFO"

coloredlogs.install(
    level=level,
    fmt="[%(levelname)s] [(%(threadName)s)] [%(asctime)s] [%(filename)s:%(lineno)d] %(message)s",
    datefmt="%H:%M:%S",
    level_styles=LEVEL_STYLES,
    field_styles=FIELD_STYLES,
)

And I write log like this:

logger.debug("debug information")

And the output like this:

[INFO] [(MainThread)] [00:06:46] [WebSpider.py:74] initial web spider phantomjs process pool...
[DEBUG] [(MainThread)] [00:06:51] [remote_connection.py:415] POST http://127.0.0.1:11225/wd/hub/session {"requiredCapabilities": {}, "desiredCapabilities": {"javascriptEnabled": true, "phantomjs.page.settings.resourceTimeout": 10, "phantomjs.page.settings.loadImages": false, "platform": "ANY", "browserName": "phantomjs", "version": ""}}
[DEBUG] [(MainThread)] [00:06:51] [remote_connection.py:510] Finished Request
[INFO] [(MainThread)] [00:06:51] [WebSpider.py:85] 25.00% finished.

The "remote_connection.py:510" isn't my log, maybe it create by selenium or phantomjs.

After read some docs, I found the coloredlogs.install() function has a param called logger, if it None, it will set to the root logger, so I pass my logger to it, like this below:

coloredlogs.install(
    level=level,
    logger=logger,
    fmt="[%(levelname)s] [(%(threadName)s)] [%(asctime)s] [%(filename)s:%(lineno)d] %(message)s",
    datefmt="%H:%M:%S",
    level_styles=LEVEL_STYLES,
    field_styles=FIELD_STYLES,
)

But this time, there is no log output to console, so I pass a stream to this function, "stream=sys.stdout", also no output.

Did I do something wrong?

@lightless233
Copy link
Author

My environment is Win10 + Python 2.7.11

@icyblade
Copy link

icyblade commented Oct 20, 2016

Same thing happened for TensorFlow, maybe coloredlogs changed something global.
I'm trying to figure it out.

Edit: Pass a logger into coloredlogs.install solves this problem.
@LiGhT1EsS
Just change this
coloredlogs.install()
to this
coloredlogs.install(logger=logger)

If no logger is passed to install(), coloredlogs will install a handler into the root logger, which means any other library will use the root logger at the same time, leads to mysterious logs.

@RedCraig
Copy link

I'm having a bit of difficulty with this actually. I have a feeling I'm misunderstanding how to set up a logger instance for coloredlogs correctly.

Using the python logging howto example, and adding coloredlogs:

import logging

# create logger
logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(formatter)
logger.addHandler(ch)

# test output
logger.debug('debug message')
logger.info('info message')
logger.warn('warn message')
logger.error('error message')
logger.critical('critical message')

import coloredlogs
coloredlogs.install(level='DEBUG', logger=logger)
logger.debug('debug message')
logger.info('info message')
logger.warn('warn message')
logger.error('error message')
logger.critical('critical message')

outputs:

2016-11-16 16:06:53,942 - simple_example - DEBUG - debug message
2016-11-16 16:06:53,942 - simple_example - INFO - info message
2016-11-16 16:06:53,942 - simple_example - WARNING - warn message
2016-11-16 16:06:53,942 - simple_example - ERROR - error message
2016-11-16 16:06:53,942 - simple_example - CRITICAL - critical message
2016-11-16 16:06:53 <hostname> simple_example[63650] WARNING warn message
2016-11-16 16:06:53 <hostname> simple_example[63650] ERROR error message
2016-11-16 16:06:53 <hostname> simple_example[63650] CRITICAL critical message

The streamhandler correctly outputs debug level logs, but after coloredlogs is installed the log level is set to warning and info/debug logs are not emitted.

How can pass in a configured logger to coloredlogs (so that other libraries do log via root logger) and set the coloredlogs level to info/debug?

Thanks for any help.

xolox added a commit that referenced this issue Mar 10, 2017
The old situation:

 - install() would unconditionally change the log level of the root
   logger to logging.NOTSET (changing it from the root logger's
   default level logging.WARNING) and the log levels of handler(s)
   would control which log messages were actually emitted.

 - enable_system_logging() would never change the root logger's
   log level, which meant that when enable_system_logging() was
   used in isolation from install() the default log level would
   implicitly be set to logging.WARNING (the default log level
   of the root logger).

Over the years I've gotten a lot of feedback about the log level
handling in the coloredlogs package, it was clearly the number
one cause of confusion for users. Here are some examples:

- #14
- #18
- #21
- #23
- #24

My hope is that with the changes I've made in the past days, the
experience for new users will be more `Do What I Mean' and less
`What The Fuck is Going On Here?!' :-). Of course only time (and
feedback, or lack thereof) will tell whether I've succeeded.
@xolox
Copy link
Owner

xolox commented Mar 13, 2017

Hi everyone and thanks for the feedback. In the opening post to this issue @LiGhT1EsS mentioned:

Did I do something wrong?

You correctly understood the documentation (and my intention for how coloredlogs should work) but a bug prevented things from working correctly. A few days ago I released coloredlogs 6.0 which should fix this bug. Please try out the latest version, I believe it resolves your problem.

By the way I've also updated the example in the readme to show how to install logging for one specific logger as you initially desired.

Later on @RedCraig mentioned:

I'm having a bit of difficulty with this actually. I have a feeling I'm misunderstanding how to set up a logger instance for coloredlogs correctly.

Sorry for the confusion! This was due to the previously mentioned bug. I believe that coloredlogs 6.0 should end this confusion, both by fixing the bug and improving the documentation.

I'm closing this issue now because I believe that the problems reported here are resolved. If someone disagrees, feel free to reopen this issue or open a new one.

@xolox xolox closed this as completed Mar 13, 2017
@jacobcxdev
Copy link

Forgive me if I'm wrong, but it appears that this issue is occurring for me with the latest version of coloredlogs.

When using Python's logging module, I can simply use the following code to set the logging level of my logger to DEBUG:

self.logger.setLevel(logging.DEBUG)

However, when using coloredlogs, the following code sets the log level on the root logger instead of self.logger:

coloredlogs.install(level=logging.DEBUG, logger=self.logger)

One workaround is to do this, but it's not particularly clean:

coloredlogs.install(level=logging.DEBUG, logger=self.logger)
logging.getLogger().setLevel(logging.WARNING)

After a little research, I noticed that the logger gets set to the root logger here:

handler, logger = replace_handler(logger, match_handler, reconfigure)

This made me wonder whether I was adding a handler to the root logger anywhere else, leading me to discover that if I call logging.basicConfig() elsewhere for any reason (e.g. to set a format for the root logger) it will cause the above issue.

Is this expected behaviour?

@maresb
Copy link

maresb commented Mar 6, 2023

@jacobcxdev, I'm also running into this. In my case it appears that running coloredlogs.install first and logging.basicConfig second is okay, but the other way around results in the root logger level being changed.

Following your analysis, I looked into the source of replace_handler, and I see that by setting the reconfigure=False parameter in coloredlogs.install prevents replace_handler from switching to the root logger.

The API docs say,

If reconfigure is True (it is by default) and an existing StreamHandler is found that is connected to either stdout or stderr the handler will be removed. This means that first calling logging.basicConfig() and then calling coloredlogs.install() will replace the stream handler instead of adding a duplicate stream handler. If reconfigure is False and an existing handler is found no further steps are taken (to avoid installing a duplicate stream handler).

I still can't say I understand the expected behavior, but I personally find it surprising that the root logger would be modified after I pass a logger which isn't the root logger. I'm confused. 😄

@WinstonJenks
Copy link

I am also seeing this problem with version 15.0.6. I use an argument, --color, to optionally turn on colored logs. This code works for me now in a class where I have my own logger, self.log, without causing other loggers to emit messages at the DEBUG level when I set my logger to the DEBUG level. Thanks to jacobcxdev above for tracking this down.

    if args.color:
        rootLogLevel = logging.getLogger().getEffectiveLevel()   # Get root logging level
        coloredlogs.install(level=self.log.getEffectiveLevel(), logger=self.log)
        logging.getLogger().setLevel(rootLogLevel)  # Restore the root logging level

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

No branches or pull requests

7 participants