Track down and file OpenAFS/apparmor bugs

[jdreed]

Users without some .config entries are encountered telepathy/mission-control apport failures shortly after the first login. AFS also briefly claims it loses contact with the file server, and operations in AFS fail with ETIMEDOUT. But then it comes right back. AppArmor? does whine about telepathy trying to access files in /var/cache/openafs, as well as the root filesystem itself (presumably because something, somewhere, drops privs and changes its cwd to /). Disabling apparmor (booting with apparmor=0) fixes this, but we should figure out exactly what's breaking and why. Anders suggested possibly adding /var/cache/openafs/** to abstractions/base. However, it may be a bit more complicated than that, because something is convincing AFS that it briefly can't talk to the fileserver. (I do not believe it be an actual network issue, because that is extremely unlikely to occur on multiple machines at the time of login, and not at any other times).

[andersk]

Replying to jdreed:

Anders suggested possibly adding /var/cache/openafs/** to abstractions/base.

To be clear, I suggested that as a way to treat the symptom, not the disease. OpenAFS is supposed to be using  separate credentials to access /var/cache/openafs, so it shouldn’t be affected by the AppArmor restrictions of the current process. But there may be an  unknown problem with that patch.

[jdreed]

I re-opened this same issue as #1508 (now closed as a dupe of this bug), but that has a bit more info about the relevant syslogs. I think what I'd like to see is OpenAFS complain loudly to syslog when it has to fall back to the process credentials, so that at least it appears in the log and we can differentiate real network failures from apparmor/selinux stupidity.

I'll note that apparmor-config 1.2.9 gives up and implements the workaround that was suggested a year ago.

I haven't seen the telepathy failures recently, so I can't further debug what is failing with a cwd of /.

[andersk]

We need write access too, so,  https://github.com/mit-athena/apparmor-config/pull/5.

[andersk]

Argh, even that didn’t solve the whole problem.

[161167.208419] type=1400 audit(1518739024.749:62): apparmor="DENIED" operation="file_perm" info="Failed name lookup - disconnected path" error=-13 profile="/usr/bin/evince" name="" pid=756 comm="evince" requested_mask="w" denied_mask="w" fsuid=111264 ouid=0
[161167.224623] type=1400 audit(1518739024.765:63): apparmor="DENIED" operation="file_perm" info="Failed name lookup - disconnected path" error=-13 profile="/usr/bin/evince" name="" pid=756 comm="evince" requested_mask="r" denied_mask="r" fsuid=111264 ouid=0
[161167.224714] type=1400 audit(1518739024.765:64): apparmor="DENIED" operation="file_perm" info="Failed name lookup - disconnected path" error=-13 profile="/usr/bin/evince" name="" pid=756 comm="evince" requested_mask="r" denied_mask="r" fsuid=111264 ouid=0
[161167.228629] type=1400 audit(1518739024.769:65): apparmor="DENIED" operation="file_perm" info="Failed name lookup - disconnected path" error=-13 profile="/usr/bin/evince" name="" pid=756 comm="evince" requested_mask="r" denied_mask="r" fsuid=111264 ouid=0
[161167.229911] type=1400 audit(1518739024.769:66): apparmor="DENIED" operation="file_perm" info="Failed name lookup - disconnected path" error=-13 profile="/usr/bin/evince" name="" pid=756 comm="evince" requested_mask="r" denied_mask="r" fsuid=111264 ouid=0
[161167.276597] type=1400 audit(1518739024.817:67): apparmor="DENIED" operation="file_perm" info="Failed name lookup - disconnected path" error=-13 profile="/usr/bin/evince" name="" pid=756 comm="evince" requested_mask="r" denied_mask="r" fsuid=111264 ouid=0
[161167.276672] type=1400 audit(1518739024.817:68): apparmor="DENIED" operation="file_perm" info="Failed name lookup - disconnected path" error=-13 profile="/usr/bin/evince" name="" pid=756 comm="evince" requested_mask="r" denied_mask="r" fsuid=111264 ouid=0
[161167.276960] type=1400 audit(1518739024.817:69): apparmor="DENIED" operation="file_perm" info="Failed name lookup - disconnected path" error=-13 profile="/usr/bin/evince" name="" pid=756 comm="evince" requested_mask="r" denied_mask="r" fsuid=111264 ouid=0
[161167.277020] type=1400 audit(1518739024.817:70): apparmor="DENIED" operation="file_perm" info="Failed name lookup - disconnected path" error=-13 profile="/usr/bin/evince" name="" pid=756 comm="evince" requested_mask="r" denied_mask="r" fsuid=111264 ouid=0
[161167.277249] type=1400 audit(1518739024.817:71): apparmor="DENIED" operation="file_perm" info="Failed name lookup - disconnected path" error=-13 profile="/usr/bin/evince" name="" pid=756 comm="evince" requested_mask="r" denied_mask="r" fsuid=111264 ouid=0
[161167.645108] afs: failed to store file (0/13)

[andersk]

This may have been fixed sometime between trusty’s kernel 3.13 and xenial’s kernel 4.4 (which is also trusty’s last HWE kernel).