!!! Assertion failed in listen.c, line 621 !!!

11 Dec 2006

      No way man!

:)

I've done a CVS clean install now (EVERYTHING old deleted before
install and rebooted machine) but the same error occurs!

It's just like the log from the previous post (below).

radiusd dies after "Sending Access-Request" to the proxy, every single time.

I'm not using any old conf, configured it from scratch.

Please help!

Thanks.

On 12/11/06, Guilherme Franco <guilhermefranco@gmail.com> wrote:
...
Ok,
The log is below, thank you.
Gonna delete and clean install it, I just thought that "./configure,
make, make install" would overwrite everything except the confs.
radiusd -xxx
Mon Dec 11 19:47:58 2006 : Info: Ready to process requests.
Mon Dec 11 19:47:58 2006 : Debug: Nothing to do.  Sleeping until we
see a request.
Mon Dec 11 19:47:58 2006 : Debug: Thread 1 waiting to be assigned a request
Mon Dec 11 19:47:58 2006 : Debug: Thread 2 waiting to be assigned a request
Mon Dec 11 19:47:58 2006 : Debug: Thread 5 waiting to be assigned a request
Mon Dec 11 19:47:58 2006 : Debug: Thread 3 waiting to be assigned a request
Mon Dec 11 19:47:58 2006 : Debug: Thread 4 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.10.2.11 port 50000,
id=206, length=234
Mon Dec 11 19:48:17 2006 : Debug: --- Walking the entire request list ---
Mon Dec 11 19:48:17 2006 : Debug: Thread 1 got semaphore
Mon Dec 11 19:48:17 2006 : Debug: Threads: total/active/spare threads = 5/0/5
Mon Dec 11 19:48:17 2006 : Debug: Thread 1 handling request 0, (1
handled so far)
Mon Dec 11 19:48:17 2006 : Debug: Waking up in 1 seconds...
       User-Password = "bogus123"
       User-Name = "bogus@foo.com"
       Acct-Session-Id = "nas GigabitEthernet 11/0.165:2165:0028716608"
       Service-Type = Framed-User
       Framed-Protocol = PPP
       ERX-Pppoe-Description = "pppoe 00:0b:23:fd:1d:8c"
       Calling-Station-Id = "NAS-01#2165"
       NAS-Port-Type = Ethernet
       NAS-Port = 2952792181
       NAS-Port-Id = "GigabitEthernet 11/0.165:2165"
       NAS-IP-Address = 10.10.2.11
       NAS-Identifier = "NAS-01"
Mon Dec 11 19:48:17 2006 : Debug:   Processing the authorize section
of radiusd.conf
Mon Dec 11 19:48:17 2006 : Debug: modcall:  entering group authorize
for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module
"preprocess" returns ok for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling
auth_log (rlm_detail) for request 0
Mon Dec 11 19:48:17 2006 : Debug: radius_xlat:
'/usr/local/var/log/radius/radacct/10.10.2.11/auth-detail-20061211'
Mon Dec 11 19:48:17 2006 : Debug: rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/10.10.2.11/auth-detail-20061211
Mon Dec 11 19:48:17 2006 : Debug: radius_xlat:  'Mon Dec 11 19:48:17 2006'
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from auth_log (rlm_detail) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module
"auth_log" returns ok for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling chap
(rlm_chap) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from chap (rlm_chap) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module "chap"
returns noop for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling
mschap (rlm_mschap) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from mschap (rlm_mschap) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module
"mschap" returns noop for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling unix
(rlm_unix) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from unix (rlm_unix) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module "unix"
returns notfound for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling
suffix (rlm_realm) for request 0
Mon Dec 11 19:48:17 2006 : Debug:     rlm_realm: Looking up realm
"foo.com" for User-Name = "bogus@foo.com"
Mon Dec 11 19:48:17 2006 : Debug:     rlm_realm: Found realm "foo.com"
Mon Dec 11 19:48:17 2006 : Debug:     rlm_realm: Adding
Stripped-User-Name = "bogus"
Mon Dec 11 19:48:17 2006 : Debug:     rlm_realm: Proxying request from
user bogus to realm foo.com
Mon Dec 11 19:48:17 2006 : Debug:     rlm_realm: Adding Realm = "foo.com"
Mon Dec 11 19:48:17 2006 : Debug:     rlm_realm: Preparing to proxy
authentication request to realm "foo.com"
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from suffix (rlm_realm) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module
"suffix" returns updated for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling
files (rlm_files) for request 0
Mon Dec 11 19:48:17 2006 : Debug:     users: Matched entry DEFAULT at line 173
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from files (rlm_files) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module "files"
returns ok for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling sql
(rlm_sql) for request 0
Mon Dec 11 19:48:17 2006 : Debug: radius_xlat:  'bogus@foo.com'
Mon Dec 11 19:48:17 2006 : Debug: rlm_sql (sql): sql_set_user escaped
user --> 'bogus@foo.com'
Mon Dec 11 19:48:17 2006 : Debug: rlm_sql (sql): Reserving sql socket id: 14
Mon Dec 11 19:48:17 2006 : Debug: radius_xlat:  'SELECT
id,UserName,Attribute,Value,op FROM radcheck WHERE Username =
'bogus@foo.com' ORDER BY id'
Mon Dec 11 19:48:17 2006 : Debug: SELECT
id,UserName,Attribute,Value,op FROM radcheck WHERE Username =
'bogus@foo.com' ORDER BY id
Mon Dec 11 19:48:17 2006 : Debug: rlm_sql (sql): User found in radcheck table
Mon Dec 11 19:48:17 2006 : Debug: radius_xlat:  'SELECT
id,UserName,Attribute,Value,op FROM radreply WHERE Username =
'bogus@foo.com' ORDER BY id'
Mon Dec 11 19:48:17 2006 : Debug: SELECT
id,UserName,Attribute,Value,op FROM radreply WHERE Username =
'bogus@foo.com' ORDER BY id
Mon Dec 11 19:48:17 2006 : Debug: rlm_sql (sql): Released sql socket id: 14
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from sql (rlm_sql) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module "sql"
returns ok for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling
expiration (rlm_expiration) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from expiration (rlm_expiration) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module
"expiration" returns noop for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling
logintime (rlm_logintime) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from logintime (rlm_logintime) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module
"logintime" returns noop for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: calling pap
(rlm_pap) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[authorize]: returned
from pap (rlm_pap) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[authorize]: module "pap"
returns noop for request 0
Mon Dec 11 19:48:17 2006 : Debug: modcall: group authorize returns
updated for request 0
Mon Dec 11 19:48:17 2006 : Debug:   Processing the pre-proxy section
of radiusd.conf
Mon Dec 11 19:48:17 2006 : Debug: modcall:  entering group pre-proxy
for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[pre-proxy]: calling
pre_proxy_log (rlm_detail) for request 0
Mon Dec 11 19:48:17 2006 : Debug: radius_xlat:
'/usr/local/var/log/radius/radacct/10.10.2.11/pre-proxy-detail-20061211'
Mon Dec 11 19:48:17 2006 : Debug: rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/10.10.2.11/pre-proxy-detail-20061211
Mon Dec 11 19:48:17 2006 : Debug: radius_xlat:  'Mon Dec 11 19:48:17 2006'
Mon Dec 11 19:48:17 2006 : Debug:   modsingle[pre-proxy]: returned
from pre_proxy_log (rlm_detail) for request 0
Mon Dec 11 19:48:17 2006 : Debug:   modcall[pre-proxy]: module
"pre_proxy_log" returns ok for request 0
Mon Dec 11 19:48:17 2006 : Debug: modcall: group pre-proxy returns ok
for request 0
Mon Dec 11 19:48:17 2006 : Debug:  proxy: allocating destination
30.30.2.1 port 1812 - Id 191
Sending Access-Request of id 191 to 30.30.2.1 port 1812
       User-Password = "bogus123"
       User-Name = "bogus"
       Acct-Session-Id = "nas GigabitEthernet 11/0.165:2165:0028716608"
       Service-Type = Framed-User
       Framed-Protocol = PPP
       ERX-Pppoe-Description = "pppoe 00:0b:23:fd:1d:8c"
       Calling-Station-Id = "NAS-01#2165"
       NAS-Port-Type = Ethernet
       NAS-Port = 2952792181
       NAS-Port-Id = "GigabitEthernet 11/0.165:2165"
       NAS-IP-Address = 10.10.2.11
       NAS-Identifier = "NAS-01"
       Proxy-State = 0x323036
Mon Dec 11 19:48:17 2006 : Error: Assertion failed in listen.c, line 621