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

No custom logger in library mode #7521

Draft
wants to merge 2 commits into
base: master
Choose a base branch
from

Conversation

yarikoptic
Copy link
Member

@yarikoptic yarikoptic commented Oct 24, 2023

Has 2 commits, but it is the first one which is most important, and its commit message describes it:

Remove custom datalad log handlers while enable library mode

ATM, if there is a root level logger set by Python application, which is a
logical thing to do for an application, then datalad log messages end up
duplicated -- once they are provided by the root level log handler and then by
our very own one. E.g. this script

        import logging

        ## The simplest and documented way to enable logging for a Python app
        logging.basicConfig(level=logging.INFO,
                                                format='%(name)s : %(asctime)s - %(levelname)s - %(message)s')

        # Alternative way to enable some root level logging
        # which surprised me
        #logging.info('This is an info message')

        import datalad.support.gitrepo as r

        r.lgr.info("datalad logger talking")

        datalad_lgr = logging.getLogger("datalad")

        print(f"logging has handlers: {logging.getLogger().handlers}")
        print(f"DataLad has handlers: {datalad_lgr.handlers}"

would produce following output:

    ❯ python simplest_app2.py
    [INFO   ] datalad logger talking
    datalad.gitrepo : 2023-10-24 16:27:02,703 - INFO    - datalad logger talking
    logging has handlers: [<StreamHandler <stderr> (NOTSET)>]
    DataLad has handlers: [<ProgressHandler (NOTSET)>]

so you see our log line duplicated! With the proposed change, we will
explicitly remove all assigned handlers when enabling library mode, and
if we add to above script the datalad.enable_librarymode() we get

    ❯ python simplest_app2.py
    datalad.gitrepo : 2023-10-24 16:29:25,478 - INFO - datalad logger talking
    logging has handlers: [<StreamHandler <stderr> (NOTSET)>]
    DataLad has handlers: []

We also have to respect config variable so we could handle properly the
DATALAD_RUNTIME_LIBRARYMODE environment variable.

edit 1: also it is likely to "interfere" in setting the level unconditionally ATM, I think the set_level is invoked and that results in changing the level here even though root logger might already be set some other level by "main library". I am leaning toward RFing this PR as doing our custom logger overall only when setting to "cmdline" mode.

TODOs:

  • decide to may be to position against maint???
  • decide to may be go more drastic: no custom logging handling unless in CLI or somehow explicitly instructed

ATM, if there is a root level logger set by Python application, which is a
logical thing to do for an application, then datalad log messages end up
duplicated -- once they are provided by the root level log handler and then by
our very own one.  E.g. this script

	import logging

	## The simplest and documented way to enable logging for a Python app
	logging.basicConfig(level=logging.INFO,
						format='%(name)s : %(asctime)s - %(levelname)s - %(message)s')

	# Alternative way to enable some root level logging
	# which surprised me
	#logging.info('This is an info message')

	import datalad.support.gitrepo as r

	r.lgr.info("datalad logger talking")

	datalad_lgr = logging.getLogger("datalad")

	print(f"logging has handlers: {logging.getLogger().handlers}")
	print(f"DataLad has handlers: {datalad_lgr.handlers}"

would produce following output:

	❯ python simplest_app2.py
	[INFO   ] datalad logger talking
	datalad.gitrepo : 2023-10-24 16:27:02,703 - INFO    - datalad logger talking
	logging has handlers: [<StreamHandler <stderr> (NOTSET)>]
	DataLad has handlers: [<ProgressHandler (NOTSET)>]

so you see our log line duplicated!   With the proposed change, we will
explicitly remove all assigned handlers when enabling library mode, and
if we add to above script the  datalad.enable_librarymode() we get

	❯ python simplest_app2.py
	datalad.gitrepo : 2023-10-24 16:29:25,478 - INFO - datalad logger talking
	logging has handlers: [<StreamHandler <stderr> (NOTSET)>]
	DataLad has handlers: []

We also have to respect config variable so we could handle properly the
DATALAD_RUNTIME_LIBRARYMODE environment variable.
…ned, takes its bool

Otherwise even assigning =0 would make it into a library mode
@codeclimate
Copy link

codeclimate bot commented Oct 24, 2023

Code Climate has analyzed commit 165a3a9 and detected 1 issue on this pull request.

Here's the issue category breakdown:

Category Count
Complexity 1

View more on Code Climate.

@yarikoptic yarikoptic added the severity-minor a problem which doesn't affect the package's usefulness, and is presumably trivial to fix label Oct 24, 2023
@codecov
Copy link

codecov bot commented Oct 24, 2023

Codecov Report

All modified and coverable lines are covered by tests ✅

Comparison is base (1d4ff45) 91.59% compared to head (165a3a9) 91.34%.

Additional details and impacted files
@@            Coverage Diff             @@
##           master    #7521      +/-   ##
==========================================
- Coverage   91.59%   91.34%   -0.25%     
==========================================
  Files         325      325              
  Lines       43427    43435       +8     
  Branches     5821     5824       +3     
==========================================
- Hits        39777    39676     -101     
- Misses       3635     3744     +109     
  Partials       15       15              
Files Coverage Δ
datalad/__init__.py 78.57% <100.00%> (-3.79%) ⬇️
datalad/cli/main.py 82.00% <100.00%> (ø)
datalad/log.py 82.69% <100.00%> (-6.03%) ⬇️

... and 26 files with indirect coverage changes

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

@yarikoptic yarikoptic added semver-minor Increment the minor version when merged and removed severity-minor a problem which doesn't affect the package's usefulness, and is presumably trivial to fix labels Oct 27, 2023
@mih
Copy link
Member

mih commented Oct 27, 2023

I am not sure if this is a sensible thing to do. I believe it would turn of any progress reporting also.

I am not familiar with what a library is supposed to do for logging, so I cannot be helpful here. However, I understand the desire to turn off datalad's logging verbosity.

@yarikoptic
Copy link
Member Author

I am not sure if this is a sensible thing to do. I believe it would turn of any progress reporting also.

Indeed worth checking would happen to them!

@yarikoptic yarikoptic marked this pull request as draft November 1, 2023 15:27
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
semver-minor Increment the minor version when merged
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants