__ratelimit: 172527 callbacks suppressed

__ratelimit: 172527 callbacks suppressed

[Sebastian Hetze]

Hi *,

in the dmesg/kern.log of my ubuntu 2.6.31-16-generic-pae guest running
on an 2.6.31-14-server host with 0.12.2-0ubuntu6 qemu-kvm I find
ratelimit messages with various numbers.

Any idea, what might cause these messages to appear? Any way to find
out?

Best regards,

  Sebastian
-- 
Sebastian Hetze
Mitglied des Vorstands
Linux Information Systems AG
Bundesallee 93, D-12161 Berlin

Fon: +49 30 726238-0, Fax: +49 30 726238-99
s.hetze@linux-ag.com, http://www.linux-ag.com
----------------------------------------------------------
Sitz der Gesellschaft: Putzbrunner Str. 71, 81739 München
Amtsgericht München: HRB 128 019
Vorstand: Rudolf Strobl, Sebastian Hetze
Aufsichtsrat: Michael Tarabochia (Vorsitzender)

Re: __ratelimit: 172527 callbacks suppressed

[Avi Kivity]

On 03/19/2010 09:30 AM, Sebastian Hetze wrote:
> Hi *,
>
> in the dmesg/kern.log of my ubuntu 2.6.31-16-generic-pae guest running
> on an 2.6.31-14-server host with 0.12.2-0ubuntu6 qemu-kvm I find
> ratelimit messages with various numbers.
>
> Any idea, what might cause these messages to appear? Any way to find
> out?
>    

What's are the few lines above this message?

-- 
Do not meddle in the internals of kernels, for they are subtle and quick to panic.

Re: __ratelimit: 172527 callbacks suppressed

[Sebastian Hetze]

On Fri, Mar 19, 2010 at 10:37:00AM +0200, Avi Kivity wrote:
> On 03/19/2010 09:30 AM, Sebastian Hetze wrote:
>> Hi *,
>>
>> in the dmesg/kern.log of my ubuntu 2.6.31-16-generic-pae guest running
>> on an 2.6.31-14-server host with 0.12.2-0ubuntu6 qemu-kvm I find
>> ratelimit messages with various numbers.
>>
>> Any idea, what might cause these messages to appear? Any way to find
>> out?
>>    
>
> What's are the few lines above this message?

Nothing that appears related to these messages. Here are a few sequences:


Feb 14 16:09:19 guest kernel: [   93.618951] type=1502 audit(1266160159.355:33): operation="file_perm" pid=4
336 parent=4238 profile="/usr/lib/cups/backend/cups-pdf" requested_mask="::w" denied_mask="::w" fsuid=0 ouid=1
0008 name="/var/spool/cups-pdf/SPOOL/cups2pdf-4336"
Feb 14 16:09:19 guest kernel: [   93.618986] type=1502 audit(1266160159.355:34): operation="file_perm" pid=4
336 parent=4238 profile="/usr/lib/cups/backend/cups-pdf" requested_mask="::w" denied_mask="::w" fsuid=0 ouid=1
0008 name="/var/spool/cups-pdf/SPOOL/cups2pdf-4336"
Feb 16 12:23:38 guest kernel: [159352.872094] __ratelimit: 31353 callbacks suppressed


Mar 15 16:21:36 guest kernel: [   73.205760] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
Mar 15 16:21:38 guest kernel: [   80.720900] __ratelimit: 6 callbacks suppressed

Mar 15 16:50:30 guest kernel: [   35.308173] eth1: no IPv6 routers present
Mar 15 16:50:33 guest kernel: [   37.725014] __ratelimit: 6 callbacks suppressed

Mar 15 21:09:55 guest kernel: [   75.494553] ppdev: user-space parallel port driver
Mar 16 08:05:34 guest kernel: [39414.502611] __ratelimit: 6 callbacks suppressed


Mar 16 08:05:34 guest kernel: [39414.625923] type=1502 audit(1268723134.166:22): operation="mknod" pid=30162 parent=4443 profile="/usr/lib/cups/backend/cups-pdf" requested_mask="w::" denied_mask="w::" fsuid=0 ouid=0 name="/var/spool/cups-pdf/SPOOL/cups2pdf-30162"
Mar 16 08:05:34 guest kernel: [39414.625957] type=1502 audit(1268723134.166:23): operation="open" pid=30162 parent=4443 profile="/usr/lib/cups/backend/cups-pdf" requested_mask="w::" denied_mask="w::" fsuid=0 ouid=0 name="/var/spool/cups-pdf/SPOOL/cups2pdf-30162"
Mar 16 10:19:40 guest kernel: [47460.715832] hrtimer: interrupt too slow, forcing clock min delta to 120001629 ns
Mar 16 11:37:23 guest kernel: [52124.205933] __ratelimit: 3441 callbacks suppressed

Feb 16 12:31:32 guest kernel: [159826.385805] type=1502 audit(1266319892.124:2327900): operation="file_perm" pid=30376 parent=4238 profile="/usr/lib/cups/backend/cups-pdf" requested_mask="::w" denied_mask="::w" fsuid=0 ouid=10214 name="/var/spool/cups-pdf/SPOOL/cups2pdf-30376"
Feb 16 12:31:32 guest kernel: [159826.385880] type=1502 audit(1266319892.124:2327901): operation="file_perm" pid=30376 parent=4238 profile="/usr/lib/cups/backend/cups-pdf" requested_mask="::w" denied_mask="::w" fsuid=0 ouid=10214 name="/var/spool/cups-pdf/SPOOL/cups2pdf-30376"
Feb 16 12:31:32 guest kernel: [159826.385955] type=1502 audit(1266319892.124:2327902): operation="file_perm" pid=30376 parent=4238 profile="/usr/lib/cups/backend/cups-pdf" requested_mask="::w" denied_mask="::w" fsuid=0 ouid=10214 name="/var/spool/cups-pdf/SPOOL/cups2pdf-30376"
Feb 16 12:31:37 guest kernel: [159831.415803] __ratelimit: 48828 callbacks suppressed


Mar 16 19:38:56 guest kernel: [   23.608569] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
Mar 16 19:40:53 guest kernel: [  144.532361] warning: `dhcpd3' uses 32-bit capabilities (legacy support in use)
Mar 16 19:41:36 guest kernel: [  188.069347] __ratelimit: 6 callbacks suppressed

Mar 16 20:19:24 guest kernel: [ 2199.456753] EXT3 FS on dm-3, internal journal
Mar 16 20:19:24 guest kernel: [ 2199.456765] EXT3-fs: mounted filesystem with writeback data mode.
Mar 17 08:34:18 guest kernel: [46293.725506] __ratelimit: 6 callbacks suppressed

Re: __ratelimit: 172527 callbacks suppressed

[Avi Kivity]

On 03/19/2010 11:17 AM, Sebastian Hetze wrote:
> On Fri, Mar 19, 2010 at 10:37:00AM +0200, Avi Kivity wrote:
>    
>> On 03/19/2010 09:30 AM, Sebastian Hetze wrote:
>>      
>>> Hi *,
>>>
>>> in the dmesg/kern.log of my ubuntu 2.6.31-16-generic-pae guest running
>>> on an 2.6.31-14-server host with 0.12.2-0ubuntu6 qemu-kvm I find
>>> ratelimit messages with various numbers.
>>>
>>> Any idea, what might cause these messages to appear? Any way to find
>>> out?
>>>
>>>        
>> What's are the few lines above this message?
>>      
> Nothing that appears related to these messages. Here are a few sequences:
>    

Try looking directly in dmesg, and 'echo 9 > /proc/sysrq-trigger'.  
ratelimit messages should always follow the message they are limiting.

-- 
Do not meddle in the internals of kernels, for they are subtle and quick to panic.

Re: __ratelimit: 172527 callbacks suppressed

[Sebastian Hetze]

On Sat, Mar 20, 2010 at 09:49:46AM +0200, Avi Kivity wrote:
> On 03/19/2010 11:17 AM, Sebastian Hetze wrote:
>> On Fri, Mar 19, 2010 at 10:37:00AM +0200, Avi Kivity wrote:
>>    
>>> On 03/19/2010 09:30 AM, Sebastian Hetze wrote:
>>>      
>>>> Hi *,
>>>>
>>>> in the dmesg/kern.log of my ubuntu 2.6.31-16-generic-pae guest running
>>>> on an 2.6.31-14-server host with 0.12.2-0ubuntu6 qemu-kvm I find
>>>> ratelimit messages with various numbers.
>>>>
>>>> Any idea, what might cause these messages to appear? Any way to find
>>>> out?
>>>>
>>>>        
>>> What's are the few lines above this message?
>>>      
>> Nothing that appears related to these messages. Here are a few sequences:
>>    
>
> Try looking directly in dmesg, and 'echo 9 > /proc/sysrq-trigger'.   
> ratelimit messages should always follow the message they are limiting.

even with log level 9 there are __ratelimit messages without preceeding
information within a hour timerange. However, all current ratelimit
messages appear right before audit messages from apparmor. So this is
not related to KVM. We will fix the apparmor setup and watch further.

Thanx alot, anyway.