Software Center Memory/Processor bug

[Dave Morley]

Bug Description:
Software Centers memory usage increases the more applications you install, to monitor this effect I am going to do a single For Purchase install and the an run with 7 For Purchase apps and attach the logs to this bug.

Then a single repo app and then several repo apps.

OS:
64bit Precise

USC Version:
5.2.1

Steps To Reproduce:
1. Open USC install an app.
2. Click on All software once app 1 has installed
3. Install another app
4. Click on All Software once app 2 has installed
5. install another app and so on
6. monitor the memory used at each point ( I used ldtp's startlog('path/to/log.file') startprocessmonitor('software-center') then when finished stopprocessmonitor('software-center') stoplog()

Expected Results:
I expect the memory usage to not increase more than a set amount per app install.

ProblemType: Bug
DistroRelease: Ubuntu 12.04
Package: software-center 5.2.1
ProcVersionSignature: Ubuntu 3.2.0-24.38-generic 3.2.16
Uname: Linux 3.2.0-24-generic x86_64
NonfreeKernelModules: fglrx
ApportVersion: 2.0.1-0ubuntu7
Architecture: amd64
Date: Wed May 23 15:32:24 2012
InstallationMedia: Ubuntu 12.04 LTS "Precise Pangolin" - Release amd64 (20120425)
PackageArchitecture: all
ProcEnviron:
 LANGUAGE=en_GB:en
 TERM=xterm
 PATH=(custom, no user)
 LANG=en_GB.UTF-8
 SHELL=/bin/bash
SourcePackage: software-center
UpgradeStatus: No upgrade log present (probably fresh install)

[Michael Vogt (mvo)]

Install/remove result from htop for the installs:
* 151mb (initial)
* 182mb (powertop)
* 235 (2vcard)
* 250 (4g8)
* 290 (2vcard)

It seems like it matters that they are different.

[Michael Vogt (mvo)]

Looking at the pmap out it looks like it the heap growing quite a bit. Probably releated to cache/db reopen.

However python-apt itself seems to be fine, the following:
from gi.repository import GObject

class GtkMainIterationProgress(apt.progress.base.OpProgress):
    """Progress that just runs the main loop"""
    def update(self, percent=0):
        context = GObject.main_context_default()
        while context.pending():
            context.iteration()

cache=apt.Cache()
while True:
 cache.open(GtkMainIterationProgress()

shows stable memory behavior. The following fragment:
import sys
sys.path.insert(0, "/usr/share/software-center")

from softwarecenter.db.pkginfo import get_pkg_info
from softwarecenter.db.database import StoreDatabase

cache = get_pkg_info()
cache.open()
db = StoreDatabase(cache=cache)
db.open()
while True:
    db.reopen()

does so too. So we need some further digging, its more than just the cache/db reopen on install/remove.

[Michael Vogt (mvo)]

Anthony pointed me to "python-objgraph": http://mg.pov.lt/objgraph/ that is also available as a package to do
analysis of what is leaking memory.

[Michael Vogt (mvo)]

Patch that triggers the leak every 1s without the need to actually install/remove

[Michael Vogt (mvo)]

Looking further it appears that the get_addons() call in aptcache.py is mostly responsible.
Removing it:
=== modified file 'softwarecenter/db/pkginfo_impl/aptcache.py'
--- softwarecenter/db/pkginfo_impl/aptcache.py 2012-04-18 08:44:00 +0000
+++ softwarecenter/db/pkginfo_impl/aptcache.py 2012-05-31 12:57:32 +0000
@@ -665,6 +665,7 @@
             :return: a tuple of pkgnames (recommends, suggests)
         """
         logging.debug("get_addons for '%s'" % pkgname)
+ return

         def _addons_filter(addon):
             """ helper for get_addons that filters out unneeded ones """

and that "fixes" the memleak.

[Michael Vogt (mvo)]

Going deeper into this rabithole it appears its actually:
def _on_app_recommendations_agent_refresh(self, cat):
        docs = cat.get_documents(self.catview.db)
        # display the recommendations
        if len(docs) > 0:
            self.catview._add_tiles_to_flowgrid(docs,
                                        self.app_recommendations_content, 3)
            self.show_all()
            self.spinner_notebook.hide_spinner()
        else:
            self._hide_app_recommendations_panel()

that is causing the pain, to be specific the _add_tiles_to_flowgrid(). This code is triggered by "update_all()" which is in turn triggered by refresh_app()

[Michael Vogt (mvo)]

And looking even further its the FeaturedTile() creation that is the problem, for some reason in combination
with the db/cache refresh. It looks like somehow it keeps old references preventing the cache to get
properly deleted. Its unclear yet how this happens as the code looks relatively innocent.

[Michael Vogt (mvo)]

With those lines commented out the memleak is more or less gone. Obviously that is not a fix,
but its hopefulyl enough to disconnect the signals in destory() and figure out what the issue
with the details is.

[Michael Vogt (mvo)]

I attached lp:~mvo/software-center/memleak-fixes-lp1003466 that is worth testing, that kills off most of the growth for me in my (artificial) testing. Dave, when you do install testing next, would be nice to give this branch a try :)

[Michael Vogt (mvo)]

No, not there yet I think

[Michael Vogt (mvo)]

The more I look into this the more I get the impression the normal python tools are not helping,
neither objgraph nor meliae give good hints.

Meliae is really awsome, and yet:
>>> om_startup.summarize()
Total 423202 objects, 394 types, Total size = 41.9MiB (43896060 bytes)

>>> om_after_three_installs.summarize()
Total 424451 objects, 414 types, Total size = 42.0MiB (44088191 bytes)

Witht the object counts in the details looking about the same. This indicates it might be a issue
in the C code either pygi, xapian or python-apt.

[Michael Vogt (mvo)]

I have some code to trace that now in lp:~mvo/software-center/inspect-memleak:

Usually when I run it it looks roughly like this:
$ PYTHONPATH=. python tests/gtk3/test_memleak.py 2>/dev/null
inspecting SoftwareCenterAppGtk3._on_transaction_finished()
nr_objs: 58141 size: 125.5M res: 360.7M (32125 92337)
nr_objs: 58130 size: 134.6M res: 368.7M (34461 94395)

inspecting AppdetailsView.show_app()
nr_objs: 68067 size: 158.1M res: 1.5G (40470 398694)
nr_objs: 70589 size: 158.4M res: 1.5G (40538 399085)

inspecting LobbyView.on_db_reopen()
nr_objs: 74882 size: 204.6M res: 1.5G (52387 403115)
nr_objs: 76934 size: 208.5M res: 1.5G (53371 404030)

Inspecting PackageInfo.open()
nr_objs: 76897 size: 248.8M res: 1.5G (63685 405016)
nr_objs: 76932 size: 257.0M res: 1.6G (65794 407125)

inspecting purchaseview
nr_objs: 77873 size: 258.1M res: 1.6G (66077 409175)
nr_objs: 77873 size: 258.1M res: 1.6G (66078 409175)

inspecting SubcategoryViewGtk.set_subcategory()
nr_objs: 80540 size: 281.5M res: 1.9G (72072 501911)
nr_objs: 84246 size: 283.7M res: 1.9G (72632 502086)

But sometimes I see:
$ PYTHONPATH=. python tests/gtk3/test_memleak.py 2>/dev/null
...
Inspecting PackageInfo.open()
nr_objs: 75790 size: 247.5M res: 1.5G (63363 404718)
nr_objs: 76068 size: 296.3M res: 1.6G (75847 408977)
...

when all the other values look normal. So that seems to be a candidate for closer inspection.

[Michael Vogt (mvo)]

A (maybe) useful script:
http://code.activestate.com/recipes/546530/

[Michael Vogt (mvo)]

I found one source:
$ PYTHONPATH=. python tests/gtk3/test_memleak.py RealMemleakTestCase
inspecting AppdetailsView.show_app()
nr_objs: 67491 size: 148.3M res: 1.4G (37963 378064)
2012-09-06 15:23:38,187 - softwarecenter.db.pkginfo_impl.aptcache - INFO - aptcache.open()
2012-09-06 15:23:40,934 - softwarecenter.db.pkginfo_impl.aptcache - INFO - aptcache.open()
2012-09-06 15:23:43,807 - softwarecenter.db.pkginfo_impl.aptcache - INFO - aptcache.open()
2012-09-06 15:23:46,604 - softwarecenter.db.pkginfo_impl.aptcache - INFO - aptcache.open()
2012-09-06 15:23:49,256 - softwarecenter.db.pkginfo_impl.aptcache - INFO - aptcache.open()
nr_objs: 70061 size: 354.7M res: 1.5G (90804 386741)

That looks a bit over the top to me ;)

[Michael Vogt (mvo)]

Similar to the observation in #11 (https://bugs.launchpad.net/ubuntu/+source/software-center/+bug/1003466/comments/11) it seems that
  a) its important that there are some "recomendations for you" in the details page (e.g. for "2vcard" the code shows very little growth)
  b) that _add_tiles_to_flowgrid() is called

That strongly indicates that the TileButtons are leaking

[Michael Vogt (mvo)]

Just found a second source of a leak, I think the big ones are now under control, at least in the testcases I created so far.

[Dave Morley (davmor2)]

Confirmed the current fix greatly reduces the leak it is however still there partially :) It knocks about 200 meg off the size.

[Launchpad Janitor (janitor)]

This bug was fixed in the package software-center - 5.3.12

---------------
software-center (5.3.12) quantal; urgency=low

  [ Michael Vogt ]
  * lp:~mvo/software-center/inspect-memleak:
    - fix two memory leaks when the cache is re-opened after
      a package has been installed/removed (LP: #1003466), add
      memory usage test/monitoring utilities and a set of new
      unit tests
  * lp:~mvo/software-center/lp1047281:
    - fix crashing bug due to a unicode decode error and add
      a regression unit test (LP: #1047281)
  * lp:~mvo/software-center/region-whitelist-lp1006570:
    - fix missing region whitelist support that is used by
      the software-center-agent (LP: #1006570)
  * debian/test/run-tests:
    - unset TMPDIR and do not run with sh -x, thanks to Martin Pitt
    - fix when run from the binary Package, thanks to
      Jean-Baptiste Lallement

  [ Gary Lasker ]
  * lp:~gary-lasker/software-center/recommender-test-fix:
    - update the recommender feedback unit test to work on systems
      that are not opted-in
 -- Michael Vogt <email address hidden> Tue, 11 Sep 2012 14:37:43 +0200

[Chris Halse Rogers (raof)]

I've rejected the software-center SRU from the precise-proposed queue, as bug #1006570 and bug #1042279 have been waiting for test cases and regression potential for over a month now.

Once these bugs have the necessary information for an SRU, please ping me or another an SRU team member in #ubuntu-release and we can fish it out of the rejected queue.

[Chris Halse Rogers (raof)]

Hello Dave, or anyone else affected,

Accepted software-center into precise-proposed. The package will build now and be available at http://launchpad.net/ubuntu/+source/software-center/5.2.7 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Timo Jyrinki (timo-jyrinki)]

Memory usage seems to increase a lot less with the -proposed version (htop RES):

162M (initial)
205M (after first install)
209M (2nd)
215M (3rd)
216M (4th)

[Dave Morley (davmor2)]

Sorry for the delay:

Yeap I'm getting similar readings:

In [6]: myutils.statinfo('software-center')
Application software-center is not running

In [7]: myutils.statinfo('software-center')
Application Name: software-center
Cpu Percentage: 46.2948
Memory size: 169.0

In [8]: myutils.statinfo('software-center')
Application Name: software-center
Cpu Percentage: 25.8111
Memory size: 178.0

In [9]: myutils.statinfo('software-center')
Application Name: software-center
Cpu Percentage: 21.7108
Memory size: 178.0

In [10]: myutils.statinfo('software-center')
Application Name: software-center
Cpu Percentage: 21.0512
Memory size: 187.0

In [11]: myutils.statinfo('software-center')
Application Name: software-center
Cpu Percentage: 23.2957
Memory size: 223.0

[Brian Murray (brian-murray)]

The verification of this Stable Release Update has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regresssions.

[Launchpad Janitor (janitor)]

This bug was fixed in the package software-center - 5.2.7

---------------
software-center (5.2.7) precise-proposed; urgency=low

  * lp:~mvo/software-center/oem-descriptor-in-user-agent-5.2:
    - include the oem-channel descriptor in the custom user agent
      string (LP: #1042749)
  * lp:~mvo/software-center/auto-fill-email-for-login:
    - allow auto-fill of the email in login.ubuntu.com if
      we have it (LP: #1042279)
  * lp:~mvo/software-center/fix-memleak-5.2:
    - fix two memory leaks when the cache is re-opened after
      a package has been installed/removed (LP: #1003466)
  * lp:~mvo/software-center/region-whitelist-5.2:
    - fix missing region whitelist support that is used by
      the software-center-agent (LP: #1006570)
  * lp:~mvo/software-center/downloader-fix-race839462-again-5.2:
    - fix a race condition in the SimpleFileDownloader when the file
      is downloaded but the signal did not get delivered yet by the
      gtk event loop (LP: #1055441)
 -- Michael Vogt <email address hidden> Wed, 26 Sep 2012 09:39:43 +0200