[Apparmor-general] Apparmor-general

[John Johansen]

On Wed, Jan 23, 2008 at 02:22:16AM +0100, Carlos E. R. wrote:
>
>> 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?
>
Hmm, I have to go and check whether that is possible to set up with bind
mounts.

> 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?
>
yes please.

>
> 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!
>
yikes, me too.  If it is apparmor related you should see apparmor reject
messages near those failures.  What apparmor is doing is failing to revalidate
the pathname of lazily umounted files (if apparmor has cached the access as
the first access things are okay).  The reporting bug that resulted in
the bad inode_permission message does cause a crash or an improper reject
just a bad message so that isn't the problem at least.

regards
john
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 194 bytes
Desc: not available
Url : http://forge.novell.com/pipermail/apparmor-general/attachments/20080123/b2904515/attachment.pgp