rad_recv: Access-Request packet from host 127.0.0.1 port 47871, id=159, length=84
User-Name = "KV60Rp2vtrEe5B"
User-Password = "yuxNtwKbSH"
NAS-IP-Address = 31.241.205.211
NAS-Port = 1812
Message-Authenticator = 0x2e53acc3936310719d3dc335a640afd4
# Executing section authorize from file /etc/raddb/sites-enabled/default
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
++[digest] returns noop
[suffix] No '@' in User-Name = "KV60Rp2vtrEe5B", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
[sql] expand: %{User-Name} -> KV60Rp2vtrEe5B
[sql] sql_set_user escaped user --> 'KV60Rp2vtrEe5B'
rlm_sql (sql): Reserving sql socket id: 3
[sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'KV60Rp2vtrEe5B' ORDER BY id
[sql] User found in radcheck table
[sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'KV60Rp2vtrEe5B' ORDER BY id
[sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'KV60Rp2vtrEe5B' ORDER BY priority
[sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'One_Hour_Access' ORDER BY id
[sql] User found in group One_Hour_Access
[sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'One_Hour_Access' ORDER BY id
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[pap] returns updated
rlm_counter: Entering module authorize code
rlm_counter: Could not find Check item value pair
++[daily] returns noop
rlm_sqlcounter: Entering module authorize code
sqlcounter_expand: 'SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='User-Name''
[noresetcounter] expand: SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='User-Name' -> SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='User-Name'
WARNING: Please replace '%S' with '${sqlmod-inst}'
sqlcounter_expand: '%{sql:SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='User-Name'}'
[noresetcounter] sql_xlat
[noresetcounter] expand: %{User-Name} -> KV60Rp2vtrEe5B
[noresetcounter] sql_set_user escaped user --> 'KV60Rp2vtrEe5B'
[noresetcounter] expand: SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='User-Name' -> SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='User-Name'
rlm_sql (sql): Reserving sql socket id: 2
[noresetcounter] sql_xlat finished
rlm_sql (sql): Released sql socket id: 2
[noresetcounter] expand: %{sql:SELECT IFNULL(SUM(AcctSessionTime),0) FROM radacct WHERE UserName='User-Name'} -> 0
rlm_sqlcounter: Check item is greater than query result
rlm_sqlcounter: Authorized user KV60Rp2vtrEe5B, check_item=3600, counter=0 <------- This Value
rlm_sqlcounter: Sent Reply-Item for user KV60Rp2vtrEe5B, Type=Session-Timeout, value=3600
++[noresetcounter] returns ok
[expiration] Checking Expiration time: '10 Jan 2013'
++[expiration] returns ok
++[logintime] returns noop
Found Auth-Type = PAP
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!! Replacing User-Password in config items with Cleartext-Password. !!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!! Please update your configuration so that the "known good" !!!
!!! clear text password is in Cleartext-Password, and not in User-Password. !!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
# Executing group from file /etc/raddb/sites-enabled/default
+- entering group PAP {...}
[pap] login attempt with password "yuxNtwKbSH"
[pap] Using clear text password "yuxNtwKbSH"
[pap] User authenticated successfully
++[pap] returns ok
# Executing section session from file /etc/raddb/sites-enabled/default
+- entering group session {...}
[radutmp] expand: /var/log/radius/radutmp -> /var/log/radius/radutmp
[radutmp] expand: %{User-Name} -> KV60Rp2vtrEe5B
++[radutmp] returns ok
# Executing section post-auth from file /etc/raddb/sites-enabled/default
+- entering group post-auth {...}
[sql] expand: %{User-Name} -> KV60Rp2vtrEe5B
[sql] sql_set_user escaped user --> 'KV60Rp2vtrEe5B'
[sql] expand: %{User-Password} -> yuxNtwKbSH
[sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'KV60Rp2vtrEe5B', 'yuxNtwKbSH', 'Access-Accept', '2013-01-07 08:41:59')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'KV60Rp2vtrEe5B', 'yuxNtwKbSH', 'Access-Accept', '2013-01-07 08:41:59')
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
++[exec] returns noop
Sending Access-Accept of id 159 to 127.0.0.1 port 47871
Session-Timeout := 3600
Idle-Timeout := 60
Acct-Interim-Interval := 120
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 0 ID 159 with timestamp +311
Ready to process requests.
Why rlm_counter returns the zero value.