rad_recv: Accounting-Request packet from host *SOURCE-HOST-IP* port 1814, id=90, length=219 Acct-Session-Id = "0000332C" Framed-Protocol = PPP Framed-IP-Address = *FRAMED-IP-ADDRESS* User-Name = "IPASS/*USERNAME*" X-Ascend-Connect-Progress = LAN-Session-Up Acct-Authentic = RADIUS Acct-Status-Type = Start Calling-Station-Id = "0123454229" Called-Station-Id = "0300" NAS-Port-Type = Async Connect-Info = "45333/26400 V90/V42bis/LAPM" NAS-Port = 273 NAS-Port-Id = "Async1/57" Service-Type = Framed-User NAS-IP-Address = *NAS-IP-ADDRESS* Acct-Delay-Time = 58387 UPSTREAMPROVIDER-Access-Type = "DIAL" Proxy-State = 0x3139 Proxy-State = 0x3239393537 server default { # Executing section preacct from file /etc/freeradius/sites-enabled/default +- entering group preacct {...} sql_xlat expand: %{Stripped-User-Name} -> ... expanding second conditional expand: %{User-Name} -> IPASS/*USERNAME* expand: %{%{Stripped-User-Name}:-%{User-Name}} -> IPASS/*USERNAME* sql_set_user escaped user --> 'IPASS/*USERNAME*' expand: SELECT server FROM nas WHERE nasname = '%{NAS-IP-Address}' -> SELECT server FROM nas WHERE nasname = '*NAS-IP-ADDRESS*' expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql rlm_sql (sql): Reserving sql socket id: 118 rlm_sql_mysql: query: SELECT server FROM nas WHERE nasname = '*NAS-IP-ADDRESS*' SQL query did not return any results rlm_sql (sql): Released sql socket id: 118 expand: %{sql: SELECT server FROM nas WHERE nasname = '%{NAS-IP-Address}'} -> ... expanding second conditional expand: %{%{sql: SELECT server FROM nas WHERE nasname = '%{NAS-IP-Address}'}:-UPSTREAMPROVIDER} -> UPSTREAMPROVIDER ++[control] returns noop WARNING: Empty accounting section. Using default return values. } # server default WARNING: Empty pre-proxy section. Using default return values. >>> Sending proxied request internally to virtual server. server UPSTREAMPROVIDER { # Executing section preacct from file /etc/freeradius/sites-enabled/UPSTREAMPROVIDER +- entering group preacct {...} ++[preprocess] returns ok [acct_unique] Hashing 'NAS-IP-Address = *NAS-IP-ADDRESS*,Acct-Session-Id = "0000332C",User-Name = "IPASS/*USERNAME*"' [acct_unique] Acct-Unique-Session-ID = "0639689086600ad6". ++[acct_unique] returns ok [IPASS] Looking up realm "IPASS" for User-Name = "IPASS/*USERNAME*" [IPASS] Found realm "IPASS" [IPASS] Adding Realm = "IPASS" [IPASS] Proxying request from user *USERNAME* to realm IPASS [IPASS] Preparing to proxy accounting request to realm "IPASS" ++[IPASS] returns updated [KING] Request already proxied. Ignoring. ++[KING] returns ok [KDIAL] Request already proxied. Ignoring. ++[KDIAL] returns ok [KADSL] Request already proxied. Ignoring. ++[KADSL] returns ok # Executing section accounting from file /etc/freeradius/sites-enabled/UPSTREAMPROVIDER +- entering group accounting {...} expand: %{Packet-Src-IP-Address} -> *SOURCE-HOST-IP* ++- entering switch %{Packet-Src-IP-Address} {...} +++- entering case *SOURCE-HOST-IP* {...} ++++[ok] returns ok +++- case *SOURCE-HOST-IP* returns ok ++- switch %{Packet-Src-IP-Address} returns ok rlm_perl: Added pair NAS-Port-Type = Async rlm_perl: Added pair X-Ascend-Connect-Progress = LAN-Session-Up rlm_perl: Added pair Acct-Session-Id = 0000332C rlm_perl: Added pair UPSTREAMPROVIDER-Access-Type = DIAL rlm_perl: Added pair Proxy-State = 0x3139 rlm_perl: Added pair Proxy-State = 0x3239393537 rlm_perl: Added pair Proxy-State = 0x3930 rlm_perl: Added pair Service-Type = Framed-User rlm_perl: Added pair Acct-Unique-Session-Id = 0639689086600ad6 rlm_perl: Added pair Called-Station-Id = 0300 rlm_perl: Added pair Acct-Authentic = RADIUS rlm_perl: Added pair Acct-Status-Type = Start rlm_perl: Added pair Connect-Info = 45333/26400 V90/V42bis/LAPM rlm_perl: Added pair Realm = IPASS rlm_perl: Added pair NAS-IP-Address = *NAS-IP-ADDRESS* rlm_perl: Added pair NAS-Port-Id = Async1/57 rlm_perl: Added pair SQL-User-Name = IPASS/*USERNAME* rlm_perl: Added pair Calling-Station-Id = 0123454229 rlm_perl: Added pair Framed-Protocol = PPP rlm_perl: Added pair User-Name = IPASS/*USERNAME* rlm_perl: Added pair Framed-IP-Address = *FRAMED-IP-ADDRESS* rlm_perl: Added pair NAS-Port = 273 rlm_perl: Added pair Acct-Delay-Time = 58387 rlm_perl: Added pair Proxy-To-Realm = IPASS ++[perl] returns noop [sql] expand: %{Stripped-User-Name} -> [sql] ... expanding second conditional [sql] expand: %{User-Name} -> IPASS/*USERNAME* [sql] expand: %{%{Stripped-User-Name}:-%{User-Name}} -> IPASS/*USERNAME* [sql] sql_set_user escaped user --> 'IPASS/*USERNAME*' [sql] expand: %{UPSTREAMPROVIDER-Access-Type} -> DIAL [sql] expand: %{Acct-Delay-Time} -> 58387 [sql] expand: INSERT INTO radacct (acctsessionid, acctuniqueid, username, groupname, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey, class) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{%{UPSTREAMPROVIDER-Access-Type}:-WIRELESS}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', [sql] expand: /var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql rlm_sql (sql): Reserving sql socket id: 117 rlm_sql_mysql: query: INSERT INTO radacct (acctsessionid, acctuniqueid, username, groupname, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey, class) VALUES ('0000332C', '0639689086600ad6', 'IPASS/*USERNAME*', 'DIAL', 'IPASS', '*NAS-IP-ADDRESS*', '273', 'Async', '2011-04-15 09:37:50', NULL, '0', 'RADIUS', '45333/26400 V90/V42bis/LAPM', '', '0', '0', '0300', '0123454229', '', 'Framed-User', 'PPP', '*FRAMED-IP-ADDRESS*', '58387', '0', '', '') rlm_sql (sql): Released sql socket id: 117 ++[sql] returns ok ++? if (noop) ? Evaluating (noop) -> FALSE ++? if (noop) -> FALSE expand: %{request:Acct-Session-Id} -> 0000332C ++- entering switch %{request:Acct-Session-Id} {...} +++- entering case {...} [sradutmp] expand: /var/log/freeradius/sradutmp -> /var/log/freeradius/sradutmp [sradutmp] expand: %{User-Name} -> IPASS/*USERNAME* rlm_radutmp: Login entry for NAS *NAS-IP-ADDRESS* port 273 duplicate ++++[sradutmp] returns ok +++- case returns ok ++- switch %{request:Acct-Session-Id} returns ok [attr_filter.accounting_response] expand: %{User-Name} -> IPASS/*USERNAME* attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated } # server UPSTREAMPROVIDER Going to the next request <<< Received proxied response code 0 from internal virtual server. WARNING: Empty post-proxy section. Using default return values. Finished request 2. Cleaning up request 2 ID 90 with timestamp +115 Going to the next request Ready to process requests.