apport-retrace has become slower

Bug #1370230 reported by Brian Murray
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Apport
Fix Released
High
Brian Murray

Bug Description

The time it takes to retrace a crash has increased somewhat, on the Ubuntu Error Tracker, with the rollout of apport version 2854.
See https://errors.ubuntu.com/api/1.0/retracers-average-processing-time/?limit=32767&format=json for data, particularly before and after 9/4/2014 when the retracers switched to revision 2854 of apport.

I've tracked this down to the change in r2849 (https://bazaar.launchpad.net/~apport-hackers/apport/trunk/revision/2849) of apport. It used to be that all libraries were considered up to date if the file for them existed in the sandbox, but now version tracking is used. However, because that is used we now have to call apport.packaging.get_file_package() for every shared library, which the function indicates is very expensive.

Perhaps we could include the library file in packages.txt along with the package name and version, thereby reducing the number of times we need to call get_file_package.

Additionally, I realized we are now (as of r2758) checking three more Contents.gz files (-updates, -security, -proposed) in apport.packaging._search_contents() which probably also had a negative impact on the time to retrace. Its hard to confirm this though since we switched cassandra databases and average processing time data is not available for January of 2014.

Related branches

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

I also did some manual testing of apport-retrace with the _usr_bin_gnome-calculator.2001.crash from the apport-test-crashes. All times are in minutes : seconds.

Using apport version 2830 with no cache the retrace took approximately 2:32.
Using apport version 2830 with a cache the retrace took 0:18.
Using apport version 2854 with no cache the retrace took approximately 2:21.
Using apport version 2854 with a cache the retrace took 1:18.

Revision history for this message
Martin Pitt (pitti) wrote :

Indeed, that was quite expected. Before this, in a well-filled sandbox it hardly installed anything at all due to the "does not track versions" issue that you reported. So merely by having to download and install a lot more packages we'll get longer execution times.

> Using apport version 2830 with no cache the retrace took approximately 2:32.

Is that actually --cache (i. e. the place to cache downloaded debs and package indexes) or --sandbox-dir? Measuring without --cache isn't very useful as a starting point for optimization as the time for downloading the .debs probably varies a lot. But measuring with/without an existing --sandbox-dir would be interesting: I. e. how much slower did the current code get for the same report, filled cache (to eliminate download times), and empty sandbox.

> However, because that is used we now have to call apport.packaging.get_file_package() for every shared library, which the function indicates is very expensive.

Indeed. The first time you call it it has to download Contents.gz which is quite large; it also gets refreshed after a day. Subsequent calls will use the locally cached version. However, that function still uses zgrep, which is quite slow for multiple lookups. I think this is a good first point to optimize: Instead of storing the raw Contents.gz, we could build a path → package Python dict and cache that instead (in RAM during one retrace, and pickling it to the cache dir for subsequent invocations), and then we can use the mtime of the pickled file as an indication when to refresh it.

Changed in apport:
importance: Undecided → Low
status: New → Triaged
Revision history for this message
Brian Murray (brian-murray) wrote :

To be clear, this is the command I used to perform the retracing.

sudo PYTHONPATH=$PYTHONPATH:/srv/daisy.staging.ubuntu.com/production/apport python /srv/daisy.staging.u
buntu.com/production/apport/bin/apport-retrace ~/_usr_bin_gnome-calculator.2001.crash -S /srv/daisy.staging.ubuntu.com/production/daisy/ret
racer/config --sandbox-dir /srv/daisy.staging.ubuntu.com/production/cache/Ubuntu\ 14.04/cache-m34lGD/ -C /srv/daisy.staging.ubuntu.com/product
ion/cache/Ubuntu\ 14.04/cache-m34lGD/ -v -o ~/_usr_bin_gnome-calculator.2001.crash; date

Additionally, after updating apport I did an rm -fr of /srv/daisy.staging.ubuntu.com/production/cache/Ubuntu\ 14.04/cache-m34lGD/.

Martin Pitt (pitti)
Changed in apport:
assignee: nobody → Martin Pitt (pitti)
Martin Pitt (pitti)
Changed in apport:
importance: Low → High
Revision history for this message
Brian Murray (brian-murray) wrote :

Could you look at this after the release of Wily?

Martin Pitt (pitti)
Changed in apport:
assignee: Martin Pitt (pitti) → nobody
tags: added: id-5bb4eb47f4ddb750d2814d2a
Changed in apport:
status: Triaged → In Progress
assignee: nobody → Brian Murray (brian-murray)
Changed in apport:
status: In Progress → Fix Released
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.