Re: [gentoo-portage-dev] emerge getting slower

[Zac Medico]

On 12/22/2015 12:59 AM, Joakim Tjernlund wrote:
> On Mon, 2015-12-21 at 12:36 -0800, Zac Medico wrote:
>> On 12/21/2015 12:24 PM, Joakim Tjernlund wrote:
>>> Lately it feels like emerge has been getting unusual slow to calculate dependencies.
>>> I did a strace while emerge was running and noticed a lot of:
>>>
>>> stat64("/usr/portage/profiles/base/profile.bashrc", {st_mode=S_IFREG|0644, st_size=183, ...}) = 0
>>> stat64("/usr/portage/profiles/default/linux/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/arch/base/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/arch/powerpc/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/default/linux/powerpc/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file
>>> or directory)
>>> stat64("/usr/portage/profiles/arch/base/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/arch/powerpc/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/arch/powerpc/ppc32/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/default/linux/powerpc/ppc32/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No
>>> such file or directory)
>>> stat64("/usr/portage/profiles/releases/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/releases/13.0/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/default/linux/powerpc/ppc32/13.0/profile.bashrc", 0xbfbb02d0) = -1 ENOENT
>>> (No such file or directory)
>>> stat64("/usr/local/portage/tmv3-target-overlay/profiles/cusfpv3/profile.bashrc", {st_mode=S_IFREG|0644,
>>> st_size=133, ...}) = 0
>>> stat64("/etc/portage/profile/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or directory)
>>> access("/usr/local/portage/tmv3-target-overlay/dev-libs/apr/apr-1.5.1-r1.ebuild", R_OK) = -1 ENOENT (No
>>> such file or directory)
>>> access("/usr/portage/dev-libs/apr/apr-1.5.1-r1.ebuild", R_OK) = 0
>>> stat64("/usr/portage/dev-libs/apr/apr-1.5.1-r1.ebuild", {st_mode=S_IFREG|0644, st_size=4215, ...}) = 0
>>> open("/usr/portage/metadata/md5-cache/dev-libs/apr-1.5.1-r1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 5
>>> fstat64(5, {st_mode=S_IFREG|0644, st_size=1350, ...}) = 0
>>> ioctl(5, TCGETS, 0xbfbb0d88)            = -1 ENOTTY (Inappropriate ioctl for device)
>>> fstat64(5, {st_mode=S_IFREG|0644, st_size=1350, ...}) = 0
>>> _llseek(5, 0, [0], SEEK_CUR)            = 0
>>> _llseek(5, 0, [0], SEEK_CUR)            = 0
>>> _llseek(5, 0, [0], SEEK_CUR)            = 0
>>> fstat64(5, {st_mode=S_IFREG|0644, st_size=1350, ...}) = 0
>>> read(5, "DEFINED_PHASES=compile configure"..., 1351) = 1350
>>> read(5, "", 1)                          = 0
>>> fstat64(5, {st_mode=S_IFREG|0644, st_size=1350, ...}) = 0
>>> close(5)                                = 0
>>> open("/usr/portage/dev-libs/apr/apr-1.5.1-r1.ebuild", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 5
>>> fstat64(5, {st_mode=S_IFREG|0644, st_size=4215, ...}) = 0
>>> ioctl(5, TCGETS, 0xbfbb0898)            = -1 ENOTTY (Inappropriate ioctl for device)
>>> fstat64(5, {st_mode=S_IFREG|0644, st_size=4215, ...}) = 0
>>> _llseek(5, 0, [0], SEEK_CUR)            = 0
>>> read(5, "# Copyright 1999-2015 Gentoo Fou"..., 32768) = 4215
>>> read(5, "", 24576)                      = 0
>>> read(5, "", 32768)                      = 0
>>> close(5)                                = 0
>>> stat64("/usr/portage/profiles/base/profile.bashrc", {st_mode=S_IFREG|0644, st_size=183, ...}) = 0
>>> stat64("/usr/portage/profiles/default/linux/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/arch/base/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/arch/powerpc/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/default/linux/powerpc/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file
>>> or directory)
>>> stat64("/usr/portage/profiles/arch/base/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/arch/powerpc/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/arch/powerpc/ppc32/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/default/linux/powerpc/ppc32/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No
>>> such file or directory)
>>> stat64("/usr/portage/profiles/releases/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/releases/13.0/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or
>>> directory)
>>> stat64("/usr/portage/profiles/default/linux/powerpc/ppc32/13.0/profile.bashrc", 0xbfbb02d0) = -1 ENOENT
>>> (No such file or directory)
>>> stat64("/usr/local/portage/tmv3-target-overlay/profiles/cusfpv3/profile.bashrc", {st_mode=S_IFREG|0644,
>>> st_size=133, ...}) = 0
>>> stat64("/etc/portage/profile/profile.bashrc", 0xbfbb02d0) = -1 ENOENT (No such file or directory)
>>> access("/usr/local/portage/tmv3-target-overlay/dev-libs/apr/apr-1.5.0-r2.ebuild", R_OK) = -1 ENOENT (No
>>> such file or directory)
>>> access("/usr/portage/dev-libs/apr/apr-1.5.0-r2.ebuild", R_OK) = 0
>>> stat64("/usr/portage/dev-libs/apr/apr-1.5.0-r2.ebuild", {st_mode=S_IFREG|0644, st_size=4047, ...}) = 0
>>> open("/usr/portage/metadata/md5-cache/dev-libs/apr-1.5.0-r2", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 5
>>> fstat64(5, {st_mode=S_IFREG|0644, st_size=1341, ...}) = 0
>>> ioctl(5, TCGETS, 0xbfbb0d88)            = -1 ENOTTY (Inappropriate ioctl for device)
>>>
>>>
>>> Could this constant stating of profile.bashrc account for some slowness?
>>
>> The stat calls indicate that it is executing the "depend" phase to
>> generate ebuild metadata cache, which only happens when data in the
>> md5-cache directory is stale for some reason. For example, you can see
>> this happen above for the
>> /usr/portage/metadata/md5-cache/dev-libs/apr-1.5.1-r1 cache entry. An
>> eclass-overrides setting in repos.conf can cause this. Are you using
>> eclass-overrides?
>
> No, not yet. I do use in layout.conf
>  profile-formats = portage-2 profile-bashrcs profile-set
>
> profile-bashrcs perhaps?

No, eclass-overrrides is the only potentially relevant setting I can
think of at the moment.

> I just did a
>   egencache --update --update-use-local-desc --update-pkg-desc-index
> for all repos on that system and it is still there.
>
> Then I recalled portage renames my repo to x-portage so I tried
>  egencache --update --update-use-local-desc --update-pkg-desc-index --repo x-portage
> but that did not help either.
>
>   Jocke
>

If you run egencache to populate $repo/metadata/md5-cache with valid
cache, and remove the corresponding cache entries from
/var/cache/edb/dep/$repo_location, do dependency calculations still
trigger regeneration of cache entries in
/var/cache/edb/dep/$repo_location? That would indicate that egencache is
writing invalid cache entries, or the cache validation mechanism failing
somehow.
-- 
Thanks,
Zac