Re: yum 3.2.23 more than 10x slower than 3.2.21?! (BZ #508445)

2009-06-27 Thread Roberto Ragusa
Roberto Ragusa wrote:
 Never programmed in python, but this could be O(N^2).
 
   for pkg in pkgs[1:]:
   if pkg.repo.cost  lowcost:
   msg = _('excluding for cost: %s from %s') % (pkg, pkg.repo.id)
   self.verbose_logger.log(logginglevels.DEBUG_3, msg)
   pkg.repo.sack.delPackage(pkg)

Replying to myself to say a filed the problem into bugzilla.

#508445

-- 
   Roberto Ragusamail at robertoragusa.it

-- 
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Seth Vidal



On Fri, 26 Jun 2009, Roberto Ragusa wrote:


Hi,

yum got really slower a few days ago on F10, so I investigated and found that:

(3.2.23) #yum list updates
real1m28.446s
user1m24.553s
sys 0m0.546s

(3.2.21) #yum list updates
real0m7.621s
user0m6.673s
sys 0m0.390s

this is with a few repositories, no net access, no disk access (everything
is cached), trivially reproduceable. No yum plugins (just downloadonly), no
PackageKit installed.

About 90 seconds of 100% CPU (2.4GHz Core 2) is a disaster.


just for fun:
set color=never in your yum.conf

and run it again.

-sv

--
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Seth Vidal



On Fri, 26 Jun 2009, Seth Vidal wrote:




On Fri, 26 Jun 2009, Roberto Ragusa wrote:


Hi,

yum got really slower a few days ago on F10, so I investigated and found 
that:


(3.2.23) #yum list updates
real1m28.446s
user1m24.553s
sys 0m0.546s

(3.2.21) #yum list updates
real0m7.621s
user0m6.673s
sys 0m0.390s

this is with a few repositories, no net access, no disk access (everything
is cached), trivially reproduceable. No yum plugins (just downloadonly), no
PackageKit installed.

About 90 seconds of 100% CPU (2.4GHz Core 2) is a disaster.


just for fun:
set color=never in your yum.conf

and run it again.


Just tested locally.


3.2.23 is showing 3.186s for a yum list updates on my system

3.2.21 is shwoing 3.339s for the same.


I think we need more info on what you're seeing.

b/c it is not what I'm seeing at all.

-sv

--
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Joe Nall


On Jun 26, 2009, at 9:11 AM, Seth Vidal wrote:




On Fri, 26 Jun 2009, Roberto Ragusa wrote:


Hi,

yum got really slower a few days ago on F10, so I investigated and  
found that:


(3.2.23) #yum list updates
real1m28.446s
user1m24.553s
sys 0m0.546s

(3.2.21) #yum list updates
real0m7.621s
user0m6.673s
sys 0m0.390s

this is with a few repositories, no net access, no disk access  
(everything
is cached), trivially reproduceable. No yum plugins (just  
downloadonly), no

PackageKit installed.

About 90 seconds of 100% CPU (2.4GHz Core 2) is a disaster.


just for fun:
set color=never in your yum.conf

and run it again.


No time difference here (2:23-2:26) for color=never on yum 3.2.23.  
More than 2 minutes of cpu time on a 3.1GHz E8400. Downgraded to  
3.2.21-2 from koji and the same 'yum list updates' takes 6.4 seconds.


joe


--
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Seth Vidal



On Fri, 26 Jun 2009, Joe Nall wrote:



just for fun:
set color=never in your yum.conf

and run it again.


No time difference here (2:23-2:26) for color=never on yum 3.2.23. More than 
2 minutes of cpu time on a 3.1GHz E8400. Downgraded to 3.2.21-2 from koji and 
the same 'yum list updates' takes 6.4 seconds.




just to be sure - in both cases you're working from a completely cached 
set of metadata, right?


-sv

--
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Roberto Ragusa
Seth Vidal wrote:
 
 and if you can make this happen every time with 3.2.23 if you could
 please run:
 
 time yum -d 3 list updates | grep 'time:'

You were not talking to me, but I tried and
look at this: (added -C to avoid net access)

# time yum -C -d 3 list updates --disablerepo=atrpms\* | grep 'time:'
Config time: 0.271
repo time: 0.001
pkgsack time: 86.684
rpmdb time: 0.003
up:Obs Init time: 0.230
up:simple updates time: 0.312
up:obs time: 0.015
up:condense time: 0.000
updates time: 1.583

real1m29.527s
user1m24.252s
sys 0m0.409s


-- 
   Roberto Ragusamail at robertoragusa.it

-- 
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Seth Vidal



On Fri, 26 Jun 2009, Roberto Ragusa wrote:


It is really CPU intensive. I see some unicode related stuff in the changelog
and my memory goes to years ago (RedHat 8?) when the UTF8 enabled grep
got a similar slowdown (the lib was then improved after that).

Hm, made other experiments
Really weird.

#time yum list updates --disablerepo=\* --enablerepo=ROB10\*
(less than 3 seconds)

#time yum list updates --disablerepo=\* --enablerepo=updates
(less than 3 seconds)

#time yum list updates --disablerepo=\* --enablerepo=ROB10\*  
--enablerepo=updates
(more than one minute)

ROB10\* is some local repositories, containing mirrored stuff from some
repositories, _including fedora_updates_, so the same rpms are found in two
different repositories. How can this trigger such a slowdown, I don't know.

I have to correct what I said before, the time is not always spent
on read64() and gettimeofday(); there is a lot of strace-silent activity
(just spurious brk() calls).

Maybe something like hashing of some data structure is taking a really bad
direction?



run:

time yum -d 3 --disablerepo=\* --enablerepo=ROB10\*  \
   --enablerepo=updates  list updates | grep 'time:'


and post that output.

thanks,
-sv

--
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Seth Vidal



On Fri, 26 Jun 2009, Roberto Ragusa wrote:


Seth Vidal wrote:


and if you can make this happen every time with 3.2.23 if you could
please run:

time yum -d 3 list updates | grep 'time:'


You were not talking to me, but I tried and
look at this: (added -C to avoid net access)

# time yum -C -d 3 list updates --disablerepo=atrpms\* | grep 'time:'
Config time: 0.271
repo time: 0.001
pkgsack time: 86.684


and you're POSITIVE nothing is being downloaded here? Nothing at all?

Run it again, please and capture all the output and post it to a pastebin.

-sv

--
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Joe Nall


On Jun 26, 2009, at 9:49 AM, Seth Vidal wrote:




On Fri, 26 Jun 2009, Joe Nall wrote:

just for fun:
set color=never in your yum.conf
and run it again.


No time difference here (2:23-2:26) for color=never on yum 3.2.23.  
More than 2 minutes of cpu time on a 3.1GHz E8400. Downgraded to  
3.2.21-2 from koji and the same 'yum list updates' takes 6.4 seconds.




and if you can make this happen every time with 3.2.23 if you could  
please run:


time yum -d 3 list updates | grep 'time:'

and paste all the output.

thanks


[r...@fast ~]# yum --version
3.2.21
  Installed: yum-metadata-parser-1.1.2-10.fc10.x86_64 at 2009-01-04  
17:01

  Built: Fedora Project at 2008-10-15 13:38
  Committed: James Antill james at fedoraproject.org at 2008-10-14  
22:00


  Installed: yum-3.2.21-2.fc10.noarch at 2009-06-26 14:42
  Built: Fedora Project at 2009-01-12 17:30
  Committed: Seth Vidal skvidal at fedoraproject.org at 2009-01-07  
22:00


  Installed: rpm-4.6.1-1.fc10.x86_64 at 2009-06-06 05:29
  Built: Fedora Project at 2009-05-18 11:26
  Committed: Panu Matilainen pmati...@redhat.com at 2009-05-18 22:00
[r...@fast ~]# time yum -d 3 list updates | grep 'time:'
Config time: 0.067
pkgsack time: 4.729
rpmdb time: 0.000
up:Obs Init time: 0.691
up:simple updates time: 0.183
up:obs time: 0.004
up:condense time: 0.000
updates time: 1.384

real0m6.428s
user0m6.004s
sys 0m0.424s



Second of two identical runs with 3.2.23:

[r...@fast ~]# yum --version
3.2.23
  Installed: rpm-4.6.1-1.fc10.x86_64 at 2009-06-06 05:29
  Built: Fedora Project at 2009-05-18 11:26
  Committed: Panu Matilainen pmati...@redhat.com at 2009-05-18 22:00

  Installed: yum-3.2.23-3.fc10.noarch at 2009-06-26 15:02
  Built: Fedora Project at 2009-05-20 22:30
  Committed: Seth Vidal skvidal at fedoraproject.org at 2009-05-20  
22:00


  Installed: yum-metadata-parser-1.1.2-10.fc10.x86_64 at 2009-01-04  
17:01

  Built: Fedora Project at 2008-10-15 13:38
  Committed: James Antill james at fedoraproject.org at 2008-10-14  
22:00

[r...@fast ~]# time yum -d 3 list updates | grep 'time:'
Config time: 0.040
pkgsack time: 141.108
rpmdb time: 0.002
up:Obs Init time: 0.158
up:simple updates time: 0.172
up:obs time: 0.005
up:condense time: 0.000
updates time: 0.846

real2m22.245s
user2m21.764s
sys 0m0.426s


--
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Roberto Ragusa
Seth Vidal wrote:
 
 run:
 
 time yum -d 3 --disablerepo=\* --enablerepo=ROB10\*  \
--enablerepo=updates  list updates | grep 'time:'
 
 
 and post that output.
 

Just pasted something similar in another mail, where the time is 1:30
as there are more repositories enabled than in this test.
Anyway this is it:

# time yum -d 3 --disablerepo=\* --enablerepo=ROB10\*  \
--enablerepo=updates  list updates | grep 'time:'
Config time: 0.205
repo time: 0.001
pkgsack time: 58.515
rpmdb time: 0.004
up:Obs Init time: 0.143
up:simple updates time: 0.156
up:obs time: 0.008
up:condense time: 0.000
updates time: 1.067

real1m0.595s
user0m57.970s
sys 0m0.519s


-- 
   Roberto Ragusamail at robertoragusa.it

-- 
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Roberto Ragusa
Seth Vidal wrote:
 
 
 On Fri, 26 Jun 2009, Roberto Ragusa wrote:
 
 Seth Vidal wrote:

 and if you can make this happen every time with 3.2.23 if you could
 please run:

 time yum -d 3 list updates | grep 'time:'

 You were not talking to me, but I tried and
 look at this: (added -C to avoid net access)

 # time yum -C -d 3 list updates --disablerepo=atrpms\* | grep 'time:'
 Config time: 0.271
 repo time: 0.001
 pkgsack time: 86.684
 
 and you're POSITIVE nothing is being downloaded here? Nothing at all?
 
 Run it again, please and capture all the output and post it to a pastebin.
 

Consider that there is a -C, that is repeatable, and that the CPU is at 100%:
it is not waiting, it is computing (user time result).

Just repeated the test.
No disk activity.
No net activity. (in any case I'm on a connection where remote downloads 
sometimes reach 100Mbit/s).

# time yum -d 3 --disablerepo=\* --enablerepo=ROB10\* 
--enablerepo=updates  list updates | grep 'time:'
Config time: 0.199
repo time: 0.001
pkgsack time: 57.204
rpmdb time: 0.003
up:Obs Init time: 0.132
up:simple updates time: 0.152
up:obs time: 0.009
up:condense time: 0.000
updates time: 1.005

real0m59.227s
user0m57.726s
sys 0m0.498s



-- 
   Roberto Ragusamail at robertoragusa.it

-- 
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Joe Nall


On Jun 26, 2009, at 10:25 AM, Roberto Ragusa wrote:


Seth Vidal wrote:



On Fri, 26 Jun 2009, Roberto Ragusa wrote:


Seth Vidal wrote:


and if you can make this happen every time with 3.2.23 if you could
please run:

time yum -d 3 list updates | grep 'time:'


You were not talking to me, but I tried and
look at this: (added -C to avoid net access)

# time yum -C -d 3 list updates --disablerepo=atrpms\* | grep  
'time:'

Config time: 0.271
repo time: 0.001
pkgsack time: 86.684


and you're POSITIVE nothing is being downloaded here? Nothing at all?

Run it again, please and capture all the output and post it to a  
pastebin.




I have a hint and it points to the same rpms in more than one repo
hypothesis.

yum -d 5 lists a lot of

excluding for cost: firefox-3.0.11-1.fc10.i386 from updates
excluding for cost: gnome-session-2.24.3-1.fc10.i386 from updates
[...]

I see something related to cost handling fixes in the yum Changelog.

My guess is that elements are removed from an array one at a time
and everything after that is moved back one position.
Or some inefficiency of that kind.

You may be able to reproduce it by configuring two updates repos.


The performance change occurred between 3.2.21-2 and 3.2.22-5 based on  
testing on koji f10 downloads.


joe


--
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Seth Vidal



On Fri, 26 Jun 2009, Roberto Ragusa wrote:



I have a hint and it points to the same rpms in more than one repo
hypothesis.

yum -d 5 lists a lot of

excluding for cost: firefox-3.0.11-1.fc10.i386 from updates
excluding for cost: gnome-session-2.24.3-1.fc10.i386 from updates
[...]

I see something related to cost handling fixes in the yum Changelog.

My guess is that elements are removed from an array one at a time
and everything after that is moved back one position.
Or some inefficiency of that kind.

You may be able to reproduce it by configuring two updates repos.



Grab yum from rawhide here:

http://koji.fedoraproject.org/koji/buildinfo?buildID=111297

see if the recent exclude changes help the problem.

-sv

--
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Roberto Ragusa
Joe Nall wrote:
 
 On Jun 26, 2009, at 10:25 AM, Roberto Ragusa wrote:
 
 Seth Vidal wrote:


 On Fri, 26 Jun 2009, Roberto Ragusa wrote:

 Seth Vidal wrote:

 and if you can make this happen every time with 3.2.23 if you could
 please run:

 time yum -d 3 list updates | grep 'time:'

 You were not talking to me, but I tried and
 look at this: (added -C to avoid net access)

 # time yum -C -d 3 list updates --disablerepo=atrpms\* | grep 'time:'
 Config time: 0.271
 repo time: 0.001
 pkgsack time: 86.684

 and you're POSITIVE nothing is being downloaded here? Nothing at all?

 Run it again, please and capture all the output and post it to a
 pastebin.


 I have a hint and it points to the same rpms in more than one repo
 hypothesis.

 yum -d 5 lists a lot of

 excluding for cost: firefox-3.0.11-1.fc10.i386 from updates
 excluding for cost: gnome-session-2.24.3-1.fc10.i386 from updates
 [...]

 I see something related to cost handling fixes in the yum Changelog.

 My guess is that elements are removed from an array one at a time
 and everything after that is moved back one position.
 Or some inefficiency of that kind.

 You may be able to reproduce it by configuring two updates repos.
 
 The performance change occurred between 3.2.21-2 and 3.2.22-5 based on
 testing on koji f10 downloads.

from rpm -q -changelog yum:

* Tue May 12 2009 Seth Vidal skvidal at fedoraproject.org - 3.2.22-5


from ChangeLog in yum tar.gz:

2009-04-13  James Antill ja...@and.org

* yum/yumRepo.py: Fix cost sorting of repos.


-- 
   Roberto Ragusamail at robertoragusa.it

-- 
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list


Re: yum 3.2.23 more than 10x slower than 3.2.21?!

2009-06-26 Thread Joe Nall


On Jun 26, 2009, at 10:35 AM, Seth Vidal wrote:




On Fri, 26 Jun 2009, Roberto Ragusa wrote:



I have a hint and it points to the same rpms in more than one repo
hypothesis.

yum -d 5 lists a lot of

excluding for cost: firefox-3.0.11-1.fc10.i386 from updates
excluding for cost: gnome-session-2.24.3-1.fc10.i386 from updates
[...]

I see something related to cost handling fixes in the yum Changelog.

My guess is that elements are removed from an array one at a time
and everything after that is moved back one position.
Or some inefficiency of that kind.

You may be able to reproduce it by configuring two updates repos.



Grab yum from rawhide here:

http://koji.fedoraproject.org/koji/buildinfo?buildID=111297

see if the recent exclude changes help the problem.


Built from the src rpm because there was a python ABI change. No change.

[r...@fast rpmbuild]# yum --version
3.2.23
  Installed: rpm-4.6.1-1.fc10.x86_64 at 2009-06-06 05:29
  Built: Fedora Project at 2009-05-18 11:26
  Committed: Panu Matilainen pmati...@redhat.com at 2009-05-18 22:00

  Installed: yum-3.2.23-8.fc10.noarch at 2009-06-26 15:39
  Built: None at 2009-06-26 15:39
  Committed: James Antill james at fedoraproject.org at 2009-06-23  
00:00


  Installed: yum-metadata-parser-1.1.2-10.fc10.x86_64 at 2009-01-04  
17:01

  Built: Fedora Project at 2008-10-15 13:38
  Committed: James Antill james at fedoraproject.org at 2008-10-14  
22:00

[r...@fast rpmbuild]# time yum -d 3 list updates | grep 'time:'
Config time: 0.041
pkgsack time: 143.857
rpmdb time: 0.002
up:Obs Init time: 0.191
up:simple updates time: 0.410
up:obs time: 0.005
up:condense time: 0.000
updates time: 1.142

real2m25.310s
user2m24.969s
sys 0m0.287s

--
fedora-devel-list mailing list
fedora-devel-list@redhat.com
https://www.redhat.com/mailman/listinfo/fedora-devel-list