rlm_sqlcounter + PostgreSQL problem

[Miguel Cabrera]

Hi list!

I have a problem with the rlm_sqlcounter. It send the Session-Time-Out
correctly but when if check the time limit against the data base it
always return 0.  I've  added some debugging output and recompile.

This is the output:
Tue Jul  5 14:46:51 2005 : Debug: rlm_sqlcounter: Entering module authorize code
Tue Jul  5 14:46:51 2005 : Debug: sqlcounter_expand:  'SELECT
SUM(AcctSessionTime) FROM radacct WHERE UserName='%{User-Name}' AND
AcctStartTime > abstime(1120539600)'
Tue Jul  5 14:46:51 2005 : Debug: radius_xlat:  'SELECT
SUM(AcctSessionTime) FROM radacct WHERE UserName='ceruno' AND
AcctStartTime > abstime(1120539600)'
Tue Jul  5 14:46:51 2005 : Debug: sqlcounter_expand: 
'%{sqlcca3:SELECT SUM(AcctSessionTime) FROM radacct WHERE
UserName='ceruno' AND AcctStartTime > abstime(1120539600)}'
Tue Jul  5 14:46:51 2005 : Debug: rlm_sqlcounter: querystr:
%{%S:SELECT SUM(AcctSessionTime) FROM radacct WHERE UserName='ceruno'
AND AcctStartTime > abstime(1120539600)}
Tue Jul  5 14:46:51 2005 : Debug: rlm_sqlcounter: responsestr:
%{sqlcca3:SELECT SUM(AcctSessionTime) FROM radacct WHERE
UserName='ceruno' AND AcctStartTime > abstime(1120539600)}
Tue Jul  5 14:46:51 2005 : Debug: rlm_sqlcounter: Valor obtenido de la
consulta: 0
Tue Jul  5 14:46:51 2005 : Debug: rlm_sqlcounter: Valor a checkar: 90
Tue Jul  5 14:46:51 2005 : Debug: rlm_sqlcounter: (Check item -
counter) is greater than zero
Tue Jul  5 14:46:51 2005 : Debug: rlm_sqlcounter: Authorized user
ceruno, check_item=90, counter=0
Tue Jul  5 14:46:51 2005 : Debug: rlm_sqlcounter: Sent Reply-Item for
user ceruno, Type=Session-Timeout, value=90
Tue Jul  5 14:46:51 2005 : Debug:   modsingle[authorize]: returned
from dailycounter (rlm_sqlcounter) for request 9
Tue Jul  5 14:46:51 2005 : Debug:   modcall[authorize]: module
"dailycounter" returns ok for request 9
Tue Jul  5 14:46:51 2005 : Debug:   modsingle[authorize]: calling
monthlycounter (rlm_sqlcounter) for request 9
Tue Jul  5 14:46:51 2005 : Debug: rlm_sqlcounter: Entering module authorize code
Tue Jul  5 14:46:51 2005 : Debug: rlm_sqlcounter: Could not find Check
item value pair
Tue Jul  5 14:46:51 2005 : Debug:   modsingle[authorize]: returned
from monthlycounter (rlm_sqlcounter) for request 9
Tue Jul  5 14:46:51 2005 : Debug:   modcall[authorize]: module
"monthlycounter" returns noop for request 9
Tue Jul  5 14:46:51 2005 : Debug: modcall: group authorize returns ok
for request 9
Tue Jul  5 14:46:51 2005 : Debug:   rad_check_password:  Found Auth-Type System
Tue Jul  5 14:46:51 2005 : Debug: auth: type "System"
Tue Jul  5 14:46:51 2005 : Debug:   Processing the authenticate
section of radiusd.conf
Tue Jul  5 14:46:51 2005 : Debug: modcall: entering group authenticate
for request 9
Tue Jul  5 14:46:51 2005 : Debug:   modsingle[authenticate]: calling
unix (rlm_unix) for request 9
Tue Jul  5 14:46:51 2005 : Debug:   modsingle[authenticate]: returned
from unix (rlm_unix) for request 9
Tue Jul  5 14:46:51 2005 : Debug:   modcall[authenticate]: module
"unix" returns ok for request 9
Tue Jul  5 14:46:51 2005 : Debug: modcall: group authenticate returns
ok for request 9


Looking at the code in rlm_sqlcounter.c in the sqlcounter_authorize
function (the lines starting with * is what I've added).

/* third, wrap query with sql module & expand */
	sprintf(querystr, "%%{%%S:%s}", responsestr);
        sqlcounter_expand(responsestr, MAX_QUERY_LEN, querystr, instance);

	/* Finally, xlat resulting SQL query */
	radius_xlat(querystr, MAX_QUERY_LEN, responsestr, request, NULL);

*	DEBUG2("rlm_sqlcounter: querystr: %s",querystr);
*	DEBUG2("rlm_sqlcounter: responsestr: %s",responsestr);
	counter = atoi(querystr);
	
*	DEBUG2("rlm_sqlcounter: Valor obtenido de la consulta: %d",counter);
*	DEBUG2("rlm_sqlcounter: Valor a checkar: %d",check_vp->lvalue);
	
If you compare the output above you will note that when 'counter =
atoi(querystr)' happens the value of querystr is : ' %{%S:SELECT
SUM(AcctSessionTime) FROM radacct WHERE UserName='ceruno' AND
AcctStartTime > abstime(1120539600)}' . So I think is maybe a bug.

I also have  a question:  Where the SQL query really happens? I
couldn't figure it out :(

I'am runnig in a FC3 with PostgreSQL 7.4.8 and the last stable release
of freeRadius. (Version 1.0.4)

I'll appreciate any help you can give me.

Miguel.