Re: Assertion failed in listen.c, line 621

11 Dec 2006

      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

Re: Assertion failed in listen.c, line 621

Guilherme Franco