Bug Description

Symptoms are that cache files in /var/cache/apparmor and profiles in /var/lib/apparmor/profiles are sometimes corrupted after a reboot. We've already fixed several bugs in the apparmor and click-apparmor and made both more robust in the face of corruption and we've reduced the impact when there is a corrupted profile, but we've still not found the cause of the corruption. This corruption can still affect real-world devices: if a profile in /var/lib/apparmor/profiles is corrupted and the cache file is out of date, then the profile won't compile and that app/scope won't start.

Workaround: remove the affected profile and then run 'sudo aa-clickhook'. This obviously is not viable on an end-user device.

The investigation is ongoing and this may not be a problem with the kernel at all, so this bug may be retargeted to another project.

The security team and the kernel team have discussed this a lot and Colin King is currently looking at this. This bug is just so it can be tracked. Here is an excerpt from my latest email to Colin:

"I believe I have conclusively ruled out apparmor_parser and aa-clickhook by creating a new 'home/bug/test-with-true.sh'. Here is the test output:

Specifically, home/bug/test-with-true.sh changes the interesting parts of the algorithm to:

1. wait for unity8 to start (this ensures the apparmor upstart job is finished)
2. restore apparmor_parser and aa-clickhook, if needed
3. if /home/bug/profiles... exists, perform a diff -Naur /home/bug/profiles...
/var/lib/apparmor/profiles and fail if differences (note, apparmor_parser
and aa-clickhook were /bin/true during boot so they could not have changed
/var/lib/apparmor/profiles)
4. verify the profiles, exit with error if they do not
5. alternately upgrade/downgrade the packages
6. verify the profiles, exit with error if they do not
7. copy the known good profiles in the previous step to /home/bug/profiles...
8. have apparmor_parser and aa-clickhook point to /bin/true
9. reboot
10. go to step 1

In the paste you'll notice that in step 6 the profiles were successfully created by the installation of the packages, then verified, then copied aside, then apparmor_parser and aa-clickhook diverted, then rebooted, only to have the profiles in /var/lib/apparmor/profiles be different than what was copied aside. It would be nice to verify on your device as well (I reproduced several times here) and verify the reproducer algorithm. I think this suggests this is a kernel issue and not userspace.

The corruption to /var/lib/apparmor/profiles/click_com.ubuntu.filemanager_filemanager_0.3.275 survives multiple reboots. I'll take another 6GB snapshot of the underlying partition and see if that's now corrupted.

After several reboots, the data still appears corrupted on the phone, but copying the underlying raw device /dev/mmcblk0p23 to my laptop and loop mounting it and then loop mounting ubuntu.img shows an uncorrupted var/lib/apparmor/profiles/click_com.ubuntu.filemanager_filemanager_0.3.275. I'm now going to test this on another device with a 3.4 kernel to see what I get.

1. copied raw data off the phone to may laptop
2. using sshfs, mounted the directory containing the raw data snapshot back on the phone
3. loop mounted it
4. loop mounted ubuntu.img from this
5. /ubuntu/var/lib/apparmor/profiles is sane, no corruption

I've searched the entire block device for the string /usr/share/click/preinstalled/com.ubuntu.music/1.3.625/apparmor.json and tagged it in such a way as it is obvious it that it has been modified on the flash drive. I rebooted and double checked - the modified data is still modified on disk however the corrupted file contains the original data.

So the underlying file system is sane. The in-memory view of the file seems borked.

After a lot of deep digging into the bind mount, loop driver, and buffer cache and tracking the corrupt pages back down the layers of the stack we've sanity checked this down to the image. The smoking gun was the kernel message:

I want to state that this is a very real problem and not theoretical. I've seen it many times, it is triggerable with enough reboots, and it has been seen on krillin by non-developers (ie, just through normal reboots and system-image updates). stgraber outlined the start of a fix here: http://paste.ubuntu.com/8851794/

IMO, we must solve #2 from Colin's comment #9 (perform an fsck using something like stgraber's approach) before the golden image. If we have that, we can solve #1 in OTA (though in an ideal world that would be fixed prior to golden image since we don't want people dropping into recovery mode if we can at all help it).

If you want a separate fsck command in ubuntu_command, please file a separate bug on upstream system-image project. Other than that, it doesn't look like this particular bug affects system-image client.

The partition I have had files corrupted on does have a e2fsck run on it before mounting, it's a LUKS encrypted partition and I added the e2fsck check after it became corrupted and I have also had files corrupted since.

I hadn't done anything to ensure that this partition was unmounted when the device is shutdown but I have now amended /etc/init.d/umountfs so it should be next time.

I've had this issue multiple times yet. For me it has always been like that: The content of a file gets overriden and therefore the system fails to do something.

Last time my system settings broke completely. When doing a "cat ~/.config/dconf/user" I got:
"/opt/click.ubuntu.com/com.ubuntu.developer.webapps.webapp-gmail/1.0.25"
And after a reboot it now shows this:
"/opt/click.ubuntu.com/com.ubuntu.developer.filip-dobrocky.2048native/0.2"

Deleting "~/.config/dconf/user" did the trick for me.

Some other time system updates didn't work and doing a "cat /cache/recovery/image-master.tar.xz.asc" revealed it contained the following content:
"/opt/click.ubuntu.com/com.ubuntu.developer.majster-pl.utorch/1.6"

your dconf issues are caused by illegal use of dconf by an app (apps should not be able to use dconf according to the security policy as i understand it, to avoid exactly this), please file a fresh bug for this.

Doing a short grep, I also found that line in a lot of files, e.g. in the following one: "~/.cache/upstart/logrotate.log"

The file started with "/opt/click.ubuntu.com/com.ubuntu.developer.filip-dobrocky.2048native/0.2", then continued with its normal content and in the middle of the file the following line could be found which clearly isn't there for logical reasons:
"error: b/opt/click.ubuntu.com/com.ubuntu.developer.dpniel.dekko/0.2.9error: bad top line in state file /home/phablet/.cache/logrotate/status" All other lines looked like this one: "error: bad top line in state file /home/phablet/.cache/logrotate/status"

Having seen that error message, I checked the file it mentioned. Guess what its content is:
"/opt/click.ubuntu.com/com.ubuntu.developer.dpniel.dekko/0.2.9"

There actually seem to be a lot of corrupt files like these ones and it's the second Ubuntu (Touch) installation which gives me those results.

However, if you still think, it's a different bug, I will be happy to hide all my comments here and file a new bug. ;)

As far as I know, there is no design spec for the startup process, and no designer assigned to it. In the meantime...

An automatic filesystem check being interactive makes less and less sense over time. (As the sheer number of files on a device increases, and the proportion of apps that are document-based decreases, you're less and less likely to recognize a file by its pathname.) And it makes *much* less sense on a phone, where you barely see the filesystem at all, so the probability that you can make an informed decision about fixing an individual file is pretty much zero.

So, in the "minimal fsck reveals an error" case, I suggest just triggering a fsck -y. Don't make it interactive. Ideally, add text something like "Repairing…" to the startup screen, or (during string freeze) vary the visual design of the startup screen in *some* tasteful way, to minimize the proportion of people who will think that the phone has got stuck while starting up and try to fix it by holding down the power button.

So this is not a normal fs corruption issue. I was able to run the aa-corruption test quite a few times with the extra e2fsck logic we added, and was easily able to get the corrupted files on krillin, but which is even more interesting is that the files are not actually corrupted for e2fsck (not pointing out a single fs error, even though the files are incorrect).

There's clearly a pattern with click paths under /opt/click.ubuntu.com inside the corrupted files. /opt/click.ubuntu.com is also bind-mounted, and it seems to be where it's mostly heavily used by the system.

So in the end it looks like with a quite bizarre error under rw filesystems (ext4) that are bind-mounted. After migrating /opt/click.ubuntu.com, /var/lib/apparmor and /var/cache/apparmor under '/' (not bind-mounted), I was able to run the same aa-corruption test case for a few without any issues (by default I can always get the issue after the first test iteration).

Will let it running for a few more iterations and report back, but one bad thing is that running e2fsck is really not going to help much here.

It works fine if I move the writable paths under /, and it also works fine after creating another image file (ext4) that gets stored under /userdata, to be consumed by the writable paths (using bind-mounts and everything).

But if I use bind mounts from /userdata/system-data directly, I can easily get it to break. The same setup works fine when using / instead (same bind-mounts and etc, but on a different dir path).

The only peculiarity with /userdata is that it's shared between both containers. Ubuntu uses /userdata/system-data, /userdata/SWAP.img and /userdata/user-data. Android uses /userdata/android-data.

after researching the adbd part for two days it seems that adbd already tries to call "echo u > /proc/sysrq-trigger" when adb reboot is issued but at this point we already dropped privs to the phablet user ...

/proc/sysrq-trigger is owned by root:system and writable for both, the only solution i see (beyond making /proc/sysrq-trigger owned by phablet or its group which would rip a giant security hole) is to make adbd start with "setguid system" and have it drop this group membership right before any adb shell call (so that the logged in phablet user is not member of system by default)

i'm trying to implement this but am constantly running into smaller issues.

And also on another spare device using rtm image,
device #3, 176 iterations, - no corruption observed

I can continue running these for another few days if need be, but I think it is fairly conclusive that the data=journal change prevents the apparmor metadata from ending up on the /var/lib/apparmor/profiles/* files.

I'm added copious amounts of debug into the kernel and a shim on umount too and I can't see /dev/mmcblk023 being unmounted anywhere. Can you inform me where to expect this umount is actioned on shutdown. I just can't see it.

With full journaling on I'd expect this to cope with a non-umount as it can replay the journaled data and metadata and so we don't get errors, however, with the data=ordered option I could expect to see metadata being perhaps sane where as the file data being not written back and hence we see old data and possibly the reason for this corruption.

So, I'd really like to have some idea where the umount actually occurs.

1. I believe the file system is not being cleanly umounted.
2. data=journal saved us from disaster because it works so well.

My recommendation is to keep data=journal because a user can power off the device (battery death, pulling out battery, random kernel reboot, etc) and data=journal has conclusively shown it the only RELIABLE way to ensure data and metadata are sane.

I really would like to warn against fixing this bug by doing the umount and changing back to the faster but definitely less rugged data=ordered option. I think that would really be too risky IMHO.

after running with the change for one week on my krillin i must say that i dont really see any performance impact or any other bad behavior from the change ...

it would be nice to have some upstart job that at least does an emergecy readonly mount on shutdown/reboot like we plan for adbd "adb reboot" by echoing "u" into /proc/sysrq-trigger ... that way we would at least be sure we do not unmount dirty and calling this command takes close to no time.

I don't thing we're seeing many writes to that partition, most of it's probably data pages being flushed out in the background so it's not going to bite too hard. We do have tools to figure out how much is being written if it needs some analysis.

On Fri, Nov 28, 2014 at 3:29 PM, Oliver Grawert <email address hidden> wrote:
> it would be nice to have some upstart job that at least does an emergecy
> readonly mount on shutdown/reboot like we plan for adbd "adb reboot" by
> echoing "u" into /proc/sysrq-trigger ... that way we would at least be
> sure we do not unmount dirty and calling this command takes close to no
> time.

We could cover most of the possible causes for not unmounting it
properly, just wonder if we should still take the risk of moving back
to data=ordered.

Some use cases:
* Hard reboot (power + volume up): the userspace can probably be
notified by that, forcing the ro remount
* Adb: doing the emergency readonly mount as suggested by oliver
* $ sudo reboot: just making sure the halt process indeed umount the
partition successfully
* Low battery: forcing shutdown if batter lower than 3% (?)
* Kernel panic: can we force kernel to flush things into the disk when
we get a crash? This is important as well as it seems we can easily
make the kernel to crash still (specially when using bluetooth).

i think the "sudo reboot" and "low battery" case are the same, both should use init's shutdown/reboot commands ...

i dont think a kernel panic is a "normal usecase", if we ship panicking devices i think we failed ... developers should simply be aware that panics can cause corruption, this is no different to desktop development

> i dont think a kernel panic is a "normal usecase", if we ship panicking
> devices i think we failed ... developers should simply be aware that
> panics can cause corruption, this is no different to desktop development

Well, it might not necessarily be a "normal" usecase, but we should
expect that to happen. It's better to better handle the crash than
expecting it to no crash at all, as we can't guarantee that with this
kernel.

And we should be thinking about normal users instead of developers :-)

I think also we need to consider security of data is the ultimate goal. Quite frankly, unpredictable things happen users can do all kinds of things like yank out the battery and trip kernel panics. Nobody has formally verified that the kernel is perfect so there is always the possibility of the device spontaneously rebooting or dieing before data is written back.

adbd can still not remount the filesystem readonly on "adb reboot" due to the fact that we drop all privileges writing to /proc/sysrq-trigger isnt possible and i havent found a way around this yet ... (this is a corner case and potential fs corruption should be handled by the fsck on next boot anyway, but it would be nice if adbd could work as expected here, which is why the task is still open)

This is a 6.5K zlib compressed data file, when I moved it out of the way and tried to do a `git commit -a` I was prompted to add things to the repo that were already there, at this point I gave up and checked out a fresh working copy of the repo.

It is of course possible that this corruption was caused by something like a `git pull` failing half way though due to a network connection issue, but I don't remember this happening.