refresh Session-Timeout in Access-Accept

bLn pruebasradius at gmail.com
Mon Jan 26 13:37:17 CET 2009


tnt at kalik.net escribió:
>> Hi again,
>>
>> I use that operator :=
>>
>>     
>
> Post the debug then.
>
> Ivan Kalik
> Kalik Informatika ISP
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>
>   
hi again,

I post my debug:

**
Ready to process requests.
rad_recv: Access-Request packet from host xx.xx.xx.xx port 27230, id=27, 
length=212
        NAS-Port-Type = Wireless-802.11
        Calling-Station-Id = "00:15:C5:72:9E:D2"
        Called-Station-Id = "hotspot1"
        NAS-Port-Id = "ether2"
        User-Name = "belen at wifiya.com"
        NAS-Port = 2156920840
        Acct-Session-Id = "80900008"
        Framed-IP-Address = 192.168.10.5
        Mikrotik-Host-IP = 192.168.10.5
        CHAP-Challenge = 0xcfb6c69e706cf277bacb734dbab2d57c
        CHAP-Password = 0x80ade15e6b644f755e95c481630aee5393
        Service-Type = Login-User
        WISPr-Logoff-URL = "http://192.168.1.1/logout"
        NAS-Identifier = "pruebas wiloc"
        NAS-IP-Address = 192.168.1.11
+- entering group authorize {...}
++[preprocess] returns ok
[chap] Setting 'Auth-Type := CHAP'
++[chap] returns ok
++[mschap] returns noop
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
++[unix] returns notfound
[sql]   expand: %{User-Name} -> belen at wifiya.com
[sql] sql_set_user escaped user --> 'belen at wifiya.com'
rlm_sql (sql): Reserving sql socket id: 4
[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 = 'belen at wifiya.com'           ORDER BY id
[sql] User found in radcheck table
[sql]   expand: SELECT groupname           FROM usergroup           
WHERE username = '%{SQL-User-Name}'           ORDER BY id -> SELECT 
groupname           FROM usergroup           WHERE username = 
'belen at wifiya.com'           ORDER BY id
[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 = 'Navega24horas'           ORDER BY id
[sql] User found in group Navega24horas
[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 = 'Navega24horas'           
ORDER BY id
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
Found Auth-Type = CHAP
+- entering group CHAP {...}
[chap] login attempt by "belen at wifiya.com" with CHAP password
[chap] Using clear text password "*******" for user belen at wifiya.com 
authentication.
[chap] chap user belen at wifiya.com authenticated succesfully
++[chap] returns ok
Login OK: [belen at wifiya.com/<CHAP-Password>] (from client malditaprueba 
port 2156920840 cli 00:15:C5:72:9E:D2)
+- entering group post-auth {...}
[sql]   expand: %{User-Name} -> belen at wifiya.com
[sql] sql_set_user escaped user --> 'belen at wifiya.com'
[sql]   expand: %{User-Password} ->
[sql]   expand: %{Chap-Password} -> 0x80ade15e6b644f755e95c481630aee5393
[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 (                           
'belen at wifiya.com',                           
'0x80ade15e6b644f755e95c481630aee5393',                           
'Access-Accept', '2009-01-26 13:11:49')
rlm_sql (sql) in sql_postauth: query is INSERT INTO 
radpostauth                           (username, pass, reply, 
authdate)                           VALUES (                           
'belen at wifiya.com',                           
'0x80ade15e6b644f755e95c481630aee5393',                           
'Access-Accept', '2009-01-26 13:11:49')
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
[sql_log] Processing sql_log_postauth
[sql_log]       expand: %{User-Name} -> belen at wifiya.com
[sql_log]       expand: %{%{User-Name}:-DEFAULT} -> belen at wifiya.com
[sql_log] sql_set_user escaped user --> 'belen at wifiya.com'
[sql_log] WARNING: Deprecated conditional expansion ":-".  See "man 
unlang" for details
[sql_log]       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                        ('belen at wifiya.com', 
'Chap-Password',            'Access-Accept', '2009-01-26 13:11:49');
[sql_log]       expand: 
/usr/local/freeradius/var/log/radius/radacct/sql-relay -> 
/usr/local/freeradius/var/log/radius/radacct/sql-relay
++[sql_log] returns ok
[exec]  expand: %{User-Name} -> belen at wifiya.com
Exec-Program output: VALOR 1(Username) ES belen at wifiya.com
Session-Timeout = 79845
Exec-Program-Wait: plaintext: VALOR 1(Username) ES belen at wifiya.com
*Session-Timeout = 79845*
Exec-Program: returned: 0
++[exec] returns ok
Sending Access-Accept of id 27 to xx.xx.xx.xx port 27230
        Idle-Timeout := 300
        Mikrotik-Rate-Limit := "128k/3M"
*        Session-Timeout := 80143*
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host xx.xx.xx.xx port 27230, id=27, 
length=212
Sending duplicate reply to client malditaprueba port 27230 - ID: 27
Sending Access-Accept of id 27 to xx.xx.xx.xx port 27230
Waking up in 4.9 seconds.
rad_recv: Accounting-Request packet from host xx.xx.xx.xx port 27232, 
id=28, length=154
        Acct-Status-Type = Start
        NAS-Port-Type = Wireless-802.11
        Calling-Station-Id = "00:15:C5:72:9E:D2"
        Called-Station-Id = "hotspot1"
        NAS-Port-Id = "ether2"
        User-Name = "belen at wifiya.com"
        NAS-Port = 2156920840
        Acct-Session-Id = "80900008"
        Framed-IP-Address = 192.168.10.5
        Mikrotik-Host-IP = 192.168.10.5
        Event-Timestamp = "Jan  1 1970 03:56:42 CET"
        NAS-Identifier = "pruebas wiloc"
        NAS-IP-Address = 192.168.1.11
        Acct-Delay-Time = 0
+- entering group preacct {...}
++[preprocess] returns ok
[acct_unique] Hashing 'NAS-Port = 2156920840,Client-IP-Address = 
83.150.207.2,NAS-IP-Address = 192.168.1.11,Acct-Session-Id = 
"80900008",User-Name = "belen at wifiya.com"'
[acct_unique] Acct-Unique-Session-ID = "ef62a1fd47a430c6".
++[acct_unique] returns ok
[suffix] Looking up realm "wifiya.com" for User-Name = "belen at wifiya.com"
[suffix] Found realm "wifiya.com"
[suffix] Adding Stripped-User-Name = "belen"
[suffix] Adding Realm = "wifiya.com"
[suffix] Accounting realm is LOCAL.
++[suffix] returns ok
++[files] returns noop
+- entering group accounting {...}
[detail]        expand: 
/usr/local/freeradius/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d 
-> /usr/local/freeradius/var/log/radius/radacct/83.150.207.2/detail-20090126
[detail] 
/usr/local/freeradius/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d 
expands to 
/usr/local/freeradius/var/log/radius/radacct/83.150.207.2/detail-20090126
[detail]        expand: %t -> Mon Jan 26 13:11:50 2009
++[detail] returns ok
[radutmp]       expand: /usr/local/freeradius/var/log/radius/radutmp -> 
/usr/local/freeradius/var/log/radius/radutmp
[radutmp]       expand: %{User-Name} -> belen at wifiya.com
++[radutmp] returns ok
[sql]   expand: %{User-Name} -> belen at wifiya.com
[sql] sql_set_user escaped user --> 'belen at wifiya.com'
[sql]   expand: %{Acct-Delay-Time} -> 0
[sql]   expand:            INSERT INTO radacct             
(acctsessionid,    acctuniqueid,     username,              
realm,            nasipaddress,     nasportid,              
nasporttype,      acctstarttime,    acctstoptime,              
acctsessiontime,  acctauthentic,    connectinfo_start,              
connectinfo_stop, acctinputoctets,  acctoutputoctets,              
calledstationid,  callingstationid, acctterminatecause,              
servicetype,      framedprotocol,   framedipaddress,              
acctstartdelay,   acctstopdelay)           VALUES             
('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',              
'%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}', 
'%{NAS-Port}',              '%{NAS-Port-Type}', '%S', NULL,              
'0', '%{Acct-Authentic}', '%{Connect-Info}',              '', '0', 
'0',              '%{Called-Station-Id}', '%{Calling-Station-Id}', 
'',              '%{Service-Type}', '%{Framed-Protocol}', 
'%{Framed-IP-Address}',              '%{%{Acct-Delay-T
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
[sql_log] Processing sql_log_accounting
[sql_log]       expand: %{User-Name} -> belen at wifiya.com
[sql_log]       expand: %{%{User-Name}:-DEFAULT} -> belen at wifiya.com
[sql_log] sql_set_user escaped user --> 'belen at wifiya.com'
[sql_log]       expand: INSERT INTO radacct (AcctSessionId, UserName,    
NASIPAddress, FramedIPAddress, AcctStartTime, AcctStopTime,     
AcctSessionTime, AcctTerminateCause) VALUES                      
('%{Acct-Session-Id}', '%{User-Name}', '%{NAS-IP-Address}',     
'%{Framed-IP-Address}', '%S', '0', '0', ''); -> INSERT INTO radacct 
(AcctSessionId, UserName,    NASIPAddress, FramedIPAddress, 
AcctStartTime, AcctStopTime,     AcctSessionTime, AcctTerminateCause) 
VALUES                     ('80900008', 'belen at wifiya.com', 
'192.168.1.11',         '192.168.10.5', '2009-01-26 13:11:50', '0', '0', 
'');
[sql_log]       expand: 
/usr/local/freeradius/var/log/radius/radacct/sql-relay -> 
/usr/local/freeradius/var/log/radius/radacct/sql-relay
++[sql_log] returns ok
[attr_filter.accounting_response]       expand: %{User-Name} -> 
belen at wifiya.com
 attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] returns updated
Sending Accounting-Response of id 28 to xx.xx.xx.xx port 27232
Finished request 1.
Cleaning up request 1 ID 28 with timestamp +10
Going to the next request
Waking up in 4.8 seconds.
Cleaning up request 0 ID 27 with timestamp +9

as you can see, my script update the database with value = 79845 but my 
Access-Accept packet send to the NAS = 80143, this is the before value 
set into the database.
I guess, the query to radgroupreply save this before value in some cache 
memory and not update it.
How can I send the new calculated value????

Regards.



More information about the Freeradius-Users mailing list