I straced a emerge -pNDu world and it seesm to me that there are some nonoptimal file IO: 14:32:16.076574 openat(AT_FDCWD, "/var/lib/layman/transmode/media-fonts/font-misc-misc", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = -1 ENOENT (No such file or directory) 14:32:16.076674 access("/var/lib/layman/transmode/media-fonts/font-misc-misc/font-misc-misc-1.1.2.ebuild", R_OK) = -1 ENOENT (No such file or directory) 14:32:16.076734 access("/usr/portage/media-fonts/font-misc-misc/font-misc-misc-1.1.2.ebuild", R_OK) = 0 14:32:16.076771 stat("/usr/portage/media-fonts/font-misc-misc/font-misc-misc-1.1.2.ebuild", {st_mode=S_IFREG|0644, st_size=576, ...}) = 0 14:32:16.076806 open("/usr/portage/metadata/md5-cache/media-fonts/font-misc-misc-1.1.2", O_RDONLY) = 4 14:32:16.076822 fstat(4, {st_mode=S_IFREG|0644, st_size=1692, ...}) = 0 14:32:16.076838 ioctl(4, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fffe600b8e0) = -1 ENOTTY (Inappropriate ioctl for device) 14:32:16.076852 fstat(4, {st_mode=S_IFREG|0644, st_size=1692, ...}) = 0 14:32:16.076868 lseek(4, 0, SEEK_CUR) = 0 14:32:16.076888 lseek(4, 0, SEEK_CUR) = 0 14:32:16.076905 fstat(4, {st_mode=S_IFREG|0644, st_size=1692, ...}) = 0 14:32:16.076918 lseek(4, 0, SEEK_CUR) = 0 14:32:16.076929 read(4, "DEFINE", 6) = 6 14:32:16.076943 fstat(4, {st_mode=S_IFREG|0644, st_size=1692, ...}) = 0 14:32:16.076956 lseek(4, 0, SEEK_CUR) = 6 14:32:16.076968 read(4, "D_PHAS", 6) = 6 14:32:16.076981 fstat(4, {st_mode=S_IFREG|0644, st_size=1692, ...}) = 0 14:32:16.076994 lseek(4, 0, SEEK_CUR) = 12 14:32:16.077005 read(4, "ES=comp", 7) = 7 14:32:16.077018 fstat(4, {st_mode=S_IFREG|0644, st_size=1692, ...}) = 0 14:32:16.077031 lseek(4, 0, SEEK_CUR) = 19 14:32:16.077042 read(4, "ile conf", 8) = 8 14:32:16.077055 fstat(4, {st_mode=S_IFREG|0644, st_size=1692, ...}) = 0 14:32:16.077068 lseek(4, 0, SEEK_CUR) = 27 14:32:16.077079 read(4, "igure ins", 9) = 9 14:32:16.077092 fstat(4, {st_mode=S_IFREG|0644, st_size=1692, ...}) = 0 Lots of small fstat,lseek and reads. This could de made much more efficient I hope. --------------------------- 14:32:00.016482 stat("/usr/lib64/portage/pym/portage/dbapi/codecs", 0x7fffe600af40) = -1 ENOENT (No such file or directory) 14:32:00.016516 open("/usr/lib64/portage/pym/portage/dbapi/codecs.so", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016549 open("/usr/lib64/portage/pym/portage/dbapi/codecsmodule.so", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016580 open("/usr/lib64/portage/pym/portage/dbapi/codecs.py", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016611 open("/usr/lib64/portage/pym/portage/dbapi/codecs.pyc", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016662 stat("/usr/lib64/portage/pym/portage/dbapi/subprocess", 0x7fffe600af40) = -1 ENOENT (No such file or directory) 14:32:00.016694 open("/usr/lib64/portage/pym/portage/dbapi/subprocess.so", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016726 open("/usr/lib64/portage/pym/portage/dbapi/subprocessmodule.so", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016766 open("/usr/lib64/portage/pym/portage/dbapi/subprocess.py", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016798 open("/usr/lib64/portage/pym/portage/dbapi/subprocess.pyc", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016853 stat("/usr/lib64/portage/pym/portage/dbapi/gzip", 0x7fffe600af40) = -1 ENOENT (No such file or directory) 14:32:00.016885 open("/usr/lib64/portage/pym/portage/dbapi/gzip.so", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016917 open("/usr/lib64/portage/pym/portage/dbapi/gzipmodule.so", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016949 open("/usr/lib64/portage/pym/portage/dbapi/gzip.py", O_RDONLY) = -1 ENOENT (No such file or directory) 14:32:00.016981 open("/usr/lib64/portage/pym/portage/dbapi/gzip.pyc", O_RDONLY) = -1 ENOENT (No such file or directory) Portage tries to open lots of non exsting modules, all possible variants it seems. Could this be reduced somehow?
Forgot emerge --info: Portage 2.2.8-r1 (default/linux/amd64/13.0/desktop/gnome, gcc-4.7.3, glibc-2.17-r1, 3.10.34 x86_64) ================================================================= System uname: Linux-3.10.34-x86_64-Intel-R-_Core-TM-_i7-2600_CPU_@_3.40GHz-with-gentoo-2.2 KiB Mem: 12308316 total, 1404144 free KiB Swap: 4194300 total, 4141248 free Timestamp of tree: Mon, 05 May 2014 15:45:01 +0000 ld GNU ld (GNU Binutils) 2.23.2 app-shells/bash: 4.2_p45 dev-java/java-config: 2.2.0 dev-lang/python: 2.7.5-r3, 3.3.3 dev-util/cmake: 2.8.12.2 dev-util/pkgconfig: 0.28 sys-apps/baselayout: 2.2 sys-apps/openrc: 0.12.4 sys-apps/sandbox: 2.6-r1 sys-devel/autoconf: 2.13, 2.69 sys-devel/automake: 1.10.3, 1.11.6, 1.12.6, 1.13.4 sys-devel/binutils: 2.23.2 sys-devel/gcc: 4.5.4, 4.7.3-r1 sys-devel/gcc-config: 1.7.3 sys-devel/libtool: 2.4.2 sys-devel/make: 3.82-r4 sys-kernel/linux-headers: 3.10 (virtual/os-headers) sys-libs/glibc: 2.17-r1::transmode Repositories: gentoo transmode ACCEPT_KEYWORDS="amd64" ACCEPT_LICENSE="* -@EULA PUEL dlj-1.1 Oracle-BCLA-JavaSE AdobeFlash-11.x google-chrome" CBUILD="x86_64-pc-linux-gnu" CFLAGS="-O2 -pipe -ggdb" CHOST="x86_64-pc-linux-gnu" CONFIG_PROTECT="/etc /etc/entropy /usr/share/gnupg/qualified.txt /var/lib/hsqldb" CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/dconf /etc/env.d /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/php/apache2-php5.5/ext-active/ /etc/php/cgi-php5.5/ext-active/ /etc/php/cli-php5.5/ext-active/ /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo" CXXFLAGS="-O2 -pipe -ggdb" DISTDIR="/usr/portage/distfiles" EMERGE_DEFAULT_OPTS="--quiet --jobs=8" FCFLAGS="-O2 -pipe" FEATURES="assume-digests binpkg-logs config-protect-if-modified distlocks ebuild-locks fixlafiles merge-sync news parallel-fetch preserve-libs protect-owned sandbox sfperms strict unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox usersync" FFLAGS="-O2 -pipe" GENTOO_MIRRORS="http://devsrv.transmode.se/portage http://devsrv.transmode.se/portage/local http://ftp.df.lth.se/pub/gentoo" LANG="en_GB.UTF-8" LDFLAGS="-Wl,-O1 -Wl,--as-needed" MAKEOPTS="-j9 -s" PKGDIR="/usr/portage/packages" PORTAGE_CONFIGROOT="/" PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --omit-dir-times --compress --force --whole-file --delete --stats --human-readable --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages" PORTAGE_TMPDIR="/var/tmp" PORTDIR="/usr/portage" PORTDIR_OVERLAY="/var/lib/layman/transmode" SYNC="rsync://devsrv.transmode.se/portage" USE="X a52 aac accessibility acl acpi ads alsa amd64 bash-completion berkdb bluetooth branding bzip2 cairo cdda cdr cli colord consolekit cracklib crypt cups cxx dbus device-mapper dhcpcd dri dts dvd dvdr eds emacs emboss encode evo exif fam ffmpeg firefox flac fontconfig fortran gdbm gif gnome gnome-keyring gnome-online-accounts gnutls gpm gstreamer gtk iconv infinality introspection ipv6 java jpeg kerberos kvm lcms ldap libnotify libsecret mad meanwhile mmx mng modules mp3 mp4 mpeg multilib nautilus ncurses networkmanager nis nls nptl ogg opengl openmp pam pango pcre pdf pdfimport perl png policykit ppds pulseaudio python qemu qt3support readline resolvconf samba sdl secure-delete session socialweb spell spice sqlite sse sse2 sse3 sse4 sse4_1 ssl ssse3 startup-notification subversion svg system-cairo system-icu system-jpeg system-sqlite tcpd tiff truetype udev udisks unicode upcall upower urandom usb virt-network virtualbox vorbis webdav winbind wxwidgets x264 xcb xinerama xml xv xvid zlib" ABI_X86="64" ALSA_CARDS="ali5451 als4000 atiixp atiixp-modem bt87x ca0106 cmipci emu10k1x ens1370 ens1371 es1938 es1968 fm801 hda-intel intel8x0 intel8x0m maestro3 trident usb-audio via82xx via82xx-modem ymfpci" APACHE2_MODULES="authn_core authz_core socache_shmcb unixd actions alias auth_basic authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache cgi cgid dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter file_cache filter headers include info log_config logio mem_cache mime mime_magic negotiation rewrite setenvif speling status unique_id userdir usertrack vhost_alias" CALLIGRA_FEATURES="kexi words flow plan sheets stage tables krita karbon braindump author" CAMERAS="ptp2" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf superstar2 timing tsip tripmate tnt ublox ubx" INPUT_DEVICES="evdev synaptics" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LIBREOFFICE_EXTENSIONS="pdfimport" LINGUAS="en sv" OFFICE_IMPLEMENTATION="libreoffice" PHP_TARGETS="php5-4" PYTHON_SINGLE_TARGET="python2_7" PYTHON_TARGETS="python2_7 python3_3" QEMU_SOFTMMU_TARGETS="i386 x86_64 ppc" QEMU_USER_TARGETS="i386 x86_64 ppc" RUBY_TARGETS="ruby19 ruby20" USERLAND="GNU" VIDEO_CARDS="intel radeon" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq steal rawnat logmark ipmark dhcpmac delude chaos account" Unset: CPPFLAGS, CTARGET, INSTALL_MASK, LC_ALL, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS, USE_PYTHON
(In reply to Joakim Tjernlund from comment #0) > I straced a emerge -pNDu world and it seesm to me that there are > some nonoptimal file IO: > > [...] > > Lots of small fstat,lseek and reads. This could de made much more efficient > I hope. Those only span a millisecond or so; the real question is how much they take of the real time, otherwise this might be a false positive. > [...] > > Portage tries to open lots of non exsting modules, all possible variants it > seems. Could this be reduced somehow? Seems like a standard way to find some module; again, I wonder if the time span as well as frequency might yield this to be a false positive. That Portage could be made faster due to for example IO improvements is known; however, it's harder to tell which improvements where in the code would help with that. Portage does a lot, given that its input isn't optimal; more efficient input (less, compressed, grouped, sorted, aggregated, ...), more efficient IO.
All those stat("/usr/lib64/portage/pym/portage/dbapi/...") calls are not portage's fault, but basic python imports. Python is looking for those modules in the dbapi portage sub-pkg (in case they are there to override the std. ones) before getting them from it's standard lib. The other small fstat,lseek and reads are likely due to the cache not having been updated with your overlays. If you have lots of overlays or an overlay with lots of pkgs, try running emerge --regen. It might benefit from adding your overlay info to it's cache to help speed things up.
Solution for majority of unneeded import-related stat etc. calls is to use Python 3. $ cd /tmp $ mkdir test $ echo "import gzip; print(gzip)" > test/__init__.py $ touch test/gzip.py $ python2.7 -c "import test" <module 'test.gzip' from 'test/gzip.py'> $ python3.4 -c "import test" <module 'gzip' from '/usr/lib64/python3.4/gzip.py'>
(In reply to Tom Wijsman (TomWij) from comment #2) > (In reply to Joakim Tjernlund from comment #0) > > I straced a emerge -pNDu world and it seesm to me that there are > > some nonoptimal file IO: > > > > [...] > > > > Lots of small fstat,lseek and reads. This could de made much more efficient > > I hope. > > Those only span a millisecond or so; the real question is how much they take > of the real time, otherwise this might be a false positive. Well, they seem to dominate my log, it starts at: 14:32:00.810919 open("/var/db/pkg/dev-util/patchelf-0.6/DEFINED_PHASES", O_RDONLY) = 4 14:32:00.810939 fstat(4, {st_mode=S_IFREG|0644, st_size=10, ...}) = 0 14:32:00.810958 ioctl(4, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fffe600cdd0) = -1 ENOTTY (Inappropriate ioctl for device) and ends at: 14:33:14.466216 open("/usr/portage/metadata/md5-cache/media-plugins/gst-plugins-meta-0.10-r8", O_RDONLY) = 6 14:33:14.466253 fstat(6, {st_mode=S_IFREG|0644, st_size=2596, ...}) = 0 14:33:14.466287 ioctl(6, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fffe600c570) = -1 ENOTTY (Inappropriate ioctl for device) I haven't looked at every line in between though. This is with a hot VFS cache too. I am not buying the false poitive argument here. This pattern is bad practice and should be fixed. Hopefully it will have an performance impact but we will never known if it isn't fixed. > > > [...] > > > > Portage tries to open lots of non exsting modules, all possible variants it > > seems. Could this be reduced somehow? > > Seems like a standard way to find some module; again, I wonder if the time > span as well as frequency might yield this to be a false positive. On a very fast system you probable don't notice much but on low end embedded it can make a difference. I got one and if I get some time tomorrow I will have a look. > > That Portage could be made faster due to for example IO improvements is > known; however, it's harder to tell which improvements where in the code > would help with that. Portage does a lot, given that its input isn't > optimal; more efficient input (less, compressed, grouped, sorted, > aggregated, ...), more efficient IO. Sounds like you have given up fixing portages performance. I would have hoped that portages devs would appriciate some possible leads to resolving some of portages performance problems.
(In reply to Brian Dolbec from comment #3) > All those stat("/usr/lib64/portage/pym/portage/dbapi/...") calls are not > portage's fault, but basic python imports. Python is looking for those > modules in the dbapi portage sub-pkg (in case they are there to override the > std. ones) before getting them from it's standard lib. Good to know. > > The other small fstat,lseek and reads are likely due to the cache not having > been updated with your overlays. If you have lots of overlays or an overlay > with lots of pkgs, try running emerge --regen. It might benefit from adding > your overlay info to it's cache to help speed things up. I have 1 overlay, our own with misc fixes for transmode, it is small. I haven't looked into speeding up things with emerge --regen though but I don't that it should be an excuse for portage to behave as it does.
(In reply to Arfrever Frehtes Taifersar Arahesis from comment #4) > Solution for majority of unneeded import-related stat etc. calls is to use > Python 3. > > $ cd /tmp > $ mkdir test > $ echo "import gzip; print(gzip)" > test/__init__.py > $ touch test/gzip.py > $ python2.7 -c "import test" > <module 'test.gzip' from 'test/gzip.py'> > $ python3.4 -c "import test" > <module 'gzip' from '/usr/lib64/python3.4/gzip.py'> Ah, I will try switching portage to pyton 3.3/3.4, thanks
You can use alternative type of ebuild metadata cache to avoid reading ${repository_location}/metadata/md5-cache/*/* files. When SQLite type is used, then there is only 1 SQLite database for each repository. To enable it, add "portdbapi.auxdbmodule = cache.sqlite.database" line to /etc/portage/modules file and run: rm -r /var/cache/edb/dep emerge --regen
(In reply to Arfrever Frehtes Taifersar Arahesis from comment #8) > You can use alternative type of ebuild metadata cache to avoid reading > ${repository_location}/metadata/md5-cache/*/* files. When SQLite type is > used, then there is only 1 SQLite database for each repository. > To enable it, add "portdbapi.auxdbmodule = cache.sqlite.database" line to > /etc/portage/modules file and run: > rm -r /var/cache/edb/dep > emerge --regen I will try that too, any downside to using sqllite?
(In reply to Joakim Tjernlund from comment #5) > > On a very fast system you probable don't notice much but on low end embedded > it can make a difference. I got one and if I get some time tomorrow I will > have a look. > > > > > That Portage could be made faster due to for example IO improvements is > > known; however, it's harder to tell which improvements where in the code > > would help with that. Portage does a lot, given that its input isn't > > optimal; more efficient input (less, compressed, grouped, sorted, > > aggregated, ...), more efficient IO. > > Sounds like you have given up fixing portages performance. I would have hoped > that portages devs would appriciate some possible leads to resolving some of > portages performance problems. No, we have not given up. The portage team is quite new still and portage is a very complex code base. It was never designed with performance in mind and has grown a great deal in features and as a result complexity. It is by no means an easy task. This is also not the first time IO issues like these have been reported. But they are a fundamental part of how portage gathers it's information, updates it's caches, etc.. Many of those are just not possible to remove at this time. We are working towards improving the code base more, but it will take time. For a much better performance pkg manager, one which has been re-designed to optimize performance, especially on slower hardware like embedded systems. You should look at pkgcore. It does not have as many features, and so far EAPI 5 support is not quite complete, but it could be a much better solution for your embedded needs. Only downside to the sqlite backend, is it is not threading compatible, but unless you are wrapping portage code in custom scripts using threading, there will be no problem.
I withdraw suggestion of unconditional `emerge --regen`. 1. If you use rsync for synchronization of repository "gentoo", then you should run `emerge --metadata` after each `emerge --sync`. 1.1. If you also use other repositories, then you should run `emerge --regen` after `emerge --metadata` referenced above. 2. If you use CVS for synchronization of repository "gentoo", then you should run `emerge --regen` after each synchronization of repositories. (`emerge --regen` always generates correct cache, but `emerge --metadata` is faster and should be used when it is sufficient.)
(In reply to Brian Dolbec from comment #10) > (In reply to Joakim Tjernlund from comment #5) > > > > On a very fast system you probable don't notice much but on low end embedded > > it can make a difference. I got one and if I get some time tomorrow I will > > have a look. > > > > > > > > That Portage could be made faster due to for example IO improvements is > > > known; however, it's harder to tell which improvements where in the code > > > would help with that. Portage does a lot, given that its input isn't > > > optimal; more efficient input (less, compressed, grouped, sorted, > > > aggregated, ...), more efficient IO. > > > > Sounds like you have given up fixing portages performance. I would have hoped > > that portages devs would appriciate some possible leads to resolving some of > > portages performance problems. > > > No, we have not given up. The portage team is quite new still and portage > is a very complex code base. It was never designed with performance in mind > and has grown a great deal in features and as a result complexity. It is by > no means an easy task. This is also not the first time IO issues like these > have been reported. But they are a fundamental part of how portage gathers > it's information, updates it's caches, etc.. Many of those are just not > possible to remove at this time. We are working towards improving the code > base more, but it will take time. OK, so trying to improve file IO isn't going anywher ATM. I am sure it is tied to portages inner workings. > > For a much better performance pkg manager, one which has been re-designed to > optimize performance, especially on slower hardware like embedded systems. > You should look at pkgcore. It does not have as many features, and so far > EAPI 5 support is not quite complete, but it could be a much better solution > for your embedded needs. I did look at pkgcore a while ago but: Last release for pkgcore was 29 Oct 2012, a bit old. Looks lite there is much activity in the git repo though but it is hard to know what is going on without any releases. EAPI 5 is getting rather common so I think it is hard to avoid it. Some stats as to what can be done/built with it would be nice. cross building, binary packages and proper fakeroot support would be high on my list :) > > > Only downside to the sqlite backend, is it is not threading compatible, but > unless you are wrapping portage code in custom scripts using threading, > there will be no problem. Thanks, I will will have a go tomorrow. It is getting late here.
After upgraing to python3.4 I can see that the IO access patterns has become much improved. So this is resolved for me, thanks.
