Skip to content

joblib now logs to joblib namespace and no longer adds a stream handler to the root logger.#1033

Closed
amniskin wants to merge 3 commits intojoblib:masterfrom
amniskin:master
Closed

joblib now logs to joblib namespace and no longer adds a stream handler to the root logger.#1033
amniskin wants to merge 3 commits intojoblib:masterfrom
amniskin:master

Conversation

@amniskin
Copy link
Copy Markdown
Contributor

@amniskin amniskin commented Apr 16, 2020 

#!/usr/bin/env python3

import logging
from joblib import Memory

ROOT_LOGGER = logging.getLogger()

mem = Memory('/tmp/', verbose=100)


@mem.cache
def foo(x):
    print('running foo')
    return x + 1


print('pre-function-call', ROOT_LOGGER.handlers)
x = foo(0)

print('post-function-call', ROOT_LOGGER.handlers)
ROOT_LOGGER.removeHandler(ROOT_LOGGER.handlers[0])
print('post-remove', ROOT_LOGGER.handlers)
x = foo(1)
print('post-second-function-call', ROOT_LOGGER.handlers)
ROOT_LOGGER.removeHandler(ROOT_LOGGER.handlers[0])
x = foo(1)
print('post-memoized-function-call', ROOT_LOGGER.handlers)

produces the following output:

pre-function-call []
WARNING:root:[MemorizedFunc(func=<function foo at 0x7ff7da2e6e60>, location=/tmp/joblib)]: Computing func foo, argument hash eafd7cd8280c6ace8622a25cf1f54934 in location /tmp/joblib/__main__--home-ubuntu-scratch-tmp/foo
________________________________________________________________________________
[Memory] Calling __main__--home-ubuntu-scratch-tmp.foo...
foo(0)
running foo
Persisting in /tmp/joblib/__main__--home-ubuntu-scratch-tmp/foo/eafd7cd8280c6ace8622a25cf1f54934
______________________________________________________________foo - 0.0s, 0.0min
post-function-call [<StreamHandler <stderr> (NOTSET)>]
post-remove []
WARNING:root:[MemorizedFunc(func=<function foo at 0x7ff7da2e6e60>, location=/tmp/joblib)]: Computing func foo, argument hash d3ffa92536e9b2aeb96c6d0e11ccd857 in location /tmp/joblib/__main__--home-ubuntu-scratch-tmp/foo
________________________________________________________________________________
[Memory] Calling __main__--home-ubuntu-scratch-tmp.foo...
foo(1)
running foo
Persisting in /tmp/joblib/__main__--home-ubuntu-scratch-tmp/foo/d3ffa92536e9b2aeb96c6d0e11ccd857
______________________________________________________________foo - 0.0s, 0.0min
post-second-function-call [<StreamHandler <stderr> (NOTSET)>]
[Memory]0.0s, 0.0min    : Loading foo from /tmp/joblib/__main__--home-ubuntu-scratch-tmp/foo/d3ffa92536e9b2aeb96c6d0e11ccd857
_________________________________________________foo cache loaded - 0.0s, 0.0min
post-memoized-function-call []

The culprit was that the Logger class was using the bare logging.warning functions instead of instantiating a logger and then using that logger's logging functions as it should have. Furthermore, it should be logging to a joblib namespace.

amniskin added 2 commits April 16, 2020 06:39
@amniskin
created a joblib logger.
667bfd6 
using logging.(debug,warning, etc) from within a library is unwise as it forces the end user to have a stream handler on the root logger. Now you'll be logging to the joblib namespace, so that users can specify a logging level via `logging.getLogger('joblib').setLevel(logging.DEBUG)` or whatever they want.
@amniskin
Merge pull request #1 from amniskin/amniskin-patch-1
4b11dc8 
created a joblib logger.
@codecov
Copy link
Copy Markdown

codecov bot commented Apr 16, 2020 •
edited
Loading

Codecov Report

Merging #1033 into master will increase coverage by 0.03%.
The diff coverage is 75.00%.

Impacted file tree graph

@@            Coverage Diff             @@
##           master    #1033      +/-   ##
==========================================
+ Coverage   94.89%   94.92%   +0.03%     
==========================================
  Files          45       45              
  Lines        6803     6804       +1     
==========================================
+ Hits         6456     6459       +3     
+ Misses        347      345       -2
Impacted Files Coverage Δ
joblib/logger.py 87.01% <75.00%> (+0.17%) ⬆️
joblib/memory.py 95.72% <0.00%> (-0.54%) ⬇️
joblib/disk.py 88.33% <0.00%> (+6.66%) ⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 5b7acb6...3a5ec63. Read the comment docs.

@amniskin
Copy link
Copy Markdown
Contributor Author

amniskin commented Apr 16, 2020

What's going on here? A bunch of things that seem to have nothing to do with anything I changed are now broken (things like pickling io objects). Was that me?

@amniskin amniskin mentioned this pull request Apr 16, 2020
Closed
@pierreglaser
Copy link
Copy Markdown
Contributor

pierreglaser commented Apr 16, 2020

Yes most probably: joblib visibly expects Memory objects to be pickleable, which is not the case in your implementation because you append a Logger object to the Memory instances, but this Logger object is not always pickleable.

I'm actively (right now) working on a consistent and compliant usage of logging across the joblib codebase. Hopefully this will land in the next few weeks.

@amniskin
no longer storing the thread-local logger
3a5ec63 
It adds about 10ns to each log use.
@amniskin
Copy link
Copy Markdown
Contributor Author

amniskin commented Apr 17, 2020

Thanks! I thought joblib was supposed to be able to pickle loggers. Hmm...

@amniskin
Copy link
Copy Markdown
Contributor Author

amniskin commented Apr 17, 2020 •
edited
Loading

So now there are no loggers stored in the object, and it adds minimal overhead (I timed it and it's like 10ns to get a logger). Would this be an acceptable (if temporary) fix?

@amniskin
Copy link
Copy Markdown
Contributor Author

amniskin commented Apr 17, 2020

This way the user can attach whatever log handlers they want to the joblib logger. And if we wanted to get even crazier, we could have each subclass specify a child namespace to log to (e.g. joblib.memory, etc), and then users could attach log handlers to joblib, joblib.memory, or whatever they want.

@pierreglaser
Copy link
Copy Markdown
Contributor

pierreglaser commented Apr 22, 2020 •
edited
Loading

This way the user can attach whatever log handlers they want to the joblib logger. And if we wanted to get even crazier, we could have each subclass specify a child namespace to log to (e.g. joblib.memory, etc), and then users could attach log handlers to joblib, joblib.memory, or whatever they want.

Indeed this would be much better -- I have been working on this last week and I'll open a PR once #1018 is merged.

@tomMoral tomMoral closed this Apr 28, 2023
@tomMoral
Copy link
Copy Markdown
Contributor

tomMoral commented Apr 28, 2023

Oops, I wanted to close and reopen this PR to make the CI pass but I cannot reopen it because the repository has been deleted. Will duplicate it.

@tomMoral tomMoral mentioned this pull request Apr 28, 2023
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

No reviews

Assignees

No one assigned

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

3 participants

@amniskin @pierreglaser @tomMoral