ACCESS-REJECT authentication messages are not logged

[Grzegorz_Bech]

Hi 
I have difficulty in setting radius to create logs of ACCESS-REJECT
authentication messages. It logs only ACCESS-ACCEPT packets (sent and
received). 
Double debug mode (radiusd -xx) shows the following lines (when recive
ACCESS-REJECT messages): 
rad_recv: Access-Request packet from host 192.168.12.22:1327, id=63,
length=63 
--- Walking the entire request list --- 
Waking up in 31 seconds... 
Thread 1 got semaphore 
Thread 1 handling request 1, (2 handled so far) 
User-Name = "dialog" 
User-Password = "test" 
Cisco-NAS-Port = "tty" 
NAS-IP-Address = 192.168.12.22 
Processing the authorize section of radiusd.conf 
modcall: entering group authorize for request 1 
modcall[authorize]: module "preprocess" returns ok for request 1 
rlm_ora3arts : - encode_context 
rlm_ora3arts (ora3arts): Reserving sql socket id: 28 
preparing statement begin :result := t3arts42.iradius.authorize(:context);
end; 
executing statement begin :result := t3arts42.iradius.authorize(:context);
end; 
statement executed begin :result := t3arts42.iradius.authorize(:context);
end; 
result encoded context result:n=0; 
parsing reply result:n=0; 
parsing attribute result:n=0 
reply parsed , returning -1 
rlm_ora3arts : request rejected 
rlm_ora3arts (ora3arts): Released sql socket id: 28 
modcall[authorize]: module "ora3arts" returns reject for request 1 
modcall: group authorize returns reject for request 1 
Invalid user: [dialog/test] (from client localhost port 0) 
Sending Access-Reject of id 63 to 192.168.12.22:1327 
Finished request 1 
Going to the next request 
Thread 1 waiting to be assigned a request

----------------------------------------------------------------------------
----------------------------------------------------------------------------
-------------------------------------------------------------------------
Double debug mode (radiusd -xx) shows the following lines (when recive
ACCESS-ACCEPT messages): 
rad_recv: Access-Request packet from host 192.168.12.22:1326, id=62,
length=63 
Thread spawned new child 1. Total threads in pool: 1 
--- Walking the entire request list --- 
Waking up in 31 seconds... 
Threads: total/active/spare threads = 1/0/1 
Threads: Spawning 2 spares 
Thread spawned new child 2. Total threads in pool: 2 
Thread spawned new child 3. Total threads in pool: 3 
Thread 1 waiting to be assigned a request 
Thread 1 got semaphore 
Thread 1 handling request 0, (1 handled so far) 
User-Name = "dialog" 
User-Password = "test1" 
Cisco-NAS-Port = "tty" 
NAS-IP-Address = 192.168.12.22 
Processing the authorize section of radiusd.conf 
modcall: entering group authorize for request 0 
modcall[authorize]: module "preprocess" returns ok for request 0 
rlm_ora3arts : - encode_context 
rlm_ora3arts (ora3arts): Reserving sql socket id: 29 
preparing statement begin :result := t3arts42.iradius.authorize(:context);
end; 
executing statement begin :result := t3arts42.iradius.authorize(:context);
end; 
Thread 2 waiting to be assigned a request 
Thread 3 waiting to be assigned a request 
statement executed begin :result := t3arts42.iradius.authorize(:context);
end; 
result encoded context
result:n=1;Cisco-AVPair:589825:s=shell:priv-lvl=14;Service-Type:6:n=7; 
parsing reply
result:n=1;Cisco-AVPair:589825:s=shell:priv-lvl=14;Service-Type:6:n=7; 
parsing attribute result:n=1 
parsing attribute Cisco-AVPair:589825:s=shell:priv-lvl=14 
creating pair Cisco-AVPair shell:priv-lvl=14 
Cisco-AVPair = "shell:priv-lvl=14" 
parsing attribute Service-Type:6:n=7 
creating pair Service-Type 7 
Service-Type = NAS-Prompt-User 
reply parsed , returning 1 
Cisco-AVPair = "shell:priv-lvl=14" 
Service-Type = NAS-Prompt-User 
rlm_ora3arts: check items 
Auth-Type = Accept 
rlm_ora3arts: reply items 
Cisco-AVPair = "shell:priv-lvl=14" 
Service-Type = NAS-Prompt-User 
rlm_ora3arts (ora3arts): Released sql socket id: 29 
returning OK 
modcall[authorize]: module "ora3arts" returns ok for request 0 
radius_xlat: '/u01/radius_data/detail-20070327' 
rlm_detail: /u01/radius_data/detail-%Y%m%d expands to
/u01/radius_data/detail-20070327 
modcall[authorize]: module "auth_log" returns ok for request 0 
modcall: group authorize returns ok for request 0 
rad_check_password: Found Auth-Type Accept 
rad_check_password: Auth-Type = Accept, accepting the user 
Login OK: [dialog/test1] (from client localhost port 0) 
Processing the post-auth section of radiusd.conf 
modcall: entering group post-auth for request 0 
radius_xlat: '/u01/radius_data/detail-20070327' 
rlm_detail: /u01/radius_data/detail-%Y%m%d expands to
/u01/radius_data/detail-20070327 
modcall[post-auth]: module "reply_log" returns ok for request 0 
modcall: group post-auth returns ok for request 0 
Sending Access-Accept of id 62 to 192.168.12.22:1326 
Cisco-AVPair = "shell:priv-lvl=14" 
Service-Type = NAS-Prompt-User 
Finished request 0 
Going to the next request 
Thread 1 waiting to be assigned a request 
--- Walking the entire request list --- 
Cleaning up request 0 ID 62 with timestamp 4608ed7f 
Nothing to do. Sleeping until we see a request. 
Threads: total/active/spare threads = 3/0/3 
----------------------------------------------------------------------------
---------------------------------------------------------
 
Perhaps some of you know how to solve this problem? 
Greg 


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20070329/48209ca5/attachment.html>