<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">
<html>
<head>
<meta http-equiv="content-type" content="text/html; charset=ISO-8859-1">
</head>
<body bgcolor="#ffffff" text="#000000">
<font size="-1">Hi ,<br>
<br>
I have a problem with some user proxied.<br>
<br>
In the accounting-request the username is stripped and realm is
NULL.<br>
<br>
Why le realm is lost?<br>
<br>
here is le debug output.<br>
<br>
<br>
<br>
rad_recv: Access-Request packet from host 192.168.58.5 port 20007,
id=13, length=256<br>
NAS-Port-Id = "AP59/1"<br>
Calling-Station-Id = "98-0C-82-A0-9C-53"<br>
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"<br>
Service-Type = Framed-User<br>
User-Name = <a class="moz-txt-link-rfc2396E" href="mailto:pierre.dupont@univ-lille1.fr">"pierre.dupont@univ-lille1.fr"</a><br>
NAS-Port = 13815<br>
State = 0xce6b1f07c76006eefba5daa495da75ed<br>
EAP-Message =
0x020b005019001703010020c523a88c2350d93086ec64726de2c365f717579f7b45e134cdc419b070885ab1170301002088cce6caf3b1d263d7731cb2b8c1c6e20b1967450888d652b5dc399cd6c8fe1a<br>
NAS-Port-Type = Wireless-802.11<br>
NAS-IP-Address = 192.168.58.5<br>
NAS-Identifier = "Trapeze"<br>
Message-Authenticator = 0x318ab29add69625365a854e67782de40<br>
Wed Feb 6 10:08:07 2013 : Info: # Executing section authorize
from file /etc/freeradius/sites-enabled/eduroam<br>
Wed Feb 6 10:08:07 2013 : Info: +- entering group authorize {...}<br>
Wed Feb 6 10:08:07 2013 : Info: ++[preprocess] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: ++? if (User-name !~
/^([^@]*)@(.+)$/)<br>
Wed Feb 6 10:08:07 2013 : Info: ? Evaluating (User-name !~
/^([^@]*)@(.+)$/) -> FALSE<br>
Wed Feb 6 10:08:07 2013 : Info: ++? if (User-name !~
/^([^@]*)@(.+)$/) -> FALSE<br>
Wed Feb 6 10:08:07 2013 : Info: ++- entering else else {...}<br>
Wed Feb 6 10:08:07 2013 : Info: +++[ok] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: ++- else else returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: ++[mschap] returns noop<br>
Wed Feb 6 10:08:07 2013 : Info: [suffix] Looking up realm
"univ-lille1.fr" for User-Name = <a class="moz-txt-link-rfc2396E" href="mailto:pierre.dupont@univ-lille1.fr">"pierre.dupont@univ-lille1.fr"</a><br>
Wed Feb 6 10:08:07 2013 : Info: [suffix] Found realm "~.+$"<br>
Wed Feb 6 10:08:07 2013 : Info: [suffix] Adding Realm =
"univ-lille1.fr"<br>
Wed Feb 6 10:08:07 2013 : Info: [suffix] Proxying request from
user pierre.dupont to realm ~.+$<br>
Wed Feb 6 10:08:07 2013 : Info: [suffix] Preparing to proxy
authentication request to realm "~.+$" <br>
Wed Feb 6 10:08:07 2013 : Info: ++[suffix] returns updated<br>
Wed Feb 6 10:08:07 2013 : Info: [eap] Request is supposed to be
proxied to Realm ~.+$. Not doing EAP.<br>
Wed Feb 6 10:08:07 2013 : Info: ++[eap] returns noop<br>
Wed Feb 6 10:08:07 2013 : Info: ++[pap] returns noop<br>
Wed Feb 6 10:08:07 2013 : Info: # Executing section pre-proxy
from file /etc/freeradius/sites-enabled/eduroam<br>
Wed Feb 6 10:08:07 2013 : Info: +- entering group pre-proxy {...}<br>
Wed Feb 6 10:08:07 2013 : Info: [pre_proxy_log] expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d
->
/var/log/freeradius/radacct/192.168.58.5/pre-proxy-detail-20130206<br>
Wed Feb 6 10:08:07 2013 : Info: [pre_proxy_log]
/var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d
expands to
/var/log/freeradius/radacct/192.168.58.5/pre-proxy-detail-20130206<br>
Wed Feb 6 10:08:07 2013 : Info: [pre_proxy_log] expand: %t
-> Wed Feb 6 10:08:07 2013<br>
Wed Feb 6 10:08:07 2013 : Info: ++[pre_proxy_log] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: ++? if (Packet-Type !=
Accounting-Request)<br>
Wed Feb 6 10:08:07 2013 : Info: ? Evaluating (Packet-Type !=
Accounting-Request) -> FALSE<br>
Wed Feb 6 10:08:07 2013 : Info: ++? if (Packet-Type !=
Accounting-Request) -> FALSE<br>
Sending Access-Request of id 223 to 193.51.224.109 port 1812<br>
NAS-Port-Id = "AP59/1"<br>
Calling-Station-Id = "98-0C-82-A0-9C-53"<br>
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"<br>
Service-Type = Framed-User<br>
User-Name = <a class="moz-txt-link-rfc2396E" href="mailto:pierre.dupont@univ-lille1.fr">"pierre.dupont@univ-lille1.fr"</a><br>
NAS-Port = 13815<br>
State = 0xce6b1f07c76006eefba5daa495da75ed<br>
EAP-Message =
0x020b005019001703010020c523a88c2350d93086ec64726de2c365f717579f7b45e134cdc419b070885ab1170301002088cce6caf3b1d263d7731cb2b8c1c6e20b1967450888d652b5dc399cd6c8fe1a<br>
NAS-Port-Type = Wireless-802.11<br>
NAS-IP-Address = 192.168.58.5<br>
NAS-Identifier = "Trapeze"<br>
Message-Authenticator = 0x00000000000000000000000000000000<br>
Proxy-State = 0x3133<br>
Wed Feb 6 10:08:07 2013 : Info: Proxying request 223 to home
server 193.51.224.109 port 1812<br>
Sending Access-Request of id 223 to 193.51.224.109 port 1812<br>
NAS-Port-Id = "AP59/1"<br>
Calling-Station-Id = "98-0C-82-A0-9C-53"<br>
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"<br>
Service-Type = Framed-User<br>
User-Name = <a class="moz-txt-link-rfc2396E" href="mailto:pierre.dupont@univ-lille1.fr">"pierre.dupont@univ-lille1.fr"</a><br>
NAS-Port = 13815<br>
State = 0xce6b1f07c76006eefba5daa495da75ed<br>
EAP-Message =
0x020b005019001703010020c523a88c2350d93086ec64726de2c365f717579f7b45e134cdc419b070885ab1170301002088cce6caf3b1d263d7731cb2b8c1c6e20b1967450888d652b5dc399cd6c8fe1a<br>
NAS-Port-Type = Wireless-802.11<br>
NAS-IP-Address = 192.168.58.5<br>
NAS-Identifier = "Trapeze"<br>
Message-Authenticator = 0x00000000000000000000000000000000<br>
Proxy-State = 0x3133<br>
Wed Feb 6 10:08:07 2013 : Debug: Going to the next request<br>
Wed Feb 6 10:08:07 2013 : Debug: Waking up in 0.9 seconds.<br>
rad_recv: Access-Accept packet from host 193.51.224.109 port 1812,
id=223, length=182<br>
User-Name = "pierre.dupont\000"<br>
MS-MPPE-Recv-Key =
0x948d791f2da3af530868839e7df666aa1886290c40bfe70643d3cc079f9c24f4<br>
MS-MPPE-Send-Key =
0x0a525d10d48467385a134bf6b1c4bee916e17fd24016a6f6c01b35ef243f07b2<br>
EAP-Message = 0x030b0004<br>
Message-Authenticator = 0xf6f125f6e9767f4dc8f9decb26a31021<br>
Proxy-State = 0x3133<br>
Wed Feb 6 10:08:07 2013 : Info: # Executing section post-proxy
from file /etc/freeradius/sites-enabled/eduroam<br>
Wed Feb 6 10:08:07 2013 : Info: +- entering group post-proxy
{...}<br>
Wed Feb 6 10:08:07 2013 : Info: [post_proxy_log] expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d
->
/var/log/freeradius/radacct/192.168.58.5/post-proxy-detail-20130206<br>
Wed Feb 6 10:08:07 2013 : Info: [post_proxy_log]
/var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d
expands to
/var/log/freeradius/radacct/192.168.58.5/post-proxy-detail-20130206<br>
Wed Feb 6 10:08:07 2013 : Info: [post_proxy_log] expand: %t
-> Wed Feb 6 10:08:07 2013<br>
Wed Feb 6 10:08:07 2013 : Info: ++[post_proxy_log] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: [eap] No pre-existing handler
found<br>
Wed Feb 6 10:08:07 2013 : Info: ++[eap] returns noop<br>
Wed Feb 6 10:08:07 2013 : Info: Found Auth-Type = Accept<br>
Wed Feb 6 10:08:07 2013 : Info: Auth-Type = Accept, accepting the
user<br>
Wed Feb 6 10:08:07 2013 : Info: # Executing section post-auth
from file /etc/freeradius/sites-enabled/eduroam<br>
Wed Feb 6 10:08:07 2013 : Info: +- entering group post-auth {...}<br>
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand:
%{reply:Packet-Type} -> Access-Accept<br>
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand:
%{%{reply:Packet-Type}:-format} -> Access-Accept<br>
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand:
/var/log/freeradius/linelog.log ->
/var/log/freeradius/linelog.log<br>
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand: %S
%{reply:Packet-Type} %{Packet-Src-IP-Address}
%{NAS-IP-Address} %{Client-Shortname} %{User-Name}
%{Calling-Station-Id} %{Called-Station-Id} -> 2013-02-06
10:08:07 Access-Accept 192.168.58.5 192.168.58.5
MX800R-2 <a class="moz-txt-link-abbreviated" href="mailto:pierre.dupont@univ-lille1.fr">pierre.dupont@univ-lille1.fr</a> 98-0C-82-A0-9C-53
00-26-3E-70-6F-C0:eduroam<br>
Wed Feb 6 10:08:07 2013 : Info: ++[linelog] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand:
%{reply:Packet-Type} -> Access-Accept<br>
Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand:
f_ticks.%{%{reply:Packet-Type}:-format} ->
f_ticks.Access-Accept<br>
Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand:
/var/log/freeradius/f_ticks.log ->
/var/log/freeradius/f_ticks.log<br>
Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand: %S -
F-TICKS/eduroam/1.0#REALM=%{Realm}#VISCOUNTRY=FR#VISINST=LILLE3#CSI=%{Calling-Station-Id}#RESULT=OK
-> 2013-02-06 10:08:07 -
F-TICKS/eduroam/1.0#REALM=univ-lille1.fr#VISCOUNTRY=FR#VISINST=LILLE3#CSI=98-0C-82-A0-9C-53#RESULT=OK<br>
Wed Feb 6 10:08:07 2013 : Info: ++[f_ticks] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: expand: %{Realm} ->
univ-lille1.fr<br>
Wed Feb 6 10:08:07 2013 : Info: ++- entering switch %{Realm}
{...}<br>
Wed Feb 6 10:08:07 2013 : Info: +++- switch %{Realm} returns noop<br>
Wed Feb 6 10:08:07 2013 : Info: ++- group post-auth returns noop<br>
Wed Feb 6 10:08:07 2013 : Info: ++? if (("%{Realm}" !~
/^(ext\.|etu\.|)univ-lille3\.fr$/) &&
("%{Called-Station-Id}" =~
/^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/))<br>
Wed Feb 6 10:08:07 2013 : Info: expand: %{Realm} ->
univ-lille1.fr<br>
Wed Feb 6 10:08:07 2013 : Info: ?? Evaluating ("%{Realm}" !~
/^(ext\.|etu\.|)univ-lille3\.fr$/) -> TRUE<br>
Wed Feb 6 10:08:07 2013 : Info: expand: %{Called-Station-Id}
-> 00-26-3E-70-6F-C0:eduroam<br>
Wed Feb 6 10:08:07 2013 : Info: ?? Evaluating
("%{Called-Station-Id}" =~
/^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/) -> TRUE<br>
Wed Feb 6 10:08:07 2013 : Info: ++? if (("%{Realm}" !~
/^(ext\.|etu\.|)univ-lille3\.fr$/) &&
("%{Called-Station-Id}" =~
/^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/)) -> TRUE<br>
Wed Feb 6 10:08:07 2013 : Info: ++- entering if (("%{Realm}" !~
/^(ext\.|etu\.|)univ-lille3\.fr$/) &&
("%{Called-Station-Id}" =~
/^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/)) {...}<br>
Wed Feb 6 10:08:07 2013 : Info: +++[reply] returns noop<br>
Wed Feb 6 10:08:07 2013 : Info: ++- if (("%{Realm}" !~
/^(ext\.|etu\.|)univ-lille3\.fr$/) &&
("%{Called-Station-Id}" =~
/^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/)) returns noop<br>
Wed Feb 6 10:08:07 2013 : Info: ++[exec] returns noop<br>
Sending Access-Accept of id 13 to 192.168.58.5 port 20007<br>
User-Name = "pierre.dupont\000"<br>
MS-MPPE-Recv-Key =
0x948d791f2da3af530868839e7df666aa1886290c40bfe70643d3cc079f9c24f4<br>
MS-MPPE-Send-Key =
0x0a525d10d48467385a134bf6b1c4bee916e17fd24016a6f6c01b35ef243f07b2<br>
EAP-Message = 0x030b0004<br>
Message-Authenticator = 0x00000000000000000000000000000000<br>
Tunnel-Type:0 = VLAN<br>
Tunnel-Medium-Type:0 = IEEE-802<br>
Tunnel-Private-Group-Id:0 = "56"<br>
Wed Feb 6 10:08:07 2013 : Info: Finished request 223.<br>
Wed Feb 6 10:08:07 2013 : Debug: Going to the next request<br>
Wed Feb 6 10:08:07 2013 : Debug: Waking up in 1.5 seconds.<br>
rad_recv: Accounting-Request packet from host 192.168.58.5 port
20007, id=14, length=222<br>
Acct-Status-Type = Start<br>
Acct-Authentic = RADIUS<br>
Acct-Multi-Session-Id = "SESS-13815-54b752-141653-ef2"<br>
Acct-Session-Id = "SESS-13815-54b752-141653-ef2"<br>
User-Name = "pierre.dupont"<br>
Event-Timestamp = "Feb 6 2013 10:08:07 CET"<br>
Trapeze-VLAN-Name = "EduExterieurs"<br>
Calling-Station-Id = "98-0C-82-A0-9C-53"<br>
NAS-Port-Id = "AP59/1"<br>
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"<br>
NAS-Port = 13815<br>
NAS-Port-Type = Wireless-802.11<br>
NAS-IP-Address = 192.168.58.5<br>
NAS-Identifier = "Trapeze"<br>
Acct-Delay-Time = 0<br>
Wed Feb 6 10:08:07 2013 : Info: # Executing section preacct from
file /etc/freeradius/sites-enabled/eduroam<br>
Wed Feb 6 10:08:07 2013 : Info: +- entering group preacct {...}<br>
Wed Feb 6 10:08:07 2013 : Info: ++[preprocess] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand:
%{reply:Packet-Type} -> 0<br>
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand:
%{%{reply:Packet-Type}:-format} -> 0<br>
Wed Feb 6 10:08:07 2013 : Debug: WARNING: No such configuration
item .0<br>
Wed Feb 6 10:08:07 2013 : Info: [linelog] No such entry ".0"<br>
Wed Feb 6 10:08:07 2013 : Info: ++[linelog] returns noop<br>
Wed Feb 6 10:08:07 2013 : Info: [acct_unique] Hashing 'NAS-Port =
13815,Client-IP-Address = 192.168.58.5,NAS-IP-Address =
192.168.58.5,Acct-Session-Id =
"SESS-13815-54b752-141653-ef2",User-Name = "pierre.dupont"'<br>
Wed Feb 6 10:08:07 2013 : Info: [acct_unique]
Acct-Unique-Session-ID = "98d6d9a9c729efc3".<br>
Wed Feb 6 10:08:07 2013 : Info: ++[acct_unique] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: [suffix] No '@' in User-Name =
"pierre.dupont", looking up realm NULL<br>
Wed Feb 6 10:08:07 2013 : Info: [suffix] Found realm "NULL"<br>
Wed Feb 6 10:08:07 2013 : Info: [suffix] Adding
Stripped-User-Name = "pierre.dupont"<br>
Wed Feb 6 10:08:07 2013 : Info: [suffix] Adding Realm = "NULL"<br>
Wed Feb 6 10:08:07 2013 : Info: [suffix] Accounting realm is
LOCAL.<br>
Wed Feb 6 10:08:07 2013 : Info: ++[suffix] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: # Executing section accounting
from file /etc/freeradius/sites-enabled/eduroam<br>
Wed Feb 6 10:08:07 2013 : Info: +- entering group accounting
{...}<br>
Wed Feb 6 10:08:07 2013 : Info: [detail] expand:
%{Packet-Src-IP-Address} -> 192.168.58.5<br>
Wed Feb 6 10:08:07 2013 : Info: [detail] expand:
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/freeradius/radacct/192.168.58.5/detail-20130206<br>
Wed Feb 6 10:08:07 2013 : Info: [detail]
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to
/var/log/freeradius/radacct/192.168.58.5/detail-20130206<br>
Wed Feb 6 10:08:07 2013 : Info: [detail] expand: %t -> Wed
Feb 6 10:08:07 2013<br>
Wed Feb 6 10:08:07 2013 : Info: ++[detail] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: [sql_acct] expand:
%{User-Name} -> pierre.dupont<br>
Wed Feb 6 10:08:07 2013 : Info: [sql_acct] sql_set_user escaped
user --> 'pierre.dupont'<br>
Wed Feb 6 10:08:07 2013 : Info: [sql_acct] expand:
%{Acct-Delay-Time} -> 0<br>
Wed Feb 6 10:08:07 2013 : Info: [sql_acct] 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, xascendsessionsvrkey)
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}', <br>
Wed Feb 6 10:08:07 2013 : Info: [sql_acct] expand:
/var/log/freeradius/sqltrace.sql ->
/var/log/freeradius/sqltrace.sql<br>
Wed Feb 6 10:08:07 2013 : Debug: rlm_sql (sql_acct): Reserving
sql socket id: 5<br>
Wed Feb 6 10:08:07 2013 : Debug: rlm_sql_mysql:
query: 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,
xascendsessionsvrkey) VALUES
('SESS-13815-54b752-141653-ef2', '98d6d9a9c729efc3',
'pierre.dupont', 'NULL', '192.168.58.5',
'13815', 'Wireless-802.11', '2013-02-06 10:08:07',
NULL, '0', 'RADIUS', '', '', '0',
'0', '00-26-3E-70-6F-C0:eduroam',
'98-0C-82-A0-9C-53', '', '', '', '',
'0', '0', '')<br>
Wed Feb 6 10:08:07 2013 : Debug: rlm_sql (sql_acct): Released sql
socket id: 5<br>
Wed Feb 6 10:08:07 2013 : Info: ++[sql_acct] returns ok<br>
Wed Feb 6 10:08:07 2013 : Info: ++[exec] returns noop<br>
Wed Feb 6 10:08:07 2013 : Info: [attr_filter.accounting_response]
expand: %{User-Name} -> pierre.dupont<br>
Wed Feb 6 10:08:07 2013 : Debug: attr_filter: Matched entry
DEFAULT at line 12<br>
Wed Feb 6 10:08:07 2013 : Info:
++[attr_filter.accounting_response] returns updated<br>
Sending Accounting-Response of id 14 to 192.168.58.5 port 20007<br>
Wed Feb 6 10:08:07 2013 : Info: Finished request 224.<br>
Wed Feb 6 10:08:07 2013 : Info: Cleaning up request 224 ID 14
with timestamp +229<br>
Wed Feb 6 10:08:07 2013 : Debug: Going to the next request<br>
Wed Feb 6 10:08:07 2013 : Debug: Waking up in 1.4 seconds.<br>
rad_recv: Accounting-Request packet from host 192.168.58.5 port
20007, id=16, length=258<br>
Acct-Status-Type = Interim-Update<br>
Acct-Authentic = RADIUS<br>
Acct-Multi-Session-Id = "SESS-13815-54b752-141653-ef2"<br>
Acct-Session-Id = "SESS-13815-54b752-141653-ef2"<br>
User-Name = "pierre.dupont"<br>
Event-Timestamp = "Feb 6 2013 10:08:09 CET"<br>
Trapeze-VLAN-Name = "EduExterieurs"<br>
Calling-Station-Id = "98-0C-82-A0-9C-53"<br>
NAS-Port-Id = "AP59/1"<br>
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"<br>
NAS-Port = 13815<br>
Framed-IP-Address = 10.56.0.149<br>
Acct-Session-Time = 2<br>
Acct-Output-Octets = 9330<br>
Acct-Input-Octets = 1202<br>
Acct-Output-Packets = 38<br>
Acct-Input-Packets = 230<br>
NAS-Port-Type = Wireless-802.11<br>
NAS-IP-Address = 192.168.58.5<br>
NAS-Identifier = "Trapeze"<br>
Acct-Delay-Time = 0<br>
Wed Feb 6 10:08:09 2013 : Info: # Executing section preacct from
file /etc/freeradius/sites-enabled/eduroam<br>
Wed Feb 6 10:08:09 2013 : Info: +- entering group preacct {...}<br>
Wed Feb 6 10:08:09 2013 : Info: ++[preprocess] returns ok<br>
Wed Feb 6 10:08:09 2013 : Info: [linelog] expand:
%{reply:Packet-Type} -> 0<br>
Wed Feb 6 10:08:09 2013 : Info: [linelog] expand:
%{%{reply:Packet-Type}:-format} -> 0<br>
Wed Feb 6 10:08:09 2013 : Debug: WARNING: No such configuration
item .0<br>
Wed Feb 6 10:08:09 2013 : Info: [linelog] No such entry ".0"<br>
Wed Feb 6 10:08:09 2013 : Info: ++[linelog] returns noop<br>
Wed Feb 6 10:08:09 2013 : Info: [acct_unique] Hashing 'NAS-Port =
13815,Client-IP-Address = 192.168.58.5,NAS-IP-Address =
192.168.58.5,Acct-Session-Id =
"SESS-13815-54b752-141653-ef2",User-Name = "pierre.dupont"'<br>
Wed Feb 6 10:08:09 2013 : Info: [acct_unique]
Acct-Unique-Session-ID = "98d6d9a9c729efc3".<br>
Wed Feb 6 10:08:09 2013 : Info: ++[acct_unique] returns ok<br>
Wed Feb 6 10:08:09 2013 : Info: [suffix] No '@' in User-Name =
"pierre.dupont", looking up realm NULL<br>
Wed Feb 6 10:08:09 2013 : Info: [suffix] Found realm "NULL"<br>
Wed Feb 6 10:08:09 2013 : Info: [suffix] Adding
Stripped-User-Name = "pierre.dupont"<br>
Wed Feb 6 10:08:09 2013 : Info: [suffix] Adding Realm = "NULL"<br>
Wed Feb 6 10:08:09 2013 : Info: [suffix] Accounting realm is
LOCAL.<br>
Wed Feb 6 10:08:09 2013 : Info: ++[suffix] returns ok<br>
Wed Feb 6 10:08:09 2013 : Info: # Executing section accounting
from file /etc/freeradius/sites-enabled/eduroam<br>
Wed Feb 6 10:08:09 2013 : Info: +- entering group accounting
{...}<br>
Wed Feb 6 10:08:09 2013 : Info: [detail] expand:
%{Packet-Src-IP-Address} -> 192.168.58.5<br>
Wed Feb 6 10:08:09 2013 : Info: [detail] expand:
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/freeradius/radacct/192.168.58.5/detail-20130206<br>
Wed Feb 6 10:08:09 2013 : Info: [detail]
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to
/var/log/freeradius/radacct/192.168.58.5/detail-20130206<br>
Wed Feb 6 10:08:09 2013 : Info: [detail] expand: %t -> Wed
Feb 6 10:08:09 2013<br>
Wed Feb 6 10:08:09 2013 : Info: ++[detail] returns ok<br>
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
%{User-Name} -> pierre.dupont<br>
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] sql_set_user escaped
user --> 'pierre.dupont'<br>
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
%{Acct-Input-Gigawords} -> <br>
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] ... expanding
second conditional<br>
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
%{Acct-Input-Octets} -> 1202<br>
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
%{Acct-Output-Gigawords} -> <br>
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] ... expanding
second conditional<br>
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
%{Acct-Output-Octets} -> 9330<br>
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
UPDATE radacct SET framedipaddress =
'%{Framed-IP-Address}', acctsessiontime =
'%{Acct-Session-Time}', acctinputoctets =
'%{%{Acct-Input-Gigawords}:-0}' << 32
|
'%{%{Acct-Input-Octets}:-0}', acctoutputoctets =
'%{%{Acct-Output-Gigawords}:-0}' << 32
|
'%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid =
'%{Acct-Session-Id}' AND username =
'%{SQL-User-Name}' AND nasipaddress =
'%{NAS-IP-Address}' -> UPDATE radacct
SET framedipaddress = '10.56.0.149',
acctsessiontime = '2', acctinputoctets = '0'
<< 32 |
'1202', acctoutputoctets = '0' << 32
| '9330' WHERE
acctsessionid = 'SESS-13815-54b752-141653-ef2' AND
username = 'yacine<br>
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
/var/log/freeradius/sqltrace.sql ->
/var/log/freeradius/sqltrace.sql<br>
Wed Feb 6 10:08:09 2013 : Debug: rlm_sql (sql_acct): Reserving
sql socket id: 3<br>
Wed Feb 6 10:08:09 2013 : Debug: rlm_sql_mysql:
query: UPDATE radacct SET
framedipaddress = '10.56.0.149', acctsessiontime
= '2', acctinputoctets = '0' << 32
| '1202',
acctoutputoctets = '0' << 32
| '9330' WHERE
acctsessionid = 'SESS-13815-54b752-141653-ef2' AND
username = 'pierre.dupont' AND nasipaddress =
'192.168.58.5'<br>
Wed Feb 6 10:08:09 2013 : Debug: rlm_sql (sql_acct): Released sql
socket id: 3<br>
Wed Feb 6 10:08:09 2013 : Info: ++[sql_acct] returns ok<br>
Wed Feb 6 10:08:09 2013 : Info: ++[exec] returns noop<br>
Wed Feb 6 10:08:09 2013 : Info: [attr_filter.accounting_response]
expand: %{User-Name} -> pierre.dupont<br>
Wed Feb 6 10:08:09 2013 : Debug: attr_filter: Matched entry
DEFAULT at line 12<br>
Wed Feb 6 10:08:09 2013 : Info:
++[attr_filter.accounting_response] returns updated<br>
Sending Accounting-Response of id 16 to 192.168.58.5 port 20007<br>
Wed Feb 6 10:08:09 2013 : Info: Finished request 226.<br>
Wed Feb 6 10:08:09 2013 : Info: Cleaning up request 226 ID 16
with timestamp +231<br>
Wed Feb 6 10:08:09 2013 : Debug: Going to the next request<br>
Wed Feb 6 10:08:09 2013 : Debug: Waking up in 0.1 seconds.<br>
Wed Feb 6 10:08:09 2013 : Info: Cleaning up request 216 ID 9 with
timestamp +226<br>
Wed Feb 6 10:08:09 2013 : Info: Cleaning up request 217 ID 10
with timestamp +226<br>
Wed Feb 6 10:08:09 2013 : Debug: Waking up in 2.7 seconds.<br>
rad_recv: Accounting-Request packet from host 192.168.58.5 port
20007, id=17, length=258<br>
Acct-Status-Type = Interim-Update<br>
Acct-Authentic = RADIUS<br>
Acct-Multi-Session-Id = "SESS-13815-54b752-141653-ef2"<br>
Acct-Session-Id = "SESS-13815-54b752-141653-ef2"<br>
User-Name = "pierre.dupont"<br>
Event-Timestamp = "Feb 6 2013 10:08:10 CET"<br>
Trapeze-VLAN-Name = "EduExterieurs"<br>
Calling-Station-Id = "98-0C-82-A0-9C-53"<br>
NAS-Port-Id = "AP59/1"<br>
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"<br>
NAS-Port = 13815<br>
Framed-IP-Address = 10.71.113.16<br>
Acct-Session-Time = 3<br>
Acct-Output-Octets = 9508<br>
Acct-Input-Octets = 1274<br>
Acct-Output-Packets = 40<br>
Acct-Input-Packets = 234<br>
NAS-Port-Type = Wireless-802.11<br>
NAS-IP-Address = 192.168.58.5<br>
NAS-Identifier = "Trapeze"<br>
Acct-Delay-Time = 0<br>
Wed Feb 6 10:08:10 2013 : Info: # Executing section preacct from
file /etc/freeradius/sites-enabled/eduroam<br>
Wed Feb 6 10:08:10 2013 : Info: +- entering group preacct {...}<br>
Wed Feb 6 10:08:10 2013 : Info: ++[preprocess] returns ok<br>
Wed Feb 6 10:08:10 2013 : Info: [linelog] expand:
%{reply:Packet-Type} -> 0<br>
Wed Feb 6 10:08:10 2013 : Info: [linelog] expand:
%{%{reply:Packet-Type}:-format} -> 0<br>
Wed Feb 6 10:08:10 2013 : Debug: WARNING: No such configuration
item .0<br>
Wed Feb 6 10:08:10 2013 : Info: [linelog] No such entry ".0"<br>
Wed Feb 6 10:08:10 2013 : Info: ++[linelog] returns noop<br>
Wed Feb 6 10:08:10 2013 : Info: [acct_unique] Hashing 'NAS-Port =
13815,Client-IP-Address = 192.168.58.5,NAS-IP-Address =
192.168.58.5,Acct-Session-Id =
"SESS-13815-54b752-141653-ef2",User-Name = "pierre.dupont"'<br>
Wed Feb 6 10:08:10 2013 : Info: [acct_unique]
Acct-Unique-Session-ID = "98d6d9a9c729efc3".<br>
Wed Feb 6 10:08:10 2013 : Info: ++[acct_unique] returns ok<br>
Wed Feb 6 10:08:10 2013 : Info: [suffix] No '@' in User-Name =
"pierre.dupont", looking up realm NULL<br>
Wed Feb 6 10:08:10 2013 : Info: [suffix] Found realm "NULL"<br>
Wed Feb 6 10:08:10 2013 : Info: [suffix] Adding
Stripped-User-Name = "pierre.dupont"<br>
Wed Feb 6 10:08:10 2013 : Info: [suffix] Adding Realm = "NULL"<br>
Wed Feb 6 10:08:10 2013 : Info: [suffix] Accounting realm is
LOCAL.<br>
Wed Feb 6 10:08:10 2013 : Info: ++[suffix] returns ok<br>
Wed Feb 6 10:08:10 2013 : Info: # Executing section accounting
from file /etc/freeradius/sites-enabled/eduroam<br>
Wed Feb 6 10:08:10 2013 : Info: +- entering group accounting
{...}<br>
Wed Feb 6 10:08:10 2013 : Info: [detail] expand:
%{Packet-Src-IP-Address} -> 192.168.58.5<br>
Wed Feb 6 10:08:10 2013 : Info: [detail] expand:
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /var/log/freeradius/radacct/192.168.58.5/detail-20130206<br>
Wed Feb 6 10:08:10 2013 : Info: [detail]
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to
/var/log/freeradius/radacct/192.168.58.5/detail-20130206<br>
Wed Feb 6 10:08:10 2013 : Info: [detail] expand: %t -> Wed
Feb 6 10:08:10 2013<br>
Wed Feb 6 10:08:10 2013 : Info: ++[detail] returns ok<br>
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
%{User-Name} -> pierre.dupont<br>
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] sql_set_user escaped
user --> 'pierre.dupont'<br>
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
%{Acct-Input-Gigawords} -> <br>
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] ... expanding
second conditional<br>
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
%{Acct-Input-Octets} -> 1274<br>
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
%{Acct-Output-Gigawords} -> <br>
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] ... expanding
second conditional<br>
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
%{Acct-Output-Octets} -> 9508<br>
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
UPDATE radacct SET framedipaddress =
'%{Framed-IP-Address}', acctsessiontime =
'%{Acct-Session-Time}', acctinputoctets =
'%{%{Acct-Input-Gigawords}:-0}' << 32
|
'%{%{Acct-Input-Octets}:-0}', acctoutputoctets =
'%{%{Acct-Output-Gigawords}:-0}' << 32
|
'%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid =
'%{Acct-Session-Id}' AND username =
'%{SQL-User-Name}' AND nasipaddress =
'%{NAS-IP-Address}' -> UPDATE radacct
SET framedipaddress = '10.71.113.16',
acctsessiontime = '3', acctinputoctets = '0'
<< 32 |
'1274', acctoutputoctets = '0' << 32
| '9508' WHERE
acctsessionid = 'SESS-13815-54b752-141653-ef2' AND
username = 'yacin<br>
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
/var/log/freeradius/sqltrace.sql ->
/var/log/freeradius/sqltrace.sql<br>
Wed Feb 6 10:08:10 2013 : Debug: rlm_sql (sql_acct): Reserving
sql socket id: 2<br>
Wed Feb 6 10:08:10 2013 : Debug: rlm_sql_mysql:
query: UPDATE radacct SET
framedipaddress = '10.71.113.16', acctsessiontime
= '3', acctinputoctets = '0' << 32
| '1274',
acctoutputoctets = '0' << 32
| '9508' WHERE
acctsessionid = 'SESS-13815-54b752-141653-ef2' AND
username = 'pierre.dupont' AND nasipaddress =
'192.168.58.5'<br>
Wed Feb 6 10:08:10 2013 : Debug: rlm_sql (sql_acct): Released sql
socket id: 2<br>
Wed Feb 6 10:08:10 2013 : Info: ++[sql_acct] returns ok<br>
Wed Feb 6 10:08:10 2013 : Info: ++[exec] returns noop<br>
Wed Feb 6 10:08:10 2013 : Info: [attr_filter.accounting_response]
expand: %{User-Name} -> pierre.dupont<br>
Wed Feb 6 10:08:10 2013 : Debug: attr_filter: Matched entry
DEFAULT at line 12<br>
Wed Feb 6 10:08:10 2013 : Info:
++[attr_filter.accounting_response] returns updated<br>
Sending Accounting-Response of id 17 to 192.168.58.5 port 20007<br>
Wed Feb 6 10:08:10 2013 : Info: Finished request 227.<br>
<br>
</font>
</body>
</html>