pb with realm
Hocine M
hocine.maoucha at free.fr
Wed Feb 6 11:03:26 CET 2013
Hi ,
I have a problem with some user proxied.
In the accounting-request the username is stripped and realm is NULL.
Why le realm is lost?
here is le debug output.
rad_recv: Access-Request packet from host 192.168.58.5 port 20007,
id=13, length=256
NAS-Port-Id = "AP59/1"
Calling-Station-Id = "98-0C-82-A0-9C-53"
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"
Service-Type = Framed-User
User-Name = "pierre.dupont at univ-lille1.fr"
NAS-Port = 13815
State = 0xce6b1f07c76006eefba5daa495da75ed
EAP-Message =
0x020b005019001703010020c523a88c2350d93086ec64726de2c365f717579f7b45e134cdc419b070885ab1170301002088cce6caf3b1d263d7731cb2b8c1c6e20b1967450888d652b5dc399cd6c8fe1a
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 192.168.58.5
NAS-Identifier = "Trapeze"
Message-Authenticator = 0x318ab29add69625365a854e67782de40
Wed Feb 6 10:08:07 2013 : Info: # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam
Wed Feb 6 10:08:07 2013 : Info: +- entering group authorize {...}
Wed Feb 6 10:08:07 2013 : Info: ++[preprocess] returns ok
Wed Feb 6 10:08:07 2013 : Info: ++? if (User-name !~ /^([^@]*)@(.+)$/)
Wed Feb 6 10:08:07 2013 : Info: ? Evaluating (User-name !~
/^([^@]*)@(.+)$/) -> FALSE
Wed Feb 6 10:08:07 2013 : Info: ++? if (User-name !~ /^([^@]*)@(.+)$/)
-> FALSE
Wed Feb 6 10:08:07 2013 : Info: ++- entering else else {...}
Wed Feb 6 10:08:07 2013 : Info: +++[ok] returns ok
Wed Feb 6 10:08:07 2013 : Info: ++- else else returns ok
Wed Feb 6 10:08:07 2013 : Info: ++[mschap] returns noop
Wed Feb 6 10:08:07 2013 : Info: [suffix] Looking up realm
"univ-lille1.fr" for User-Name = "pierre.dupont at univ-lille1.fr"
Wed Feb 6 10:08:07 2013 : Info: [suffix] Found realm "~.+$"
Wed Feb 6 10:08:07 2013 : Info: [suffix] Adding Realm = "univ-lille1.fr"
Wed Feb 6 10:08:07 2013 : Info: [suffix] Proxying request from user
pierre.dupont to realm ~.+$
Wed Feb 6 10:08:07 2013 : Info: [suffix] Preparing to proxy
authentication request to realm "~.+$"
Wed Feb 6 10:08:07 2013 : Info: ++[suffix] returns updated
Wed Feb 6 10:08:07 2013 : Info: [eap] Request is supposed to be proxied
to Realm ~.+$. Not doing EAP.
Wed Feb 6 10:08:07 2013 : Info: ++[eap] returns noop
Wed Feb 6 10:08:07 2013 : Info: ++[pap] returns noop
Wed Feb 6 10:08:07 2013 : Info: # Executing section pre-proxy from file
/etc/freeradius/sites-enabled/eduroam
Wed Feb 6 10:08:07 2013 : Info: +- entering group pre-proxy {...}
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
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
Wed Feb 6 10:08:07 2013 : Info: [pre_proxy_log] expand: %t -> Wed
Feb 6 10:08:07 2013
Wed Feb 6 10:08:07 2013 : Info: ++[pre_proxy_log] returns ok
Wed Feb 6 10:08:07 2013 : Info: ++? if (Packet-Type != Accounting-Request)
Wed Feb 6 10:08:07 2013 : Info: ? Evaluating (Packet-Type !=
Accounting-Request) -> FALSE
Wed Feb 6 10:08:07 2013 : Info: ++? if (Packet-Type !=
Accounting-Request) -> FALSE
Sending Access-Request of id 223 to 193.51.224.109 port 1812
NAS-Port-Id = "AP59/1"
Calling-Station-Id = "98-0C-82-A0-9C-53"
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"
Service-Type = Framed-User
User-Name = "pierre.dupont at univ-lille1.fr"
NAS-Port = 13815
State = 0xce6b1f07c76006eefba5daa495da75ed
EAP-Message =
0x020b005019001703010020c523a88c2350d93086ec64726de2c365f717579f7b45e134cdc419b070885ab1170301002088cce6caf3b1d263d7731cb2b8c1c6e20b1967450888d652b5dc399cd6c8fe1a
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 192.168.58.5
NAS-Identifier = "Trapeze"
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x3133
Wed Feb 6 10:08:07 2013 : Info: Proxying request 223 to home server
193.51.224.109 port 1812
Sending Access-Request of id 223 to 193.51.224.109 port 1812
NAS-Port-Id = "AP59/1"
Calling-Station-Id = "98-0C-82-A0-9C-53"
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"
Service-Type = Framed-User
User-Name = "pierre.dupont at univ-lille1.fr"
NAS-Port = 13815
State = 0xce6b1f07c76006eefba5daa495da75ed
EAP-Message =
0x020b005019001703010020c523a88c2350d93086ec64726de2c365f717579f7b45e134cdc419b070885ab1170301002088cce6caf3b1d263d7731cb2b8c1c6e20b1967450888d652b5dc399cd6c8fe1a
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 192.168.58.5
NAS-Identifier = "Trapeze"
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x3133
Wed Feb 6 10:08:07 2013 : Debug: Going to the next request
Wed Feb 6 10:08:07 2013 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Accept packet from host 193.51.224.109 port 1812,
id=223, length=182
User-Name = "pierre.dupont\000"
MS-MPPE-Recv-Key =
0x948d791f2da3af530868839e7df666aa1886290c40bfe70643d3cc079f9c24f4
MS-MPPE-Send-Key =
0x0a525d10d48467385a134bf6b1c4bee916e17fd24016a6f6c01b35ef243f07b2
EAP-Message = 0x030b0004
Message-Authenticator = 0xf6f125f6e9767f4dc8f9decb26a31021
Proxy-State = 0x3133
Wed Feb 6 10:08:07 2013 : Info: # Executing section post-proxy from
file /etc/freeradius/sites-enabled/eduroam
Wed Feb 6 10:08:07 2013 : Info: +- entering group post-proxy {...}
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
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
Wed Feb 6 10:08:07 2013 : Info: [post_proxy_log] expand: %t -> Wed
Feb 6 10:08:07 2013
Wed Feb 6 10:08:07 2013 : Info: ++[post_proxy_log] returns ok
Wed Feb 6 10:08:07 2013 : Info: [eap] No pre-existing handler found
Wed Feb 6 10:08:07 2013 : Info: ++[eap] returns noop
Wed Feb 6 10:08:07 2013 : Info: Found Auth-Type = Accept
Wed Feb 6 10:08:07 2013 : Info: Auth-Type = Accept, accepting the user
Wed Feb 6 10:08:07 2013 : Info: # Executing section post-auth from file
/etc/freeradius/sites-enabled/eduroam
Wed Feb 6 10:08:07 2013 : Info: +- entering group post-auth {...}
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand:
%{reply:Packet-Type} -> Access-Accept
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand:
%{%{reply:Packet-Type}:-format} -> Access-Accept
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand:
/var/log/freeradius/linelog.log -> /var/log/freeradius/linelog.log
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
pierre.dupont at univ-lille1.fr 98-0C-82-A0-9C-53
00-26-3E-70-6F-C0:eduroam
Wed Feb 6 10:08:07 2013 : Info: ++[linelog] returns ok
Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand:
%{reply:Packet-Type} -> Access-Accept
Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand:
f_ticks.%{%{reply:Packet-Type}:-format} -> f_ticks.Access-Accept
Wed Feb 6 10:08:07 2013 : Info: [f_ticks] expand:
/var/log/freeradius/f_ticks.log -> /var/log/freeradius/f_ticks.log
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
Wed Feb 6 10:08:07 2013 : Info: ++[f_ticks] returns ok
Wed Feb 6 10:08:07 2013 : Info: expand: %{Realm} -> univ-lille1.fr
Wed Feb 6 10:08:07 2013 : Info: ++- entering switch %{Realm} {...}
Wed Feb 6 10:08:07 2013 : Info: +++- switch %{Realm} returns noop
Wed Feb 6 10:08:07 2013 : Info: ++- group post-auth returns noop
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$/))
Wed Feb 6 10:08:07 2013 : Info: expand: %{Realm} -> univ-lille1.fr
Wed Feb 6 10:08:07 2013 : Info: ?? Evaluating ("%{Realm}" !~
/^(ext\.|etu\.|)univ-lille3\.fr$/) -> TRUE
Wed Feb 6 10:08:07 2013 : Info: expand: %{Called-Station-Id} ->
00-26-3E-70-6F-C0:eduroam
Wed Feb 6 10:08:07 2013 : Info: ?? Evaluating ("%{Called-Station-Id}"
=~ /^([0-9A-F]{2}-){5}[0-9A-F]{2}:eduroam$/) -> TRUE
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
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$/)) {...}
Wed Feb 6 10:08:07 2013 : Info: +++[reply] returns noop
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
Wed Feb 6 10:08:07 2013 : Info: ++[exec] returns noop
Sending Access-Accept of id 13 to 192.168.58.5 port 20007
User-Name = "pierre.dupont\000"
MS-MPPE-Recv-Key =
0x948d791f2da3af530868839e7df666aa1886290c40bfe70643d3cc079f9c24f4
MS-MPPE-Send-Key =
0x0a525d10d48467385a134bf6b1c4bee916e17fd24016a6f6c01b35ef243f07b2
EAP-Message = 0x030b0004
Message-Authenticator = 0x00000000000000000000000000000000
Tunnel-Type:0 = VLAN
Tunnel-Medium-Type:0 = IEEE-802
Tunnel-Private-Group-Id:0 = "56"
Wed Feb 6 10:08:07 2013 : Info: Finished request 223.
Wed Feb 6 10:08:07 2013 : Debug: Going to the next request
Wed Feb 6 10:08:07 2013 : Debug: Waking up in 1.5 seconds.
rad_recv: Accounting-Request packet from host 192.168.58.5 port 20007,
id=14, length=222
Acct-Status-Type = Start
Acct-Authentic = RADIUS
Acct-Multi-Session-Id = "SESS-13815-54b752-141653-ef2"
Acct-Session-Id = "SESS-13815-54b752-141653-ef2"
User-Name = "pierre.dupont"
Event-Timestamp = "Feb 6 2013 10:08:07 CET"
Trapeze-VLAN-Name = "EduExterieurs"
Calling-Station-Id = "98-0C-82-A0-9C-53"
NAS-Port-Id = "AP59/1"
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"
NAS-Port = 13815
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 192.168.58.5
NAS-Identifier = "Trapeze"
Acct-Delay-Time = 0
Wed Feb 6 10:08:07 2013 : Info: # Executing section preacct from file
/etc/freeradius/sites-enabled/eduroam
Wed Feb 6 10:08:07 2013 : Info: +- entering group preacct {...}
Wed Feb 6 10:08:07 2013 : Info: ++[preprocess] returns ok
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand:
%{reply:Packet-Type} -> 0
Wed Feb 6 10:08:07 2013 : Info: [linelog] expand:
%{%{reply:Packet-Type}:-format} -> 0
Wed Feb 6 10:08:07 2013 : Debug: WARNING: No such configuration item .0
Wed Feb 6 10:08:07 2013 : Info: [linelog] No such entry ".0"
Wed Feb 6 10:08:07 2013 : Info: ++[linelog] returns noop
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"'
Wed Feb 6 10:08:07 2013 : Info: [acct_unique] Acct-Unique-Session-ID =
"98d6d9a9c729efc3".
Wed Feb 6 10:08:07 2013 : Info: ++[acct_unique] returns ok
Wed Feb 6 10:08:07 2013 : Info: [suffix] No '@' in User-Name =
"pierre.dupont", looking up realm NULL
Wed Feb 6 10:08:07 2013 : Info: [suffix] Found realm "NULL"
Wed Feb 6 10:08:07 2013 : Info: [suffix] Adding Stripped-User-Name =
"pierre.dupont"
Wed Feb 6 10:08:07 2013 : Info: [suffix] Adding Realm = "NULL"
Wed Feb 6 10:08:07 2013 : Info: [suffix] Accounting realm is LOCAL.
Wed Feb 6 10:08:07 2013 : Info: ++[suffix] returns ok
Wed Feb 6 10:08:07 2013 : Info: # Executing section accounting from
file /etc/freeradius/sites-enabled/eduroam
Wed Feb 6 10:08:07 2013 : Info: +- entering group accounting {...}
Wed Feb 6 10:08:07 2013 : Info: [detail] expand:
%{Packet-Src-IP-Address} -> 192.168.58.5
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
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
Wed Feb 6 10:08:07 2013 : Info: [detail] expand: %t -> Wed Feb 6
10:08:07 2013
Wed Feb 6 10:08:07 2013 : Info: ++[detail] returns ok
Wed Feb 6 10:08:07 2013 : Info: [sql_acct] expand: %{User-Name} ->
pierre.dupont
Wed Feb 6 10:08:07 2013 : Info: [sql_acct] sql_set_user escaped user
--> 'pierre.dupont'
Wed Feb 6 10:08:07 2013 : Info: [sql_acct] expand:
%{Acct-Delay-Time} -> 0
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}',
Wed Feb 6 10:08:07 2013 : Info: [sql_acct] expand:
/var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql
Wed Feb 6 10:08:07 2013 : Debug: rlm_sql (sql_acct): Reserving sql
socket id: 5
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', '')
Wed Feb 6 10:08:07 2013 : Debug: rlm_sql (sql_acct): Released sql
socket id: 5
Wed Feb 6 10:08:07 2013 : Info: ++[sql_acct] returns ok
Wed Feb 6 10:08:07 2013 : Info: ++[exec] returns noop
Wed Feb 6 10:08:07 2013 : Info: [attr_filter.accounting_response]
expand: %{User-Name} -> pierre.dupont
Wed Feb 6 10:08:07 2013 : Debug: attr_filter: Matched entry DEFAULT at
line 12
Wed Feb 6 10:08:07 2013 : Info: ++[attr_filter.accounting_response]
returns updated
Sending Accounting-Response of id 14 to 192.168.58.5 port 20007
Wed Feb 6 10:08:07 2013 : Info: Finished request 224.
Wed Feb 6 10:08:07 2013 : Info: Cleaning up request 224 ID 14 with
timestamp +229
Wed Feb 6 10:08:07 2013 : Debug: Going to the next request
Wed Feb 6 10:08:07 2013 : Debug: Waking up in 1.4 seconds.
rad_recv: Accounting-Request packet from host 192.168.58.5 port 20007,
id=16, length=258
Acct-Status-Type = Interim-Update
Acct-Authentic = RADIUS
Acct-Multi-Session-Id = "SESS-13815-54b752-141653-ef2"
Acct-Session-Id = "SESS-13815-54b752-141653-ef2"
User-Name = "pierre.dupont"
Event-Timestamp = "Feb 6 2013 10:08:09 CET"
Trapeze-VLAN-Name = "EduExterieurs"
Calling-Station-Id = "98-0C-82-A0-9C-53"
NAS-Port-Id = "AP59/1"
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"
NAS-Port = 13815
Framed-IP-Address = 10.56.0.149
Acct-Session-Time = 2
Acct-Output-Octets = 9330
Acct-Input-Octets = 1202
Acct-Output-Packets = 38
Acct-Input-Packets = 230
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 192.168.58.5
NAS-Identifier = "Trapeze"
Acct-Delay-Time = 0
Wed Feb 6 10:08:09 2013 : Info: # Executing section preacct from file
/etc/freeradius/sites-enabled/eduroam
Wed Feb 6 10:08:09 2013 : Info: +- entering group preacct {...}
Wed Feb 6 10:08:09 2013 : Info: ++[preprocess] returns ok
Wed Feb 6 10:08:09 2013 : Info: [linelog] expand:
%{reply:Packet-Type} -> 0
Wed Feb 6 10:08:09 2013 : Info: [linelog] expand:
%{%{reply:Packet-Type}:-format} -> 0
Wed Feb 6 10:08:09 2013 : Debug: WARNING: No such configuration item .0
Wed Feb 6 10:08:09 2013 : Info: [linelog] No such entry ".0"
Wed Feb 6 10:08:09 2013 : Info: ++[linelog] returns noop
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"'
Wed Feb 6 10:08:09 2013 : Info: [acct_unique] Acct-Unique-Session-ID =
"98d6d9a9c729efc3".
Wed Feb 6 10:08:09 2013 : Info: ++[acct_unique] returns ok
Wed Feb 6 10:08:09 2013 : Info: [suffix] No '@' in User-Name =
"pierre.dupont", looking up realm NULL
Wed Feb 6 10:08:09 2013 : Info: [suffix] Found realm "NULL"
Wed Feb 6 10:08:09 2013 : Info: [suffix] Adding Stripped-User-Name =
"pierre.dupont"
Wed Feb 6 10:08:09 2013 : Info: [suffix] Adding Realm = "NULL"
Wed Feb 6 10:08:09 2013 : Info: [suffix] Accounting realm is LOCAL.
Wed Feb 6 10:08:09 2013 : Info: ++[suffix] returns ok
Wed Feb 6 10:08:09 2013 : Info: # Executing section accounting from
file /etc/freeradius/sites-enabled/eduroam
Wed Feb 6 10:08:09 2013 : Info: +- entering group accounting {...}
Wed Feb 6 10:08:09 2013 : Info: [detail] expand:
%{Packet-Src-IP-Address} -> 192.168.58.5
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
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
Wed Feb 6 10:08:09 2013 : Info: [detail] expand: %t -> Wed Feb 6
10:08:09 2013
Wed Feb 6 10:08:09 2013 : Info: ++[detail] returns ok
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand: %{User-Name} ->
pierre.dupont
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] sql_set_user escaped user
--> 'pierre.dupont'
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
%{Acct-Input-Gigawords} ->
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] ... expanding second
conditional
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
%{Acct-Input-Octets} -> 1202
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
%{Acct-Output-Gigawords} ->
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] ... expanding second
conditional
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
%{Acct-Output-Octets} -> 9330
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
Wed Feb 6 10:08:09 2013 : Info: [sql_acct] expand:
/var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql
Wed Feb 6 10:08:09 2013 : Debug: rlm_sql (sql_acct): Reserving sql
socket id: 3
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'
Wed Feb 6 10:08:09 2013 : Debug: rlm_sql (sql_acct): Released sql
socket id: 3
Wed Feb 6 10:08:09 2013 : Info: ++[sql_acct] returns ok
Wed Feb 6 10:08:09 2013 : Info: ++[exec] returns noop
Wed Feb 6 10:08:09 2013 : Info: [attr_filter.accounting_response]
expand: %{User-Name} -> pierre.dupont
Wed Feb 6 10:08:09 2013 : Debug: attr_filter: Matched entry DEFAULT at
line 12
Wed Feb 6 10:08:09 2013 : Info: ++[attr_filter.accounting_response]
returns updated
Sending Accounting-Response of id 16 to 192.168.58.5 port 20007
Wed Feb 6 10:08:09 2013 : Info: Finished request 226.
Wed Feb 6 10:08:09 2013 : Info: Cleaning up request 226 ID 16 with
timestamp +231
Wed Feb 6 10:08:09 2013 : Debug: Going to the next request
Wed Feb 6 10:08:09 2013 : Debug: Waking up in 0.1 seconds.
Wed Feb 6 10:08:09 2013 : Info: Cleaning up request 216 ID 9 with
timestamp +226
Wed Feb 6 10:08:09 2013 : Info: Cleaning up request 217 ID 10 with
timestamp +226
Wed Feb 6 10:08:09 2013 : Debug: Waking up in 2.7 seconds.
rad_recv: Accounting-Request packet from host 192.168.58.5 port 20007,
id=17, length=258
Acct-Status-Type = Interim-Update
Acct-Authentic = RADIUS
Acct-Multi-Session-Id = "SESS-13815-54b752-141653-ef2"
Acct-Session-Id = "SESS-13815-54b752-141653-ef2"
User-Name = "pierre.dupont"
Event-Timestamp = "Feb 6 2013 10:08:10 CET"
Trapeze-VLAN-Name = "EduExterieurs"
Calling-Station-Id = "98-0C-82-A0-9C-53"
NAS-Port-Id = "AP59/1"
Called-Station-Id = "00-26-3E-70-6F-C0:eduroam"
NAS-Port = 13815
Framed-IP-Address = 10.71.113.16
Acct-Session-Time = 3
Acct-Output-Octets = 9508
Acct-Input-Octets = 1274
Acct-Output-Packets = 40
Acct-Input-Packets = 234
NAS-Port-Type = Wireless-802.11
NAS-IP-Address = 192.168.58.5
NAS-Identifier = "Trapeze"
Acct-Delay-Time = 0
Wed Feb 6 10:08:10 2013 : Info: # Executing section preacct from file
/etc/freeradius/sites-enabled/eduroam
Wed Feb 6 10:08:10 2013 : Info: +- entering group preacct {...}
Wed Feb 6 10:08:10 2013 : Info: ++[preprocess] returns ok
Wed Feb 6 10:08:10 2013 : Info: [linelog] expand:
%{reply:Packet-Type} -> 0
Wed Feb 6 10:08:10 2013 : Info: [linelog] expand:
%{%{reply:Packet-Type}:-format} -> 0
Wed Feb 6 10:08:10 2013 : Debug: WARNING: No such configuration item .0
Wed Feb 6 10:08:10 2013 : Info: [linelog] No such entry ".0"
Wed Feb 6 10:08:10 2013 : Info: ++[linelog] returns noop
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"'
Wed Feb 6 10:08:10 2013 : Info: [acct_unique] Acct-Unique-Session-ID =
"98d6d9a9c729efc3".
Wed Feb 6 10:08:10 2013 : Info: ++[acct_unique] returns ok
Wed Feb 6 10:08:10 2013 : Info: [suffix] No '@' in User-Name =
"pierre.dupont", looking up realm NULL
Wed Feb 6 10:08:10 2013 : Info: [suffix] Found realm "NULL"
Wed Feb 6 10:08:10 2013 : Info: [suffix] Adding Stripped-User-Name =
"pierre.dupont"
Wed Feb 6 10:08:10 2013 : Info: [suffix] Adding Realm = "NULL"
Wed Feb 6 10:08:10 2013 : Info: [suffix] Accounting realm is LOCAL.
Wed Feb 6 10:08:10 2013 : Info: ++[suffix] returns ok
Wed Feb 6 10:08:10 2013 : Info: # Executing section accounting from
file /etc/freeradius/sites-enabled/eduroam
Wed Feb 6 10:08:10 2013 : Info: +- entering group accounting {...}
Wed Feb 6 10:08:10 2013 : Info: [detail] expand:
%{Packet-Src-IP-Address} -> 192.168.58.5
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
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
Wed Feb 6 10:08:10 2013 : Info: [detail] expand: %t -> Wed Feb 6
10:08:10 2013
Wed Feb 6 10:08:10 2013 : Info: ++[detail] returns ok
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand: %{User-Name} ->
pierre.dupont
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] sql_set_user escaped user
--> 'pierre.dupont'
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
%{Acct-Input-Gigawords} ->
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] ... expanding second
conditional
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
%{Acct-Input-Octets} -> 1274
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
%{Acct-Output-Gigawords} ->
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] ... expanding second
conditional
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
%{Acct-Output-Octets} -> 9508
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
Wed Feb 6 10:08:10 2013 : Info: [sql_acct] expand:
/var/log/freeradius/sqltrace.sql -> /var/log/freeradius/sqltrace.sql
Wed Feb 6 10:08:10 2013 : Debug: rlm_sql (sql_acct): Reserving sql
socket id: 2
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'
Wed Feb 6 10:08:10 2013 : Debug: rlm_sql (sql_acct): Released sql
socket id: 2
Wed Feb 6 10:08:10 2013 : Info: ++[sql_acct] returns ok
Wed Feb 6 10:08:10 2013 : Info: ++[exec] returns noop
Wed Feb 6 10:08:10 2013 : Info: [attr_filter.accounting_response]
expand: %{User-Name} -> pierre.dupont
Wed Feb 6 10:08:10 2013 : Debug: attr_filter: Matched entry DEFAULT at
line 12
Wed Feb 6 10:08:10 2013 : Info: ++[attr_filter.accounting_response]
returns updated
Sending Accounting-Response of id 17 to 192.168.58.5 port 20007
Wed Feb 6 10:08:10 2013 : Info: Finished request 227.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20130206/97634eab/attachment-0001.html>
More information about the Freeradius-Users
mailing list