Red Hat Bugzilla – Bug 209323
choosing packages to update is too slow by a factor of 10
Last modified: 2014-01-21 17:55:25 EST
Description of problem: A "yum update" from FC6Pre (Sept.30) to rawhide of Oct.3 took 10 minutes of CPU time to go from "############## 3446/3446" to "Populating transaction set with selected packages" when 159 packages (275MB) were chosen to be updated; only one repository was active. That was on PowerPC Apple Macintosh mini (1.25GHz, 512MB DDR RAM, no paging). On a "3200" AMD x86_64 (2.0GHz clock, 1GB DDR RAM, no paging), a "yum update" from rawhide of Oct.2 to Rawhide of Oct.3 took 3.5 minutes of CPU time when 19 packages (25MB) were chosen from two repositories (2935/2935 and 3459/3459 packages). Times were measured using "top"; CPU utilization was usually at least 95%. In each case the CPU usage is too large by a factor of ten. Version-Release number of selected component (if applicable): yum-2.9.8-1 How reproducible: "always" Steps to Reproduce: 1. yum update 2. 3. Actual results: Choosing which packages to update takes much too long. Expected results: Choosing packages to update takes at most one minute on a 1GHz machine that has enough RAM to avoid paging. Additional info:
Seeing it here too. x86_64, only 52 packages listed by 'yum list updates' done just a few minutes before. A 2Ghz Core2 Duo, 2G of memory - and it takes it 14:27 to get from 'yum update' to 'Total Download SIze/Is this OK?' yum-3.1.4-1.fc7 - so either it's some horrendous cycle sucker in a shared library (sqlite?) or something, or everything from 2.9.8 to 3.1.4 is busticated.
2.9.8->3.1.4 is a huge difference in code and we've had thousands and thousands of success reports on 3.0.X reported so I'm a little confused that NOTHING b/t those has worked for you.
Obviously some profiling is needed, I'll dig in and follow up when I have more concrete information.
So I pointed oprofile at the system, and it said most of the time was being spent in libpython.so. And I caught a few seconds worth of strace output: # strace -p 10973 > /tmp/trace 2>&1 (wait about 10 seconds and then ^C) # wc /tmp/trace 346510 1733628 16765630 /tmp/trace # sort /tmp/trace | uniq -c | sort -nr | more 270228 futex(0xc7baf0, FUTEX_WAKE, 1) = 0 83 read(16, "\0\0\0\0amimageplugin_unsharp.mo/dig"..., 1024) = 1024 67 read(16, "\0\0\0\0ffffffffffffffffffffffffffff"..., 1024) = 1024 34 read(16, "\0\0\0\0-4300.5.0.ppd.gz/stp-bjc-400"..., 1024) = 1024 28 read(16, "\0\0\0\0tle-5-active.xpm/title-4-ina"..., 1024) = 1024 24 read(16, "\r\0\0\0\1\0\'\0\0\'\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 10 24) = 1024 24 read(16, "\r\0\0\0\1\0!\0\0!\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 10 24) = 1024 20 read(16, "\0\0\0\0ctive.xpm/menu-inactive.png/"..., 1024) = 1024 18 read(16, "\r\0\0\0\1\1D\0\1D\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 10 24) = 1024 18 read(16, "\0\0\0\0g/network-wireless.png/netwo"..., 1024) = 1024 18 read(16, "\0\0\0\0etwork-offline.png/network-i"..., 1024) = 1024 18 read(16, "\0\0\0\0dhat-system_tools.png/redhat"..., 1024) = 1024 18 read(16, "\0\0\0\0.png/locale.png/kwin.png/kus"..., 1024) = 1024 Yowza. Looks like we're spinning on a futex for some reason. (And it looks like somebody could be a bit better about in-memory caching and not be re-reading the same blocks several dozen times, but I suspect that's in the 5 or 6% of the time we spent in libsqlite3.so - hardly a performance hit) Any suggestions where to look next? I know zip about python - any way to get it to do statement-level profiling/execution counts?
OK, *major* weirdness, maybe this is a useful clue.. After some 15 minutes of grinding, the 'yum update' bombed out during the download phase: <....> Installing for dependencies: java_cup x86_64 1:0.10-0.k.6jpp.1 development 206 k <....> Error Downloading Packages: java_cup - 1:0.10-0.k.6jpp.1.x86_64: failure: Fedora/RPMS/java_cup-0.10-0.k.6jpp.1.x86_64.rpm from development: [Errno 256] No more mirrors to try. Note that RPM was a "install for dependencies". So I ran: # yum --exclude="*java*" update and *that* finished its crunching in the minute or so I expected it to take. Maybe the problem is in handling the "added for dependencies" RPMs?
3.1.6 si even better, 3.1.7 has even more better