public inbox for gentoo-portage-dev@lists.gentoo.org
 help / color / mirror / Atom feed
* [gentoo-portage-dev] portage 9999 at commit 2d5e38b495776e5bb2266848a3365667f3ca7233 **SLOW**
@ 2013-05-01  6:19 James Cloos
  2013-05-01  6:29 ` Zac Medico
  0 siblings, 1 reply; 6+ messages in thread
From: James Cloos @ 2013-05-01  6:19 UTC (permalink / raw
  To: gentoo-portage-dev

My typical emerge -upvDN world went up from 10s of minutes to several
hours sometime between portage 37f33e9 and 2d5e38b.

I noticed by way of strace(8) that it access(2)es each ebuild in
/usr/portage on each configured overay 10 times.  Each.

It does so in order from the last overlay in PORTDIR_OVERLAY to the
first.  It is the whole cycle which repeats a total of 10 iterations.

Seems it would be simpler to do the python equiv of ls */*/*.ebuild
in each overlay's top dir, note what ebuilds exist in each overlay
in a data structure, and use that.  Portage shouldn't worry about
any changes which occur in the middle of any single run.  (Which
is not to claim that it currently does, lest that sentence be
misunderstood. :)

Each access(2) is averaging about 300 or so micro seconds.  So about 66
miliseconds per ebuild.  There are 33728 ebuild files in /usr/portage,
so that is about 2226 seconds.  Or nearly 40 minutes just wasting time.

I run it in script(1) these days; /usr/bin/time output for one run was:

4314.78user 305.06system 5:17:03elapsed 24%CPU (0avgtext+0avgdata 4977056maxresident)k
145208inputs+14296outputs (9major+34541240minor)pagefaults 0swaps

So that is on the order of 20 times as long as it used to take.

I looked at git log.  The depgraph commit (62dbcaa4d873784f1) seems to
be the only one in that range which could have an effect.  At least at
first glance.

After doing the 7420160 access(2) calls, it read in some from a file
(the descriptor was closed by the time a was able to run lsof(8) to see
what fd 4 was), seek(2)ing between reads, and then seems to have started
doing the 7420160 access(2) calls again. (!)  As if once wasn't enough. :^/

No wonder the first run took 5+ hours.

(I'm falling asleep at the kbd; I hope I didn't miss any needed edits above.)

-JimC
-- 
James Cloos <cloos@jhcloos.com>         OpenPGP: 1024D/ED7DAEA6


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [gentoo-portage-dev] portage 9999 at commit 2d5e38b495776e5bb2266848a3365667f3ca7233 **SLOW**
  2013-05-01  6:19 [gentoo-portage-dev] portage 9999 at commit 2d5e38b495776e5bb2266848a3365667f3ca7233 **SLOW** James Cloos
@ 2013-05-01  6:29 ` Zac Medico
  2013-05-01 20:56   ` James Cloos
  0 siblings, 1 reply; 6+ messages in thread
From: Zac Medico @ 2013-05-01  6:29 UTC (permalink / raw
  To: gentoo-portage-dev

On 04/30/2013 11:19 PM, James Cloos wrote:
> My typical emerge -upvDN world went up from 10s of minutes to several
> hours sometime between portage 37f33e9 and 2d5e38b.

I don't see any regressions on my end. Please feel free to bisect those
commits and isolate it to a particular one. :)
-- 
Thanks,
Zac


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [gentoo-portage-dev] portage 9999 at commit 2d5e38b495776e5bb2266848a3365667f3ca7233 **SLOW**
  2013-05-01  6:29 ` Zac Medico
@ 2013-05-01 20:56   ` James Cloos
  2013-05-01 21:15     ` Zac Medico
  0 siblings, 1 reply; 6+ messages in thread
From: James Cloos @ 2013-05-01 20:56 UTC (permalink / raw
  To: Zac Medico; +Cc: gentoo-portage-dev

>>>>> "ZM" == Zac Medico <zmedico@gentoo.org> writes:

ZM> On 04/30/2013 11:19 PM, James Cloos wrote:
>> My typical emerge -upvDN world went up from 10s of minutes to several
>> hours sometime between portage 37f33e9 and 2d5e38b.

ZM> I don't see any regressions on my end. Please feel free to bisect those
ZM> commits and isolate it to a particular one. :)

Before trying that, I tried reverting 62dbcaa4d873784f1 and that worked.
emerge -upvDN world only took:

        User time (seconds): 682.19
        System time (seconds): 432.78
        Percent of CPU this job got: 91%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 20:17.37
        Maximum resident set size (kbytes): 4628592
        File system inputs: 260072
        File system outputs: 907632

Note how it hit >4 GB RSS, though.

-JimC
-- 
James Cloos <cloos@jhcloos.com>         OpenPGP: 1024D/ED7DAEA6


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [gentoo-portage-dev] portage 9999 at commit 2d5e38b495776e5bb2266848a3365667f3ca7233 **SLOW**
  2013-05-01 20:56   ` James Cloos
@ 2013-05-01 21:15     ` Zac Medico
  2013-05-01 21:42       ` James Cloos
  0 siblings, 1 reply; 6+ messages in thread
From: Zac Medico @ 2013-05-01 21:15 UTC (permalink / raw
  To: gentoo-portage-dev, cloos

On 05/01/2013 01:56 PM, James Cloos wrote:
>>>>>> "ZM" == Zac Medico <zmedico@gentoo.org> writes:
> 
> ZM> On 04/30/2013 11:19 PM, James Cloos wrote:
>>> My typical emerge -upvDN world went up from 10s of minutes to several
>>> hours sometime between portage 37f33e9 and 2d5e38b.
> 
> ZM> I don't see any regressions on my end. Please feel free to bisect those
> ZM> commits and isolate it to a particular one. :)
> 
> Before trying that, I tried reverting 62dbcaa4d873784f1 and that worked.

That commit allows backtracking to continue in the event that unsolved
blockers are encountered, solving this bug:

  https://bugs.gentoo.org/show_bug.cgi?id=465638

That means that emerge may spend some more time backtracking in some
cases involving blockers, even though the backtracking may not
ultimately lead to a useful solution.

Did your test case involve blockers? Are you using the --backtrack
option to increase the amount of backtracking that is allowed?
-- 
Thanks,
Zac


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [gentoo-portage-dev] portage 9999 at commit 2d5e38b495776e5bb2266848a3365667f3ca7233 **SLOW**
  2013-05-01 21:15     ` Zac Medico
@ 2013-05-01 21:42       ` James Cloos
  2013-05-01 22:08         ` Zac Medico
  0 siblings, 1 reply; 6+ messages in thread
From: James Cloos @ 2013-05-01 21:42 UTC (permalink / raw
  To: Zac Medico; +Cc: gentoo-portage-dev

>>>>> "ZM" == Zac Medico <zmedico@gentoo.org> writes:

ZM> That commit allows backtracking to continue in the event that unsolved
ZM> blockers are encountered, solving this bug:

ZM>   https://bugs.gentoo.org/show_bug.cgi?id=465638

I read the bug.  But it was the only commit that at first glance *could*
have been the issue.

ZM> That means that emerge may spend some more time backtracking in some
ZM> cases involving blockers, even though the backtracking may not
ZM> ultimately lead to a useful solution.

Five hours more, in my case.

ZM> Did your test case involve blockers? Are you using the --backtrack
ZM> option to increase the amount of backtracking that is allowed?

Yes.  There are several blockers and at some point in the fuzzy past I
added --backtrack=30 to get around some issue which was preventing the
automated sync && pv from reporting any possible updates.

The larger backtrace allowed pv to complete.  Then the scripts use -O
to merge a few packages at a time in the pv order.

As a side note, my next workstation will split most stuff into smaller
topic-spcific VMs so as to avoid the annoying conflicts which occur when
one tries to keep everything one might need available at once.

-JimC
-- 
James Cloos <cloos@jhcloos.com>         OpenPGP: 1024D/ED7DAEA6


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: [gentoo-portage-dev] portage 9999 at commit 2d5e38b495776e5bb2266848a3365667f3ca7233 **SLOW**
  2013-05-01 21:42       ` James Cloos
@ 2013-05-01 22:08         ` Zac Medico
  0 siblings, 0 replies; 6+ messages in thread
From: Zac Medico @ 2013-05-01 22:08 UTC (permalink / raw
  To: James Cloos, gentoo-portage-dev

On 05/01/2013 02:42 PM, James Cloos wrote:
>>>>>> "ZM" == Zac Medico <zmedico@gentoo.org> writes:
> 
> ZM> That commit allows backtracking to continue in the event that unsolved
> ZM> blockers are encountered, solving this bug:
> 
> ZM>   https://bugs.gentoo.org/show_bug.cgi?id=465638
> 
> I read the bug.  But it was the only commit that at first glance *could*
> have been the issue.
> 
> ZM> That means that emerge may spend some more time backtracking in some
> ZM> cases involving blockers, even though the backtracking may not
> ZM> ultimately lead to a useful solution.
> 
> Five hours more, in my case.
> 
> ZM> Did your test case involve blockers? Are you using the --backtrack
> ZM> option to increase the amount of backtracking that is allowed?
> 
> Yes.  There are several blockers and at some point in the fuzzy past I
> added --backtrack=30 to get around some issue which was preventing the
> automated sync && pv from reporting any possible updates.

Okay, then I'd suggest to use a lower --backtrack setting (10 is
default), at least until you decide how you are going to resolve the
blockers.
-- 
Thanks,
Zac


^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2013-05-01 22:08 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2013-05-01  6:19 [gentoo-portage-dev] portage 9999 at commit 2d5e38b495776e5bb2266848a3365667f3ca7233 **SLOW** James Cloos
2013-05-01  6:29 ` Zac Medico
2013-05-01 20:56   ` James Cloos
2013-05-01 21:15     ` Zac Medico
2013-05-01 21:42       ` James Cloos
2013-05-01 22:08         ` Zac Medico

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox