[NoCat] Strange problem with Radius

kyleena at tele2.it kyleena at tele2.it
Thu May 11 07:08:59 PDT 2006


Hi all,
I'm here again with a strange problem. I hadn't found 
anything similar on this archive...

I'm running NoCatAuth gateway and server on two separate 
machines. The version is the nightly one. Server's IP is 
172.16.10.123. External interface of gateway is 
172.16.10.100, and the internal interface (which clients 
are connected to) is 10.0.0.1.

Everything works fine with an authorization file-based. 
But my need is to run a RADIUS server with Postresql.

I found Pogozone patch and I applied it (even if I don't 
understand if it must be applied only on the gateway or on 
both server and gateway...).

Now, the problem...

It seems that Radius works fine. When I run radiusd -X and 
a client tries to autheticate, I have this output:

*****************RADIUS 
OUTPUT********************************
**************************************************************

rad_recv: Access-Request packet from host 127.0.0.1:32833, 
id=124, length=46
         User-Name = "monica"
         User-Password = "monica"
   Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 3
   modcall[authorize]: module "preprocess" returns ok for 
request 3
   modcall[authorize]: module "chap" returns noop for 
request 3
   modcall[authorize]: module "mschap" returns noop for 
request 3
     rlm_realm: No '@' in User-Name = "monica", looking up 
realm NULL
     rlm_realm: No such realm "NULL"
   modcall[authorize]: module "suffix" returns noop for 
request 3
radius_xlat:  'monica'
rlm_sql (sql): sql_set_user escaped user --> 'monica'
radius_xlat:  'SELECT id, UserName, Attribute, Value, Op 
FROM radcheck WHERE Username = 'monica' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql_postgresql: query: SELECT id, UserName, Attribute, 
Value, Op FROM radcheck WHERE Username = 'monica' ORDER BY 
id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: affected rows =
radius_xlat:  'SELECT radgroupcheck.id, 
radgroupcheck.GroupName, radgroupcheck.Attribute, 
radgroupcheck.Value,radgroupcheck.Op FROM radgroupcheck, 
usergroup WHERE usergroup.Username = 'monica' AND 
usergroup.GroupName = radgroupcheck.GroupName ORDER BY 
radgroupcheck.id'
rlm_sql_postgresql: query: SELECT radgroupcheck.id, 
radgroupcheck.GroupName, radgroupcheck.Attribute, 
radgroupcheck.Value,radgroupcheck.Op FROM radgroupcheck, 
usergroup WHERE usergroup.Username = 'monica' AND 
usergroup.GroupName = radgroupcheck.GroupName ORDER BY 
radgroupcheck.id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: affected rows =
radius_xlat:  'SELECT id, UserName, Attribute, Value, Op 
FROM radreply WHERE Username = 'monica' ORDER BY id'
rlm_sql_postgresql: query: SELECT id, UserName, Attribute, 
Value, Op FROM radreply WHERE Username = 'monica' ORDER BY 
id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: affected rows =
radius_xlat:  'SELECT radgroupreply.id, 
radgroupreply.GroupName, radgroupreply.Attribute, 
radgroupreply.Value, radgroupreply.Op FROM 
radgroupreply,usergroup WHERE usergroup.Username = 
'monica' AND usergroup.GroupName = radgroupreply.GroupName 
ORDER BY radgroupreply.id'
rlm_sql_postgresql: query: SELECT radgroupreply.id, 
radgroupreply.GroupName, radgroupreply.Attribute, 
radgroupreply.Value, radgroupreply.Op FROM 
radgroupreply,usergroup WHERE usergroup.Username = 
'monica' AND usergroup.GroupName = radgroupreply.GroupName 
ORDER BY radgroupreply.id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: affected rows =
rlm_sql (sql): Released sql socket id: 1
   modcall[authorize]: module "sql" returns ok for request 
3
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
   modcall[authorize]: module "noresetcounter" returns 
noop for request 3
modcall: leaving group authorize (returns ok) for request 
3
auth: type Local
auth: user supplied User-Password matches local 
User-Password
Login OK: [monica/monica] (from client localhost port 0)
Sending Access-Accept of id 124 to 127.0.0.1 port 32833
Finished request 3
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 3 ID 124 with timestamp 44633e91
Nothing to do.  Sleeping until we see a request.

********END OF RADIUS OUTPUT****************************
********************************************************

I am not very smart with Radius, but it seems sending an 
Access-Accept, isn't it?

But my client sees a "Sorry, your session has expired" 
message, and it is redirecting to login page again.

I found this error in my gateway nocat.log:

*************NOCAT.LOG*********************************
*******************************************************

[2006-05-11 15:36:41] Connection to 172.16.10.100 from 
172.16.10.123
[2006-05-11 15:36:41] Spawning child process 7284.
[2006-05-11 15:36:41] Received notify from 172.16.10.123
[2006-05-11 15:36:41] Missing notify from 172.16.10.123
[2006-05-11 15:36:41] Capturing  172.16.10.123  for 
http://172.16.10.100:528010.0.0.30
[2006-05-11 15:36:41] Notifying parent of Capture on peer 
172.16.10.123
[2006-05-11 15:36:41] Got notification Capture of peer 
172.16.10.123
[2006-05-11 15:36:41] Child process returned 1
[2006-05-11 15:36:47] Connection to 10.0.0.1 from 
10.0.0.30
[2006-05-11 15:36:47] Capturing  10.0.0.30  for 
http://www.google.it/
[2006-05-11 15:36:47] Notifying parent of Capture on peer 
10.0.0.30
[2006-05-11 15:36:47] Spawning child process 7285.
[2006-05-11 15:36:47] Got notification Capture of peer 
10.0.0.30
[2006-05-11 15:36:47] Child process returned 1

******END OF NOCAT.LOG**********************************
********************************************************

It seems that it concatenates the LocalGateway's IP and 
the client's IP !!

And finally, this is my Apache ssl_eeror_log:

************APACHE LOG**********************************
********************************************************

[Thu May 11 16:02:34 2006] [error] [client 172.16.10.100] 
[2006-05-11 16:02:34] User monica from 172.16.10.100 
requests form, referer: 
https://172.16.10.123/cgi-bin/login?redirect=http%3a%2f%2fwww%2egoogle%2eit%2f&timeout=300&gateway=&mac=10%2e0%2e0%2e30&token=%241%2454466498%24C8cywEtMUbwuuxZxdACFz%2f
[Thu May 11 16:02:34 2006] [error] [client 172.16.10.100] 
[2006-05-11 16:02:34] Use of uninitialized value in 
concatenation (.) or string at 
../lib//NoCat/Source/RADIUS.pm line 46, <FILE> line 1., 
referer: 
https://172.16.10.123/cgi-bin/login?redirect=http%3a%2f%2fwww%2egoogle%2eit%2f&timeout=300&gateway=&mac=10%2e0%2e0%2e30&token=%241%2454466498%24C8cywEtMUbwuuxZxdACFz%2f
[Thu May 11 16:02:34 2006] [error] [client 172.16.10.100] 
[2006-05-11 16:02:34] Connecting to RADIUS server 
localhost:1812 with Timeout , referer: 
https://172.16.10.123/cgi-bin/login?redirect=http%3a%2f%2fwww%2egoogle%2eit%2f&timeout=300&gateway=&mac=10%2e0%2e0%2e30&token=%241%2454466498%24C8cywEtMUbwuuxZxdACFz%2f
[Thu May 11 16:02:34 2006] [error] [client 172.16.10.100] 
[2006-05-11 16:02:34] Request from local ip 172.16.10.100, 
directing to local gateway 172.16.10.100:5280., referer: 
https://172.16.10.123/cgi-bin/login?redirect=http%3a%2f%2fwww%2egoogle%2eit%2f&timeout=300&gateway=&mac=10%2e0%2e0%2e30&token=%241%2454466498%24C8cywEtMUbwuuxZxdACFz%2f
[Thu May 11 16:02:34 2006] [error] [client 172.16.10.100] 
[2006-05-11 16:02:34] Gateway returned 302 (Moved ) for 
10.0.0.30., referer: 
https://172.16.10.123/cgi-bin/login?redirect=http%3a%2f%2fwww%2egoogle%2eit%2f&timeout=300&gateway=&mac=10%2e0%2e0%2e30&token=%241%2454466498%24C8cywEtMUbwuuxZxdACFz%2f
[Thu May 11 16:02:34 2006] [error] [client 172.16.10.100] 
[2006-05-11 16:02:34] Request from local ip 172.16.10.100, 
directing to local gateway 172.16.10.100:5280., referer: 
https://172.16.10.123/cgi-bin/login?redirect=http%3a%2f%2fwww%2egoogle%2eit%2f&timeout=300&gateway=&mac=10%2e0%2e0%2e30&token=%241%2454466498%24C8cywEtMUbwuuxZxdACFz%2f
[Thu May 11 16:02:40 2006] [error] [client 172.16.10.100] 
[2006-05-11 16:02:40] User UNKNOWN from 172.16.10.100 
requests form

***************END OF APACHE 
LOG**********************************
******************************************************************

The strange line for me is "Request from local ip 
172.16.10.100, directing to local gateway 
172.16.10.100:5280". I think that local ip would be the 
client's one, but it sees the gateway's one.

I have no idea how to find the bug!! Please help me... 
thanks!

Monica



More information about the NoCat mailing list