[Bug 953130] New: zypper up "checking for file conflicts" takes 3.5 cpu-minutes for 32 packages
http://bugzilla.opensuse.org/show_bug.cgi?id=953130 Bug ID: 953130 Summary: zypper up "checking for file conflicts" takes 3.5 cpu-minutes for 32 packages Classification: openSUSE Product: openSUSE Distribution Version: Leap 42.1 Hardware: x86-64 OS: Other Status: NEW Severity: Normal Priority: P5 - None Component: Basesystem Assignee: bnc-team-screening@forge.provo.novell.com Reporter: koenig@linux.de QA Contact: qa-bugs@suse.de Found By: --- Blocker: --- User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:41.0) Gecko/20100101 Firefox/41.0 Build Identifier: just run "zypper up" again, and for 32 RPMs the Checking for file conflicts: ..................................<48%>===========================================[|] took > 3.5 minutes cpu time (mostly at the 48% 'location'. that sucks! comparing even a huge list of files shouldn't take that long -- maybe do some intelligent sorting/indexing of filename lists ?! this is the update summary from zypper, more details on request: Reading installed packages... The following 13 NEW packages are going to be installed: crash-kmp-default-7.1.3_k4.1.12_1-4.14 crash-kmp-xen-7.1.3_k4.1.12_1-4.14 hdjmod-kmp-xen-1.28_k4.1.12_1-23.17 kernel-default-4.1.12-1.1 kernel-default-devel-4.1.12-1.1 kernel-devel-4.1.12-1.1 kernel-pv-devel-4.1.12-1.1 kernel-source-4.1.12-1.1 kernel-syms-4.1.12-1.1 kernel-xen-4.1.12-1.1 kernel-xen-devel-4.1.12-1.1 lttng-modules-kmp-default-2.7.0_k4.1.12_1-1.6 xen-kmp-default-4.5.1_10_k4.1.12_1-1.4 The following 19 packages are going to be upgraded: crash install-initrd-openSUSE kernel-macros lttng-modules package-translations virtualbox virtualbox-guest-kmp-default virtualbox-guest-tools virtualbox-guest-x11 virtualbox-host-kmp-default virtualbox-qt xen xen-doc-html xen-libs xen-tools yast2-kdump yast2-ntp-client yast2-storage yast2-storage-devel 19 packages to upgrade, 13 new. Overall download size: 251.4 MiB. Already cached: 0 B. After the operation, additional 980.8 MiB will be used. Continue? [y/n/? shows all options] (y): Reproducible: Always Actual Results: takes too much time, too slow Expected Results: should be *much* faster ;-) you ask, I'll provide... -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
Dominique Leuenberger
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c1
Michael Andres
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c2
--- Comment #2 from Harald Koenig
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c3
Michael Andres
11:30:34 [zypp] TargetImpl.commitFindFileConflicts.cc(commitFindFileConflicts):127 Checking for file conflicts in 32 new packages... 11:30:34 [libsolv++] PoolImpl.cc(logSat):114 searching for file conflicts 11:30:34 [libsolv++] PoolImpl.cc(logSat):114 packages: 8577, cutoff 32 . 11:30:48 [libsolv++] PoolImpl.cc(logSat):114 filemap size: 131072, used 44568 11:30:48 [libsolv++] PoolImpl.cc(logSat):114 filemap memory usage: 1024 K 11:30:48 [libsolv++] PoolImpl.cc(logSat):114 filemap creation took 14006 ms 11:30:48 [libsolv++] PoolImpl.cc(logSat):114 lookat_dir size: 206004 . 11:31:54 [libsolv++] PoolImpl.cc(logSat):114 normap size: 262144, used 85084 11:31:54 [libsolv++] PoolImpl.cc(logSat):114 normap memory usage: 2048 K 11:31:54 [libsolv++] PoolImpl.cc(logSat):114 stats made: 85084 11:31:54 [libsolv++] PoolImpl.cc(logSat):114 statmap size: 262144, used 68329 11:31:54 [libsolv++] PoolImpl.cc(logSat):114 statmap memory usage: 2048 K 11:31:54 [libsolv++] PoolImpl.cc(logSat):114 alias processing took 66379 ms 11:31:54 [libsolv++] PoolImpl.cc(logSat):114 raw candidates: 688248, pruning 11:31:55 [libsolv++] PoolImpl.cc(logSat):114 candidates now: 95267 . 11:33:51 [libsolv++] PoolImpl.cc(logSat):114 filespace size: 15430 K 11:33:51 [libsolv++] PoolImpl.cc(logSat):114 candidate check took 117017 ms 11:33:51 [libsolv++] PoolImpl.cc(logSat):114 found 0 file conflicts 11:33:51 [libsolv++] PoolImpl.cc(logSat):114 file conflict detection took 197407 ms 11:33:51 [zypp] TargetImpl.commitFindFileConflicts.cc(commitFindFileConflicts):160 Found 0 file conflicts.
@mls: Retrieving the RPM headers seems to take some time, but the last pass seems to be very slow. Any idea how to improve it? -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
H. Hansen
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c4
Michael Andres
# zypper in --debug-solver nopackage ... Generating solver test case... Solver test case generated successfully at /var/log/zypper.solverTestCase. Then pack the output directory together with /var/log/zypper.log and attach it to the bugreport.
In case the testcase exceeds the 10MB limit for bugzilla uploads, you can use 'split' to divide the file into smaller pieces:
$ cd /tmp $ tar cvjf zypper.solverTestCase.tar.bz2 /var/log/zypper.solverTestCase/ $ split -b 9M --additional-suffix=-zypper.solverTestCase.tar.bz2 \ zypper.solverTestCase.tar.bz2 The created pieces will be named like this: xaa-zypper.solverTestCase.tar.bz2 xab-zypper.solverTestCase.tar.bz2 xac-zypper.solverTestCase.tar.bz2 ...
-- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c8
Stefan Quandt
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c9
Michael Andres
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c10
Daniel Faust
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c11
--- Comment #11 from Daniel Faust
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c12
Stefan Brüns
http://bugzilla.opensuse.org/show_bug.cgi?id=953130 http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c13 Peter Sütterlin
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
Thomas Renninger
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c22
Michael Andres
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
- -
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
Vadim Krevs
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c29
--- Comment #29 from Vadim Krevs
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c30
--- Comment #30 from Vadim Krevs
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c31
Michael Hanscho
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c32
--- Comment #32 from Michael Andres
..I could provide a zypper debug logfile. Yes, maybe it reveals some detail that helps us to reproduce it.
-- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c33
--- Comment #33 from Michael Hanscho
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
Michiel Janssens
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
Andrei Borzenkov
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c34
Freek de Kruijf
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c35
--- Comment #35 from Michiel Janssens
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c36
--- Comment #36 from H. Hansen
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c37
Qi Fan
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c38
--- Comment #38 from Stefan Brüns
$ zypper se -s kernel-default-devel S | Name | Type | Version | Arch | Repository ---+----------------------+---------+-------------+--------+------------------ v | kernel-default-devel | package | 4.4.85-22.1 | x86_64 | update-oss (42.3) i+ | kernel-default-devel | package | 4.4.79-19.1 | x86_64 | update-oss (42.3) i+ | kernel-default-devel | package | 4.4.79-4.2 | x86_64 | update-oss (42.3) i+ | kernel-default-devel | package | 4.4.76-1.1 | x86_64 | repo-oss (42.3)
$ time zypper in kernel-default-devel-4.4.85-22.1 real 0m13.329s user 0m3.534s sys 0m1.048s
[zypper] main.cc(main):75 ===== '/Local/ma/zypp/BUILD/zypper/src/zypper' 'in' 'kernel-default-devel-4.4.85-22.1' ===== [libsolv++] PoolImpl.cc(logSat):119 file conflict detection took 328 ms
Similar on my other machines (Leap/TW). I don't experience these kind of delays. Something is missing...
What happens if you reinstall (zypper in --force ..) one of the already installed kernel-default-devel packages? -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c39
--- Comment #39 from Stefan Brüns
Will information from "valgrind --tool=callgrind" help if I run it next time I zypper dup?
It spends most of the time in rpm_iterate_filelist, as already said. rpm_iterate_filelist itself could be speed up by a factor of ~2 if it were better optimized (it does e.g. multiple mallocs per entry, where one would suffice), but this helps only a little. The big problem still is the O(n^2) behaviour (for each candidate, check each file in each package if it conflicts). -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c40
--- Comment #40 from Michael Andres
What happens if you reinstall (zypper in --force ..) one of the already installed kernel-default-devel packages?
The largest amount of time seems to be spent reading data from disk:
1.) real 0m41.645s 2.) real 0m5.820s sync; echo 3 > /proc/sys/vm/drop_caches 3.) real 0m53.244s 4.) real 0m6.750s
-- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c41
--- Comment #41 from Qi Fan
(In reply to Qi Fan from comment #37)
Will information from "valgrind --tool=callgrind" help if I run it next time I zypper dup?
It spends most of the time in rpm_iterate_filelist, as already said.
rpm_iterate_filelist itself could be speed up by a factor of ~2 if it were better optimized (it does e.g. multiple mallocs per entry, where one would suffice), but this helps only a little.
The big problem still is the O(n^2) behaviour (for each candidate, check each file in each package if it conflicts).
I think you are right. The comment like this: https://github.com/openSUSE/libsolv/blob/bef46d75f6d2537060114eea0f3a892e958... does seem to have assumed that n is pretty small. Some O(n) algorithm should be used instead. -- You are receiving this mail because: You are on the CC list for the bug.
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c48
Michael Andres
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c53
--- Comment #53 from Adam Spiers
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c54
--- Comment #54 from H. Hansen
http://bugzilla.opensuse.org/show_bug.cgi?id=953130
http://bugzilla.opensuse.org/show_bug.cgi?id=953130#c56
--- Comment #56 from Harald Koenig
(you need to test this on a normal HD (no ssd))
at least for my original issue that's not true, for me it was 100% cpu bound... -- You are receiving this mail because: You are on the CC list for the bug.
participants (1)
-
bugzilla_noreply@novell.com