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

utils.get_logger dominates rerender performance #5382

Closed
2 tasks done
minrk opened this issue Jun 21, 2024 · 1 comment · Fixed by #5384
Closed
2 tasks done

utils.get_logger dominates rerender performance #5382

minrk opened this issue Jun 21, 2024 · 1 comment · Fixed by #5384
Labels
type::bug describes erroneous operation, use severity::* to classify the type
Milestone

Comments

@minrk
Copy link
Contributor

minrk commented Jun 21, 2024

Checklist

  • I added a descriptive title
  • I searched open reports and couldn't find a duplicate

What happened?

I'm Investigating rerender performance where our rerenders are taking over 30 minutes (conda-forge/petsc4py).

after #5281, which reduces total rerender time by ~80% (from 30 minutes to 5), 30% of render time (40 seconds out of 2 minutes for a single render call) is spent in logger.setLevel here (more than in the optimized deepcopy).

If get_logger could avoid re-initializing the logger if it's already been initialized, render could be 30% faster. It's not clear to me what's expected if the args other than name are specified in terms of re-initialization, which prevents me from making a simple PR.

Related to #5224

Conda Info

mamba version : 1.5.8
     active environment : None
            shell level : 0
       user config file : /Users/minrk/.condarc
 populated config files : /Users/minrk/conda/.condarc
                          /Users/minrk/.condarc
          conda version : 24.3.0
    conda-build version : 24.5.1
         python version : 3.10.13.final.0
                 solver : libmamba (default)
       virtual packages : __archspec=1=m1
                          __conda=24.3.0=0
                          __mpich=4.2.1=0
                          __osx=14.5=0
                          __unix=0=0
       base environment : /Users/minrk/conda  (writable)
      conda av data dir : /Users/minrk/conda/etc/conda
  conda av metadata url : None
           channel URLs : https://conda.anaconda.org/conda-forge/osx-arm64
                          https://conda.anaconda.org/conda-forge/noarch
          package cache : /Users/minrk/conda/pkgs
                          /Users/minrk/.conda/pkgs
       envs directories : /Users/minrk/conda/envs
                          /Users/minrk/.conda/envs
               platform : osx-arm64
             user-agent : conda/24.3.0 requests/2.31.0 CPython/3.10.13 Darwin/23.5.0 OSX/14.5 solver/libmamba conda-libmamba-solver/23.11.1 libmambapy/1.5.8
                UID:GID : 501:20
             netrc file : /Users/minrk/.netrc
           offline mode : False

Conda Config

==> /Users/minrk/conda/.condarc <==
channels:
  - conda-forge

==> /Users/minrk/.condarc <==
local_repodata_ttl: 86400
channels:
  - conda-forge
show_channel_urls: True
report_errors: False

==> envvars <==
allow_softlinks: False

Conda list

No response

Additional Context

No response

@minrk minrk added the type::bug describes erroneous operation, use severity::* to classify the type label Jun 21, 2024
@beckermr
Copy link
Contributor

I checked the source code and internally, there is a lock that python needs to acquire in order to set the level. This is likely the source of the slow down.

This was referenced Jun 21, 2024
@isuruf isuruf added this to the 24.7.x milestone Jun 22, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type::bug describes erroneous operation, use severity::* to classify the type
Projects
Archived in project
3 participants