Boot speed is significantly affected by installing apps

Bug #1227604 reported by Alan Pope 🍺🐧🐱 πŸ¦„
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
click (Ubuntu)
Fix Released
High
Colin Watson
lxc-android-config (Ubuntu)
Fix Released
High
Jamie Strandboge

Bug Description

Install a bunch of apps.
Reboot phone
Notice a significant lengthening of the boot process.

My nexus 4 takes 4 minutes to get to a Unity welcome screen.

If I adb shell in I can see a bunch of apparmor_parser processes running and a load average of 6.

ProblemType: Bug
DistroRelease: Ubuntu 13.10
Package: apparmor 2.8.0-0ubuntu28
ProcVersionSignature: Error: [Errno 2] No such file or directory: '/proc/version_signature'
Uname: Linux 3.4.0-3-mako armv7l
ApportVersion: 2.12.2-0ubuntu1
Architecture: armhf
Date: Thu Sep 19 11:48:59 2013
InstallationDate: Installed on 2013-09-18 (0 days ago)
InstallationMedia: Ubuntu Saucy Salamander (development branch) - armhf (20130918.1)
MarkForUpload: True
ProcEnviron:
 TERM=linux
 PATH=(custom, no user)
ProcKernelCmdline: console=ttyHSL0,115200,n8 androidboot.hardware=mako lpj=67677 uart_console=enable lcd_maker_id=primary lge.hreset=off lge.reset=mode_reset gpt=enable lge.kcal=0|0|0|x lge.rev=rev_11 mdm_force_dump_enabled androidboot.emmc=true androidboot.serialno=0071ae7610994b1d androidboot.bootloader=MAKOZ10o androidboot.baseband=mdm bootreason=reboot
SourcePackage: apparmor
UpgradeStatus: No upgrade log present (probably fresh install)

Related branches

Revision history for this message
Alan Pope 🍺🐧🐱 πŸ¦„ (popey) wrote :
tags: added: avengers
Revision history for this message
John Johansen (jjohansen) wrote :

This looks like a policy recompile happening on boot. Which means the policy cache is out of date.

Does this happen if you reboot. On a reboot the policy cache should be up to date, so that the apparmor_parser won't be compiling policy.

Revision history for this message
Jamie Strandboge (jdstrand) wrote :

This is related to click running system hooks on every boot. I'm poking at it now.

Changed in apparmor (Ubuntu):
assignee: nobody → Jamie Strandboge (jdstrand)
importance: Undecided → Critical
status: New → In Progress
Revision history for this message
Jamie Strandboge (jdstrand) wrote :

Actually, that is (partially) wrong. click-apparmor is not regenerating the profile (and therefore updating the timestamp) for the files in /var/lib/apparmor/profiles, which is good. But based on IRC feedback, there are two problems when using the following command:
$ echo "= clicks =" && sudo stat /var/lib/apparmor/clicks/* | egrep '(File|Modify):' ; echo "= profiles =" && sudo stat /var/lib/apparmor/profiles/* | egrep '(File|Modify):' ; echo "= cache =" && stat /var/cache/apparmor/* | egrep '(File|Modify):' ; echo "= system cache =" && stat /etc/apparmor.d/cache/* | egrep '(File|Modify):'
...
= cache =
stat: cannot stat '/var/cache/apparmor/*': No such file or directory
= system cache =
stat: cannot stat '/etc/apparmor.d/cache/*': No such file or directory

Revision history for this message
Jamie Strandboge (jdstrand) wrote :

/etc/apparmor.d/cache is fixable by adjusting lxc-android-config to make /etc/apparmor.d/cache writable.

On IRC, confirmed that /var/cache/apparmor/ is writable. On my system, cache is getting written out there so this shouldn't be a problem with apparmor_parser or with click-apparmor not using apparmor_parser correctly. I haven't been able to reproduce this yet on my device, so I believe there may be a race of some sort between the click upstart job and the lxc rw mounts.

Revision history for this message
Jamie Strandboge (jdstrand) wrote :

I still can't reproduce this. There is definitely a bug in lxc-android-config for /etc/apparmor.d/cache being read only, but on up to date mako and grouper using system-image-cli -vv, files are being created in /var/cache/apparmor. I will be rephlashing anew on grouper to test.

I might also mention that on these system click itself takes up a lot of time during boot, but there are no apparmor_parser processes, so even if this gets fixed for apparmor, there is likely more to be done.

Changed in apparmor (Ubuntu):
status: In Progress → Incomplete
Revision history for this message
Jamie Strandboge (jdstrand) wrote :

Can you reflash to the latest image and report back if you see the problem still?

Changed in lxc-android-config (Ubuntu):
importance: Undecided → High
status: New → Triaged
Changed in apparmor (Ubuntu):
importance: Critical → High
Revision history for this message
Jamie Strandboge (jdstrand) wrote :

Also, can you give the list of packages that you have installed on this device?

Revision history for this message
Jamie Strandboge (jdstrand) wrote :

Sorry, I meant the list of click packages.

Revision history for this message
Colin Watson (cjwatson) wrote :

I think this is mostly click's fault. It's rerunning hooks entirely unnecessarily.

Changed in click (Ubuntu):
assignee: nobody → Colin Watson (cjwatson)
importance: Undecided → High
status: New → In Progress
status: In Progress → Fix Committed
Revision history for this message
Jamie Strandboge (jdstrand) wrote :

Btw, I reflashed grouper anew and still couldn't reproduce the apparmor_parser bits. I'll fix the lxc-android-config bit and between that and click, this will hopefully all be better.

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

This bug was fixed in the package click - 0.4.7

---------------
click (0.4.7) saucy; urgency=low

  * Run system hooks when removing a package from the file system
    (LP: #1227681).
  * If a hook symlink is already correct, don't unnecessarily remove and
    recreate it.
  * Improve "click hook install-system" and "click hook install-user" to
    remove any stale symlinks they find, and to run Exec commands only once
    per hook. This significantly speeds up system and session startup when
    lots of applications are installed (LP: #1227604).
  * Rename "click hook install-system" and "click hook install-user" to
    "click hook run-system" and "click hook run-user" respectively, to
    better fit their semantics. (I expect these commands only to have been
    used internally by click's own Upstart jobs.)
  * Filter version control metadata and editor backup files out of binary
    packages in "click build" (LP: #1223640).
 -- Colin Watson <email address hidden> Fri, 20 Sep 2013 18:07:13 +0100

Changed in click (Ubuntu):
status: Fix Committed → Fix Released
Revision history for this message
Jamie Strandboge (jdstrand) wrote :

I'm going to remove the apparmor task for now. If boot is slow and cache files are not being updated on an image that has click 0.4.7 and lxc-android-config 0.100, please file a new bug with steps on how to reproduce. Thanks!

Changed in lxc-android-config (Ubuntu):
assignee: nobody → Jamie Strandboge (jdstrand)
status: Triaged → Fix Committed
no longer affects: apparmor (Ubuntu)
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package lxc-android-config - 0.100

---------------
lxc-android-config (0.100) saucy; urgency=low

  * add /etc/apparmor.d/cache as writable path so we don't have to regenerate
    system policy on every boot (LP: #1227604)
 -- Jamie Strandboge <email address hidden> Fri, 20 Sep 2013 12:18:06 -0500

Changed in lxc-android-config (Ubuntu):
status: Fix Committed → 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.