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

Demote (to level 1 from DEBUG) and speed-up API doc logging (parseParameters) #6635

Merged
merged 1 commit into from
Apr 21, 2022

Conversation

mih
Copy link
Member

@mih mih commented Apr 21, 2022

Previously, log messages like this would appear at DEBUG level:

[DEBUG] parseParameters: Given "exclude_special_remotes: bool, optional
  if True, don't return annex special remotes", we split into [('exclude_special_remotes', "exclude_special_remotes: bool, optional\n  if True, don't return annex special remotes")]

These are very verbose and large in number, making debug
output needlessly complicated to read.

Moreover, they log the outcome of a trivial operation that practically
never fails in production code, at a comparatively high level (DEBUG),
and they did it in an expensive way that actually built the log string
unconditionally of the effective log level.

This change demote the log level to the lowest possible, and uses a proper
logging pattern that avoid needless string operations.

Changelog

Not needed

Previously, log messages like this would appear at DEBUG level:

```
[DEBUG] parseParameters: Given "exclude_special_remotes: bool, optional
  if True, don't return annex special remotes", we split into [('exclude_special_remotes', "exclude_special_remotes: bool, optional\n  if True, don't return annex special remotes")]
```

These are very verbose and large in number, making debug
output needlessly complicated to read.

Moreover, they log the outcome of a trivial operation that practically
never fails in production code, at a comparatively high level (DEBUG),
and they did it in an expensive way that actually built the log string
unconditionally of the effective log level.

This change demote the log level to the lowest possible, and uses a proper
logging pattern that avoid needless string operations.
@mih mih added the semver-internal Changes only affect the internal API label Apr 21, 2022
@codecov
Copy link

codecov bot commented Apr 21, 2022

Codecov Report

Merging #6635 (ae7cce2) into maint (eb55f5a) will not change coverage.
The diff coverage is 100.00%.

@@           Coverage Diff           @@
##            maint    #6635   +/-   ##
=======================================
  Coverage   91.17%   91.17%           
=======================================
  Files         353      353           
  Lines       44496    44496           
=======================================
  Hits        40568    40568           
  Misses       3928     3928           
Impacted Files Coverage Δ
datalad/dochelpers.py 84.74% <100.00%> (ø)

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 eb55f5a...ae7cce2. Read the comment docs.

lgr.debug('parseParameters: Given "%s", we split into %s' %
(paramdoc, result))
lgr.log(
1,
Copy link
Member

Choose a reason for hiding this comment

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

I remember there was some interaction between 1 and "something else" . That is why we hardly ever have logging at that low level

$> git grep -A1 '\.log($'
datalad/cmd.py:                lgr.log(
datalad/cmd.py-                    5,
--
datalad/core/local/repo.py:            lgr.log(
datalad/core/local/repo.py-                5,
--
datalad/runner/coreprotocols.py:            lgr.log(
datalad/runner/coreprotocols.py-                5,
--
datalad/runner/protocol.py:        lgr.log(
datalad/runner/protocol.py-            8,
--
datalad/runner/runnerthreads.py:        lgr.log(
datalad/runner/runnerthreads.py-            5,
--
datalad/support/sshconnector.py:            lgr.log(
datalad/support/sshconnector.py-                5,

$> git grep '\.log(1'    
datalad/dataset/gitrepo.py:        lgr.log(1, "Finalizer called on: GitRepo(%s)", path)
datalad/support/annexrepo.py:        lgr.log(1, "Finalizer called on: AnnexRepo(%s)", path)

but IIRC it was relating to custom special remotes and custom implementation of those is gone, so might no longer be pertinent. I personally would have not made it 1 but something like 5 (HEAVYDEBUG) but I also do not care enough. Let's proceed. I will release maint with this

@yarikoptic yarikoptic changed the title Demote and speed-up API doc logging Demote (to level 1 from DEBUG) and speed-up API doc logging (parseParameters) Apr 21, 2022
@yarikoptic yarikoptic added the release Create a release when this pr is merged label Apr 21, 2022
@yarikoptic yarikoptic merged commit 84b287b into datalad:maint Apr 21, 2022
@mih mih deleted the rf-log branch July 19, 2022 11:40
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
release Create a release when this pr is merged semver-internal Changes only affect the internal API
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants