logprof assumes //null-xy belongs to the main profile

Christian

yes it looks like there may be some tracking issues when a new profile is added (could be only around children and hats). The "r" permission is definitely there in the log, and there is even enough info to track across the exec. So its not the problem I initially suspected; there is a huge logging problem at the moment around exec where do to lsm_audit many of apparmor's messages get lost especially around exec. This permission not getting added to profiles as well but in this case logprof would not pick up the second time through.

I just re-tested this with the new python utils (inherit cat, child profile for rm, allow everything). The result was a nice backtrace when permissions were added to the "rm" child profile:

[...]
Profile: /home/cb/linuxtag/apparmor/scripts/hello^/usr/bin/rm
Path: /home/sys-tmp/hello.txt
Mode: w
Severity: 6

 [1 - /home/sys-tmp/hello.txt]
  2 - /home/*/hello.txt
[(A)llow] / (D)eny / (I)gnore / (G)lob / Glob with (E)xtension / (N)ew / Abo(r)t / (F)inish / (M)ore
    [pressed 'a']
Adding /home/sys-tmp/hello.txt w to profile
Traceback (most recent call last):
  File "aa-genprof", line 160, in <module>
    lp_ret = apparmor.do_logprof_pass(logmark, passno)
  File "/home/cb/apparmor/HEAD-CLEAN/utils/apparmor/aa.py", line 2291, in do_logprof_pass
    save_profiles()
  File "/home/cb/apparmor/HEAD-CLEAN/utils/apparmor/aa.py", line 2309, in save_profiles
    for prof_name in changed.keys():
RuntimeError: dictionary changed size during iteration

after digging into the code, it seems for some reason "/usr/bin/rm" is added to "changed" - I doubt this is correct...

After digging a bit more, I found out that create_new_profile() is (ab)used to create a new stub profile to be used as child profile. create_new_profile then adds the new child (which looks like a normal profile to it) to "changed".

I'll send a patch to the ML that most probably makes the cleanup round in save_profile() superfluous.

Patch for comment #5 / #6 commited to bzr r2526.

After this is fixed, I can reproduce the problem with the python tools too.

However it looks like aa-logprof is the broken part - it seems to assign events for the null-xx subprofiles to the main profile instead of a) assigning them to the right subprofile or at least b) dropping them as "unknown null-xx subprofile" :-(

# python3 aa-logprof
Reading log entries from /var/log/audit/audit.log.
Updating AppArmor profiles in /etc/apparmor.d.
Complain-mode changes:

Profile: /home/cb/linuxtag/apparmor/scripts/hello
Path: /home/sys-tmp/hello.txt
Old Mode: w
New Mode: rw (owner permissions off)
Severity: 6

  1 - /home/sys-tmp/hello.txt
 [2 - /home/*/hello.txt]
[(A)llow] / (D)eny / (I)gnore / (G)lob / Glob with (E)xtension / (N)ew / Abo(r)t / (F)inish / (M)ore

# grep hello.txt /var/log/audit/audit.log
type=AVC msg=audit(1402352804.785:2172): apparmor="ALLOWED" operation="mknod" profile="/home/cb/linuxtag/apparmor/scripts/hello" name="/home/sys-tmp/hello.txt" pid=20095 comm="hello" requested_mask="c" denied_mask="c" fsuid=1000 ouid=1000
type=AVC msg=audit(1402352804.785:2172): apparmor="ALLOWED" operation="open" profile="/home/cb/linuxtag/apparmor/scripts/hello" name="/home/sys-tmp/hello.txt" pid=20095 comm="hello" requested_mask="wc" denied_mask="wc" fsuid=1000 ouid=1000
type=AVC msg=audit(1402352804.787:2210): apparmor="ALLOWED" operation="open" profile="/home/cb/linuxtag/apparmor/scripts/hello//null-15" name="/home/sys-tmp/hello.txt" pid=20096 comm="cat" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
type=AVC msg=audit(1402352804.787:2211): apparmor="ALLOWED" operation="getattr" profile="/home/cb/linuxtag/apparmor/scripts/hello//null-15" name="/home/sys-tmp/hello.txt" pid=20096 comm="cat" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
type=AVC msg=audit(1402352804.789:2248): apparmor="ALLOWED" operation="getattr" profile="/home/cb/linuxtag/apparmor/scripts/hello//null-16" name="/home/sys-tmp/hello.txt" pid=20097 comm="rm" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
type=AVC msg=audit(1402352804.789:2249): apparmor="ALLOWED" operation="getattr" profile="/home/cb/linuxtag/apparmor/scripts/hello//null-16" name="/home/sys-tmp/hello.txt" pid=20097 comm="rm" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000
type=AVC msg=audit(1402352804.789:2250): apparmor="ALLOWED" operation="unlink" profile="/home/cb/linuxtag/apparmor/scripts/hello//null-16" name="/home/sys-tmp/hello.txt" pid=20097 comm="rm" requested_mask="d" denied_mask="d" fsuid=1000 ouid=1000

Minimal testcase:

Save this profile as /etc/apparmor.d/home.cb.linuxtag.apparmor.scripts.hello

/home/cb/linuxtag/apparmor/scripts/hello {
  /home/cb/linuxtag/apparmor/scripts/hello r,
  /home/sys-tmp/hello.txt w,
}

Then create a file audit-1014304.log and add the following 3 lines to it:

type=AVC msg=audit(1408292461.263:527): apparmor="ALLOWED" operation="exec" profile="/home/cb/linuxtag/apparmor/scripts/hello" name="/usr/bin/cat" pid=16989 comm="hello" requested_mask="x" denied_mask="x" fsuid=1000 ouid=0 target="/home/cb/linuxtag/apparmor/scripts/hello//null-3"
type=AVC msg=audit(1408292461.264:533): apparmor="ALLOWED" operation="file_mprotect" profile="/home/cb/linuxtag/apparmor/scripts/hello//null-3" name="/usr/bin/cat" pid=16989 comm="cat" requested_mask="r" denied_mask="r" fsuid=1000 ouid=0
type=AVC msg=audit(1408292461.265:564): apparmor="ALLOWED" operation="open" profile="/home/cb/linuxtag/apparmor/scripts/hello//null-3" name="/home/sys-tmp/hello.txt" pid=16989 comm="cat" requested_mask="r" denied_mask="r" fsuid=1000 ouid=1000

Run "aa-logprof -f audit-1014304.log", select "(C)hild" for cat, "(A)llow" for hello.txt and save the modified profile.

Run "aa-logprof -f audit-1014304.log" again - it will propose read access for cat and hello.txt in the main profile (which does _not_ require those permissions)

Kshitij and I worked on this today. After a very interesting[tm] hunt through the code, here's a proof-of-concept patch:

=== modified file 'utils/apparmor/aa.py'
--- utils/apparmor/aa.py 2014-08-17 16:16:33 +0000
+++ utils/apparmor/aa.py 2014-08-17 20:51:09 +0000
@@ -1043,6 +1043,14 @@
                 if not regex_nullcomplain.search(p) and not regex_nullcomplain.search(h):
                     profile = p
                     hat = h
+ else:
+ if profile_changes[pid]:
+ print(profile_changes[pid])
+ if len(profile_changes[pid].split("//"))>1:
+ profile,hat=profile_changes[pid].split("//")
+ else:
+ profile=profile_changes[pid]
+ hat=profile
                 if not profile or not hat or not detail:
                     continue

@@ -1097,6 +1106,7 @@

                 if do_execute:
                     if profile_known_exec(aa[profile][hat], 'exec', exec_target):
+ profile_changes[pid] = '/home/cb/linuxtag/apparmor/scripts/hello///usr/bin/cat'
                         continue

                     p = update_repo_profile(aa[profile][profile])

The first section of the patch is probably the final version already.

Needless to say that profile_changes[pid] = ... line should not be hardcoded ;-) - it needs to be filled based on the exec mode which we already have in the profile.