Stage "searching for obsolete software" takes a very long time (30 minutes)

Bug #1874272 reported by Jean-Baptiste Lallement
106
This bug affects 22 people
Affects Status Importance Assigned to Milestone
ubuntu-release-upgrader (Ubuntu)
Status tracked in Noble
Focal
Triaged
High
Unassigned
Noble
Triaged
High
Unassigned

Bug Description

Test Case:
1. Fresh Bionic installation from 18.04.4 + all updates applied
2. Run: update-manager -d
3. Proceed with the upgrade.

Actual Result:
Everything goes well but the stage "Searching for obsolete software" takes a very long time.

ProblemType: Bug
DistroRelease: Ubuntu 20.04
Package: ubuntu-release-upgrader-core 1:20.04.18
ProcVersionSignature: Ubuntu 5.4.0-26.30-generic 5.4.30
Uname: Linux 5.4.0-26-generic x86_64
ApportVersion: 2.20.11-0ubuntu27
Architecture: amd64
CasperMD5CheckResult: skip
CrashDB: ubuntu
CurrentDesktop: ubuntu:GNOME
Date: Wed Apr 22 10:34:19 2020
InstallationDate: Installed on 2020-04-20 (2 days ago)
InstallationMedia: Ubuntu 18.04.4 LTS "Bionic Beaver" - Release amd64 (20200203.1)
PackageArchitecture: all
ProcEnviron:
 TERM=xterm-256color
 PATH=(custom, no user)
 XDG_RUNTIME_DIR=<set>
 LANG=en_US.UTF-8
 SHELL=/bin/bash
SourcePackage: ubuntu-release-upgrader
Symptom: ubuntu-release-upgrader
UpgradeStatus: Upgraded to focal on 2020-04-22 (0 days ago)
VarLogDistupgradeTermlog:

Revision history for this message
Jean-Baptiste Lallement (jibel) wrote :
Revision history for this message
Brian Murray (brian-murray) wrote :

I restored this apt-clone file to an Ubuntu 18.04 LTS system and then upgraded to Ubuntu 20.04 LTS. The search for obsolete software only took a minute.

bdmurray@clean-bionic-amd64:~$ grep "obsolete pkgs" /var/log/dist-upgrade/main.log
2020-04-22 14:04:41,576 DEBUG Start checking for obsolete pkgs
2020-04-22 14:05:27,656 DEBUG Finish checking for obsolete pkgs

It's not immediately clear to me what is going on. This other cache operation of yours also took a long time.

2020-04-22 09:17:49,110 INFO cache.commit()
2020-04-22 09:42:51,188 DEBUG cache.commit() returned None
2020-04-22 09:42:51,332 DEBUG openCache()
2020-04-22 09:42:54,210 DEBUG /openCache(), new cache size 65224

Revision history for this message
Brian Murray (brian-murray) wrote :

I also did a spot check of open bugs in Launchpad for Mainlog.txt files with an extremely long times between starting and finishing the check for obsolete packages and I found none. Although, maybe I should check closed bugs too.

Revision history for this message
Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in ubuntu-release-upgrader (Ubuntu):
status: New → Confirmed
Revision history for this message
Fabricio G. Scaglioni (fgscaglioni) wrote :

I was upgrading from version 18.04 to 20.04 when this bug has appeared.

2020-04-25 11:47:59,154 DEBUG Start checking for obsolete pkgs
2020-04-25 12:37:11,877 DEBUG Finish checking for obsolete pkgs

Revision history for this message
RarSa (rarsa) wrote :

I can confirm the problem. Including the delay in the cache.commit():

2020-04-26 13:05:59,023 INFO cache.commit()
2020-04-26 14:24:25,464 DEBUG cache.commit() returned None

For the obsolete packages
2020-04-26 14:32:27,989 DEBUG Start checking for obsolete pkgs
2020-04-26 14:53:12,608 DEBUG Finish checking for obsolete pkgs

Most of the packages report a "DEBUG package '<package name' produces an unwanted removal'gnome-software-plugin-snap', skipping

tags: added: rls-ff-incoming
Revision history for this message
piktogramm (piktogramm) wrote :

Sorry, I can't add much, but the process on my machine (2Core 4T Intel Haswell, 16GB Ram, Samsung 860Evo SSD) took over 6 hours. Update was from 19.10 to 20.04.

$ grep "obsolete pkgs" /var/log/dist-upgrade/main.log
2020-04-30 20:17:50,550 DEBUG Start checking for obsolete pkgs
2020-05-01 02:39:51,833 DEBUG Finish checking for obsolete pkgs

Changed in ubuntu-release-upgrader (Ubuntu):
importance: Undecided → High
Revision history for this message
Dimitri John Ledkov (xnox) wrote :

I wonder if something stray is holding locks or doing things, and thus we are waiting on locks to expire.

Do we like stop unatanded upgrades / apt-daily timer units when we start the ugprade? Cause they may have "cought" the lock between us finish update, and starting to check for obsolete pkgs.

I have managed to catch lock "half-way in between doing things" before.

Changed in ubuntu-release-upgrader (Ubuntu Focal):
status: New → Confirmed
importance: Undecided → High
tags: removed: rls-ff-incoming
tags: added: id-5eb44cb5b465575ffac8f476
Revision history for this message
Lincoln Phipps (lincoln-phipps) wrote :

I've got this right now and if I tail the /var/log/dist-upgrade/main.log I have...

DEBUG package 'foo' produces an unwanted removal 'libomp5-10', skipping
DEBUG 'foo' scheduled for removal but not safe to remove, skipping

Where 'foo' changes and takes solid core 100% 20 seconds cpu to move to next package. The libomp5-10 stays the same.

Upgrade is 19.10 to 20.04 using do-release-upgrade in a console.

Revision history for this message
Steve Langasek (vorlon) wrote :

Marking this incomplete since we don't have a reliable reproducer for it. If someone experiencing this problem can check for other processes holding a lock (Dimitri's question), that would be helpful.

Changed in ubuntu-release-upgrader (Ubuntu Focal):
status: Confirmed → Incomplete
Changed in ubuntu-release-upgrader (Ubuntu):
status: Confirmed → Incomplete
Revision history for this message
David Jung (djung) wrote :

Same occurrence here form GUI 'updater'. Not a clean install - I upgraded from 17 first, then 18 LTS -> 20.04. See the same pattern in /var/log/dist-upgrade/main.log as seen by @Lincoln above. Timestamps span ~20mins.

Revision history for this message
Jani Uusitalo (uusijani) wrote :

Currently experiencing this. `lsof /var/lib/dpkg/lock` shows only "focal" as holding the lock. The same "focal" process is also eating up all of the CPU. No dpkg or apt processes are listed by `ps` either.

Revision history for this message
John Rose (johnaaronrose) wrote :

Same problem. What would happen if I stopped the upgrade (e.g. by cutting power on my Intel Barebones PC)?

Revision history for this message
bsy (bennet-yee) wrote :

37 minutes so far. Top shows final using 100% of a core. Top -H shows only one thread. Main.log shows the skipping messages.

Revision history for this message
bsy (bennet-yee) wrote :

Upgrading a second system. 47 minutes of CPU time burned so far.

Revision history for this message
paul fox (pgf-launchpad) wrote :

I've upgraded 4 systems from 18.04 to 20.04, and only one has shown this behavior. Will attach an strace of the focal process. I ran the strace for approximately 30 seconds.

tags: added: rls-ff-incoming
Revision history for this message
Noam Mor (noam-mor) wrote :

Upgraded with do-release-upgrade, "searching for obsolete software" took about 50 minutes. Attaching upgrade log (partial, upgrade has not finished yet).

tags: added: fr-328
tags: removed: rls-ff-incoming
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for ubuntu-release-upgrader (Ubuntu Focal) because there has been no activity for 60 days.]

Changed in ubuntu-release-upgrader (Ubuntu Focal):
status: Incomplete → Expired
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for ubuntu-release-upgrader (Ubuntu) because there has been no activity for 60 days.]

Changed in ubuntu-release-upgrader (Ubuntu):
status: Incomplete → Expired
Changed in ubuntu-release-upgrader (Ubuntu):
status: Expired → Confirmed
Changed in ubuntu-release-upgrader (Ubuntu Focal):
status: Expired → Confirmed
Revision history for this message
Conrad Knight (iestynapmwg) wrote :

A google search brought me here... Was this ever solved? I'm currently having the same problem, upgrading from 20.10 to 21.04. "Searching for obsolete software" was displayed about an hour and a half ago, and the line below says " eading state information... 52%" (I assume there's a display bug in the output of that last line and there should be a leading 'R').

One cpu is pegged at 100%, running the upgrade process. /var/log/dist-upgrade/apt.log is full of lines like:

Starting pkgProblemResolver with broken count: 1
Starting 2 pkgProblemResolver with broken count: 1
Investigating (0) fonts-gujr:amd64 < 2:1.4 @ii K Ib >
Broken fonts-gujr:amd64 Depends on fonts-kalapi:amd64 < 1.0-4 @ii pR >
  Considering fonts-kalapi:amd64 10001 as a solution to fonts-gujr:amd64 0
  Removing fonts-gujr:amd64 rather than change fonts-kalapi:amd64
  MarkDelete fonts-gujr:amd64 < 2:1.4 @ii K Ib > FU=0
Done
  MarkDelete pmidi:amd64 < 1.7.1-1 @ii K > FU=1
  MarkDelete librsvg2-common:i386 < 2.50.3+dfsg-1 @ii K > FU=1
  MarkDelete fonts-navilu:amd64 < 1.2-3 @ii K > FU=1
Starting pkgProblemResolver with broken count: 1
Starting 2 pkgProblemResolver with broken count: 1
Investigating (0) fonts-knda:amd64 < 2:1.3 @ii K Ib >
Broken fonts-knda:amd64 Depends on fonts-navilu:amd64 < 1.2-3 @ii pR >
  Considering fonts-navilu:amd64 10001 as a solution to fonts-knda:amd64 0
  Removing fonts-knda:amd64 rather than change fonts-navilu:amd64
  MarkDelete fonts-knda:amd64 < 2:1.3 @ii K Ib > FU=0
Done

main.log is filling with:

2021-04-24 01:44:16,280 DEBUG package 'python3.9-examples' produces an unwanted removal 'libsnack-alsa', skipping
2021-04-24 01:44:52,824 DEBUG 'python3.9-examples' scheduled for remove but not safe to remove, skipping
2021-04-24 01:44:52,969 DEBUG package 'firebird3.0-common-doc' produces an unwanted removal 'libsnack-alsa', skipping
2021-04-24 01:45:28,698 DEBUG 'firebird3.0-common-doc' scheduled for remove but not safe to remove, skipping
2021-04-24 01:45:29,665 DEBUG package 'libvdpau1:i386' produces an unwanted removal 'libsnack-alsa', skipping
2021-04-24 01:46:05,161 DEBUG 'libvdpau1:i386' scheduled for remove but not safe to remove, skipping
2021-04-24 01:46:05,313 DEBUG package 'python3-sss' produces an unwanted removal 'libsnack-alsa', skipping
2021-04-24 01:46:43,381 DEBUG 'python3-sss' scheduled for remove but not safe to remove, skipping
2021-04-24 01:46:43,517 DEBUG package 'libvo-amrwbenc0:i386' produces an unwanted removal 'libsnack-alsa', skipping
2021-04-24 01:47:19,690 DEBUG 'libvo-amrwbenc0:i386' scheduled for remove but not safe to remove, skipping
2021-04-24 01:47:19,830 DEBUG package 'ruby-svn' produces an unwanted removal 'libsnack-alsa', skipping

Revision history for this message
Cruz Fernandez (cruz-fernandez) wrote :

Similar to what @iestynapmwg said, while upgrading from Ubuntu 20.10 to 21.04 experiencing this slowness on step "searching for obsolete software". Mine took 36 minutes (in my Dell XPS 15 9550 that's not so old).

2021-05-14 08:17:28,617 DEBUG Start checking for obsolete pkgs
2021-05-14 08:41:34,610 DEBUG Finish checking for obsolete pkgs

Main difference is that my main culprit seems always package 'libqt5gui5'

2021-05-14 08:37:08,688 DEBUG 'libparams-validationcompiler-perl' scheduled for remove but not safe to remove, skipping
2021-05-14 08:37:08,776 DEBUG package 'libqt5concurrent5' produces an unwanted removal 'libqt5gui5', skipping

and lsof command returned "hirsute"

sudo lsof /var/lib/dpkg/lock
lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1002/gvfs
      Output information may be incomplete.
lsof: WARNING: can't stat() fuse.portal file system /run/user/1002/doc
      Output information may be incomplete.
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
hirsute 15215 root 16uW REG 259,5 0 1966936 /var/lib/dpkg/lock

Revision history for this message
Gregory P Smith (gpshead) wrote :

Judging by the 100% cpu utilization and entries in /var/log/dist-upgrade/apt.log... as an outside observer black box guess: is this thing loading the parsing the entire package dependency graph repeatedly once per potential package?

88% complete after 30 minutes of CPU time...

Revision history for this message
Seán Ó Séaghdha (seanos) wrote :

Happened for me on 2 machines today upgrading 18.04 -> 20.04.

Revision history for this message
Shaya Potter (sjpotter) wrote :

I don't understand how there can be a comment that its not reproducible. I upgraded from 18.04->20.04 today and hit it and then upgraded to 21.04 and hit it again harder.

i have no idea what its trying to do to remove obsolete software, but perhaps it has to be rethought or even made into an option if it can't be done efficiently (I have 129 obsoleete packages installed at the moment, can probably prune it down, but i'd rather do it by hand then have it burn a cpu for an hour+)

Revision history for this message
Sukhamjot singh (sukhamjot2001) wrote :

This has not been resolved
Just upgraded from Ubuntu 18.04 to Ubuntu 20.04
The total installation took around 3 hours
Removing obsolete softwares took around 1 hour.

I am using dual boot Intel i5 9th-gen 8gb Ram.

Revision history for this message
Alan Porter (alan.porter) wrote :

Typing this from my phone while I wait for my laptop to upgrade from 21.04 to 21.10. I did not record the time, but I've been waiting long enough to search for the problem and end up here.

Revision history for this message
Ionut Andrei Oanca (andrei-oanca) wrote :

Facing this as well. Upgrade from 20.04 to 21.04 went OK (minor issue with `openmpi-bin`). Currently upgrading from 21.04 to 21.10 and have been waiting on "Searching for obsolete software" for almost an hour now (still at 64%).

i5-3570K, 24GB of RAM, one core always at 100% usage. `/var/log/dist-upgrade/apt.log` shows lots of `pkgProblemResolver` going on.

Revision history for this message
Johan Smolders (smojo1) wrote (last edit ):

Upgrading from 21.10 to 22.04 same issue. "Searching for obsolete software"

Burning 1 core for 100%

/var/log/dist-upgrade/apt.log is spammed with messages like

Starting pkgProblemResolver with broken count: 1
Starting 2 pkgProblemResolver with broken count: 1
Investigating (0) linux-modules-extra-5.13.0-39-generic:amd64 < 5.13.0-39.44 @ii K Ib >
Broken linux-modules-extra-5.13.0-39-generic:amd64 Depends on crda:amd64 < 4.14+git20191112.9856751-1build1 @ii pR >
  Considering crda:amd64 10001 as a solution to linux-modules-extra-5.13.0-39-generic:amd64 -2
Broken linux-modules-extra-5.13.0-39-generic:amd64 Depends on wireless-crda:amd64 < none @un H >
  Or group remove for linux-modules-extra-5.13.0-39-generic:amd64
  MarkDelete linux-modules-extra-5.13.0-39-generic:amd64 < 5.13.0-39.44 @ii K Ib > FU=0

/var/log/dist-upgrade/main.log is spammed with messages like

2022-04-18 22:25:31,314 DEBUG 'fonts-vlgothic' scheduled for remove but not safe to remove, skipping
2022-04-18 22:25:31,377 DEBUG package 'libnspr4:i386' produces an unwanted removal 'firefox-locale-en', skipping
2022-04-18 22:25:40,712 DEBUG 'libnspr4:i386' scheduled for remove but not safe to remove, skipping
2022-04-18 22:25:40,769 DEBUG package 'node-getpass' produces an unwanted removal 'firefox-locale-en', skipping
2022-04-18 22:25:50,094 DEBUG 'node-getpass' scheduled for remove but not safe to remove, skipping
2022-04-18 22:25:50,152 DEBUG package 'libvpx6:i386' produces an unwanted removal 'firefox-locale-en', skipping
2022-04-18 22:25:59,365 DEBUG 'libvpx6:i386' scheduled for remove but not safe to remove, skipping
2022-04-18 22:25:59,429 DEBUG package 'libmbedtls12' produces an unwanted removal 'firefox-locale-en', skipping
2022-04-18 22:26:08,726 DEBUG 'libmbedtls12' scheduled for remove but not safe to remove, skipping
2022-04-18 22:26:08,778 DEBUG package 'libpango-perl' produces an unwanted removal 'firefox-locale-en', skipping
2022-04-18 22:26:18,153 DEBUG 'libpango-perl' scheduled for remove but not safe to remove, skipping
2022-04-18 22:26:18,225 DEBUG package 'plasma-wallpapers-addons' produces an unwanted removal 'firefox-locale-en', skipping
2022-04-18 22:26:27,841 DEBUG 'plasma-wallpapers-addons' scheduled for remove but not safe to remove, skipping
2022-04-18 22:26:27,900 DEBUG package 'plasma-widgets-addons' produces an unwanted removal 'firefox-locale-en', skipping

I used the APT version of Firefox on 21.10, I read it's being replaced by the SNAP version? Might that have something to do with it?

tags: removed: fr-328
Revision history for this message
Davide Barasti (dbarasti) wrote (last edit ):

Upgrading from 22.04lts to 22.10 from a Thinkpad w/ AMD Ryzen™ 7 PRO 3700U

Hours in the Cleaning up phase (I 'd say after 4 hours the process is at 85%) with errors popping up every few seconds saying "Kinetic is not responding" -> Force quit or Wait.

Can I safely force quit the process? Is it going to damage the upgrade?

Really annoying situation

Revision history for this message
Fabien C (fabich) wrote :

Upgrading from 22.10 to 23.04 same issue:
 - "Searching for obsolete software" is at 83% after ~1 hour
 - Burning 1 core for 100%
 - A lot of logs in /var/log/dist-upgrade/main.log "XXX scheduled for remove but not safe to remove, skipping" or "package YYY produces an unwanted removal ZZZ, skipping"

tags: added: rls-nn-incoming
Revision history for this message
Julian Andres Klode (juliank) wrote :

So at the moment this loops over all packages that seem obsolete, and tries to remove them and then undoes that if it removes other packages, using one actiongroup per package. This is horrible.

What we should do is use the ProblemResolver's resolve_by_keep something like this

with an actiongroup:
   problemsolver = apt_pkg.ProblemResolver(depcache)
   for package in obsolete:
       depcache.mark_delete(package)
   for package in not_obsolete:
       depcache.mark_keep(package)
       problemsolver.protect(package)
   problemsolver.resolve_by_keep()

Caveat is that this may also affect any other actions currently queued, but I think at this point there aren't any others.

tags: added: foundations-todo
removed: rls-nn-incoming
Changed in ubuntu-release-upgrader (Ubuntu Focal):
status: Confirmed → Triaged
Changed in ubuntu-release-upgrader (Ubuntu Noble):
status: Confirmed → Triaged
milestone: none → ubuntu-24.04-beta
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.