Hi,
yum got really slower a few days ago on F10, so I investigated and found that:
(3.2.23) #yum list updates real 1m28.446s user 1m24.553s sys 0m0.546s
(3.2.21) #yum list updates real 0m7.621s user 0m6.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.
What the ${REPLACE_WITH_RUDE_WORD} is it the new version doing? Is it raytracing something in background? :-) A quick strace of the process appeared to be read()ing a lot of stuff and gettimeofday()ing a lot.
gettimeofday({1246010546, 912877}, NULL) = 0 pread64(29, "\0\0\0\0\1\0\0\0A\35\0\0\0\0\0\0B\35\0\0\1\0\346?\0\7\0\0\0B\0\0E"..., 16384, 122699776) = 16384 pread64(29, "\0\0\0\0\1\0\0\0B\35\0\0A\35\0\0\0\0\0\0\1\0F\t\0\7\0\0\0\0\0\0\0"..., 16384, 122716160) = 16384 gettimeofday({1246010546, 913336}, NULL) = 0 gettimeofday({1246010546, 913696}, NULL) = 0 pread64(29, "\0\0\0\0\1\0\0\0\243\1\0\0\0\0\0\0^\25\0\0\1\0\346?\0\7\0\0\0G\0\0="..., 16384, 6864896) = 16384 pread64(29, "\0\0\0\0\1\0\0\0^\25\0\0\243\1\0\0\0\0\0\0\1\0\306\1\0\7\0cpio\0g"..., 16384, 89620480) = 16384 gettimeofday({1246010546, 926442}, NULL) = 0 gettimeofday({1246010546, 926872}, NULL) = 0 pread64(29, "\0\0\0\0\1\0\0\0\335\23\0\0\0\0\0\0\375\32\0\0\1\0\346?\0\7\0\0\0H\0\1l"..., 16384, 83312640) = 16384 pread64(29, "\0\0\0\0\1\0\0\0\375\32\0\0\335\23\0\0\235\32\0\0\1\0\346?\0\007202c8e5"..., 16384, 113197056) = 16384 pread64(29, "\0\0\0\0\1\0\0\0\235\32\0\0\375\32\0\0^\33\0\0\1\0\346?\0\7\377\377\377\377\377\377\377"..., 16384, 111624192) = 16384 pread64(29, "\0\0\0\0\1\0\0\0^\33\0\0\235\32\0\0^\35\0\0\1\0\346?\0\7\0- Add "..., 16384, 114786304) = 16384
Can someone else reproduce this? I'm not an expert at profiling python.
Best regards.
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 real 1m28.446s user 1m24.553s sys 0m0.546s
(3.2.21) #yum list updates real 0m7.621s user 0m6.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
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 real 1m28.446s user 1m24.553s sys 0m0.546s
(3.2.21) #yum list updates real 0m7.621s user 0m6.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
Seth Vidal wrote:
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.
# time yum list updates Loaded plugins: downloadonly Updated Packages [snipped list with 70-80 package]
real 1m28.537s user 1m23.830s sys 0m0.536s
# rpm -Uhv --oldpackage yum-3.2.21-2.fc10.noarch.rpm Preparing... ########################################### [100%] 1:yum ########################################### [100%] [root@thinkpad etc]# time yum list updates Loaded plugins: downloadonly Updated Packages [snipped list with 70-80 package]
real 0m7.296s user 0m6.549s sys 0m0.324s
This is my yum.conf, where I justr added the last line, as you suggested.
[main] cachedir=/var/cache/yum keepcache=0 debuglevel=2 logfile=/var/log/yum.log exactarch=1 obsoletes=1 gpgcheck=1 plugins=1 installonly_limit=3
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).
Hmmmmm, 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?
Roberto Ragusa wrote:
This is my yum.conf, where I justr added the last line, as you suggested.
[main] cachedir=/var/cache/yum keepcache=0 debuglevel=2 logfile=/var/log/yum.log exactarch=1 obsoletes=1 gpgcheck=1 plugins=1 installonly_limit=3
Sorry, snipped last line about colors.
Hello Folks,
I fired up pidgin via the cmd line and get the following error:
$ pidgin
(pidgin:25897): GStreamer-CRITICAL **: gst_element_register: assertion `g_type_is_a (type, GST_TYPE_ELEMENT)' failed
ERROR: Caught a segmentation fault while loading plugin file: /usr/lib64/gstreamer-0.10/libgsttcp.so
Please either: - remove it and restart. - run with --gst-disable-segtrap and debug.
Is there something I can do to fix this and get my stuff working again ? Empathy has the same issue.
Cheers,
ASD.
On 6/26/2009 11:01 AM, Aly Dharshi wrote:
Hello Folks,
I fired up pidgin via the cmd line and get the following error:
$ pidgin
(pidgin:25897): GStreamer-CRITICAL **: gst_element_register: assertion `g_type_is_a (type, GST_TYPE_ELEMENT)' failed
ERROR: Caught a segmentation fault while loading plugin file: /usr/lib64/gstreamer-0.10/libgsttcp.so
Please either:
remove it and restart.
run with --gst-disable-segtrap and debug.
Is there something I can do to fix this and get my stuff working
again ? Empathy has the same issue.
Cheers, ASD.
Someone may, or may not, tell you sooner or later that you need to start a new thread instead of just changing the header of and existing thread if you expect anyone to help you.
Yeah I just caught that, and started a new one already ! Sorry about the grief.
ASD.
On 06/26/2009 11:02 AM, David wrote:
On 6/26/2009 11:01 AM, Aly Dharshi wrote:
Hello Folks,
I fired up pidgin via the cmd line and get the following error:
$ pidgin
(pidgin:25897): GStreamer-CRITICAL **: gst_element_register: assertion `g_type_is_a (type, GST_TYPE_ELEMENT)' failed
ERROR: Caught a segmentation fault while loading plugin file: /usr/lib64/gstreamer-0.10/libgsttcp.so
Please either:
remove it and restart.
run with --gst-disable-segtrap and debug.
Is there something I can do to fix this and get my stuff working
again ? Empathy has the same issue.
Cheers, ASD.
Someone may, or may not, tell you sooner or later that you need to start a new thread instead of just changing the header of and existing thread if you expect anyone to help you.
On 6/26/2009 1:04 PM, Aly Dharshi wrote:
Yeah I just caught that, and started a new one already ! Sorry about the grief.
ASD.
On 06/26/2009 11:02 AM, David wrote:
On 6/26/2009 11:01 AM, Aly Dharshi wrote:
Hello Folks,
I fired up pidgin via the cmd line and get the following error:
$ pidgin
(pidgin:25897): GStreamer-CRITICAL **: gst_element_register: assertion `g_type_is_a (type, GST_TYPE_ELEMENT)' failed
ERROR: Caught a segmentation fault while loading plugin file: /usr/lib64/gstreamer-0.10/libgsttcp.so
Please either:
remove it and restart.
run with --gst-disable-segtrap and debug.
Is there something I can do to fix this and get my stuff working
again ? Empathy has the same issue.
Cheers, ASD.
Someone may, or may not, tell you sooner or later that you need to start a new thread instead of just changing the header of and existing thread if you expect anyone to help you.
No grief friend. Just trying to help.
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).
Hmmmmm, 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
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
real 1m0.595s user 0m57.970s sys 0m0.519s
On Jun 26, 2009, at 10:03 AM, Seth Vidal wrote:
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).
Hmmmmm, 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.
I disabled all repos and individually enabled one repo at a time. Each individual repo performance was excellent (couple of seconds). When I included two repos, I start to see the problem. local-mirror-updates is a a low cost (500) local rsync mirror on a GbE network.
[root@fast ~]# time yum -d 3 --disablerepo=* --enablerepo=local- mirror-updates --enablerepo=updates list updates | grep 'time:' Config time: 0.040 repo time: 0.000 pkgsack time: 39.956 rpmdb time: 0.002 up:Obs Init time: 0.054 up:simple updates time: 0.047 up:obs time: 0.002 up:condense time: 0.000 updates time: 0.388
real 0m40.547s user 0m40.253s sys 0m0.195s
Joe Nall wrote:
I disabled all repos and individually enabled one repo at a time. Each individual repo performance was excellent (couple of seconds). When I included two repos, I start to see the problem. local-mirror-updates is a a low cost (500) local rsync mirror on a GbE network.
Ok, so we came to the same conclusion. Cost handling is inefficient.
Try with "-d 5", you will see "excluding for cost:" lines which do not fly out of the terminal, but every line takes a little time. And we have hundreds/thousands of those...
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 real 1m28.446s user 1m24.553s sys 0m0.546s
(3.2.21) #yum list updates real 0m7.621s user 0m6.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
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
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 -sv
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
real 1m29.527s user 1m24.252s sys 0m0.409s
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
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
real 0m59.227s user 0m57.726s sys 0m0.498s
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.
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
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 james@and.org
* yum/yumRepo.py: Fix cost sorting of repos.
Roberto Ragusa wrote:
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 james@and.org
- yum/yumRepo.py: Fix cost sorting of repos.
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)
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
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
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.
[root@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 pmatilai@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 [root@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
real 2m25.310s user 2m24.969s sys 0m0.287s
Seth Vidal wrote:
Grab yum from rawhide here:
http://koji.fedoraproject.org/koji/buildinfo?buildID=111297
see if the recent exclude changes help the problem.
No luck, I'm on F10 and this package doesn't run.
# rpm -Uhv /root/yum-3.2.23-8.fc12.noarch.rpm error: Failed dependencies: python(abi) = 2.6 is needed by yum-3.2.23-8.fc12.noarch
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
[root@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 pmatilai@redhat.com at 2009-05-18 22:00 [root@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
real 0m6.428s user 0m6.004s sys 0m0.424s
------------------------------------ Second of two identical runs with 3.2.23:
[root@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 pmatilai@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 [root@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
real 2m22.245s user 2m21.764s sys 0m0.426s
devel@lists.stg.fedoraproject.org