Stream of kernel messages: pid <n> is killed: exceeded RLIMIT_CPU

Hi,

I just booted a -current kernel on my alpha, and now the kernel
frequently logs messages like:

pid 0 is killed: exceeded RLIMIT_CPU
pid 798 is killed: exceeded RLIMIT_CPU
pid 39 is killed: exceeded RLIMIT_CPU

Now, from this I would expect bad things to happen, but it seems
that the processes aren't really killed.  Only the message
appear.  A bug somewhere, perhaps?
					-jarle

Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT_CPU

In article <20111111.191741.32105936.jarle <at> uninett.no>,
Jarle Greipsland  <jarle <at> uninett.no> wrote:
>Hi,
>
>I just booted a -current kernel on my alpha, and now the kernel
>frequently logs messages like:
>
>pid 0 is killed: exceeded RLIMIT_CPU
>pid 798 is killed: exceeded RLIMIT_CPU
>pid 39 is killed: exceeded RLIMIT_CPU
>
>Now, from this I would expect bad things to happen, but it seems
>that the processes aren't really killed.  Only the message
>appear.  A bug somewhere, perhaps?

What does ulimit print?

christos

Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT_CPU

christos <at> astron.com (Christos Zoulas) writes:
> In article <20111111.191741.32105936.jarle <at> uninett.no>,
> >I just booted a -current kernel on my alpha, and now the kernel
> >frequently logs messages like:
> >
> >pid 0 is killed: exceeded RLIMIT_CPU
> >pid 798 is killed: exceeded RLIMIT_CPU
> >pid 39 is killed: exceeded RLIMIT_CPU
> >
> >Now, from this I would expect bad things to happen, but it seems
> >that the processes aren't really killed.  Only the message
> >appear.  A bug somewhere, perhaps?
> 
> What does ulimit print?
socket buffer size       (bytes, -b) unlimited
core file size          (blocks, -c) unlimited
data seg size           (kbytes, -d) 262144
file size               (blocks, -f) unlimited
max locked memory       (kbytes, -l) 341824
max memory size         (kbytes, -m) 1025472
open files                      (-n) 128
pipe size            (512 bytes, -p) 1
stack size              (kbytes, -s) 2048
cpu time               (seconds, -t) unlimited
max user processes              (-u) 160
virtual memory          (kbytes, -v) unlimited

					-jarle

Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT_CPU

On Nov 12,  8:51pm, jarle <at> uninett.no (Jarle Greipsland) wrote:
-- Subject: Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT

| socket buffer size       (bytes, -b) unlimited
| core file size          (blocks, -c) unlimited
| data seg size           (kbytes, -d) 262144
| file size               (blocks, -f) unlimited
| max locked memory       (kbytes, -l) 341824
| max memory size         (kbytes, -m) 1025472
| open files                      (-n) 128
| pipe size            (512 bytes, -p) 1
| stack size              (kbytes, -s) 2048
| cpu time               (seconds, -t) unlimited
| max user processes              (-u) 160
| virtual memory          (kbytes, -v) unlimited

Looks good, I guess thenext step is kernel printfs.

christos

Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT_CPU

christos <at> zoulas.com (Christos Zoulas) writes:
> On Nov 12,  8:51pm, jarle <at> uninett.no (Jarle Greipsland) wrote:
> -- Subject: Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT
> 
[ ... ]
> | cpu time               (seconds, -t) unlimited
[ ... ]
> Looks good, I guess thenext step is kernel printfs.
What do you want printed, and where?

				-jarle

Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT_CPU

On Nov 13, 11:51am, jarle <at> uninett.no (Jarle Greipsland) wrote:
-- Subject: Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT

| What do you want printed, and where?

I would start with the comparison between the limit and the cpu time that
causes the limit to be exceeded. I would print the two values compared.

christos

Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT_CPU

christos <at> zoulas.com (Christos Zoulas) writes:
> On Nov 13, 11:51am, jarle <at> uninett.no (Jarle Greipsland) wrote:
> -- Subject: Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT
> 
> | What do you want printed, and where?
> 
> I would start with the comparison between the limit and the cpu time that
> causes the limit to be exceeded. I would print the two values compared.
With the attached patch applied, the kernel now prints:

pid 0 is killed: exceeded RLIMIT_CPU, runtm=18446744073709551615 rlim_cur=9223372036854775807 rlim_max=9223372036854775807
WARNING: negative runtime; monotonic clock has gone backwards
pid 0 is killed: exceeded RLIMIT_CPU, runtm=18446744073709551614 rlim_cur=9223372036854775807 rlim_max=9223372036854775807
pid 0 is killed: exceeded RLIMIT_CPU, runtm=18446744073709551613 rlim_cur=9223372036854775807 rlim_max=9223372036854775807

Also, this time the log messages seems to have stopped after just
these three messages, and no other processes than pid 0 seem to
have been affected.  Slightly suspicious that
 9223372036854775807==0x7FFFFFFFFFFFFFFF, and
18446744073709551615==0xFFFFFFFFFFFFFFFF....
					-jarle

Index: sys/kern/kern_synch.c
===================================================================
RCS file: /cvsroot/src/sys/kern/kern_synch.c,v
retrieving revision 1.296
diff -u -r1.296 kern_synch.c
--- sys/kern/kern_synch.c	6 Nov 2011 14:11:00 -0000	1.296

Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT_CPU

On Nov 13,  4:55pm, jarle <at> uninett.no (Jarle Greipsland) wrote:
-- Subject: Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT

| Also, this time the log messages seems to have stopped after just
| these three messages, and no other processes than pid 0 seem to
| have been affected.  Slightly suspicious that
|  9223372036854775807==0x7FFFFFFFFFFFFFFF, and
| 18446744073709551615==0xFFFFFFFFFFFFFFFF....
| 					-jarle
| 
check if in the update_rtime now is always greater than l->l_stime, if not,
complain.

christos

Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT_CPU

christos <at> zoulas.com (Christos Zoulas) writes:
> On Nov 13,  4:55pm, jarle <at> uninett.no (Jarle Greipsland) wrote:
> -- Subject: Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT
> 
> | Also, this time the log messages seems to have stopped after just
> | these three messages, and no other processes than pid 0 seem to
> | have been affected.  Slightly suspicious that
> |  9223372036854775807==0x7FFFFFFFFFFFFFFF, and
> | 18446744073709551615==0xFFFFFFFFFFFFFFFF....
> | 					-jarle
> | 
> check if in the update_rtime now is always greater than l->l_stime, if not,
> complain.
With the attached patch applied, the kernel now prints:

updatertime: now (6,13082990375156292405) < &l->l_stime->sec (7,2696175004034666709)
pid 0 is killed: exceeded RLIMIT_CPU, runtm=18446744073709551615 rlim_cur=9223372036854775807 rlim_max=9223372036854775807
WARNING: negative runtime; monotonic clock has gone backwards
updatertime: now (6,16614217696894460111) < &l->l_stime->sec (7,6227415493056243927)
updatertime: now (7,1062082572521342241) < &l->l_stime->sec (7,9122070055515699413)
updatertime: now (7,12178466383987892079) < &l->l_stime->sec (8,1499692050621368511)
pid 9 is killed: exceeded RLIMIT_CPU, runtm=18446744073709551615 rlim_cur=9223372036854775807 rlim_max=9223372036854775807
stray isa irq 4
pid 0 is killed: exceeded RLIMIT_CPU, runtm=18446744073709551614 rlim_cur=9223372036854775807 rlim_max=9223372036854775807
stray isa irq 4
pid 9 is killed: exceeded RLIMIT_CPU, runtm=18446744073709551615 rlim_cur=9223372036854775807 rlim_max=9223372036854775807
stray isa irq 4
pid 9 is killed: exceeded RLIMIT_CPU, runtm=18446744073709551615 rlim_cur=9223372036854775807 rlim_max=9223372036854775807
pid 9 is killed: exceeded RLIMIT_CPU, runtm=18446744073709551615 rlim_cur=9223372036854775807 rlim_max=9223372036854775807
pid 9 is killed: exceeded RLIMIT_CPU, runtm=18446744073709551615 rlim_cur=9223372036854775807 rlim_max=9223372036854775807

Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT_CPU

On Nov 13,  5:37pm, jarle <at> uninett.no (Jarle Greipsland) wrote:
-- Subject: Re: Stream of kernel messages: pid <n> is killed: exceeded RLIMIT

| With the attached patch applied, the kernel now prints:

Ok. The root of the problem is:

| WARNING: negative runtime; monotonic clock has gone backwards

I have seen that on the windows virtual pc but nowhere else. What clock
does your alpha use, and can that go backwards?

christos