attrs.filter differences between FR 2.2.0 and FR 3

Palmer J.D.F.

11 Nov 2013 11 Nov '13

12:12 p.m.

Hello, I'm just putting together a dev install of FR3 but am struggling with porting the attribute filter for post-proxy. In FR 2.2.0 I have the section below is in my attrs.post-proxy file, which matches Access-Accept packets from the jrs realm, i.e. when a visiting eduroam user authenticates successfully. Access-Accept.jrs User-Name =* ANY, Reply-Message =* ANY, State =* ANY, Class =* ANY, ... However, in FR 3 the Access-Accept not matched, the section it is only matched if I remove the Access-Accept to just leave the realm. The file is located at /usr/local/raddb/mods-config/attr_filter/post-proxy And I've added the following section to /usr/local/raddb/mods-enabled/attr_filter attr_filter attr_filter.post-proxy { filename = ${modconfdir}/${.:name}/post-proxy } Is this feature no longer available, or am I missing something? Many thanks, Jezz. Jezz Palmer Information Services and Systems Swansea University Singleton Park Swansea SA2 8PP

Attachments:

attachment.html (text/html — 4.3 KB)

Show replies by date

Arran Cudbard-Bell

11 Nov 11 Nov

12:34 p.m.

On 11 Nov 2013, at 17:12, Palmer J.D.F. <J.D.F.Palmer@SWANSEA.AC.UK> wrote:

...

Hello,

I’m just putting together a dev install of FR3 but am struggling with porting the attribute filter for post-proxy.

In FR 2.2.0 I have the section below is in my attrs.post-proxy file, which matches Access-Accept packets from the jrs realm, i.e. when a visiting eduroam user authenticates successfully.

Access-Accept.jrs User-Name =* ANY, Reply-Message =* ANY, State =* ANY, Class =* ANY, …

However, in FR 3 the Access-Accept not matched, the section it is only matched if I remove the Access-Accept to just leave the realm. The file is located at /usr/local/raddb/mods-config/attr_filter/post-proxy And I’ve added the following section to /usr/local/raddb/mods-enabled/attr_filter

attr_filter attr_filter.post-proxy { filename = ${modconfdir}/${.:name}/post-proxy }

Filters use an arbitrary key just the same as the Users-File. attr_filter attr_filter.post-proxy { key = "%{Response-Packet-Type}.%{Realm}" filename = ${modconfdir}/${.:name}/post-proxy } May work, if it doesn't we might need to add some xlat magic to expose the proxy response. Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team

Palmer J.D.F.

3:41 p.m.

Thanks Arran,

...

Filters use an arbitrary key just the same as the Users-File.

attr_filter attr_filter.post-proxy { key = "%{Response-Packet-Type}.%{Realm}" filename = ${modconfdir}/${.:name}/post-proxy }

May work, if it doesn't we might need to add some xlat magic to expose the proxy response.

I think that some xlat magic might be required... (9) [post_proxy_log] = ok (9) attr_filter.post-proxy : expand: "%{Response-Packet-Type}.%{Realm}" -> '.jrs' (9) [attr_filter.post-proxy] = noop Also on a completely different note, I've noticed that sometimes (only so far when auth'ing against our test @eduroam.ac.uk account, not locally) I get about thousands & thousands of these, until eventually it cleans up... (6) Waiting for more responses from the home server (6) Waiting for more responses from the home server (6) Waiting for more responses from the home server (6) Waiting for more responses from the home server (6) Waiting for more responses from the home server (6) Waiting for more responses from the home server (6) Waiting for more responses from the home server (6) Waiting for more responses from the home server (6) Waiting for more responses from the home server (6) Waiting for more responses from the home server Thanks, Jezz.

A.L.M.Buxey＠lboro.ac.uk

12 Nov 12 Nov

3:38 a.m.

Hi,

...

Also on a completely different note, I've noticed that sometimes (only so far when auth'ing against our test @eduroam.ac.uk account, not locally) I get about thousands & thousands of these, until eventually it cleans up...

....well thats 'interesting'. I would suggest that you run in full debug mode when performing an authentication with that test account to see what is going on at a deeper level - because If you get back an Access-Accept packet then theres no more to receive....your server should not need to be waiting for more responses... but if this is part of the 'lets get your RADIUS cert' conversation then it looks like v3 is either doing some extra things...or is just being more verbose than 2.x (and thousands of such things being logged would be annoying) alan

Palmer J.D.F.

8:57 a.m.

Hi Alan,

...

...
Also on a completely different note, I've noticed that sometimes (only so far when auth'ing against our test @eduroam.ac.uk account, not locally) I get about thousands & thousands of these, until eventually it cleans up...

...

....well thats 'interesting'. I would suggest that you run in full debug mode when performing an authentication with that test account to see what is going on at a deeper level - because If you get back an Access-Accept packet then theres no more to receive....your server should not need to be waiting for more responses... but if this is part of the 'lets get your RADIUS cert' conversation then it looks like v3 is either doing some extra things...or is just being more verbose than 2.x (and thousands of such things being logged would be annoying)...

I've just tried to use raddebug to capture the debug, but I might have unearthed another problem. Once raddebug times out after 60 second it kills radiusd. Below is the debug output, auth fails, and looks like there might be a duplicate proxies request to the NRPS. Thanks, Jezz. rad_recv: Access-Request packet from host 123.44.55.66 port 37026, id=0, length=162 User-Name = 'swansea.ac.uk@eduroam.ac.uk' Calling-Station-Id = '02-00-00-00-00-01' Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = 'CONNECT 11Mbps 802.11b' NAS-IP-Address = 137.44.0.2 EAP-Message = 0x02000020017377616e7365612e61632e756b40656475726f616d2e61632e756b Message-Authenticator = 0x999c405516f2b7db33a613f6c1a41074 Tue Nov 12 13:13:06 2013 : Debug: (160) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Tue Nov 12 13:13:06 2013 : Debug: (160) authorize { Tue Nov 12 13:13:06 2013 : Debug: (160) filter_username filter_username { Tue Nov 12 13:13:06 2013 : Debug: (160) ? if (User-Name =~ /@.*@/ ) Tue Nov 12 13:13:06 2013 : Debug: (160) ? if (User-Name =~ /@.*@/ ) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) Tue Nov 12 13:13:06 2013 : Debug: (160) %{0}: Inserting new value "@" Tue Nov 12 13:13:06 2013 : Debug: (160) %{1}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{2}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{3}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{0}: Inserting new value "@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (160) %{1}: Inserting new value "eduroam.ac" Tue Nov 12 13:13:06 2013 : Debug: (160) %{2}: Inserting new value "uk" Tue Nov 12 13:13:06 2013 : Debug: (160) %{3}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (160) ? if (User-Name =~ /\\.$/) Tue Nov 12 13:13:06 2013 : Debug: (160) ? if (User-Name =~ /\\.$/) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (160) ? if (User-Name =~ /@\\./) Tue Nov 12 13:13:06 2013 : Debug: (160) ? if (User-Name =~ /@\\./) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (160) } # filter_username filter_username = notfound Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) Tue Nov 12 13:13:06 2013 : Debug: %{reply:Reply-Message} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Reply-Message Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 2 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "%{reply:Reply-Message}" -> '' Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (160) if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) { Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) Tue Nov 12 13:13:06 2013 : Debug: %{User-Name} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: User-Name Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "%{User-Name}" -> 'swansea.ac.uk@eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (160) %{0}: Inserting new value "swansea.ac.uk@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (160) %{1}: Inserting new value "swansea.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (160) %{2}: Inserting new value "@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (160) %{3}: Inserting new value "eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (160) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (160) if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) { Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ("%{3}") Tue Nov 12 13:13:06 2013 : Debug: %{3} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: regex-var: 3 Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "%{3}" -> 'eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ("%{3}") -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (160) if ("%{3}") { Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ((User-Name =~ /([a-z0-9_\.\-]+)@(swan|colegcymraeg|swansea|abertawe|test\.colegcymraeg|test\.swansea|test\.abertawe)\.ac\.uk/i) || (User-Name =~ /@(swan|colegcymraeg|swansea|abertawe)\.ac\.uk/i)) Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ((User-Name =~ /([a-z0-9_\.\-]+)@(swan|colegcymraeg|swansea|abertawe|test\.colegcymraeg|test\.swansea|test\.abertawe)\.ac\.uk/i) || (User-Name =~ /@(swan|colegcymraeg|swansea|abertawe)\.ac\.uk/i)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (160) else else { Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ((User-Name =~ /3gppnetwork\.org/i) || (User-Name =~ /\.acuk$/i) || (User-Name =~ /\.aaac\.uk\/$/i)) Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ((User-Name =~ /3gppnetwork\.org/i) || (User-Name =~ /\.acuk$/i) || (User-Name =~ /\.aaac\.uk\/$/i)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (160) else else { Tue Nov 12 13:13:06 2013 : Debug: (160) update request { Tue Nov 12 13:13:06 2013 : Debug: %{3} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: regex-var: 3 Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "%{3}" -> 'eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (160) Stripped-User-Domain = "eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (160) ::: FROM 1 TO 8 MAX 9 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: Examining Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (160) ::: APPENDING Stripped-User-Domain FROM 0 TO 8 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: TO in 8 out 9 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[0] = User-Name Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[1] = Calling-Station-Id Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[2] = Framed-MTU Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[3] = NAS-Port-Type Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[4] = Connect-Info Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[5] = NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[6] = EAP-Message Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[7] = Message-Authenticator Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[8] = Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (160) } # update request = noop Tue Nov 12 13:13:06 2013 : Debug: (160) } # else else = noop Tue Nov 12 13:13:06 2013 : Debug: (160) } # else else = noop Tue Nov 12 13:13:06 2013 : Debug: (160) } # if ("%{3}") = noop Tue Nov 12 13:13:06 2013 : Debug: (160) ... skipping else for request 160: Preceding "if" was taken Tue Nov 12 13:13:06 2013 : Debug: (160) } # if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) = noop Tue Nov 12 13:13:06 2013 : Debug: (160) ... skipping else for request 160: Preceding "if" was taken Tue Nov 12 13:13:06 2013 : Debug: (160) ? if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) Tue Nov 12 13:13:06 2013 : Debug: %{NAS-IP-Address} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "%{NAS-IP-Address}" -> '137.44.0.2' Tue Nov 12 13:13:06 2013 : Debug: (160) %{0}: Inserting new value "137.44." Tue Nov 12 13:13:06 2013 : Debug: (160) %{1}: Clearing old value "swansea.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (160) %{2}: Clearing old value "@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (160) %{3}: Clearing old value "eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (160) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (160) ? if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (160) if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) { Tue Nov 12 13:13:06 2013 : Debug: (160) switch %{Stripped-User-Domain} { Tue Nov 12 13:13:06 2013 : Debug: %{Stripped-User-Domain} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "%{Stripped-User-Domain}" -> 'eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (160) switch %{Stripped-User-Domain} { Tue Nov 12 13:13:06 2013 : Debug: (160) case (null) { Tue Nov 12 13:13:06 2013 : Debug: (160) update control { Tue Nov 12 13:13:06 2013 : Debug: (160) Proxy-To-Realm := 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (160) ::: FROM 1 TO 0 MAX 1 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: Examining Proxy-To-Realm Tue Nov 12 13:13:06 2013 : Debug: (160) ::: APPENDING Proxy-To-Realm FROM 0 TO 0 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: TO in 0 out 1 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[0] = Proxy-To-Realm Tue Nov 12 13:13:06 2013 : Debug: (160) } # update control = noop Tue Nov 12 13:13:06 2013 : Debug: (160) update request { Tue Nov 12 13:13:06 2013 : Debug: (160) Realm := 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (160) ::: FROM 1 TO 9 MAX 10 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: Examining Realm Tue Nov 12 13:13:06 2013 : Debug: (160) ::: APPENDING Realm FROM 0 TO 9 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: TO in 9 out 10 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[0] = User-Name Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[1] = Calling-Station-Id Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[2] = Framed-MTU Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[3] = NAS-Port-Type Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[4] = Connect-Info Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[5] = NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[6] = EAP-Message Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[7] = Message-Authenticator Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[8] = Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[9] = Realm Tue Nov 12 13:13:06 2013 : Debug: (160) Operator-Name := "1swansea.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (160) ::: FROM 1 TO 10 MAX 11 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: Examining Operator-Name Tue Nov 12 13:13:06 2013 : Debug: (160) ::: APPENDING Operator-Name FROM 0 TO 10 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: TO in 10 out 11 Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[0] = User-Name Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[1] = Calling-Station-Id Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[2] = Framed-MTU Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[3] = NAS-Port-Type Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[4] = Connect-Info Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[5] = NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[6] = EAP-Message Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[7] = Message-Authenticator Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[8] = Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[9] = Realm Tue Nov 12 13:13:06 2013 : Debug: (160) ::: to[10] = Operator-Name Tue Nov 12 13:13:06 2013 : Debug: (160) } # update request = noop Tue Nov 12 13:13:06 2013 : Debug: (160) } # case = noop Tue Nov 12 13:13:06 2013 : Debug: (160) } # switch %{Stripped-User-Domain} = noop Tue Nov 12 13:13:06 2013 : Debug: (160) } # if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) = noop Tue Nov 12 13:13:06 2013 : Debug: (160) ... skipping else for request 160: Preceding "if" was taken Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ("%{Realm}" != "jrs") Tue Nov 12 13:13:06 2013 : Debug: jrs Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "jrs" -> 'jrs' Tue Nov 12 13:13:06 2013 : Debug: %{Realm} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Realm Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "%{Realm}" -> 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ("%{Realm}" != "jrs") -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (160) } # if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) = noop Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [preprocess] = ok Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: calling auth_log (rlm_detail) for request 160 Tue Nov 12 13:13:06 2013 : Debug: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: '/usr/local/var/log/radius/radacct/' Tue Nov 12 13:13:06 2013 : Debug: if { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: else { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IPv6-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: literal: '/auth-detail-' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'Y' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'm' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'd' Tue Nov 12 13:13:06 2013 : Debug: (160) auth_log : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/123.44.55.66/auth-detail-20131112' Tue Nov 12 13:13:06 2013 : Debug: (160) auth_log : /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/123.44.55.66/auth-detail-20131112 Tue Nov 12 13:13:06 2013 : Debug: %t Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 't' Tue Nov 12 13:13:06 2013 : Debug: (160) auth_log : expand: "%t" -> 'Tue Nov 12 13:13:06 2013' Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: returned from auth_log (rlm_detail) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [auth_log] = ok Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: calling chap (rlm_chap) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: returned from chap (rlm_chap) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [chap] = noop Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: calling mschap (rlm_mschap) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: returned from mschap (rlm_mschap) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [mschap] = noop Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: calling suffix (rlm_realm) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) suffix : Request already has destination realm set. Ignoring. Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: returned from suffix (rlm_realm) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [suffix] = ok Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: calling ntdomain (rlm_realm) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) ntdomain : Request already has destination realm set. Ignoring. Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: returned from ntdomain (rlm_realm) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [ntdomain] = ok Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: calling eap (rlm_eap) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) eap : Request is supposed to be proxied to Realm jrs. Not doing EAP. Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: returned from eap (rlm_eap) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [eap] = noop Tue Nov 12 13:13:06 2013 : Debug: (160) ? if (("%{NAS-IP-Address}" =~ /137.44.47.2[0-9]+[0-9]+/) && ("%{control:Tmp-String-2}" =~ /local|virus|banned|accomban/i)) Tue Nov 12 13:13:06 2013 : Debug: %{NAS-IP-Address} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "%{NAS-IP-Address}" -> '137.44.0.2' Tue Nov 12 13:13:06 2013 : Debug: (160) ? if (("%{NAS-IP-Address}" =~ /137.44.47.2[0-9]+[0-9]+/) && ("%{control:Tmp-String-2}" =~ /local|virus|banned|accomban/i)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ("%{control:Tmp-String-3}" == "guest") Tue Nov 12 13:13:06 2013 : Debug: guest Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: 'guest' Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "guest" -> 'guest' Tue Nov 12 13:13:06 2013 : Debug: %{control:Tmp-String-3} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Tmp-String-3 Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 3 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (160) expand: "%{control:Tmp-String-3}" -> '' Tue Nov 12 13:13:06 2013 : Debug: (160) ? if ("%{control:Tmp-String-3}" == "guest") -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: calling logintime (rlm_logintime) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: returned from logintime (rlm_logintime) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [logintime] = noop Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: calling pap (rlm_pap) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[authorize]: returned from pap (rlm_pap) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [pap] = noop Tue Nov 12 13:13:06 2013 : Debug: (160) } # authorize = ok Tue Nov 12 13:13:06 2013 : Debug: (160) # Executing section pre-proxy from file /usr/local/etc/raddb/sites-enabled/default Tue Nov 12 13:13:06 2013 : Debug: (160) pre-proxy { Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[pre-proxy]: calling attr_filter.pre-proxy (rlm_attr_filter) for request 160 Tue Nov 12 13:13:06 2013 : Debug: %{Realm} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Realm Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (160) attr_filter.pre-proxy : expand: "%{Realm}" -> 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (160) attr_filter.pre-proxy : Matched entry DEFAULT at line 50 Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[pre-proxy]: returned from attr_filter.pre-proxy (rlm_attr_filter) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [attr_filter.pre-proxy] = updated Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[pre-proxy]: calling pre_proxy_log (rlm_detail) for request 160 Tue Nov 12 13:13:06 2013 : Debug: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: '/usr/local/var/log/radius/radacct/' Tue Nov 12 13:13:06 2013 : Debug: if { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: else { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IPv6-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: literal: '/pre-proxy-detail-' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'Y' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'm' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'd' Tue Nov 12 13:13:06 2013 : Debug: (160) pre_proxy_log : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/123.44.55.66/pre-proxy-detail-20131112' Tue Nov 12 13:13:06 2013 : Debug: (160) pre_proxy_log : /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/123.44.55.66/pre-proxy-detail-20131112 Tue Nov 12 13:13:06 2013 : Debug: %t Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 't' Tue Nov 12 13:13:06 2013 : Debug: (160) pre_proxy_log : expand: "%t" -> 'Tue Nov 12 13:13:06 2013' Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[pre-proxy]: returned from pre_proxy_log (rlm_detail) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [pre_proxy_log] = ok Tue Nov 12 13:13:06 2013 : Debug: (160) } # pre-proxy = updated Tue Nov 12 13:13:06 2013 : Debug: (160) proxy: Trying to allocate ID (0/2) Tue Nov 12 13:13:06 2013 : Debug: (160) proxy: request is now in proxy hash Tue Nov 12 13:13:06 2013 : Debug: (160) proxy: allocating destination 194.83.56.233 port 1812 - Id 40 Tue Nov 12 13:13:06 2013 : Debug: (160) Proxying request to home server 194.83.56.233 port 1812 Sending Access-Request of id 40 from 0.0.0.0 port 1814 to 194.83.56.233 port 1812 User-Name = 'swansea.ac.uk@eduroam.ac.uk' NAS-IP-Address = 137.44.0.2 EAP-Message = 0x02000020017377616e7365612e61632e756b40656475726f616d2e61632e756b Message-Authenticator = 0x999c405516f2b7db33a613f6c1a41074 Proxy-State = 0x30 rad_recv: Access-Challenge packet from host 194.83.56.233 port 1812, id=40, length=67 EAP-Message = 0x010100061920 Message-Authenticator = 0x19f9109f3a86b45877b9fcad0eab74d5 State = 0x6ee887f26ee99ed95ce9a084cc329b80 Proxy-State = 0x30 Tue Nov 12 13:13:06 2013 : Debug: (160) proxy: request is no longer in proxy hash Tue Nov 12 13:13:06 2013 : Debug: (160) # Executing section post-proxy from file /usr/local/etc/raddb/sites-enabled/default Tue Nov 12 13:13:06 2013 : Debug: (160) post-proxy { Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[post-proxy]: calling post_proxy_log (rlm_detail) for request 160 Tue Nov 12 13:13:06 2013 : Debug: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: '/usr/local/var/log/radius/radacct/' Tue Nov 12 13:13:06 2013 : Debug: if { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: else { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IPv6-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: literal: '/post-proxy-detail-' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'Y' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'm' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'd' Tue Nov 12 13:13:06 2013 : Debug: (160) post_proxy_log : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/123.44.55.66/post-proxy-detail-20131112' Tue Nov 12 13:13:06 2013 : Debug: (160) post_proxy_log : /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/123.44.55.66/post-proxy-detail-20131112 Tue Nov 12 13:13:06 2013 : Debug: %t Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 't' Tue Nov 12 13:13:06 2013 : Debug: (160) post_proxy_log : expand: "%t" -> 'Tue Nov 12 13:13:06 2013' Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[post-proxy]: returned from post_proxy_log (rlm_detail) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [post_proxy_log] = ok Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[post-proxy]: calling eap (rlm_eap) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) eap : No pre-existing handler found Tue Nov 12 13:13:06 2013 : Debug: (160) modsingle[post-proxy]: returned from eap (rlm_eap) for request 160 Tue Nov 12 13:13:06 2013 : Debug: (160) [eap] = noop Tue Nov 12 13:13:06 2013 : Debug: (160) } # post-proxy = ok Sending Access-Challenge of id 0 from 137.44.1.53 port 1812 to 123.44.55.66 port 37026 EAP-Message = 0x010100061920 Message-Authenticator = 0x19f9109f3a86b45877b9fcad0eab74d5 State = 0x6ee887f26ee99ed95ce9a084cc329b80 Tue Nov 12 13:13:06 2013 : Debug: (160) Finished request 160. rad_recv: Access-Request packet from host 123.44.55.66 port 37026, id=1, length=270 User-Name = 'swansea.ac.uk@eduroam.ac.uk' Calling-Station-Id = '02-00-00-00-00-01' Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = 'CONNECT 11Mbps 802.11b' NAS-IP-Address = 137.44.0.2 EAP-Message = 0x0201007a198000000070160301006b01000067030152822962e4231c9e771215d6a36955588c3bc27a2c7d5bbc6a550a4f89ae664300003a00390038008800870035008400160013000a00330032009a009900450044002f00960041000500040015001200090014001100080006000300ff0100000400230000 State = 0x6ee887f26ee99ed95ce9a084cc329b80 Message-Authenticator = 0x3e189ee0ed4f4d44ecc15b259e54245c Tue Nov 12 13:13:06 2013 : Debug: (161) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Tue Nov 12 13:13:06 2013 : Debug: (161) authorize { Tue Nov 12 13:13:06 2013 : Debug: (161) filter_username filter_username { Tue Nov 12 13:13:06 2013 : Debug: (161) ? if (User-Name =~ /@.*@/ ) Tue Nov 12 13:13:06 2013 : Debug: (161) ? if (User-Name =~ /@.*@/ ) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) Tue Nov 12 13:13:06 2013 : Debug: (161) %{0}: Inserting new value "@" Tue Nov 12 13:13:06 2013 : Debug: (161) %{1}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{2}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{3}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{0}: Inserting new value "@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (161) %{1}: Inserting new value "eduroam.ac" Tue Nov 12 13:13:06 2013 : Debug: (161) %{2}: Inserting new value "uk" Tue Nov 12 13:13:06 2013 : Debug: (161) %{3}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (161) ? if (User-Name =~ /\\.$/) Tue Nov 12 13:13:06 2013 : Debug: (161) ? if (User-Name =~ /\\.$/) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (161) ? if (User-Name =~ /@\\./) Tue Nov 12 13:13:06 2013 : Debug: (161) ? if (User-Name =~ /@\\./) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (161) } # filter_username filter_username = notfound Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) Tue Nov 12 13:13:06 2013 : Debug: %{reply:Reply-Message} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Reply-Message Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 2 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "%{reply:Reply-Message}" -> '' Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (161) if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) { Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) Tue Nov 12 13:13:06 2013 : Debug: %{User-Name} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: User-Name Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "%{User-Name}" -> 'swansea.ac.uk@eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (161) %{0}: Inserting new value "swansea.ac.uk@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (161) %{1}: Inserting new value "swansea.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (161) %{2}: Inserting new value "@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (161) %{3}: Inserting new value "eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (161) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (161) if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) { Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ("%{3}") Tue Nov 12 13:13:06 2013 : Debug: %{3} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: regex-var: 3 Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "%{3}" -> 'eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ("%{3}") -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (161) if ("%{3}") { Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ((User-Name =~ /([a-z0-9_\.\-]+)@(swan|colegcymraeg|swansea|abertawe|test\.colegcymraeg|test\.swansea|test\.abertawe)\.ac\.uk/i) || (User-Name =~ /@(swan|colegcymraeg|swansea|abertawe)\.ac\.uk/i)) Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ((User-Name =~ /([a-z0-9_\.\-]+)@(swan|colegcymraeg|swansea|abertawe|test\.colegcymraeg|test\.swansea|test\.abertawe)\.ac\.uk/i) || (User-Name =~ /@(swan|colegcymraeg|swansea|abertawe)\.ac\.uk/i)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (161) else else { Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ((User-Name =~ /3gppnetwork\.org/i) || (User-Name =~ /\.acuk$/i) || (User-Name =~ /\.aaac\.uk\/$/i)) Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ((User-Name =~ /3gppnetwork\.org/i) || (User-Name =~ /\.acuk$/i) || (User-Name =~ /\.aaac\.uk\/$/i)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (161) else else { Tue Nov 12 13:13:06 2013 : Debug: (161) update request { Tue Nov 12 13:13:06 2013 : Debug: %{3} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: regex-var: 3 Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "%{3}" -> 'eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (161) Stripped-User-Domain = "eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (161) ::: FROM 1 TO 9 MAX 10 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: Examining Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (161) ::: APPENDING Stripped-User-Domain FROM 0 TO 9 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: TO in 9 out 10 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[0] = User-Name Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[1] = Calling-Station-Id Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[2] = Framed-MTU Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[3] = NAS-Port-Type Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[4] = Connect-Info Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[5] = NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[6] = EAP-Message Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[7] = State Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[8] = Message-Authenticator Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[9] = Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (161) } # update request = noop Tue Nov 12 13:13:06 2013 : Debug: (161) } # else else = noop Tue Nov 12 13:13:06 2013 : Debug: (161) } # else else = noop Tue Nov 12 13:13:06 2013 : Debug: (161) } # if ("%{3}") = noop Tue Nov 12 13:13:06 2013 : Debug: (161) ... skipping else for request 161: Preceding "if" was taken Tue Nov 12 13:13:06 2013 : Debug: (161) } # if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) = noop Tue Nov 12 13:13:06 2013 : Debug: (161) ... skipping else for request 161: Preceding "if" was taken Tue Nov 12 13:13:06 2013 : Debug: (161) ? if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) Tue Nov 12 13:13:06 2013 : Debug: %{NAS-IP-Address} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "%{NAS-IP-Address}" -> '137.44.0.2' Tue Nov 12 13:13:06 2013 : Debug: (161) %{0}: Inserting new value "137.44." Tue Nov 12 13:13:06 2013 : Debug: (161) %{1}: Clearing old value "swansea.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (161) %{2}: Clearing old value "@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (161) %{3}: Clearing old value "eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (161) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (161) ? if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (161) if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) { Tue Nov 12 13:13:06 2013 : Debug: (161) switch %{Stripped-User-Domain} { Tue Nov 12 13:13:06 2013 : Debug: %{Stripped-User-Domain} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "%{Stripped-User-Domain}" -> 'eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (161) switch %{Stripped-User-Domain} { Tue Nov 12 13:13:06 2013 : Debug: (161) case (null) { Tue Nov 12 13:13:06 2013 : Debug: (161) update control { Tue Nov 12 13:13:06 2013 : Debug: (161) Proxy-To-Realm := 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (161) ::: FROM 1 TO 0 MAX 1 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: Examining Proxy-To-Realm Tue Nov 12 13:13:06 2013 : Debug: (161) ::: APPENDING Proxy-To-Realm FROM 0 TO 0 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: TO in 0 out 1 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[0] = Proxy-To-Realm Tue Nov 12 13:13:06 2013 : Debug: (161) } # update control = noop Tue Nov 12 13:13:06 2013 : Debug: (161) update request { Tue Nov 12 13:13:06 2013 : Debug: (161) Realm := 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (161) ::: FROM 1 TO 10 MAX 11 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: Examining Realm Tue Nov 12 13:13:06 2013 : Debug: (161) ::: APPENDING Realm FROM 0 TO 10 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: TO in 10 out 11 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[0] = User-Name Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[1] = Calling-Station-Id Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[2] = Framed-MTU Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[3] = NAS-Port-Type Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[4] = Connect-Info Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[5] = NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[6] = EAP-Message Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[7] = State Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[8] = Message-Authenticator Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[9] = Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[10] = Realm Tue Nov 12 13:13:06 2013 : Debug: (161) Operator-Name := "1swansea.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (161) ::: FROM 1 TO 11 MAX 12 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: Examining Operator-Name Tue Nov 12 13:13:06 2013 : Debug: (161) ::: APPENDING Operator-Name FROM 0 TO 11 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: TO in 11 out 12 Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[0] = User-Name Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[1] = Calling-Station-Id Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[2] = Framed-MTU Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[3] = NAS-Port-Type Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[4] = Connect-Info Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[5] = NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[6] = EAP-Message Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[7] = State Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[8] = Message-Authenticator Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[9] = Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[10] = Realm Tue Nov 12 13:13:06 2013 : Debug: (161) ::: to[11] = Operator-Name Tue Nov 12 13:13:06 2013 : Debug: (161) } # update request = noop Tue Nov 12 13:13:06 2013 : Debug: (161) } # case = noop Tue Nov 12 13:13:06 2013 : Debug: (161) } # switch %{Stripped-User-Domain} = noop Tue Nov 12 13:13:06 2013 : Debug: (161) } # if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) = noop Tue Nov 12 13:13:06 2013 : Debug: (161) ... skipping else for request 161: Preceding "if" was taken Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ("%{Realm}" != "jrs") Tue Nov 12 13:13:06 2013 : Debug: jrs Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "jrs" -> 'jrs' Tue Nov 12 13:13:06 2013 : Debug: %{Realm} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Realm Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "%{Realm}" -> 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ("%{Realm}" != "jrs") -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (161) } # if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) = noop Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [preprocess] = ok Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: calling auth_log (rlm_detail) for request 161 Tue Nov 12 13:13:06 2013 : Debug: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: '/usr/local/var/log/radius/radacct/' Tue Nov 12 13:13:06 2013 : Debug: if { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: else { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IPv6-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: literal: '/auth-detail-' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'Y' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'm' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'd' Tue Nov 12 13:13:06 2013 : Debug: (161) auth_log : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/123.44.55.66/auth-detail-20131112' Tue Nov 12 13:13:06 2013 : Debug: (161) auth_log : /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/123.44.55.66/auth-detail-20131112 Tue Nov 12 13:13:06 2013 : Debug: %t Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 't' Tue Nov 12 13:13:06 2013 : Debug: (161) auth_log : expand: "%t" -> 'Tue Nov 12 13:13:06 2013' Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: returned from auth_log (rlm_detail) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [auth_log] = ok Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: calling chap (rlm_chap) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: returned from chap (rlm_chap) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [chap] = noop Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: calling mschap (rlm_mschap) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: returned from mschap (rlm_mschap) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [mschap] = noop Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: calling suffix (rlm_realm) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) suffix : Request already has destination realm set. Ignoring. Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: returned from suffix (rlm_realm) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [suffix] = ok Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: calling ntdomain (rlm_realm) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) ntdomain : Request already has destination realm set. Ignoring. Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: returned from ntdomain (rlm_realm) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [ntdomain] = ok Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: calling eap (rlm_eap) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) eap : Request is supposed to be proxied to Realm jrs. Not doing EAP. Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: returned from eap (rlm_eap) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [eap] = noop Tue Nov 12 13:13:06 2013 : Debug: (161) ? if (("%{NAS-IP-Address}" =~ /137.44.47.2[0-9]+[0-9]+/) && ("%{control:Tmp-String-2}" =~ /local|virus|banned|accomban/i)) Tue Nov 12 13:13:06 2013 : Debug: %{NAS-IP-Address} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "%{NAS-IP-Address}" -> '137.44.0.2' Tue Nov 12 13:13:06 2013 : Debug: (161) ? if (("%{NAS-IP-Address}" =~ /137.44.47.2[0-9]+[0-9]+/) && ("%{control:Tmp-String-2}" =~ /local|virus|banned|accomban/i)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ("%{control:Tmp-String-3}" == "guest") Tue Nov 12 13:13:06 2013 : Debug: guest Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: 'guest' Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "guest" -> 'guest' Tue Nov 12 13:13:06 2013 : Debug: %{control:Tmp-String-3} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Tmp-String-3 Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 3 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (161) expand: "%{control:Tmp-String-3}" -> '' Tue Nov 12 13:13:06 2013 : Debug: (161) ? if ("%{control:Tmp-String-3}" == "guest") -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: calling logintime (rlm_logintime) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: returned from logintime (rlm_logintime) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [logintime] = noop Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: calling pap (rlm_pap) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[authorize]: returned from pap (rlm_pap) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [pap] = noop Tue Nov 12 13:13:06 2013 : Debug: (161) } # authorize = ok Tue Nov 12 13:13:06 2013 : Debug: (161) # Executing section pre-proxy from file /usr/local/etc/raddb/sites-enabled/default Tue Nov 12 13:13:06 2013 : Debug: (161) pre-proxy { Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[pre-proxy]: calling attr_filter.pre-proxy (rlm_attr_filter) for request 161 Tue Nov 12 13:13:06 2013 : Debug: %{Realm} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Realm Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (161) attr_filter.pre-proxy : expand: "%{Realm}" -> 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (161) attr_filter.pre-proxy : Matched entry DEFAULT at line 50 Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[pre-proxy]: returned from attr_filter.pre-proxy (rlm_attr_filter) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [attr_filter.pre-proxy] = updated Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[pre-proxy]: calling pre_proxy_log (rlm_detail) for request 161 Tue Nov 12 13:13:06 2013 : Debug: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: '/usr/local/var/log/radius/radacct/' Tue Nov 12 13:13:06 2013 : Debug: if { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: else { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IPv6-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: literal: '/pre-proxy-detail-' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'Y' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'm' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'd' Tue Nov 12 13:13:06 2013 : Debug: (161) pre_proxy_log : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/123.44.55.66/pre-proxy-detail-20131112' Tue Nov 12 13:13:06 2013 : Debug: (161) pre_proxy_log : /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/123.44.55.66/pre-proxy-detail-20131112 Tue Nov 12 13:13:06 2013 : Debug: %t Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 't' Tue Nov 12 13:13:06 2013 : Debug: (161) pre_proxy_log : expand: "%t" -> 'Tue Nov 12 13:13:06 2013' Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[pre-proxy]: returned from pre_proxy_log (rlm_detail) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [pre_proxy_log] = ok Tue Nov 12 13:13:06 2013 : Debug: (161) } # pre-proxy = updated Tue Nov 12 13:13:06 2013 : Debug: (161) proxy: Trying to allocate ID (0/2) Tue Nov 12 13:13:06 2013 : Debug: (161) proxy: request is now in proxy hash Tue Nov 12 13:13:06 2013 : Debug: (161) proxy: allocating destination 194.83.56.233 port 1812 - Id 10 Tue Nov 12 13:13:06 2013 : Debug: (161) Proxying request to home server 194.83.56.233 port 1812 Sending Access-Request of id 10 from 0.0.0.0 port 1814 to 194.83.56.233 port 1812 User-Name = 'swansea.ac.uk@eduroam.ac.uk' NAS-IP-Address = 137.44.0.2 EAP-Message = 0x0201007a198000000070160301006b01000067030152822962e4231c9e771215d6a36955588c3bc27a2c7d5bbc6a550a4f89ae664300003a00390038008800870035008400160013000a00330032009a009900450044002f00960041000500040015001200090014001100080006000300ff0100000400230000 State = 0x6ee887f26ee99ed95ce9a084cc329b80 Message-Authenticator = 0x3e189ee0ed4f4d44ecc15b259e54245c Proxy-State = 0x31 Tue Nov 12 13:13:06 2013 : Debug: (139) Cleaning up request packet ID 9 with timestamp +31 Tue Nov 12 13:13:06 2013 : Debug: Waking up in 0.3 seconds. rad_recv: Access-Challenge packet from host 194.83.56.233 port 1812, id=10, length=1093 EAP-Message = Message-Authenticator = 0x994dd1a59a24eb48a85ea6b7548afcf6 State = 0x6ee887f26fea9ed95ce9a084cc329b80 Proxy-State = 0x31 Tue Nov 12 13:13:06 2013 : Debug: (161) proxy: request is no longer in proxy hash Tue Nov 12 13:13:06 2013 : Debug: (161) # Executing section post-proxy from file /usr/local/etc/raddb/sites-enabled/default Tue Nov 12 13:13:06 2013 : Debug: (161) post-proxy { Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[post-proxy]: calling post_proxy_log (rlm_detail) for request 161 Tue Nov 12 13:13:06 2013 : Debug: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: '/usr/local/var/log/radius/radacct/' Tue Nov 12 13:13:06 2013 : Debug: if { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: else { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IPv6-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: literal: '/post-proxy-detail-' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'Y' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'm' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'd' Tue Nov 12 13:13:06 2013 : Debug: (161) post_proxy_log : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/123.44.55.66/post-proxy-detail-20131112' Tue Nov 12 13:13:06 2013 : Debug: (161) post_proxy_log : /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/123.44.55.66/post-proxy-detail-20131112 Tue Nov 12 13:13:06 2013 : Debug: %t Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 't' Tue Nov 12 13:13:06 2013 : Debug: (161) post_proxy_log : expand: "%t" -> 'Tue Nov 12 13:13:06 2013' Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[post-proxy]: returned from post_proxy_log (rlm_detail) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [post_proxy_log] = ok Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[post-proxy]: calling eap (rlm_eap) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) eap : No pre-existing handler found Tue Nov 12 13:13:06 2013 : Debug: (161) modsingle[post-proxy]: returned from eap (rlm_eap) for request 161 Tue Nov 12 13:13:06 2013 : Debug: (161) [eap] = noop Tue Nov 12 13:13:06 2013 : Debug: (161) } # post-proxy = ok Sending Access-Challenge of id 1 from 137.44.1.53 port 1812 to 123.44.55.66 port 37026 EAP-Message = Message-Authenticator = 0x994dd1a59a24eb48a85ea6b7548afcf6 State = 0x6ee887f26fea9ed95ce9a084cc329b80 Tue Nov 12 13:13:06 2013 : Debug: (161) Finished request 161. Tue Nov 12 13:13:06 2013 : Debug: Waking up in 0.2 seconds. rad_recv: Access-Request packet from host 123.44.55.66 port 37026, id=2, length=154 User-Name = 'swansea.ac.uk@eduroam.ac.uk' Calling-Station-Id = '02-00-00-00-00-01' Framed-MTU = 1400 NAS-Port-Type = Wireless-802.11 Connect-Info = 'CONNECT 11Mbps 802.11b' NAS-IP-Address = 137.44.0.2 EAP-Message = 0x020200061900 State = 0x6ee887f26fea9ed95ce9a084cc329b80 Message-Authenticator = 0x81d5ddca52123616fc193cd8a980b775 Tue Nov 12 13:13:06 2013 : Debug: (162) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Tue Nov 12 13:13:06 2013 : Debug: (162) authorize { Tue Nov 12 13:13:06 2013 : Debug: (162) filter_username filter_username { Tue Nov 12 13:13:06 2013 : Debug: (162) ? if (User-Name =~ /@.*@/ ) Tue Nov 12 13:13:06 2013 : Debug: (162) ? if (User-Name =~ /@.*@/ ) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) Tue Nov 12 13:13:06 2013 : Debug: (162) %{0}: Inserting new value "@" Tue Nov 12 13:13:06 2013 : Debug: (162) %{1}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{2}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{3}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{0}: Inserting new value "@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (162) %{1}: Inserting new value "eduroam.ac" Tue Nov 12 13:13:06 2013 : Debug: (162) %{2}: Inserting new value "uk" Tue Nov 12 13:13:06 2013 : Debug: (162) %{3}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (162) ? if (User-Name =~ /\\.$/) Tue Nov 12 13:13:06 2013 : Debug: (162) ? if (User-Name =~ /\\.$/) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (162) ? if (User-Name =~ /@\\./) Tue Nov 12 13:13:06 2013 : Debug: (162) ? if (User-Name =~ /@\\./) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (162) } # filter_username filter_username = notfound Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) Tue Nov 12 13:13:06 2013 : Debug: %{reply:Reply-Message} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Reply-Message Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 2 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "%{reply:Reply-Message}" -> '' Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (162) if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) { Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) Tue Nov 12 13:13:06 2013 : Debug: %{User-Name} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: User-Name Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "%{User-Name}" -> 'swansea.ac.uk@eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (162) %{0}: Inserting new value "swansea.ac.uk@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (162) %{1}: Inserting new value "swansea.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (162) %{2}: Inserting new value "@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (162) %{3}: Inserting new value "eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (162) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (162) if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) { Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ("%{3}") Tue Nov 12 13:13:06 2013 : Debug: %{3} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: regex-var: 3 Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "%{3}" -> 'eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ("%{3}") -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (162) if ("%{3}") { Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ((User-Name =~ /([a-z0-9_\.\-]+)@(swan|colegcymraeg|swansea|abertawe|test\.colegcymraeg|test\.swansea|test\.abertawe)\.ac\.uk/i) || (User-Name =~ /@(swan|colegcymraeg|swansea|abertawe)\.ac\.uk/i)) Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ((User-Name =~ /([a-z0-9_\.\-]+)@(swan|colegcymraeg|swansea|abertawe|test\.colegcymraeg|test\.swansea|test\.abertawe)\.ac\.uk/i) || (User-Name =~ /@(swan|colegcymraeg|swansea|abertawe)\.ac\.uk/i)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (162) else else { Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ((User-Name =~ /3gppnetwork\.org/i) || (User-Name =~ /\.acuk$/i) || (User-Name =~ /\.aaac\.uk\/$/i)) Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ((User-Name =~ /3gppnetwork\.org/i) || (User-Name =~ /\.acuk$/i) || (User-Name =~ /\.aaac\.uk\/$/i)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (162) else else { Tue Nov 12 13:13:06 2013 : Debug: (162) update request { Tue Nov 12 13:13:06 2013 : Debug: %{3} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: regex-var: 3 Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "%{3}" -> 'eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (162) Stripped-User-Domain = "eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (162) ::: FROM 1 TO 9 MAX 10 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: Examining Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (162) ::: APPENDING Stripped-User-Domain FROM 0 TO 9 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: TO in 9 out 10 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[0] = User-Name Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[1] = Calling-Station-Id Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[2] = Framed-MTU Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[3] = NAS-Port-Type Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[4] = Connect-Info Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[5] = NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[6] = EAP-Message Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[7] = State Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[8] = Message-Authenticator Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[9] = Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (162) } # update request = noop Tue Nov 12 13:13:06 2013 : Debug: (162) } # else else = noop Tue Nov 12 13:13:06 2013 : Debug: (162) } # else else = noop Tue Nov 12 13:13:06 2013 : Debug: (162) } # if ("%{3}") = noop Tue Nov 12 13:13:06 2013 : Debug: (162) ... skipping else for request 162: Preceding "if" was taken Tue Nov 12 13:13:06 2013 : Debug: (162) } # if ("%{User-Name}" =~ /^([^@]*)(@([-[:alnum:].]+))?$/) = noop Tue Nov 12 13:13:06 2013 : Debug: (162) ... skipping else for request 162: Preceding "if" was taken Tue Nov 12 13:13:06 2013 : Debug: (162) ? if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) Tue Nov 12 13:13:06 2013 : Debug: %{NAS-IP-Address} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "%{NAS-IP-Address}" -> '137.44.0.2' Tue Nov 12 13:13:06 2013 : Debug: (162) %{0}: Inserting new value "137.44." Tue Nov 12 13:13:06 2013 : Debug: (162) %{1}: Clearing old value "swansea.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (162) %{2}: Clearing old value "@eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (162) %{3}: Clearing old value "eduroam.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (162) %{4}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{5}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{6}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{7}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) %{8}: Was empty Tue Nov 12 13:13:06 2013 : Debug: (162) ? if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) -> TRUE Tue Nov 12 13:13:06 2013 : Debug: (162) if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) { Tue Nov 12 13:13:06 2013 : Debug: (162) switch %{Stripped-User-Domain} { Tue Nov 12 13:13:06 2013 : Debug: %{Stripped-User-Domain} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "%{Stripped-User-Domain}" -> 'eduroam.ac.uk' Tue Nov 12 13:13:06 2013 : Debug: (162) switch %{Stripped-User-Domain} { Tue Nov 12 13:13:06 2013 : Debug: (162) case (null) { Tue Nov 12 13:13:06 2013 : Debug: (162) update control { Tue Nov 12 13:13:06 2013 : Debug: (162) Proxy-To-Realm := 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (162) ::: FROM 1 TO 0 MAX 1 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: Examining Proxy-To-Realm Tue Nov 12 13:13:06 2013 : Debug: (162) ::: APPENDING Proxy-To-Realm FROM 0 TO 0 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: TO in 0 out 1 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[0] = Proxy-To-Realm Tue Nov 12 13:13:06 2013 : Debug: (162) } # update control = noop Tue Nov 12 13:13:06 2013 : Debug: (162) update request { Tue Nov 12 13:13:06 2013 : Debug: (162) Realm := 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (162) ::: FROM 1 TO 10 MAX 11 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: Examining Realm Tue Nov 12 13:13:06 2013 : Debug: (162) ::: APPENDING Realm FROM 0 TO 10 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: TO in 10 out 11 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[0] = User-Name Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[1] = Calling-Station-Id Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[2] = Framed-MTU Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[3] = NAS-Port-Type Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[4] = Connect-Info Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[5] = NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[6] = EAP-Message Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[7] = State Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[8] = Message-Authenticator Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[9] = Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[10] = Realm Tue Nov 12 13:13:06 2013 : Debug: (162) Operator-Name := "1swansea.ac.uk" Tue Nov 12 13:13:06 2013 : Debug: (162) ::: FROM 1 TO 11 MAX 12 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: Examining Operator-Name Tue Nov 12 13:13:06 2013 : Debug: (162) ::: APPENDING Operator-Name FROM 0 TO 11 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: TO in 11 out 12 Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[0] = User-Name Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[1] = Calling-Station-Id Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[2] = Framed-MTU Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[3] = NAS-Port-Type Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[4] = Connect-Info Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[5] = NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[6] = EAP-Message Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[7] = State Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[8] = Message-Authenticator Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[9] = Stripped-User-Domain Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[10] = Realm Tue Nov 12 13:13:06 2013 : Debug: (162) ::: to[11] = Operator-Name Tue Nov 12 13:13:06 2013 : Debug: (162) } # update request = noop Tue Nov 12 13:13:06 2013 : Debug: (162) } # case = noop Tue Nov 12 13:13:06 2013 : Debug: (162) } # switch %{Stripped-User-Domain} = noop Tue Nov 12 13:13:06 2013 : Debug: (162) } # if (("%{NAS-IP-Address}" =~ /^137\.44\./) || ("%{NAS-IP-Address}" =~ /^10\.56\.14\./) || ("%{NAS-IP-Address}" =~ /^10\.60\./) || ("%{NAS-IP-Address}" =~ /^10\.10\.246\./)) = noop Tue Nov 12 13:13:06 2013 : Debug: (162) ... skipping else for request 162: Preceding "if" was taken Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ("%{Realm}" != "jrs") Tue Nov 12 13:13:06 2013 : Debug: jrs Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "jrs" -> 'jrs' Tue Nov 12 13:13:06 2013 : Debug: %{Realm} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Realm Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "%{Realm}" -> 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ("%{Realm}" != "jrs") -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (162) } # if ("%{reply:Reply-Message}" !~ /MAC-AUTH/) = noop Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: calling preprocess (rlm_preprocess) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [preprocess] = ok Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: calling auth_log (rlm_detail) for request 162 Tue Nov 12 13:13:06 2013 : Debug: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: '/usr/local/var/log/radius/radacct/' Tue Nov 12 13:13:06 2013 : Debug: if { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: else { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IPv6-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: literal: '/auth-detail-' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'Y' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'm' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'd' Tue Nov 12 13:13:06 2013 : Debug: (162) auth_log : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/123.44.55.66/auth-detail-20131112' Tue Nov 12 13:13:06 2013 : Debug: (162) auth_log : /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/123.44.55.66/auth-detail-20131112 Tue Nov 12 13:13:06 2013 : Debug: %t Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 't' Tue Nov 12 13:13:06 2013 : Debug: (162) auth_log : expand: "%t" -> 'Tue Nov 12 13:13:06 2013' Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: returned from auth_log (rlm_detail) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [auth_log] = ok Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: calling chap (rlm_chap) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: returned from chap (rlm_chap) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [chap] = noop Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: calling mschap (rlm_mschap) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: returned from mschap (rlm_mschap) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [mschap] = noop Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: calling suffix (rlm_realm) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) suffix : Request already has destination realm set. Ignoring. Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: returned from suffix (rlm_realm) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [suffix] = ok Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: calling ntdomain (rlm_realm) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) ntdomain : Request already has destination realm set. Ignoring. Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: returned from ntdomain (rlm_realm) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [ntdomain] = ok Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: calling eap (rlm_eap) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) eap : Request is supposed to be proxied to Realm jrs. Not doing EAP. Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: returned from eap (rlm_eap) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [eap] = noop Tue Nov 12 13:13:06 2013 : Debug: (162) ? if (("%{NAS-IP-Address}" =~ /137.44.47.2[0-9]+[0-9]+/) && ("%{control:Tmp-String-2}" =~ /local|virus|banned|accomban/i)) Tue Nov 12 13:13:06 2013 : Debug: %{NAS-IP-Address} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: NAS-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "%{NAS-IP-Address}" -> '137.44.0.2' Tue Nov 12 13:13:06 2013 : Debug: (162) ? if (("%{NAS-IP-Address}" =~ /137.44.47.2[0-9]+[0-9]+/) && ("%{control:Tmp-String-2}" =~ /local|virus|banned|accomban/i)) -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ("%{control:Tmp-String-3}" == "guest") Tue Nov 12 13:13:06 2013 : Debug: guest Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: 'guest' Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "guest" -> 'guest' Tue Nov 12 13:13:06 2013 : Debug: %{control:Tmp-String-3} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Tmp-String-3 Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 3 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (162) expand: "%{control:Tmp-String-3}" -> '' Tue Nov 12 13:13:06 2013 : Debug: (162) ? if ("%{control:Tmp-String-3}" == "guest") -> FALSE Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: calling logintime (rlm_logintime) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: returned from logintime (rlm_logintime) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [logintime] = noop Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: calling pap (rlm_pap) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[authorize]: returned from pap (rlm_pap) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [pap] = noop Tue Nov 12 13:13:06 2013 : Debug: (162) } # authorize = ok Tue Nov 12 13:13:06 2013 : Debug: (162) # Executing section pre-proxy from file /usr/local/etc/raddb/sites-enabled/default Tue Nov 12 13:13:06 2013 : Debug: (162) pre-proxy { Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[pre-proxy]: calling attr_filter.pre-proxy (rlm_attr_filter) for request 162 Tue Nov 12 13:13:06 2013 : Debug: %{Realm} Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: attribute: Realm Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: (162) attr_filter.pre-proxy : expand: "%{Realm}" -> 'jrs' Tue Nov 12 13:13:06 2013 : Debug: (162) attr_filter.pre-proxy : Matched entry DEFAULT at line 50 Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[pre-proxy]: returned from attr_filter.pre-proxy (rlm_attr_filter) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [attr_filter.pre-proxy] = updated Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[pre-proxy]: calling pre_proxy_log (rlm_detail) for request 162 Tue Nov 12 13:13:06 2013 : Debug: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal: '/usr/local/var/log/radius/radacct/' Tue Nov 12 13:13:06 2013 : Debug: if { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IP-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: else { Tue Nov 12 13:13:06 2013 : Debug: attribute: Packet-Src-IPv6-Address Tue Nov 12 13:13:06 2013 : Debug: { Tue Nov 12 13:13:06 2013 : Debug: ref 2 Tue Nov 12 13:13:06 2013 : Debug: list 1 Tue Nov 12 13:13:06 2013 : Debug: tag -128 Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: } Tue Nov 12 13:13:06 2013 : Debug: literal: '/pre-proxy-detail-' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'Y' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'm' Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 'd' Tue Nov 12 13:13:06 2013 : Debug: (162) pre_proxy_log : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/123.44.55.66/pre-proxy-detail-20131112' Tue Nov 12 13:13:06 2013 : Debug: (162) pre_proxy_log : /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/123.44.55.66/pre-proxy-detail-20131112 Tue Nov 12 13:13:06 2013 : Debug: %t Tue Nov 12 13:13:06 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:06 2013 : Debug: literal (with %): 't' Tue Nov 12 13:13:06 2013 : Debug: (162) pre_proxy_log : expand: "%t" -> 'Tue Nov 12 13:13:06 2013' Tue Nov 12 13:13:06 2013 : Debug: (162) modsingle[pre-proxy]: returned from pre_proxy_log (rlm_detail) for request 162 Tue Nov 12 13:13:06 2013 : Debug: (162) [pre_proxy_log] = ok Tue Nov 12 13:13:06 2013 : Debug: (162) } # pre-proxy = updated Tue Nov 12 13:13:06 2013 : Debug: (162) proxy: Trying to allocate ID (0/2) Tue Nov 12 13:13:06 2013 : Debug: (162) proxy: request is now in proxy hash Tue Nov 12 13:13:06 2013 : Debug: (162) proxy: allocating destination 194.83.56.233 port 1812 - Id 252 Tue Nov 12 13:13:06 2013 : Debug: (162) Proxying request to home server 194.83.56.233 port 1812 Sending Access-Request of id 252 from 0.0.0.0 port 1814 to 194.83.56.233 port 1812 User-Name = 'swansea.ac.uk@eduroam.ac.uk' NAS-IP-Address = 137.44.0.2 EAP-Message = 0x020200061900 State = 0x6ee887f26fea9ed95ce9a084cc329b80 Message-Authenticator = 0x81d5ddca52123616fc193cd8a980b775 Proxy-State = 0x32 Tue Nov 12 13:13:06 2013 : Debug: Waking up in 0.2 seconds. Tue Nov 12 13:13:07 2013 : Debug: Waking up in 0.4 seconds. Tue Nov 12 13:13:07 2013 : Debug: (162) Expecting proxy response no later than 30 seconds from now Tue Nov 12 13:13:07 2013 : Debug: Waking up in 1.4 seconds. Tue Nov 12 13:13:09 2013 : Debug: (140) Cleaning up request packet ID 0 with timestamp +34 Tue Nov 12 13:13:09 2013 : Debug: (141) Cleaning up request packet ID 1 with timestamp +34 Tue Nov 12 13:13:09 2013 : Debug: (142) Cleaning up request packet ID 2 with timestamp +34 Tue Nov 12 13:13:09 2013 : Debug: (143) Cleaning up request packet ID 3 with timestamp +34 Tue Nov 12 13:13:09 2013 : Debug: (144) Cleaning up request packet ID 4 with timestamp +34 Tue Nov 12 13:13:09 2013 : Debug: (145) Cleaning up request packet ID 5 with timestamp +34 Tue Nov 12 13:13:09 2013 : Debug: (146) Cleaning up request packet ID 6 with timestamp +34 Tue Nov 12 13:13:09 2013 : Debug: (147) Cleaning up request packet ID 7 with timestamp +34 Tue Nov 12 13:13:09 2013 : Debug: (148) Cleaning up request packet ID 8 with timestamp +34 Tue Nov 12 13:13:09 2013 : Debug: (149) Cleaning up request packet ID 9 with timestamp +34 Tue Nov 12 13:13:09 2013 : Debug: Waking up in 0.8 seconds. rad_recv: Access-Request packet from host 123.44.55.66 port 37026, id=2, length=154 Tue Nov 12 13:13:09 2013 : Debug: (162) Sending duplicate proxied request to home server 194.83.56.233 port 1812 - ID: 252 Sending Access-Request of id 252 from 0.0.0.0 port 1814 to 194.83.56.233 port 1812 User-Name = 'swansea.ac.uk@eduroam.ac.uk' NAS-IP-Address = 137.44.0.2 EAP-Message = 0x020200061900 State = 0x6ee887f26fea9ed95ce9a084cc329b80 Message-Authenticator = 0x81d5ddca52123616fc193cd8a980b775 Proxy-State = 0x32 Tue Nov 12 13:13:09 2013 : Debug: Waking up in 0.5 seconds. rad_recv: Access-Reject packet from host 194.83.56.233 port 1812, id=252, length=39 Reply-Message = 'Request Denied' Proxy-State = 0x32 Tue Nov 12 13:13:09 2013 : Debug: (162) # Executing section post-proxy from file /usr/local/etc/raddb/sites-enabled/default Tue Nov 12 13:13:09 2013 : Debug: (162) post-proxy { Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-proxy]: calling post_proxy_log (rlm_detail) for request 162 Tue Nov 12 13:13:09 2013 : Debug: /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d Tue Nov 12 13:13:09 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:09 2013 : Debug: literal: '/usr/local/var/log/radius/radacct/' Tue Nov 12 13:13:09 2013 : Debug: if { Tue Nov 12 13:13:09 2013 : Debug: attribute: Packet-Src-IP-Address Tue Nov 12 13:13:09 2013 : Debug: { Tue Nov 12 13:13:09 2013 : Debug: ref 2 Tue Nov 12 13:13:09 2013 : Debug: list 1 Tue Nov 12 13:13:09 2013 : Debug: tag -128 Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: else { Tue Nov 12 13:13:09 2013 : Debug: attribute: Packet-Src-IPv6-Address Tue Nov 12 13:13:09 2013 : Debug: { Tue Nov 12 13:13:09 2013 : Debug: ref 2 Tue Nov 12 13:13:09 2013 : Debug: list 1 Tue Nov 12 13:13:09 2013 : Debug: tag -128 Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: literal: '/post-proxy-detail-' Tue Nov 12 13:13:09 2013 : Debug: literal (with %): 'Y' Tue Nov 12 13:13:09 2013 : Debug: literal (with %): 'm' Tue Nov 12 13:13:09 2013 : Debug: literal (with %): 'd' Tue Nov 12 13:13:09 2013 : Debug: (162) post_proxy_log : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/123.44.55.66/post-proxy-detail-20131112' Tue Nov 12 13:13:09 2013 : Debug: (162) post_proxy_log : /usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/123.44.55.66/post-proxy-detail-20131112 Tue Nov 12 13:13:09 2013 : Debug: %t Tue Nov 12 13:13:09 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:09 2013 : Debug: literal (with %): 't' Tue Nov 12 13:13:09 2013 : Debug: (162) post_proxy_log : expand: "%t" -> 'Tue Nov 12 13:13:06 2013' Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-proxy]: returned from post_proxy_log (rlm_detail) for request 162 Tue Nov 12 13:13:09 2013 : Debug: (162) [post_proxy_log] = ok Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-proxy]: calling eap (rlm_eap) for request 162 Tue Nov 12 13:13:09 2013 : Debug: (162) eap : No pre-existing handler found Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-proxy]: returned from eap (rlm_eap) for request 162 Tue Nov 12 13:13:09 2013 : Debug: (162) [eap] = noop Tue Nov 12 13:13:09 2013 : Debug: (162) } # post-proxy = ok Tue Nov 12 13:13:09 2013 : Debug: (162) Using Post-Auth-Type Reject Tue Nov 12 13:13:09 2013 : Debug: (162) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Tue Nov 12 13:13:09 2013 : Debug: (162) Post-Auth-Type REJECT { Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-auth]: calling sql (rlm_sql) for request 162 Tue Nov 12 13:13:09 2013 : Debug: .query Tue Nov 12 13:13:09 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:09 2013 : Debug: literal: '.query' Tue Nov 12 13:13:09 2013 : Debug: (162) sql : expand: ".query" -> '.query' Tue Nov 12 13:13:09 2013 : Debug: (162) sql : Using query template 'query' Tue Nov 12 13:13:09 2013 : Debug: rlm_sql (sql): Reserved connection (4) Tue Nov 12 13:13:09 2013 : Debug: %{User-Name} Tue Nov 12 13:13:09 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:09 2013 : Debug: attribute: User-Name Tue Nov 12 13:13:09 2013 : Debug: { Tue Nov 12 13:13:09 2013 : Debug: ref 2 Tue Nov 12 13:13:09 2013 : Debug: list 1 Tue Nov 12 13:13:09 2013 : Debug: tag -128 Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: (162) sql : expand: "%{User-Name}" -> 'swansea.ac.uk@eduroam.ac.uk' Tue Nov 12 13:13:09 2013 : Debug: (162) sql : SQL-User-Name set to "swansea.ac.uk@eduroam.ac.uk" Tue Nov 12 13:13:09 2013 : Debug: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') Tue Nov 12 13:13:09 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:09 2013 : Debug: literal: 'INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '' Tue Nov 12 13:13:09 2013 : Debug: attribute: SQL-User-Name Tue Nov 12 13:13:09 2013 : Debug: { Tue Nov 12 13:13:09 2013 : Debug: ref 2 Tue Nov 12 13:13:09 2013 : Debug: list 1 Tue Nov 12 13:13:09 2013 : Debug: tag -128 Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: literal: '', '' Tue Nov 12 13:13:09 2013 : Debug: if { Tue Nov 12 13:13:09 2013 : Debug: attribute: User-Password Tue Nov 12 13:13:09 2013 : Debug: { Tue Nov 12 13:13:09 2013 : Debug: ref 2 Tue Nov 12 13:13:09 2013 : Debug: list 1 Tue Nov 12 13:13:09 2013 : Debug: tag -128 Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: else { Tue Nov 12 13:13:09 2013 : Debug: attribute: CHAP-Password Tue Nov 12 13:13:09 2013 : Debug: { Tue Nov 12 13:13:09 2013 : Debug: ref 2 Tue Nov 12 13:13:09 2013 : Debug: list 1 Tue Nov 12 13:13:09 2013 : Debug: tag -128 Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: literal: '', '' Tue Nov 12 13:13:09 2013 : Debug: attribute: Packet-Type Tue Nov 12 13:13:09 2013 : Debug: { Tue Nov 12 13:13:09 2013 : Debug: ref 2 Tue Nov 12 13:13:09 2013 : Debug: list 2 Tue Nov 12 13:13:09 2013 : Debug: tag -128 Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: literal: '', '' Tue Nov 12 13:13:09 2013 : Debug: literal (with %): 'S' Tue Nov 12 13:13:09 2013 : Debug: literal: '')' Tue Nov 12 13:13:09 2013 : Debug: (162) sql : expand: "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" -> 'INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'swansea.ac.uk@eduroam.ac.uk', '', 'Access-Reject', '2013-11-12 13:13:06')' Tue Nov 12 13:13:09 2013 : Debug: rlm_sql (sql): Executing query: 'INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'swansea.ac.uk@eduroam.ac.uk', '', 'Access-Reject', '2013-11-12 13:13:06')' Tue Nov 12 13:13:09 2013 : Debug: rlm_sql (sql): Released connection (4) Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-auth]: returned from sql (rlm_sql) for request 162 Tue Nov 12 13:13:09 2013 : Debug: (162) [-sql] = ok Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) for request 162 Tue Nov 12 13:13:09 2013 : Debug: %{User-Name} Tue Nov 12 13:13:09 2013 : Debug: Parsed xlat tree: Tue Nov 12 13:13:09 2013 : Debug: attribute: User-Name Tue Nov 12 13:13:09 2013 : Debug: { Tue Nov 12 13:13:09 2013 : Debug: ref 2 Tue Nov 12 13:13:09 2013 : Debug: list 1 Tue Nov 12 13:13:09 2013 : Debug: tag -128 Tue Nov 12 13:13:09 2013 : Debug: } Tue Nov 12 13:13:09 2013 : Debug: (162) attr_filter.access_reject : expand: "%{User-Name}" -> 'swansea.ac.uk@eduroam.ac.uk' Tue Nov 12 13:13:09 2013 : Debug: (162) attr_filter.access_reject : Matched entry DEFAULT at line 11 Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) for request 162 Tue Nov 12 13:13:09 2013 : Debug: (162) [attr_filter.access_reject] = updated Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-auth]: calling eap (rlm_eap) for request 162 Tue Nov 12 13:13:09 2013 : Error: rlm_eap (EAP): No EAP session matching state 0x6ee887f26fea9ed9 Tue Nov 12 13:13:09 2013 : Debug: (162) eap : Either EAP-request timed out OR EAP-response to an unknown EAP-request Tue Nov 12 13:13:09 2013 : Debug: (162) eap : Failed to get handler, probably already removed, not inserting EAP-Failure Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-auth]: returned from eap (rlm_eap) for request 162 Tue Nov 12 13:13:09 2013 : Debug: (162) [eap] = noop Tue Nov 12 13:13:09 2013 : Debug: (162) remove_reply_message_if_eap remove_reply_message_if_eap { Tue Nov 12 13:13:09 2013 : Debug: (162) ? if (reply:EAP-Message && reply:Reply-Message) Tue Nov 12 13:13:09 2013 : Debug: (162) ? if (reply:EAP-Message && reply:Reply-Message) -> FALSE Tue Nov 12 13:13:09 2013 : Debug: (162) else else { Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-auth]: calling noop (rlm_always) for request 162 Tue Nov 12 13:13:09 2013 : Debug: (162) modsingle[post-auth]: returned from noop (rlm_always) for request 162 Tue Nov 12 13:13:09 2013 : Debug: (162) [noop] = noop Tue Nov 12 13:13:09 2013 : Debug: (162) } # else else = noop Tue Nov 12 13:13:09 2013 : Debug: (162) } # remove_reply_message_if_eap remove_reply_message_if_eap = noop Tue Nov 12 13:13:09 2013 : Debug: (162) } # Post-Auth-Type REJECT = updated Tue Nov 12 13:13:09 2013 : Debug: (162) Finished request 162. Tue Nov 12 13:13:09 2013 : Debug: Waking up in 0.3 seconds. Tue Nov 12 13:13:10 2013 : Debug: Waking up in 0.1 seconds. Tue Nov 12 13:13:10 2013 : Debug: (150) Cleaning up request packet ID 0 with timestamp +35 Tue Nov 12 13:13:10 2013 : Debug: (151) Cleaning up request packet ID 1 with timestamp +35 Tue Nov 12 13:13:10 2013 : Debug: (152) Cleaning up request packet ID 2 with timestamp +35 Tue Nov 12 13:13:10 2013 : Debug: (153) Cleaning up request packet ID 3 with timestamp +35 Tue Nov 12 13:13:10 2013 : Debug: (154) Cleaning up request packet ID 4 with timestamp +35 Tue Nov 12 13:13:10 2013 : Debug: (155) Cleaning up request packet ID 5 with timestamp +35 Tue Nov 12 13:13:10 2013 : Debug: (156) Cleaning up request packet ID 6 with timestamp +35 Tue Nov 12 13:13:10 2013 : Debug: (157) Cleaning up request packet ID 7 with timestamp +35 Tue Nov 12 13:13:10 2013 : Debug: (158) Cleaning up request packet ID 8 with timestamp +35 Tue Nov 12 13:13:10 2013 : Debug: (159) Cleaning up request packet ID 9 with timestamp +35 Tue Nov 12 13:13:10 2013 : Debug: Waking up in 0.1 seconds. Tue Nov 12 13:13:10 2013 : Debug: (162) Sending delayed reject Sending Access-Reject of id 2 from 137.44.1.53 port 1812 to 123.44.55.66 port 37026 Reply-Message = 'Request Denied' Tue Nov 12 13:13:10 2013 : Debug: Waking up in 0.8 seconds. Tue Nov 12 13:13:11 2013 : Debug: (160) Cleaning up request packet ID 0 with timestamp +36 Tue Nov 12 13:13:11 2013 : Debug: (161) Cleaning up request packet ID 1 with timestamp +36 Tue Nov 12 13:13:11 2013 : Debug: Waking up in 4.0 seconds. Tue Nov 12 13:13:15 2013 : Debug: (162) Waiting for more responses from the home server Tue Nov 12 13:13:15 2013 : Debug: (162) Waiting for more responses from the home server ... This line is then repeated over 1 million times ... Tue Nov 12 13:13:36 2013 : Debug: (162) Waiting for more responses from the home server Tue Nov 12 13:13:36 2013 : Debug: (162) proxy: request is no longer in proxy hash Tue Nov 12 13:13:36 2013 : Debug: (162) Cleaning up request packet ID 2 with timestamp +36 Tue Nov 12 13:13:36 2013 : Info: Ready to process requests.

Alan DeKok

2:59 p.m.

Palmer J.D.F. wrote:

...

but if this is part of the 'lets get your RADIUS cert' conversation then it looks like v3 is either doing some extra things...or is just being more verbose than 2.x (and thousands of such things being logged would be annoying)...

Those messages are only produced in debug mode, so that's OK.

...

I've just tried to use raddebug to capture the debug, but I might have unearthed another problem. Once raddebug times out after 60 second it kills radiusd.

Does the server *die*? The debug log doesn't show that.

...

Tue Nov 12 13:13:15 2013 : Debug: (162) Waiting for more responses from the home server Tue Nov 12 13:13:15 2013 : Debug: (162) Waiting for more responses from the home server

... This line is then repeated over 1 million times ...

Tue Nov 12 13:13:36 2013 : Debug: (162) Waiting for more responses from the home server

That's not supposed to happen. What is the value of "response_window" for that home server? If it's zero, then that's the problem. Alan DeKok.

Palmer J.D.F.

3:43 p.m.

Hi Alan,

...

...
I've just tried to use raddebug to capture the debug, but I might have unearthed another problem. Once raddebug times out after 60 second it kills radiusd.

Does the server *die*? The debug log doesn't show that.

The debug I attached was from capture of a terminal, I didn't use raddebug in the end. Before that I ran radiusd, then raddebug; after a minute my test auths were failing and discovered the radius process had stopped. I've just done it again, raddebug start & stop times are below, and below that is snippet from radius.log [root@server raddb]# date; raddebug; date Tue Nov 12 20:33:08 GMT 2013 Tue Nov 12 20:34:09 GMT 2013 Tue Nov 12 20:32:59 2013 : Info: Ready to process requests. Tue Nov 12 20:33:08 2013 : Info: ... adding new socket control address port 0 Tue Nov 12 20:33:08 2013 : Info: ... closing socket control address port 0 Tue Nov 12 20:33:08 2013 : Info: ... adding new socket control address port 0 Tue Nov 12 20:33:08 2013 : Info: ... closing socket control address port 0 Tue Nov 12 20:33:09 2013 : Info: ... adding new socket control address port 0 Tue Nov 12 20:33:09 2013 : Info: ... closing socket control address port 0 Tue Nov 12 20:33:09 2013 : Info: ... adding new socket control address port 0 Tue Nov 12 20:33:09 2013 : Info: ... closing socket control address port 0 Tue Nov 12 20:34:09 2013 : Info: ... adding new socket control address port 0 Tue Nov 12 20:34:09 2013 : Info: talloc: double free error - first free may be at src/main/listen.c:3218 Tue Nov 12 20:34:09 2013 : Info: Bad talloc magic value - double free

...

...
This line is then repeated over 1 million times ...

Tue Nov 12 13:13:36 2013 : Debug: (162) Waiting for more responses from the home server

That's not supposed to happen. What is the value of "response_window" for that home server? If it's zero, then that's the problem.

response_window isn't set for the three eduroam homeservers. Is it defaulted to zero if not set? Thanks, Jezz.

A.L.M.Buxey＠lboro.ac.uk

4:14 p.m.

Hi,

...

Tue Nov 12 20:34:09 2013 : Info: talloc: double free error - first free may be at src/main/listen.c:3218 Tue Nov 12 20:34:09 2013 : Info: Bad talloc magic value - double free

those messages arent right. something lurks there

...

response_window isn't set for the three eduroam homeservers. Is it defaulted to zero if not set?

from memory its 30s if not set.... it can be as low as 1s and as high as 60s alan

Palmer J.D.F.

13 Nov 13 Nov

9:46 a.m.

...

...
Tue Nov 12 20:34:09 2013 : Info: talloc: double free error - first free may be at src/main/listen.c:3218 Tue Nov 12 20:34:09 2013 : Info: Bad talloc magic value - double free

those messages arent right. something lurks there

No, given the fact that's the last thing it does before radiusd dies it's definitely got something lurking. Can you/someone confirm whether you have the same issue on FR3?

...

...
response_window isn't set for the three eduroam homeservers. Is it defaulted to zero if not set?

from memory its 30s if not set....

I think you are right, from the debug I sent... Tue Nov 12 13:13:07 2013 : Debug: (162) Expecting proxy response no later than 30 seconds from now. Cheers, Jezz.

Alan Buxey

10:27 a.m.

Hi Tell me the steps you are doing before the server dies and I'll try to reproduce on a dev/test system. We are not running v3 in production yet (are using it in Dev/test and for moonshot beta) at work. I am using it at home though. We are currently looking at other wireless issues so forklift upgrade of the server to v3 is not on the cards right now. alan -- Sent from my Android device with K-9 Mail. Please excuse my brevity.

Arran Cudbard-Bell

12 Nov 12 Nov

9:51 a.m.

On 11 Nov 2013, at 20:41, Palmer J.D.F. <J.D.F.Palmer@SWANSEA.AC.UK> wrote:

...

Thanks Arran,

...
Filters use an arbitrary key just the same as the Users-File.

attr_filter attr_filter.post-proxy { key = "%{Response-Packet-Type}.%{Realm}" filename = ${modconfdir}/${.:name}/post-proxy }

May work, if it doesn't we might need to add some xlat magic to expose the proxy response.

I think that some xlat magic might be required...

(9) [post_proxy_log] = ok (9) attr_filter.post-proxy : expand: "%{Response-Packet-Type}.%{Realm}" -> '.jrs' (9) [attr_filter.post-proxy] = noop

Yes, this appears to of been missed off from the virtual attributes hack in the xlat parser. Added it back in. If the request has a proxy response associated with it and no reply code set, this will return the proxy response. case PW_RESPONSE_PACKET_TYPE: { int code = 0; if (request->proxy_reply && (!request->reply || !request->reply->code)) { code = request->proxy_reply->code; } else if (request->reply) { code = request->reply->code; } return talloc_strdup(ctx, fr_packet_codes[code]); } If it has a reply code set, it'll return that. Should work as expected in most situations. IIRC key had to be set for this behaviour in 2.x.x. I think <response type>.<realm> was just a neat hack I suggested in the JRS docs for the Sussex case study, and other people started using it. Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team

Palmer J.D.F.

13 Nov 13 Nov

8:29 a.m.

...

Yes, this appears to of been missed off from the virtual attributes hack in the xlat parser.

Added it back in.

Thanks Arran. Had trouble building the git clone, so copied the code into the stable release's source, complied it and it works. [root@server freeradius-server]# make UNIT-TEST rfc.txt ./build/bin/radattr: symbol lookup error: ./build/bin/radattr: undefined symbol: _fr_cursor_init make: *** [build/tests/unit/rfc.txt] Error 127

...

If the request has a proxy response associated with it and no reply code set, this will return the proxy response.

case PW_RESPONSE_PACKET_TYPE: { int code = 0;

if (request->proxy_reply && (!request->reply || !request-

...
reply->code)) { code = request->proxy_reply->code; } else if (request->reply) { code = request->reply->code; } return talloc_strdup(ctx, fr_packet_codes[code]); }

If it has a reply code set, it'll return that. Should work as expected in most situations.

IIRC key had to be set for this behaviour in 2.x.x. I think <response type>.<realm> was just a neat hack I suggested in the JRS docs for the Sussex case study, and other people started using it.

Ah, yes that rings a bell; confirmed by blowing the dust off the case study you did all those moons ago. Cheers, Jezz.

Arran Cudbard-Bell

8:53 a.m.

...

Thanks Arran. Had trouble building the git clone, so copied the code into the stable release's source, complied it and it works.

[root@server freeradius-server]# make UNIT-TEST rfc.txt ./build/bin/radattr: symbol lookup error: ./build/bin/radattr: undefined symbol: _fr_cursor_init make: *** [build/tests/unit/rfc.txt] Error 127

Probably dependencies not being rebuilt correctly. make clean/make should fix it.

...

Ah, yes that rings a bell; confirmed by blowing the dust off the case study you did all those moons ago.

Yeah six or seven years now. I feel old :( Anyone know what's happening with the new case study? Guessing there's going to be a radsec section? -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team

Alan Buxey

9:19 a.m.

New case study? Noone has approached Janet. We do have a course being developed for eduroam/moonshot sites in the UK using freeradius ... that will have radsec section as a matter of course other relevant docs have been added to the Janet community site and the eduroam confluence wiki as time allows I have your old document for editing to just bring it up to 2.2 and current eduroam UK tech spec level. alan -- Sent from my Android device with K-9 Mail. Please excuse my brevity.

4620

Age (days ago)

4622

Last active (days ago)

List overview

Download

13 comments

5 participants

participants (5)

A.L.M.Buxey＠lboro.ac.uk
Alan Buxey
Alan DeKok
Arran Cudbard-Bell
Palmer J.D.F.