!!! Assertion failed in listen.c, line 621 !!!
Guilherme Franco
guilhermefranco at gmail.com
Tue Dec 12 02:08:47 CET 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 at 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 at 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 at 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 at foo.com'
> Mon Dec 11 19:48:17 2006 : Debug: rlm_sql (sql): sql_set_user escaped
> user --> 'bogus at 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 at foo.com' ORDER BY id'
> Mon Dec 11 19:48:17 2006 : Debug: SELECT
> id,UserName,Attribute,Value,op FROM radcheck WHERE Username =
> 'bogus at 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 at foo.com' ORDER BY id'
> Mon Dec 11 19:48:17 2006 : Debug: SELECT
> id,UserName,Attribute,Value,op FROM radreply WHERE Username =
> 'bogus at 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
>
More information about the Freeradius-Users
mailing list