Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bug 770829 - Please upload your pstats dumps here.
Summary: Please upload your pstats dumps here.
Status: CONFIRMED
Alias: None
Product: Portage Development
Classification: Unclassified
Component: Core (show other bugs)
Hardware: All Linux
: Normal normal (vote)
Assignee: Portage team
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-02-15 19:54 UTC by Alec Warner (RETIRED)
Modified: 2023-05-22 02:51 UTC (History)
5 users (show)

See Also:
Package list:
Runtime testing required: ---


Attachments
Profile dump (portage-stats.bin,641.55 KB, application/octet-stream)
2021-02-16 01:44 UTC, Mike Gilbert
Details
emerge -ep @world (emerge-ep.bin,460.99 KB, application/octet-stream)
2021-02-16 19:00 UTC, Mike Gilbert
Details
Multiple profile dumps (portage.cprof.dump.zip,578.29 KB, application/zip)
2021-02-16 21:38 UTC, Conrad Kostecki
Details
Log for multiple profile dumps (portage.cprof.log,8.60 KB, text/plain)
2021-02-16 21:38 UTC, Conrad Kostecki
Details
python -m cProfile -o portage.cprof /usr/bin/emerge -pe @world (emerge,2.47 KB, text/plain)
2021-04-28 03:11 UTC, bpholman5
Details
complex tree update with backtrack (portage.cprof,516.87 KB, application/octet-stream)
2021-04-29 20:11 UTC, Alessandro Barbieri
Details
cProfile form my hardened stable KDE desktop (portage.cprof,483.79 KB, application/octet-stream)
2021-06-13 11:52 UTC, Toralf Förster
Details
portage.cprof from my stable server (tor + tinderbox) (portage.cprof,480.03 KB, application/octet-stream)
2021-06-13 11:53 UTC, Toralf Förster
Details
portage.cprof from an 11 days old tinderbox image (~9,500 packages) (portage.cprof,498.99 KB, application/octet-stream)
2021-06-13 12:13 UTC, Toralf Förster
Details
profile of emerge --version (outfile,365.39 KB, application/octet-stream)
2023-05-22 02:51 UTC, Berin Aniesh
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Alec Warner (RETIRED) archtester gentoo-dev Security 2021-02-15 19:54:06 UTC
I'd like to do some performance improvements. If you want portage to be faster:

Follow the instructions here to generate a profile dump.

https://wiki.gentoo.org/wiki/Project:Portage/Profiling

Then attach the dumps here. I'm trying to find common areas where portage is spending its time.

-A
Comment 1 Mike Gilbert gentoo-dev 2021-02-16 01:44:50 UTC
Created attachment 686847 [details]
Profile dump
Comment 2 Mike Gilbert gentoo-dev 2021-02-16 01:45:58 UTC
Comment on attachment 686847 [details]
Profile dump

That's the output of "sudo python -m cProfile -o /tmp/portage-stats ~/src/portage/bin/emerge -uUDv --changed-deps y @world"
Comment 3 Mike Gilbert gentoo-dev 2021-02-16 19:00:31 UTC
Created attachment 686997 [details]
emerge -ep @world
Comment 4 Conrad Kostecki gentoo-dev 2021-02-16 21:38:35 UTC
Created attachment 687048 [details]
Multiple profile dumps
Comment 5 Conrad Kostecki gentoo-dev 2021-02-16 21:38:53 UTC
Created attachment 687051 [details]
Log for multiple profile dumps
Comment 6 Alec Warner (RETIRED) archtester gentoo-dev Security 2021-03-02 09:04:41 UTC
Just for my notes:

- I made a stage3; on my recent ryzen system (with an SSD and lots of ram.)
- I merged some packages (around 400).

emerge -ep @world takes about 5s
emerge -uDpv @world takes about 9s

My depgraph is non-complex.
turning off backtracking (via --backtrack=0) saves 3-4s for -uDpv @world

Comparing the two:
--backtrack=0 # this results in no slot_operator_update_probes.
--backtrack=1 # this results in slot_operator_update_probes.

The dump of the slot_operator_update_probes means:
 - We create an additional 40k Atom objects (costing around 0.5s)
 - 0.2s spent matching additional regexp patterns (I expect this to be associated with the above item, as Atom uses re's often.)
 - match_from_list goes from 31000 calls (total cost: 85ms) to 180,000 calls: total cost: 467ms.

So some obvious things are like: 
 - improve heuristic for when slot_operator_update_probe is needed?
 - match_from_list for slot operators is slow; we could make it potentially faster.
 - We spend about 1-2s total just making "Atoms and _pkg_strs" even though its likely that..while backtracking, we can have a better cache methodology for these.
Comment 7 bpholman5 2021-04-28 03:11:52 UTC
Created attachment 702747 [details]
python -m cProfile -o portage.cprof /usr/bin/emerge -pe @world

python -m cProfile -o portage.cprof /usr/bin/emerge -pe @world
Comment 8 Alessandro Barbieri 2021-04-29 20:11:19 UTC
Created attachment 704103 [details]
complex tree update with backtrack

I have 4715 packages and a lot of useflags enabled

COMMAND:

python3.8 -m cProfile -o portage.cprof /usr/bin/emerge -pv --update --deep --newuse --changed-use --backtrack=300 @system @world


RESULT:

p.sort_stats('time').print_stats(20)
Thu Apr 29 06:36:48 2021    portage.cprof

         6230524576 function calls (5751898107 primitive calls) in 3430.805 seconds

   Ordered by: internal time
   List reduced from 3420 to 20 due to restriction <20>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
212933328  997.162    0.000 1587.655    0.000 /usr/lib/python3.8/site-packages/portage/util/digraph.py:163(child_nodes)
482916066/5763176  537.546    0.000 2559.246    0.000 /usr/lib/python3.8/site-packages/_emerge/depgraph.py:7838(gather_deps)
1253234157  306.471    0.000  306.471    0.000 /usr/lib/python3.8/site-packages/_emerge/DepPrioritySatisfiedRange.py:43(_ignore_runtime_post)
213749350  254.152    0.000  254.152    0.000 /usr/lib/python3.8/site-packages/_emerge/Task.py:9(__eq__)
1245804515  161.713    0.000  161.713    0.000 /usr/lib/python3.8/site-packages/_emerge/Task.py:23(__hash__)
243602376   76.454    0.000  106.299    0.000 {method 'add' of 'set' objects}
780809039   73.263    0.000   73.263    0.000 {method 'append' of 'list' objects}
115454563   63.082    0.000   70.187    0.000 /usr/lib/python3.8/site-packages/_emerge/DepPrioritySatisfiedRange.py:53(_ignore_satisfied_runtime)
185482950   57.821    0.000   57.821    0.000 /usr/lib/python3.8/site-packages/_emerge/DepPriorityNormalRange.py:27(_ignore_runtime_post)
 15077256   53.667    0.000   70.487    0.000 /usr/lib/python3.8/site-packages/portage/dep/__init__.py:2149(match_from_list)
    25418   46.552    0.002   95.790    0.004 /usr/lib/python3.8/site-packages/portage/util/digraph.py:197(leaf_nodes)
220361731/220361730   41.810    0.000   41.908    0.000 {built-in method builtins.hasattr}
3401240/2907212   38.735    0.000  114.749    0.000 /usr/lib/python3.8/site-packages/portage/dep/__init__.py:1243(__init__)
     1722   34.019    0.020   49.012    0.028 /usr/lib/python3.8/site-packages/portage/util/digraph.py:272(clone)
228928706   32.501    0.000   32.501    0.000 {method 'items' of 'dict' objects}
     7054   28.186    0.004   38.390    0.005 /usr/lib/python3.8/site-packages/portage/package/ebuild/config.py:2266(regenerate)
  7251202   25.878    0.000   25.878    0.000 {method 'match' of 're.Pattern' objects}
  6650854   20.950    0.000  278.769    0.000 /usr/lib/python3.8/site-packages/_emerge/depgraph.py:5731(_iter_match_pkgs_atom)
  9922431   20.739    0.000  157.850    0.000 /usr/lib/python3.8/site-packages/portage/_sets/base.py:114(findAtomForPackage)
 29911875   20.131    0.000   24.114    0.000 /usr/lib/python3.8/site-packages/_emerge/DepPrioritySatisfiedRange.py:85(_ignore_runtime)
Comment 9 Toralf Förster gentoo-dev 2021-06-13 11:52:06 UTC
Created attachment 715725 [details]
cProfile form my hardened stable KDE desktop
Comment 10 Toralf Förster gentoo-dev 2021-06-13 11:53:44 UTC
Created attachment 715728 [details]
portage.cprof from my stable server (tor + tinderbox)
Comment 11 Toralf Förster gentoo-dev 2021-06-13 12:13:44 UTC
Created attachment 715731 [details]
portage.cprof from an 11 days old tinderbox image (~9,500 packages)
Comment 12 Berin Aniesh 2023-05-22 02:51:30 UTC
Created attachment 862150 [details]
profile of emerge --version