"Calculating dependencies" 118 seconds Compiling/installing to ">>> Done" 38 seconds From ">>> Done" to ">>> Installing dev-python/cherrypy-3.0.3" 9 minutes To the end: 90 seconds Reproducible: Always Portage 2.2_rc8 (default/linux/amd64/2008.0, gcc-4.3.1, glibc-2.8_p20080602-r0, 2.6.25-gentoo-r4 x86_64) ================================================================= System uname: Linux-2.6.25-gentoo-r4-x86_64-AMD_Athlon-tm-_64_Processor_4000+-with-glibc2.2.5 Timestamp of tree: Fri, 29 Aug 2008 22:30:01 +0000 distcc 2.18.3 x86_64-pc-linux-gnu (protocols 1 and 2) (default port 3632) [disabled] ccache version 2.4 [enabled] app-shells/bash: 3.2_p39 dev-java/java-config: 1.3.7, 2.1.6-r1 dev-lang/python: 2.4.4-r14, 2.5.2-r7 dev-python/pycrypto: 2.0.1-r6 dev-util/ccache: 2.4-r7 sys-apps/baselayout: 2.0.0 sys-apps/openrc: 0.2.5 sys-apps/sandbox: 1.2.18.1-r3 sys-devel/autoconf: 2.13, 2.62-r1 sys-devel/automake: 1.4_p6, 1.5, 1.6.3, 1.7.9-r1, 1.8.5-r3, 1.9.6-r2, 1.10.1-r1 sys-devel/binutils: 2.18-r1, 2.18.50.0.1 sys-devel/gcc-config: 1.4.0-r4 sys-devel/libtool: 2.2.4 virtual/os-headers: 2.6.26 ACCEPT_KEYWORDS="amd64 x86 ~amd64 ~x86" CBUILD="x86_64-pc-linux-gnu" CFLAGS="-O2 -march=athlon64 -pipe" CHOST="x86_64-pc-linux-gnu" CONFIG_PROTECT="/etc /opt/openjms/config /usr/kde/4.1/env /usr/kde/4.1/share/config /usr/kde/4.1/shutdown /usr/share/config /var/lib/hsqldb /var/qmail/alias /var/qmail/control /var/spool/torque /var/vpopmail/etc" CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/env.d/java/ /etc/eselect/postgresql /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/php/apache2-php5/ext-active/ /etc/php/cgi-php5/ext-active/ /etc/php/cli-php5/ext-active/ /etc/revdep-rebuild /etc/splash /etc/terminfo /etc/texmf/web2c /etc/udev/rules.d" CXXFLAGS="-O2 -march=athlon64 -pipe" DISTDIR="/tmp/distfiles" FEATURES="buildpkg ccache distlocks loadpolicyi metadata-transfer parallel-fetch preserve-libs sandbox sfperms unmerge-orphans userfetch" GENTOO_MIRRORS="http://ftp.snt.utwente.nl/pub/os/linux/gentoo http://ftp-stud.fht-esslingen.de/pub/Mirrors/gentoo/ http://mirrors.sec.informatik.tu-darmstadt.de/gentoo/ http://linux.rz.ruhr-uni-bochum.de/download/gentoo-mirror/ http://de-mirror.org/distro/gentoo/" LANG="de_DE.UTF-8" LDFLAGS="-Wl,-z,new -Wl,-O1,--hash-style=gnu,--sort-common,--as-needed" LINGUAS="en de" MAKEOPTS="-j1" PKGDIR="/tmp/packages" PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress --force --whole-file --delete --stats --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages" PORTAGE_TMPDIR="/tmp/tmp" PORTDIR="/usr/portage" SYNC="rsync://rsync.gentoo.org/gentoo-portage" USE="X" APACHE2_MPMS="worker" CAMERAS="canon directory template ptp2" ELIBC="glibc" INPUT_DEVICES="evdev joystick keyboard mouse void vmmouse" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LINGUAS="en de" USERLAND="GNU" VIDEO_CARDS="nv nvidia vesa fbdev vmware" Unset: CPPFLAGS, CTARGET, EMERGE_DEFAULT_OPTS, FFLAGS, INSTALL_MASK, LC_ALL, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS
1GB RAM, ~400MB free, emerge used 45% memory. CPU is 2.4GHz.
So you are not hitting swap space at all? Also, memory and time comparisons on your same system using older portage could be useful (go back to whatever version of portage you were using previously that behaved better)
I did some quick profiling with portage-2.2_rc8 and portage-2.1.5.6 using python -m cProfile /usr/bin/emerge -1 x11-misc/xrestop Postprocessing the profiling output with pstats module shows the following stats. Exact command was "p.sort_stats('time', 'cum').print_stats(10)" portage-2.2_rc8: Ordered by: internal time, cumulative time List reduced from 1457 to 10 due to restriction <10> ncalls tottime percall cumtime percall filename:lineno(function) 141 13.935 0.099 13.935 0.099 {built-in method poll} 3 1.770 0.590 8.677 2.892 vartree.py:148(rebuild) 80854 1.308 0.000 1.308 0.000 {posix.lstat} 93336 0.958 0.000 1.614 0.000 posixpath.py:56(join) 508567 0.621 0.000 0.621 0.000 {method 'setdefault' of 'dict' objects} 19031/18981 0.575 0.000 4.850 0.000 posixpath.py:410(realpath) 6 0.557 0.093 0.557 0.093 {built-in method load} 433665 0.505 0.000 0.505 0.000 {method 'append' of 'list' objects} 347558 0.468 0.000 0.468 0.000 {method 'startswith' of 'str' objects} 80694 0.386 0.000 2.016 0.000 posixpath.py:156(islink) portage-2.1.5.6: Ordered by: internal time, cumulative time List reduced from 1006 to 10 due to restriction <10> ncalls tottime percall cumtime percall filename:lineno(function) 137 11.230 0.082 11.230 0.082 {select.select} 27 0.349 0.013 0.349 0.013 {posix.waitpid} 30519/254 0.263 0.000 0.773 0.003 /usr/lib64/python2.5/copy.py:144(deepcopy) 155219 0.254 0.000 0.254 0.000 {getattr} 73722/36868 0.243 0.000 0.527 0.000 /usr/bin/emerge:1378(__eq__) 168262 0.209 0.000 0.209 0.000 {method 'get' of 'dict' objects} 32985 0.196 0.000 0.294 0.000 /usr/lib64/python2.5/sets.py:356(_update) 4238 0.194 0.000 1.311 0.000 /usr/lib64/portage/pym/portage.py:7216(aux_get) 10196 0.193 0.000 0.193 0.000 {posix.stat} 143960/134706 0.184 0.000 0.207 0.000 {len} You can notice that the calls to rebuild() [from vartree.py] are new in 2.2. The callers are unmerge(), _preserve_libs() and treewalk(). Function was called by... ncalls tottime cumtime vartree.py:148(rebuild) <- 1 0.596 2.907 vartree.py:1693(unmerge) 1 0.588 2.899 vartree.py:2305(_preserve_libs) 1 0.586 2.871 vartree.py:2576(treewalk) And the slowest function called by rebuild() is realpath() [from posixpath internal python module]. Function called... ncalls tottime cumtime vartree.py:148(rebuild) -> 37772 0.102 0.501 posixpath.py:117(dirname) 18886 0.570 4.826 posixpath.py:410(realpath) 1 0.000 0.000 util.py:85(grabfile) 3 0.000 0.000 vartree.py:131(getPreservedLibs) 3 0.014 0.073 vartree.py:686(cpv_all) 3 0.000 0.000 vartree.py:802(flush_cache) 2535 0.091 0.266 vartree.py:880(aux_get) 37772 0.069 0.069 {filter} 18886 0.022 0.022 {len} 252419 0.289 0.289 {method 'append' of 'list' objects} 37772 0.053 0.053 {method 'replace' of 'str' objects} 504838 0.612 0.612 {method 'setdefault' of 'dict' objects} 59193 0.145 0.145 {method 'split' of 'str' objects} 40307 0.051 0.051 {method 'strip' of 'str' objects}
portage 2.2rc16 Stuck at ">>> Installing mail-client/evolution-2.24.2" for an hour now... Free memory while still running: 128MB
Shouldn't the "Product field" be changed from "Gentoo Linux" to "Portage Development"?
I've been monitoring memory consumption for the past month here and finally realized, it's Portage who's caching large amounts of memory here. Although, ATop doesn't slate Portage (Python) as using the memory. But after syncing and/or compiling (using Portage/Python), large amounts of memory are apparently consumed by comparing "free -m" output. (I've finally concluded this after dropping to tty and DWM!) My best guess, it's Python and/or un-optimized Python coding. Might be a function or two in Portage not optimized to make proper use of CPU/Memory resources?? Is Bug #236748 a duplicate?
Bug #240320 seems like a tracker and hasn't been touched for sometime either. BTW, using =sys-apps/portage-2.2_rc38 here.
