Assertion on cvs head

[Stephan Jaeger]

On Fri, 2007-08-03 at 13:45 -0400, Alan DeKok wrote:

> > Assertion failed in threads.c, line 540
> > 
> > After the second request. In debug mode (-X) everything is running fine.
> 
>   I don't see that...
> 
>   Also, that code is executed *only* when there are too many threads,
> and one is being deleted.  There's no reason for that to happen after
> one request...
> 
>   What does debug mode say?  (radiusd -fxx)  That will run it
> multi-threaded, but with debugging enabled.

Here is the output of -fxxx|grep Thread

thread settings, just for testing:
start_servers = 2
min_spare_servers = 0
max_spare_servers = 0

Some of the test runs look like this:

Fri Aug  3 20:59:58 2007 : Debug: Thread spawned new child 1. Total
threads in pool: 1
Fri Aug  3 20:59:58 2007 : Debug: Thread spawned new child 2. Total
threads in pool: 2
Fri Aug  3 20:59:58 2007 : Debug: Thread pool initialized
Fri Aug  3 20:59:58 2007 : Debug: Thread 2 waiting to be assigned a
request
Fri Aug  3 20:59:58 2007 : Debug: Thread 1 waiting to be assigned a
request
Fri Aug  3 21:00:06 2007 : Debug: Thread 2 got semaphore
Fri Aug  3 21:00:06 2007 : Debug: Threads: total/active/spare threads =
2/0/2
Fri Aug  3 21:00:06 2007 : Debug: Threads: deleting 1 spare out of 2
spares
Fri Aug  3 21:00:06 2007 : Debug: Thread 2 handling request 0, (1
handled so far)
Fri Aug  3 21:00:06 2007 : Debug: Thread 1 got semaphore
Fri Aug  3 21:00:06 2007 : Debug: Thread 1 exiting...
Fri Aug  3 21:00:06 2007 : Debug: Thread 2 waiting to be assigned a
request
Fri Aug  3 21:00:06 2007 : Debug: Threads: total/active/spare threads =
1/0/1
Fri Aug  3 21:00:11 2007 : Debug: Threads: deleting 1 spare out of 1
spares

[...]

Fri Aug  3 21:07:56 2007 : Debug: Thread 2 got semaphore
Fri Aug  3 21:07:56 2007 : Debug: Threads: deleting 1 spare out of 1
spares
Fri Aug  3 21:07:56 2007 : Debug: Thread 2 handling request 47, (48
handled so far)
Fri Aug  3 21:07:56 2007 : Debug: Thread 2 waiting to be assigned a
request
Fri Aug  3 21:07:57 2007 : Debug: Threads: deleting 1 spare out of 1
spares
Fri Aug  3 21:08:01 2007 : Debug: Threads: deleting 1 spare out of 1
spares
Fri Aug  3 21:08:06 2007 : Debug: Threads: deleting 1 spare out of 1
spares
Fri Aug  3 21:08:06 2007 : Debug: Thread 2 got semaphore
Fri Aug  3 21:08:06 2007 : Debug: Thread 2 handling request 48, (49
handled so far)
Fri Aug  3 21:08:06 2007 : Debug: Thread 2 waiting to be assigned a
request
Fri Aug  3 21:08:07 2007 : Debug: Threads: deleting 1 spare out of 1
spares
Fri Aug  3 21:08:11 2007 : Debug: Threads: deleting 1 spare out of 1
spares
Fri Aug  3 21:08:16 2007 : Debug: Thread 2 got semaphore
Fri Aug  3 21:08:16 2007 : Debug: Threads: deleting 1 spare out of 1
spares
Fri Aug  3 21:08:16 2007 : Debug: Thread 2 handling request 49, (50
handled so far)
Fri Aug  3 21:08:16 2007 : Debug: Thread 2 waiting to be assigned a
request
Fri Aug  3 21:08:17 2007 : Debug: Threads: deleting 1 spare out of 1
spares


Seems to run forever, although my patience wasn't that long ;)

And some are very short:

Fri Aug  3 21:12:21 2007 : Debug: Thread spawned new child 1. Total
threads in pool: 1
Fri Aug  3 21:12:21 2007 : Debug: Thread spawned new child 2. Total
threads in pool: 2
Fri Aug  3 21:12:21 2007 : Debug: Thread pool initialized
Fri Aug  3 21:12:21 2007 : Debug: Thread 1 waiting to be assigned a
request
Fri Aug  3 21:12:21 2007 : Debug: Thread 2 waiting to be assigned a
request
Fri Aug  3 21:12:26 2007 : Debug: Threads: total/active/spare threads =
2/0/2
Fri Aug  3 21:12:26 2007 : Debug: Threads: deleting 1 spare out of 2
spares
Fri Aug  3 21:12:26 2007 : Debug: Thread 1 got semaphore
Fri Aug  3 21:12:26 2007 : Debug: Thread 1 handling request 0, (1
handled so far)
Fri Aug  3 21:12:26 2007 : Debug: Thread 2 got semaphore
Fri Aug  3 21:12:26 2007 : Debug: Thread 2 waiting to be assigned a
request
Fri Aug  3 21:12:26 2007 : Debug: Thread 1 exiting...

Ending after the first request. With the assertion in thread.c, 540.


Stephan Jaeger

-- 
Stephan Jaeger <stephan.jaeger at ewetel.de>