[Apparmor-general] Apparmor-general

[Carlos E. R.]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1



The Saturday 2008-01-19 at 15:00 -0800, John Johansen wrote:

> Carlos E. R. wrote:
>>
>>
>> Hi,
>>
>> In the audit log I see this message, repeated several times:
>>
>> DENIED msg=audit(1199356965.768:7):  type=1503
>> operation="inode_permission" requested_mask="r" denied_mask="mrwiuplk"
>> pid=4946 profile="/usr/sbin/nscd"
>>
>> This message causes the yast apparmour wizard to crash, with "unknown
>> mask mrwiuplk". This has been reported as Bug 349942 to bugzilla, and I
>> hope will be solved one of these months :-)
>
> well yes hopefully.  I am sorry to say I am way behind on my bugzilla
> but this is a new one to me as it hit someone else.  Sadly it is
> multiple bugs in one.  The kernel shouldn't be reporting "mrwiuplk",
> and the wizard shouldn't be crashing on unknown input.

Ah!

> The kernel bug causing this has been fixed but I need to submit it so it
> can be rolled out for and be made available in an update.
>
>>
>> What I want to ask here is how should I change the "/usr/sbin/nscd"
>> profile so that the message doesn't pop (and the permission is granted,
>> obviously). As the wizard can't handle it, I don't see how to add that
>> permission easily.
>>
> Ugh, well I can tell you permission you want is "r", the problem is I
> can't tell you what to add.  Notice this audit message is missing a name
> component.  That is because the name lookup failed, and the kernel side
> portion of the bug was with reporting a failed name lookup.  Either the
> pathname was to long, your machine is/was really tight on memory and
> couldn't allocate a buffer for the pathname or it was lazily unmounted
> in a race window making it impossible to retrieve the path.

I see it is more complex than I thought.

Lazy umount...? Rings a bell. I'll explain below.


> I am going to bet it wasn't running out of memory because you would have
> seen many other problems if the kernel had run out of memory.

1 GiB, and 12GiB swap, desktop use... not likely.

>
> That either leaves the path being to long, the default is 2*PATH_MAX so
> about a 2k long path.  From an unconfined root shell you can change the
> apparmor maxpath name size to 4K (or any larger value) by doing
>
> echo 4096 > /sys/module/apparmor/parameters/path_max

nimrodel:~ # cat /sys/module/apparmor/parameters/path_max
8192

So it is currently larger.


> If this is a reoccuring problem my bet would be its a really long path
> other wise you are dealing with something that was lazily unmounted, and
> that is feature yet to be implemented.

A recursive path?

It happened only two times as far as I know (I can't read the time stamps 
- - no, now I know).


>> On a side question: How do I translate the date-stamp 1199356965.768 to
>> some thing intelligible by humans? So that I can correlate the log entry
>> to the rest of the system logs.
>>
> its unix epoche time and you can use a web site
> http://www.epochconverter.com/
>
> which gives
> GMT: Thu, 03 Jan 2008 10:42:45 GMT
> Your timezone: Thu 03 Jan 2008 02:42:45 AM PST

I got an answer on the Spanish list:

   cer at nimrodel:~> date --date="@1199356965.768"
   Thu Jan  3 11:42:45 CET 2008


Knowing the date I may remember what I was doing at the time. And the bell 
is because I did have used "lazy umount" while working on a bug report of 
a filesystem crash while writing large files to an encripted partition 
(Bug 345039).

Looking at the dates of the reports:

     680 08-01-02 15:20 
+   681 08-01-03 04:12 <==
+   682 08-01-03 04:26

I see they are close to the date of the apparmour entry...

Ok, seeing my notes I did that testing on "Jan  3 11:08:28". On the log I 
see I rebooted (it crashed) at 11:48:14. The audit log go from "11:42:45" 
to 11:45:15... it matches very closely:


Jan  3 11:40:24 nimrodel smartd[5147]: Device: /dev/hdb, SMART Prefailure Attribute: 1 Raw_Read_Error_Rate changed from 58 to 59
Jan  3 11:40:24 nimrodel smartd[5147]: Device: /dev/hdb, SMART Usage Attribute: 194 Temperature_Celsius changed from 25 to 26
Jan  3 11:40:24 nimrodel smartd[5147]: Device: /dev/hdd, SMART Usage Attribute: 194 Temperature_Celsius changed from 32 to 33
Jan  3 11:42:01 nimrodel /usr/sbin/gpm[3871]: O0o.oops(): [gpm.c(157)]:
Jan  3 11:42:01 nimrodel /usr/sbin/gpm[3871]: Opening console failed.
Jan  3 11:45:01 nimrodel /usr/sbin/cron[7242]: User not known to the underlying authentication module
Jan  3 11:45:01 nimrodel /usr/sbin/cron[7243]: User not known to the underlying authentication module
Jan  3 11:48:14 nimrodel syslog-ng[3698]: syslog-ng version 1.6.12 starting


¡BINGO! Whatever this leads to... how curious, it relates to another 
bug...


Do you want me to add this info to the bugzilla?


See? If the audit log had used plain date stamps, I might have noticed the 
coincidence earlier :-P

Your mention of "lazy umount" clinched it, because that's the only 
circunstance in which I use it (see Bug 345039). Now I perhaps should try 
to recreate that situation with apparmour dissabled...


Wow! I hope this is not a simple coincidence!

- -- 
Cheers,
        Carlos E. R.
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.4-svn0 (GNU/Linux)

iD8DBQFHlpbStTMYHG2NR9URAsdRAKCQ+Mo+yi0TZtji6PfK+DqhSpDrKwCfZR28
G2YWLN5+7z1vUqK0r7fcurs=
=CnAT
-----END PGP SIGNATURE-----