Re: Add TLS version to logs with linelog in FreeRADIUS 3.2.4

15 Nov 2024

      Thanks.
...
OK. I suspect the problem is your local mailing system then. No one else has issues.
You do not have to guess / suspect, I am pretty sure it is on our side, but it is hard do find this needle in a haystack in this kind of big setup. Strangely it was only related to this explicit thread "Add TLS version to logs with linelog in FreeRADIUS 3.2.4".
...
Please post the *full* debug output.
Here we go:

(182) Received Access-Request Id 31 from 9.9.9.9:60533 to 130.92.10.33:1812 length 446
(182)   User-Name = "xyz@unibe.ch"
(182)   Service-Type = Framed-User
(182)   Cisco-AVPair = "service-type=Framed"
(182)   Framed-MTU = 1485
(182)   EAP-Message = 0x0201001d01646f6d696e69632e7374616c64657240756e6962652e6368
(182)   Message-Authenticator = 0x11a30dec371519f50eb0809f117144db
(182)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(182)   Cisco-AVPair = "method=dot1x"
(182)   Cisco-AVPair = "client-iif-id=3724547122"
(182)   Cisco-AVPair = "vlan-id=1876"
(182)   NAS-IP-Address = 9.9.9.9
(182)   NAS-Port-Type = Wireless-802.11
(182)   NAS-Port = 4211
(182)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(182)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(182)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(182)   Calling-Station-Id = "22-e0-73-f2-50-23"
(182)   Airespace-Wlan-Id = 98
(182)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(182)   WLAN-Group-Cipher = 1027076
(182)   WLAN-Pairwise-Cipher = 1027076
(182)   WLAN-AKM-Suite = 1027075
(182) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(182)   authorize {
(182)     policy rewrite_called_station_id {
(182)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(182)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(182)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(182)         update request {
(182)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(182)              --> 60-B9-C0-04-C4-40
(182)           &Called-Station-Id := 60-B9-C0-04-C4-40
(182)         } # update request = noop
(182)         if ("%{8}") {
(182)         EXPAND %{8}
(182)            --> eduroam
(182)         if ("%{8}")  -> TRUE
(182)         if ("%{8}")  {
(182)           update request {
(182)             EXPAND %{8}
(182)                --> eduroam
(182)             &Called-Station-SSID := eduroam
(182)             EXPAND %{Called-Station-Id}:%{8}
(182)                --> 60-B9-C0-04-C4-40:eduroam
(182)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(182)           } # update request = noop
(182)         } # if ("%{8}")  = noop
(182)         [updated] = updated
(182)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(182)       ... skipping else: Preceding "if" was taken
(182)     } # policy rewrite_called_station_id = updated
(182)     policy rewrite_calling_station_id {
(182)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(182)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(182)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(182)         update request {
(182)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(182)              --> 22-E0-73-F2-50-23
(182)           &Calling-Station-Id := 22-E0-73-F2-50-23
(182)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(182)              --> 22:E0:73:F2:50:23
(182)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(182)         } # update request = noop
(182)         [updated] = updated
(182)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(182)       ... skipping else: Preceding "if" was taken
(182)     } # policy rewrite_calling_station_id = updated
(182)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(182)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(182)     if (Service-Type == Call-Check) {
(182)     if (Service-Type == Call-Check)  -> FALSE
(182)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(182)     EXPAND Packet-Src-IP-Address
(182)        --> 9.9.9.9
(182)     EXPAND Packet-Src-IP-Address
(182)        --> 9.9.9.9
(182)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(182)     if (EAP-Message) {
(182)     if (EAP-Message)  -> TRUE
(182)     if (EAP-Message)  {
(182)       policy filter_username {
(182)         if (&User-Name) {
(182)         if (&User-Name)  -> TRUE
(182)         if (&User-Name)  {
(182)           if (&User-Name =~ / /) {
(182)           if (&User-Name =~ / /)  -> FALSE
(182)           if (&User-Name =~ /@[^@]*@/ ) {
(182)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(182)           if (&User-Name =~ /\.\./ ) {
(182)           if (&User-Name =~ /\.\./ )  -> FALSE
(182)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(182)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(182)           if (&User-Name =~ /\.$/)  {
(182)           if (&User-Name =~ /\.$/)   -> FALSE
(182)           if (&User-Name =~ /@\./)  {
(182)           if (&User-Name =~ /@\./)   -> FALSE
(182)         } # if (&User-Name)  = updated
(182)       } # policy filter_username = updated
(182) suffix: Checking for suffix after "@"
(182) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(182) suffix: Found realm "UNIBE.CH"
(182) suffix: Adding Realm = "UNIBE.CH"
(182) suffix: Authentication realm is LOCAL
(182)       [suffix] = ok
(182)       policy deny_no_realm {
(182)         if (User-Name && (User-Name !~ /@/)) {
(182)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(182)       } # policy deny_no_realm = updated
(182)       update request {
(182)         EXPAND %{toupper:%{Realm}}
(182)            --> UNIBE.CH
(182)         Realm := UNIBE.CH
(182)       } # update request = noop
(182) eap: Peer sent EAP Response (code 2) ID 1 length 29
(182) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize
(182)       [eap] = ok
(182)     } # if (EAP-Message)  = ok
(182)   } # authorize = updated
(182) Found Auth-Type = eap
(182) # Executing group from file /etc/freeradius/sites-enabled/default
(182)   Auth-Type eap {
(182) eap: Peer sent packet with method EAP Identity (1)
(182) eap: Calling submodule eap_peap to process data
(182) eap_peap: (TLS) PEAP -Initiating new session
(182) eap: Sending EAP Request (code 1) ID 2 length 6
(182) eap: EAP session adding &reply:State = 0xcf8ae573cf88fce6
(182)     [eap] = handled
(182)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(182)     EXPAND Response-Packet-Type
(182)        --> Access-Challenge
(182)     if (handled && (Response-Packet-Type == Access-Challenge))  -> TRUE
(182)     if (handled && (Response-Packet-Type == Access-Challenge))  {
(182) attr_filter.access_challenge: EXPAND %{User-Name}
(182) attr_filter.access_challenge:    --> xyz@unibe.ch
(182) attr_filter.access_challenge: Matched entry DEFAULT at line 12
(182)       [attr_filter.access_challenge.post-auth] = updated
(182)       [handled] = handled
(182)     } # if (handled && (Response-Packet-Type == Access-Challenge))  = handled
(182)   } # Auth-Type eap = handled
(182) Using Post-Auth-Type Challenge
(182) Post-Auth-Type sub-section not found.  Ignoring.
(182) # Executing group from file /etc/freeradius/sites-enabled/default
(182) session-state: Saving cached attributes
(182)   Framed-MTU = 1014
(182) Sent Access-Challenge Id 31 from 130.92.10.33:1812 to 9.9.9.9:60533 length 64
(182)   EAP-Message = 0x010200061920
(182)   Message-Authenticator = 0x00000000000000000000000000000000
(182)   State = 0xcf8ae573cf88fce6e3b6e72de6bf5cbc
(182) Finished request
Waking up in 4.9 seconds.
(183) Received Access-Request Id 39 from 9.9.9.9:60533 to 130.92.10.33:1812 length 596
(183)   User-Name = "xyz@unibe.ch"
(183)   Service-Type = Framed-User
(183)   Cisco-AVPair = "service-type=Framed"
(183)   Framed-MTU = 1485
(183)   EAP-Message = 0x020200a119800000009716030100920100008e030367374aaa0dddaf0e7d100625e3cfeeb8cd6518161994daa1847ad3002739d57600002c00ffc02cc02bc024c023c00ac009c008c030c02fc028c027c014c013c012009d009c003d003c0035002f000a01000039000a00080006001700180019000b00020100000d00120010040102010501060104030203050306030005000501000000000012000000170000
(183)   Message-Authenticator = 0x29862be28b4764a547e61644a45d82bf
(183)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(183)   Cisco-AVPair = "method=dot1x"
(183)   Cisco-AVPair = "client-iif-id=3724547122"
(183)   Cisco-AVPair = "vlan-id=1876"
(183)   NAS-IP-Address = 9.9.9.9
(183)   NAS-Port-Type = Wireless-802.11
(183)   NAS-Port = 4211
(183)   State = 0xcf8ae573cf88fce6e3b6e72de6bf5cbc
(183)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(183)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(183)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(183)   Calling-Station-Id = "22-e0-73-f2-50-23"
(183)   Airespace-Wlan-Id = 98
(183)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(183)   WLAN-Group-Cipher = 1027076
(183)   WLAN-Pairwise-Cipher = 1027076
(183)   WLAN-AKM-Suite = 1027075
(183) Restoring &session-state
(183)   &session-state:Framed-MTU = 1014
(183) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(183)   authorize {
(183)     policy rewrite_called_station_id {
(183)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(183)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(183)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(183)         update request {
(183)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(183)              --> 60-B9-C0-04-C4-40
(183)           &Called-Station-Id := 60-B9-C0-04-C4-40
(183)         } # update request = noop
(183)         if ("%{8}") {
(183)         EXPAND %{8}
(183)            --> eduroam
(183)         if ("%{8}")  -> TRUE
(183)         if ("%{8}")  {
(183)           update request {
(183)             EXPAND %{8}
(183)                --> eduroam
(183)             &Called-Station-SSID := eduroam
(183)             EXPAND %{Called-Station-Id}:%{8}
(183)                --> 60-B9-C0-04-C4-40:eduroam
(183)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(183)           } # update request = noop
(183)         } # if ("%{8}")  = noop
(183)         [updated] = updated
(183)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(183)       ... skipping else: Preceding "if" was taken
(183)     } # policy rewrite_called_station_id = updated
(183)     policy rewrite_calling_station_id {
(183)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(183)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(183)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(183)         update request {
(183)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(183)              --> 22-E0-73-F2-50-23
(183)           &Calling-Station-Id := 22-E0-73-F2-50-23
(183)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(183)              --> 22:E0:73:F2:50:23
(183)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(183)         } # update request = noop
(183)         [updated] = updated
(183)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(183)       ... skipping else: Preceding "if" was taken
(183)     } # policy rewrite_calling_station_id = updated
(183)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(183)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(183)     if (Service-Type == Call-Check) {
(183)     if (Service-Type == Call-Check)  -> FALSE
(183)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(183)     EXPAND Packet-Src-IP-Address
(183)        --> 9.9.9.9
(183)     EXPAND Packet-Src-IP-Address
(183)        --> 9.9.9.9
(183)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(183)     if (EAP-Message) {
(183)     if (EAP-Message)  -> TRUE
(183)     if (EAP-Message)  {
(183)       policy filter_username {
(183)         if (&User-Name) {
(183)         if (&User-Name)  -> TRUE
(183)         if (&User-Name)  {
(183)           if (&User-Name =~ / /) {
(183)           if (&User-Name =~ / /)  -> FALSE
(183)           if (&User-Name =~ /@[^@]*@/ ) {
(183)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(183)           if (&User-Name =~ /\.\./ ) {
(183)           if (&User-Name =~ /\.\./ )  -> FALSE
(183)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(183)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(183)           if (&User-Name =~ /\.$/)  {
(183)           if (&User-Name =~ /\.$/)   -> FALSE
(183)           if (&User-Name =~ /@\./)  {
(183)           if (&User-Name =~ /@\./)   -> FALSE
(183)         } # if (&User-Name)  = updated
(183)       } # policy filter_username = updated
(183) suffix: Checking for suffix after "@"
(183) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(183) suffix: Found realm "UNIBE.CH"
(183) suffix: Adding Realm = "UNIBE.CH"
(183) suffix: Authentication realm is LOCAL
(183)       [suffix] = ok
(183)       policy deny_no_realm {
(183)         if (User-Name && (User-Name !~ /@/)) {
(183)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(183)       } # policy deny_no_realm = updated
(183)       update request {
(183)         EXPAND %{toupper:%{Realm}}
(183)            --> UNIBE.CH
(183)         Realm := UNIBE.CH
(183)       } # update request = noop
(183) eap: Peer sent EAP Response (code 2) ID 2 length 161
(183) eap: Continuing tunnel setup
(183)       [eap] = ok
(183)     } # if (EAP-Message)  = ok
(183)   } # authorize = updated
(183) Found Auth-Type = eap
(183) # Executing group from file /etc/freeradius/sites-enabled/default
(183)   Auth-Type eap {
(183) eap: Removing EAP session with state 0xcf8ae573cf88fce6
(183) eap: Previous EAP request found for state 0xcf8ae573cf88fce6, released from the list
(183) eap: Peer sent packet with method EAP PEAP (25)
(183) eap: Calling submodule eap_peap to process data
(183) eap_peap: (TLS) EAP Peer says that the final record size will be 151 bytes
(183) eap_peap: (TLS) EAP Got all data (151 bytes)
(183) eap_peap: (TLS) PEAP - Handshake state - before SSL initialization
(183) eap_peap: (TLS) PEAP - Handshake state - Server before SSL initialization
(183) eap_peap: (TLS) PEAP - Handshake state - Server before SSL initialization
(183) eap_peap: (TLS) PEAP - recv TLS 1.3 Handshake, ClientHello
(183) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS read client hello
(183) eap_peap: (TLS) PEAP - send TLS 1.2 Handshake, ServerHello
(183) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS write server hello
(183) eap_peap: (TLS) PEAP - send TLS 1.2 Handshake, Certificate
(183) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS write certificate
(183) eap_peap: (TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange
(183) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS write key exchange
(183) eap_peap: (TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone
(183) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS write server done
(183) eap_peap: (TLS) PEAP - Server : Need to read more data: SSLv3/TLS write server done
(183) eap_peap: (TLS) PEAP - In Handshake Phase
(183) eap: Sending EAP Request (code 1) ID 3 length 1024
(183) eap: EAP session adding &reply:State = 0xcf8ae573ce89fce6
(183)     [eap] = handled
(183)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(183)     EXPAND Response-Packet-Type
(183)        --> Access-Challenge
(183)     if (handled && (Response-Packet-Type == Access-Challenge))  -> TRUE
(183)     if (handled && (Response-Packet-Type == Access-Challenge))  {
(183) attr_filter.access_challenge: EXPAND %{User-Name}
(183) attr_filter.access_challenge:    --> xyz@unibe.ch
(183) attr_filter.access_challenge: Matched entry DEFAULT at line 12
(183)       [attr_filter.access_challenge.post-auth] = updated
(183)       [handled] = handled
(183)     } # if (handled && (Response-Packet-Type == Access-Challenge))  = handled
(183)   } # Auth-Type eap = handled
(183) Using Post-Auth-Type Challenge
(183) Post-Auth-Type sub-section not found.  Ignoring.
(183) # Executing group from file /etc/freeradius/sites-enabled/default
(183) session-state: Saving cached attributes
(183)   Framed-MTU = 1014
(183)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(183)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(183)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(183)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(183)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(183) Sent Access-Challenge Id 39 from 130.92.10.33:1812 to 9.9.9.9:60533 length 1090
(183)   EAP-Message = 0x0103040019c000001135160303003d020000390303deaa040a2cd12b855def85a0f1cda085f35e6014c26e22fc444f574e4752440100c030000011ff01000100000b000403000102001700001603030f930b000f8f000f8c0007253082072130820609a003020102021006387c8dc0feba6f5f4a0c47e7c561cd300d06092a864886f70d01010b05003059310b300906035504061302555331153013060355040a130c446967694365727420496e63313330310603550403132a446967694365727420476c6f62616c20473220544c532052534120534841323536203230323020434131301e170d3234303532393030303030305a170d3235303532383233353935395a305f310b3009060355040613024348310d300b060355040813044265726e310d300b060355040713044265726e311b3019060355040a1312556e6976657273697479206f66204265726e311530130603550403130c6161692e756e6962652e636830820122300d06092a864886f70d01010105
(183)   Message-Authenticator = 0x00000000000000000000000000000000
(183)   State = 0xcf8ae573ce89fce6e3b6e72de6bf5cbc
(183) Finished request
Waking up in 4.9 seconds.
(184) Received Access-Request Id 47 from 9.9.9.9:60533 to 130.92.10.33:1812 length 441
(184)   User-Name = "xyz@unibe.ch"
(184)   Service-Type = Framed-User
(184)   Cisco-AVPair = "service-type=Framed"
(184)   Framed-MTU = 1485
(184)   EAP-Message = 0x020300061900
(184)   Message-Authenticator = 0xf94531ec1c265e936b60a676448e5edf
(184)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(184)   Cisco-AVPair = "method=dot1x"
(184)   Cisco-AVPair = "client-iif-id=3724547122"
(184)   Cisco-AVPair = "vlan-id=1876"
(184)   NAS-IP-Address = 9.9.9.9
(184)   NAS-Port-Type = Wireless-802.11
(184)   NAS-Port = 4211
(184)   State = 0xcf8ae573ce89fce6e3b6e72de6bf5cbc
(184)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(184)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(184)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(184)   Calling-Station-Id = "22-e0-73-f2-50-23"
(184)   Airespace-Wlan-Id = 98
(184)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(184)   WLAN-Group-Cipher = 1027076
(184)   WLAN-Pairwise-Cipher = 1027076
(184)   WLAN-AKM-Suite = 1027075
(184) Restoring &session-state
(184)   &session-state:Framed-MTU = 1014
(184)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(184)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(184)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(184)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(184)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(184) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(184)   authorize {
(184)     policy rewrite_called_station_id {
(184)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(184)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(184)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(184)         update request {
(184)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(184)              --> 60-B9-C0-04-C4-40
(184)           &Called-Station-Id := 60-B9-C0-04-C4-40
(184)         } # update request = noop
(184)         if ("%{8}") {
(184)         EXPAND %{8}
(184)            --> eduroam
(184)         if ("%{8}")  -> TRUE
(184)         if ("%{8}")  {
(184)           update request {
(184)             EXPAND %{8}
(184)                --> eduroam
(184)             &Called-Station-SSID := eduroam
(184)             EXPAND %{Called-Station-Id}:%{8}
(184)                --> 60-B9-C0-04-C4-40:eduroam
(184)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(184)           } # update request = noop
(184)         } # if ("%{8}")  = noop
(184)         [updated] = updated
(184)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(184)       ... skipping else: Preceding "if" was taken
(184)     } # policy rewrite_called_station_id = updated
(184)     policy rewrite_calling_station_id {
(184)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(184)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(184)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(184)         update request {
(184)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(184)              --> 22-E0-73-F2-50-23
(184)           &Calling-Station-Id := 22-E0-73-F2-50-23
(184)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(184)              --> 22:E0:73:F2:50:23
(184)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(184)         } # update request = noop
(184)         [updated] = updated
(184)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(184)       ... skipping else: Preceding "if" was taken
(184)     } # policy rewrite_calling_station_id = updated
(184)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(184)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(184)     if (Service-Type == Call-Check) {
(184)     if (Service-Type == Call-Check)  -> FALSE
(184)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(184)     EXPAND Packet-Src-IP-Address
(184)        --> 9.9.9.9
(184)     EXPAND Packet-Src-IP-Address
(184)        --> 9.9.9.9
(184)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(184)     if (EAP-Message) {
(184)     if (EAP-Message)  -> TRUE
(184)     if (EAP-Message)  {
(184)       policy filter_username {
(184)         if (&User-Name) {
(184)         if (&User-Name)  -> TRUE
(184)         if (&User-Name)  {
(184)           if (&User-Name =~ / /) {
(184)           if (&User-Name =~ / /)  -> FALSE
(184)           if (&User-Name =~ /@[^@]*@/ ) {
(184)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(184)           if (&User-Name =~ /\.\./ ) {
(184)           if (&User-Name =~ /\.\./ )  -> FALSE
(184)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(184)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(184)           if (&User-Name =~ /\.$/)  {
(184)           if (&User-Name =~ /\.$/)   -> FALSE
(184)           if (&User-Name =~ /@\./)  {
(184)           if (&User-Name =~ /@\./)   -> FALSE
(184)         } # if (&User-Name)  = updated
(184)       } # policy filter_username = updated
(184) suffix: Checking for suffix after "@"
(184) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(184) suffix: Found realm "UNIBE.CH"
(184) suffix: Adding Realm = "UNIBE.CH"
(184) suffix: Authentication realm is LOCAL
(184)       [suffix] = ok
(184)       policy deny_no_realm {
(184)         if (User-Name && (User-Name !~ /@/)) {
(184)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(184)       } # policy deny_no_realm = updated
(184)       update request {
(184)         EXPAND %{toupper:%{Realm}}
(184)            --> UNIBE.CH
(184)         Realm := UNIBE.CH
(184)       } # update request = noop
(184) eap: Peer sent EAP Response (code 2) ID 3 length 6
(184) eap: Continuing tunnel setup
(184)       [eap] = ok
(184)     } # if (EAP-Message)  = ok
(184)   } # authorize = updated
(184) Found Auth-Type = eap
(184) # Executing group from file /etc/freeradius/sites-enabled/default
(184)   Auth-Type eap {
(184) eap: Removing EAP session with state 0xcf8ae573ce89fce6
(184) eap: Previous EAP request found for state 0xcf8ae573ce89fce6, released from the list
(184) eap: Peer sent packet with method EAP PEAP (25)
(184) eap: Calling submodule eap_peap to process data
(184) eap_peap: (TLS) Peer ACKed our handshake fragment
(184) eap: Sending EAP Request (code 1) ID 4 length 1020
(184) eap: EAP session adding &reply:State = 0xcf8ae573cd8efce6
(184)     [eap] = handled
(184)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(184)     EXPAND Response-Packet-Type
(184)        --> Access-Challenge
(184)     if (handled && (Response-Packet-Type == Access-Challenge))  -> TRUE
(184)     if (handled && (Response-Packet-Type == Access-Challenge))  {
(184) attr_filter.access_challenge: EXPAND %{User-Name}
(184) attr_filter.access_challenge:    --> xyz@unibe.ch
(184) attr_filter.access_challenge: Matched entry DEFAULT at line 12
(184)       [attr_filter.access_challenge.post-auth] = updated
(184)       [handled] = handled
(184)     } # if (handled && (Response-Packet-Type == Access-Challenge))  = handled
(184)   } # Auth-Type eap = handled
(184) Using Post-Auth-Type Challenge
(184) Post-Auth-Type sub-section not found.  Ignoring.
(184) # Executing group from file /etc/freeradius/sites-enabled/default
(184) session-state: Saving cached attributes
(184)   Framed-MTU = 1014
(184)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(184)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(184)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(184)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(184)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(184) Sent Access-Challenge Id 47 from 130.92.10.33:1812 to 9.9.9.9:60533 length 1086
(184)   EAP-Message = 0x010403fc1940312d312e63726c3048a046a0448642687474703a2f2f63726c342e64696769636572742e636f6d2f4469676943657274476c6f62616c4732544c53525341534841323536323032304341312d312e63726c30818706082b06010505070101047b3079302406082b060105050730018618687474703a2f2f6f6373702e64696769636572742e636f6d305106082b060105050730028645687474703a2f2f636163657274732e64696769636572742e636f6d2f4469676943657274476c6f62616c4732544c53525341534841323536323032304341312d312e637274300c0603551d130101ff040230003082017f060a2b06010401d6790204020482016f0482016b01690077004e75a3275c9a10c3385b6cd4df3f52eb1df0e08e1b8d69c0b1fa64b1629a39df0000018fc49a2e690000040300483046022100c3703d534899e5150ee51285759f020d6d69574d1db223e7a6fba90105e34a98022100a96786ea2924a95667b25b5efae9fb8e9b5e2b8494
(184)   Message-Authenticator = 0x00000000000000000000000000000000
(184)   State = 0xcf8ae573cd8efce6e3b6e72de6bf5cbc
(184) Finished request
Waking up in 4.9 seconds.
(185) Received Access-Request Id 55 from 9.9.9.9:60533 to 130.92.10.33:1812 length 441
(185)   User-Name = "xyz@unibe.ch"
(185)   Service-Type = Framed-User
(185)   Cisco-AVPair = "service-type=Framed"
(185)   Framed-MTU = 1485
(185)   EAP-Message = 0x020400061900
(185)   Message-Authenticator = 0x762039fe48480c9dd55c1af554ae2e9e
(185)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(185)   Cisco-AVPair = "method=dot1x"
(185)   Cisco-AVPair = "client-iif-id=3724547122"
(185)   Cisco-AVPair = "vlan-id=1876"
(185)   NAS-IP-Address = 9.9.9.9
(185)   NAS-Port-Type = Wireless-802.11
(185)   NAS-Port = 4211
(185)   State = 0xcf8ae573cd8efce6e3b6e72de6bf5cbc
(185)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(185)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(185)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(185)   Calling-Station-Id = "22-e0-73-f2-50-23"
(185)   Airespace-Wlan-Id = 98
(185)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(185)   WLAN-Group-Cipher = 1027076
(185)   WLAN-Pairwise-Cipher = 1027076
(185)   WLAN-AKM-Suite = 1027075
(185) Restoring &session-state
(185)   &session-state:Framed-MTU = 1014
(185)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(185)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(185)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(185)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(185)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(185) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(185)   authorize {
(185)     policy rewrite_called_station_id {
(185)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(185)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(185)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(185)         update request {
(185)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(185)              --> 60-B9-C0-04-C4-40
(185)           &Called-Station-Id := 60-B9-C0-04-C4-40
(185)         } # update request = noop
(185)         if ("%{8}") {
(185)         EXPAND %{8}
(185)            --> eduroam
(185)         if ("%{8}")  -> TRUE
(185)         if ("%{8}")  {
(185)           update request {
(185)             EXPAND %{8}
(185)                --> eduroam
(185)             &Called-Station-SSID := eduroam
(185)             EXPAND %{Called-Station-Id}:%{8}
(185)                --> 60-B9-C0-04-C4-40:eduroam
(185)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(185)           } # update request = noop
(185)         } # if ("%{8}")  = noop
(185)         [updated] = updated
(185)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(185)       ... skipping else: Preceding "if" was taken
(185)     } # policy rewrite_called_station_id = updated
(185)     policy rewrite_calling_station_id {
(185)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(185)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(185)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(185)         update request {
(185)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(185)              --> 22-E0-73-F2-50-23
(185)           &Calling-Station-Id := 22-E0-73-F2-50-23
(185)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(185)              --> 22:E0:73:F2:50:23
(185)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(185)         } # update request = noop
(185)         [updated] = updated
(185)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(185)       ... skipping else: Preceding "if" was taken
(185)     } # policy rewrite_calling_station_id = updated
(185)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(185)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(185)     if (Service-Type == Call-Check) {
(185)     if (Service-Type == Call-Check)  -> FALSE
(185)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(185)     EXPAND Packet-Src-IP-Address
(185)        --> 9.9.9.9
(185)     EXPAND Packet-Src-IP-Address
(185)        --> 9.9.9.9
(185)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(185)     if (EAP-Message) {
(185)     if (EAP-Message)  -> TRUE
(185)     if (EAP-Message)  {
(185)       policy filter_username {
(185)         if (&User-Name) {
(185)         if (&User-Name)  -> TRUE
(185)         if (&User-Name)  {
(185)           if (&User-Name =~ / /) {
(185)           if (&User-Name =~ / /)  -> FALSE
(185)           if (&User-Name =~ /@[^@]*@/ ) {
(185)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(185)           if (&User-Name =~ /\.\./ ) {
(185)           if (&User-Name =~ /\.\./ )  -> FALSE
(185)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(185)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(185)           if (&User-Name =~ /\.$/)  {
(185)           if (&User-Name =~ /\.$/)   -> FALSE
(185)           if (&User-Name =~ /@\./)  {
(185)           if (&User-Name =~ /@\./)   -> FALSE
(185)         } # if (&User-Name)  = updated
(185)       } # policy filter_username = updated
(185) suffix: Checking for suffix after "@"
(185) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(185) suffix: Found realm "UNIBE.CH"
(185) suffix: Adding Realm = "UNIBE.CH"
(185) suffix: Authentication realm is LOCAL
(185)       [suffix] = ok
(185)       policy deny_no_realm {
(185)         if (User-Name && (User-Name !~ /@/)) {
(185)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(185)       } # policy deny_no_realm = updated
(185)       update request {
(185)         EXPAND %{toupper:%{Realm}}
(185)            --> UNIBE.CH
(185)         Realm := UNIBE.CH
(185)       } # update request = noop
(185) eap: Peer sent EAP Response (code 2) ID 4 length 6
(185) eap: Continuing tunnel setup
(185)       [eap] = ok
(185)     } # if (EAP-Message)  = ok
(185)   } # authorize = updated
(185) Found Auth-Type = eap
(185) # Executing group from file /etc/freeradius/sites-enabled/default
(185)   Auth-Type eap {
(185) eap: Removing EAP session with state 0xcf8ae573cd8efce6
(185) eap: Previous EAP request found for state 0xcf8ae573cd8efce6, released from the list
(185) eap: Peer sent packet with method EAP PEAP (25)
(185) eap: Calling submodule eap_peap to process data
(185) eap_peap: (TLS) Peer ACKed our handshake fragment
(185) eap: Sending EAP Request (code 1) ID 5 length 1020
(185) eap: EAP session adding &reply:State = 0xcf8ae573cc8ffce6
(185)     [eap] = handled
(185)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(185)     EXPAND Response-Packet-Type
(185)        --> Access-Challenge
(185)     if (handled && (Response-Packet-Type == Access-Challenge))  -> TRUE
(185)     if (handled && (Response-Packet-Type == Access-Challenge))  {
(185) attr_filter.access_challenge: EXPAND %{User-Name}
(185) attr_filter.access_challenge:    --> xyz@unibe.ch
(185) attr_filter.access_challenge: Matched entry DEFAULT at line 12
(185)       [attr_filter.access_challenge.post-auth] = updated
(185)       [handled] = handled
(185)     } # if (handled && (Response-Packet-Type == Access-Challenge))  = handled
(185)   } # Auth-Type eap = handled
(185) Using Post-Auth-Type Challenge
(185) Post-Auth-Type sub-section not found.  Ignoring.
(185) # Executing group from file /etc/freeradius/sites-enabled/default
(185) session-state: Saving cached attributes
(185)   Framed-MTU = 1014
(185)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(185)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(185)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(185)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(185)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(185) Sent Access-Challenge Id 55 from 130.92.10.33:1812 to 9.9.9.9:60533 length 1086
(185)   EAP-Message = 0x010503fc194006035504031317446967694365727420476c6f62616c20526f6f74204732301e170d3231303333303030303030305a170d3331303332393233353935395a3059310b300906035504061302555331153013060355040a130c446967694365727420496e63313330310603550403132a446967694365727420476c6f62616c20473220544c53205253412053484132353620323032302043413130820122300d06092a864886f70d01010105000382010f003082010a0282010100ccf710624fa6bb636fed905256c56d277b7a12568af1f4f9d6e7e18fbd95abf260411570db1200fa270ab557385b7db2519371950e6a41945b351bfa7bfabbc5be2430fe56efc4f37d97e314f5144dcba710f216eaab22f031221161699026ba78d9971fe37d66ab75449573c8acffef5d0a8a5943e1acb23a0ff348fcd76b37c163dcde46d6db45fe7d23fd90e851071e51a35fed4946547f2c88c5f4139c97153c03e8a139dc690c32c1af16574c9447427ca2c89c7d
(185)   Message-Authenticator = 0x00000000000000000000000000000000
(185)   State = 0xcf8ae573cc8ffce6e3b6e72de6bf5cbc
(185) Finished request
Waking up in 4.9 seconds.
(186) Received Access-Request Id 63 from 9.9.9.9:60533 to 130.92.10.33:1812 length 441
(186)   User-Name = "xyz@unibe.ch"
(186)   Service-Type = Framed-User
(186)   Cisco-AVPair = "service-type=Framed"
(186)   Framed-MTU = 1485
(186)   EAP-Message = 0x020500061900
(186)   Message-Authenticator = 0xe9653667a164bcf3999f9734716b49db
(186)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(186)   Cisco-AVPair = "method=dot1x"
(186)   Cisco-AVPair = "client-iif-id=3724547122"
(186)   Cisco-AVPair = "vlan-id=1876"
(186)   NAS-IP-Address = 9.9.9.9
(186)   NAS-Port-Type = Wireless-802.11
(186)   NAS-Port = 4211
(186)   State = 0xcf8ae573cc8ffce6e3b6e72de6bf5cbc
(186)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(186)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(186)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(186)   Calling-Station-Id = "22-e0-73-f2-50-23"
(186)   Airespace-Wlan-Id = 98
(186)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(186)   WLAN-Group-Cipher = 1027076
(186)   WLAN-Pairwise-Cipher = 1027076
(186)   WLAN-AKM-Suite = 1027075
(186) Restoring &session-state
(186)   &session-state:Framed-MTU = 1014
(186)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(186)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(186)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(186)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(186)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(186) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(186)   authorize {
(186)     policy rewrite_called_station_id {
(186)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(186)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(186)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(186)         update request {
(186)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(186)              --> 60-B9-C0-04-C4-40
(186)           &Called-Station-Id := 60-B9-C0-04-C4-40
(186)         } # update request = noop
(186)         if ("%{8}") {
(186)         EXPAND %{8}
(186)            --> eduroam
(186)         if ("%{8}")  -> TRUE
(186)         if ("%{8}")  {
(186)           update request {
(186)             EXPAND %{8}
(186)                --> eduroam
(186)             &Called-Station-SSID := eduroam
(186)             EXPAND %{Called-Station-Id}:%{8}
(186)                --> 60-B9-C0-04-C4-40:eduroam
(186)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(186)           } # update request = noop
(186)         } # if ("%{8}")  = noop
(186)         [updated] = updated
(186)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(186)       ... skipping else: Preceding "if" was taken
(186)     } # policy rewrite_called_station_id = updated
(186)     policy rewrite_calling_station_id {
(186)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(186)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(186)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(186)         update request {
(186)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(186)              --> 22-E0-73-F2-50-23
(186)           &Calling-Station-Id := 22-E0-73-F2-50-23
(186)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(186)              --> 22:E0:73:F2:50:23
(186)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(186)         } # update request = noop
(186)         [updated] = updated
(186)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(186)       ... skipping else: Preceding "if" was taken
(186)     } # policy rewrite_calling_station_id = updated
(186)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(186)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(186)     if (Service-Type == Call-Check) {
(186)     if (Service-Type == Call-Check)  -> FALSE
(186)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(186)     EXPAND Packet-Src-IP-Address
(186)        --> 9.9.9.9
(186)     EXPAND Packet-Src-IP-Address
(186)        --> 9.9.9.9
(186)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(186)     if (EAP-Message) {
(186)     if (EAP-Message)  -> TRUE
(186)     if (EAP-Message)  {
(186)       policy filter_username {
(186)         if (&User-Name) {
(186)         if (&User-Name)  -> TRUE
(186)         if (&User-Name)  {
(186)           if (&User-Name =~ / /) {
(186)           if (&User-Name =~ / /)  -> FALSE
(186)           if (&User-Name =~ /@[^@]*@/ ) {
(186)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(186)           if (&User-Name =~ /\.\./ ) {
(186)           if (&User-Name =~ /\.\./ )  -> FALSE
(186)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(186)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(186)           if (&User-Name =~ /\.$/)  {
(186)           if (&User-Name =~ /\.$/)   -> FALSE
(186)           if (&User-Name =~ /@\./)  {
(186)           if (&User-Name =~ /@\./)   -> FALSE
(186)         } # if (&User-Name)  = updated
(186)       } # policy filter_username = updated
(186) suffix: Checking for suffix after "@"
(186) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(186) suffix: Found realm "UNIBE.CH"
(186) suffix: Adding Realm = "UNIBE.CH"
(186) suffix: Authentication realm is LOCAL
(186)       [suffix] = ok
(186)       policy deny_no_realm {
(186)         if (User-Name && (User-Name !~ /@/)) {
(186)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(186)       } # policy deny_no_realm = updated
(186)       update request {
(186)         EXPAND %{toupper:%{Realm}}
(186)            --> UNIBE.CH
(186)         Realm := UNIBE.CH
(186)       } # update request = noop
(186) eap: Peer sent EAP Response (code 2) ID 5 length 6
(186) eap: Continuing tunnel setup
(186)       [eap] = ok
(186)     } # if (EAP-Message)  = ok
(186)   } # authorize = updated
(186) Found Auth-Type = eap
(186) # Executing group from file /etc/freeradius/sites-enabled/default
(186)   Auth-Type eap {
(186) eap: Removing EAP session with state 0xcf8ae573cc8ffce6
(186) eap: Previous EAP request found for state 0xcf8ae573cc8ffce6, released from the list
(186) eap: Peer sent packet with method EAP PEAP (25)
(186) eap: Calling submodule eap_peap to process data
(186) eap_peap: (TLS) Peer ACKed our handshake fragment
(186) eap: Sending EAP Request (code 1) ID 6 length 1020
(186) eap: EAP session adding &reply:State = 0xcf8ae573cb8cfce6
(186)     [eap] = handled
(186)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(186)     EXPAND Response-Packet-Type
(186)        --> Access-Challenge
(186)     if (handled && (Response-Packet-Type == Access-Challenge))  -> TRUE
(186)     if (handled && (Response-Packet-Type == Access-Challenge))  {
(186) attr_filter.access_challenge: EXPAND %{User-Name}
(186) attr_filter.access_challenge:    --> xyz@unibe.ch
(186) attr_filter.access_challenge: Matched entry DEFAULT at line 12
(186)       [attr_filter.access_challenge.post-auth] = updated
(186)       [handled] = handled
(186)     } # if (handled && (Response-Packet-Type == Access-Challenge))  = handled
(186)   } # Auth-Type eap = handled
(186) Using Post-Auth-Type Challenge
(186) Post-Auth-Type sub-section not found.  Ignoring.
(186) # Executing group from file /etc/freeradius/sites-enabled/default
(186) session-state: Saving cached attributes
(186)   Framed-MTU = 1014
(186)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(186)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(186)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(186)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(186)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(186) Sent Access-Challenge Id 63 from 130.92.10.33:1812 to 9.9.9.9:60533 length 1086
(186)   EAP-Message = 0x010603fc1940c6278481d47e8c8ca39b52e7c688ec377c2afbf0555a387210d80013cf4c73dbaa3735a82981699c76bcde187b90d4cacfef6703fd045a2116b1ffea3fdfdc82f5ebf45992230d242a95254ccaa191e6d4b7ac8774b3f16da399dbf9d5bd84409f07980003923082038e30820276a0030201020210033af1e6a711a9a0bb2864b11d09fae5300d06092a864886f70d01010b05003061310b300906035504061302555331153013060355040a130c446967694365727420496e6331193017060355040b13107777772e64696769636572742e636f6d3120301e06035504031317446967694365727420476c6f62616c20526f6f74204732301e170d3133303830313132303030305a170d3338303131353132303030305a3061310b300906035504061302555331153013060355040a130c446967694365727420496e6331193017060355040b13107777772e64696769636572742e636f6d3120301e06035504031317446967694365727420476c6f6261
(186)   Message-Authenticator = 0x00000000000000000000000000000000
(186)   State = 0xcf8ae573cb8cfce6e3b6e72de6bf5cbc
(186) Finished request
Waking up in 4.9 seconds.
(187) Received Access-Request Id 71 from 9.9.9.9:60533 to 130.92.10.33:1812 length 441
(187)   User-Name = "xyz@unibe.ch"
(187)   Service-Type = Framed-User
(187)   Cisco-AVPair = "service-type=Framed"
(187)   Framed-MTU = 1485
(187)   EAP-Message = 0x020600061900
(187)   Message-Authenticator = 0x242a03db3080449327126d09317dcedf
(187)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(187)   Cisco-AVPair = "method=dot1x"
(187)   Cisco-AVPair = "client-iif-id=3724547122"
(187)   Cisco-AVPair = "vlan-id=1876"
(187)   NAS-IP-Address = 9.9.9.9
(187)   NAS-Port-Type = Wireless-802.11
(187)   NAS-Port = 4211
(187)   State = 0xcf8ae573cb8cfce6e3b6e72de6bf5cbc
(187)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(187)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(187)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(187)   Calling-Station-Id = "22-e0-73-f2-50-23"
(187)   Airespace-Wlan-Id = 98
(187)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(187)   WLAN-Group-Cipher = 1027076
(187)   WLAN-Pairwise-Cipher = 1027076
(187)   WLAN-AKM-Suite = 1027075
(187) Restoring &session-state
(187)   &session-state:Framed-MTU = 1014
(187)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(187)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(187)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(187)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(187)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(187) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(187)   authorize {
(187)     policy rewrite_called_station_id {
(187)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(187)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(187)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(187)         update request {
(187)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(187)              --> 60-B9-C0-04-C4-40
(187)           &Called-Station-Id := 60-B9-C0-04-C4-40
(187)         } # update request = noop
(187)         if ("%{8}") {
(187)         EXPAND %{8}
(187)            --> eduroam
(187)         if ("%{8}")  -> TRUE
(187)         if ("%{8}")  {
(187)           update request {
(187)             EXPAND %{8}
(187)                --> eduroam
(187)             &Called-Station-SSID := eduroam
(187)             EXPAND %{Called-Station-Id}:%{8}
(187)                --> 60-B9-C0-04-C4-40:eduroam
(187)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(187)           } # update request = noop
(187)         } # if ("%{8}")  = noop
(187)         [updated] = updated
(187)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(187)       ... skipping else: Preceding "if" was taken
(187)     } # policy rewrite_called_station_id = updated
(187)     policy rewrite_calling_station_id {
(187)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(187)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(187)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(187)         update request {
(187)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(187)              --> 22-E0-73-F2-50-23
(187)           &Calling-Station-Id := 22-E0-73-F2-50-23
(187)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(187)              --> 22:E0:73:F2:50:23
(187)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(187)         } # update request = noop
(187)         [updated] = updated
(187)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(187)       ... skipping else: Preceding "if" was taken
(187)     } # policy rewrite_calling_station_id = updated
(187)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(187)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(187)     if (Service-Type == Call-Check) {
(187)     if (Service-Type == Call-Check)  -> FALSE
(187)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(187)     EXPAND Packet-Src-IP-Address
(187)        --> 9.9.9.9
(187)     EXPAND Packet-Src-IP-Address
(187)        --> 9.9.9.9
(187)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(187)     if (EAP-Message) {
(187)     if (EAP-Message)  -> TRUE
(187)     if (EAP-Message)  {
(187)       policy filter_username {
(187)         if (&User-Name) {
(187)         if (&User-Name)  -> TRUE
(187)         if (&User-Name)  {
(187)           if (&User-Name =~ / /) {
(187)           if (&User-Name =~ / /)  -> FALSE
(187)           if (&User-Name =~ /@[^@]*@/ ) {
(187)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(187)           if (&User-Name =~ /\.\./ ) {
(187)           if (&User-Name =~ /\.\./ )  -> FALSE
(187)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(187)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(187)           if (&User-Name =~ /\.$/)  {
(187)           if (&User-Name =~ /\.$/)   -> FALSE
(187)           if (&User-Name =~ /@\./)  {
(187)           if (&User-Name =~ /@\./)   -> FALSE
(187)         } # if (&User-Name)  = updated
(187)       } # policy filter_username = updated
(187) suffix: Checking for suffix after "@"
(187) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(187) suffix: Found realm "UNIBE.CH"
(187) suffix: Adding Realm = "UNIBE.CH"
(187) suffix: Authentication realm is LOCAL
(187)       [suffix] = ok
(187)       policy deny_no_realm {
(187)         if (User-Name && (User-Name !~ /@/)) {
(187)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(187)       } # policy deny_no_realm = updated
(187)       update request {
(187)         EXPAND %{toupper:%{Realm}}
(187)            --> UNIBE.CH
(187)         Realm := UNIBE.CH
(187)       } # update request = noop
(187) eap: Peer sent EAP Response (code 2) ID 6 length 6
(187) eap: Continuing tunnel setup
(187)       [eap] = ok
(187)     } # if (EAP-Message)  = ok
(187)   } # authorize = updated
(187) Found Auth-Type = eap
(187) # Executing group from file /etc/freeradius/sites-enabled/default
(187)   Auth-Type eap {
(187) eap: Removing EAP session with state 0xcf8ae573cb8cfce6
(187) eap: Previous EAP request found for state 0xcf8ae573cb8cfce6, released from the list
(187) eap: Peer sent packet with method EAP PEAP (25)
(187) eap: Calling submodule eap_peap to process data
(187) eap_peap: (TLS) Peer ACKed our handshake fragment
(187) eap: Sending EAP Request (code 1) ID 7 length 355
(187) eap: EAP session adding &reply:State = 0xcf8ae573ca8dfce6
(187)     [eap] = handled
(187)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(187)     EXPAND Response-Packet-Type
(187)        --> Access-Challenge
(187)     if (handled && (Response-Packet-Type == Access-Challenge))  -> TRUE
(187)     if (handled && (Response-Packet-Type == Access-Challenge))  {
(187) attr_filter.access_challenge: EXPAND %{User-Name}
(187) attr_filter.access_challenge:    --> xyz@unibe.ch
(187) attr_filter.access_challenge: Matched entry DEFAULT at line 12
(187)       [attr_filter.access_challenge.post-auth] = updated
(187)       [handled] = handled
(187)     } # if (handled && (Response-Packet-Type == Access-Challenge))  = handled
(187)   } # Auth-Type eap = handled
(187) Using Post-Auth-Type Challenge
(187) Post-Auth-Type sub-section not found.  Ignoring.
(187) # Executing group from file /etc/freeradius/sites-enabled/default
(187) session-state: Saving cached attributes
(187)   Framed-MTU = 1014
(187)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(187)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(187)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(187)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(187)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(187) Sent Access-Challenge Id 71 from 130.92.10.33:1812 to 9.9.9.9:60533 length 415
(187)   EAP-Message = 0x01070163190032b6160303014d0c00014903001741042ecf4619c88bd3f9d2564d80ccf135283bc2bf397860861137ed899ad3521a198102a135ceee9d6c4a1f365b28ca6fa1abcb775e7e39e54dd612eb5ea0af4c4704010100a678c60510cecc8151c293799b383fe4f21878672e4c20666f9ffbc3ee8b6ca2c799b658371ca3e82a5758e91dc96d03d419fd4a932df264d4568b93bbd88395b905d1d80917f36fd8c3bf5c88e446eabfe1b16a1c6e2d34514955ea4939e33714149c6fd768a2b751326ce3d5efcd074dc01a14d4e6cf1c21be0873fb694c9f1c06533e3788bcd5a8f3c4dfe09dedf9d6a305597ef549c9a5e270d5ed0da6e7bac6cf43a793922384b33438ef8c270441d243379e2bcaf877c216a6757c4a87cc867650abd212201fcee3745132d5988be5e2a355565b413277794fa983b381bc7d3ef806fe84e20259008fde46fbec88934273fcb43051eb51e6ffc7bc215516030300040e000000
(187)   Message-Authenticator = 0x00000000000000000000000000000000
(187)   State = 0xcf8ae573ca8dfce6e3b6e72de6bf5cbc
(187) Finished request
Waking up in 4.9 seconds.
(188) Received Access-Request Id 79 from 9.9.9.9:60533 to 130.92.10.33:1812 length 571
(188)   User-Name = "xyz@unibe.ch"
(188)   Service-Type = Framed-User
(188)   Cisco-AVPair = "service-type=Framed"
(188)   Framed-MTU = 1485
(188)   EAP-Message = 0x0207008819800000007e1603030046100000424104e6595813fcf61f0bcf33212269292b56b96c43fa1c8521b7e9ca6253bc8ba93a42bbf48836d9cd888fe082cfa6fab40327beb814a7fb7f88dd37f9af6caafe2c1403030001011603030028205b847b10fba1568b03991cae85dab7c8553e4b8fbf36eca8a4ec3411939e1e7f4d5270df2d81d8
(188)   Message-Authenticator = 0x5dc9e821834fdb1a0dbda25c60505863
(188)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(188)   Cisco-AVPair = "method=dot1x"
(188)   Cisco-AVPair = "client-iif-id=3724547122"
(188)   Cisco-AVPair = "vlan-id=1876"
(188)   NAS-IP-Address = 9.9.9.9
(188)   NAS-Port-Type = Wireless-802.11
(188)   NAS-Port = 4211
(188)   State = 0xcf8ae573ca8dfce6e3b6e72de6bf5cbc
(188)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(188)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(188)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(188)   Calling-Station-Id = "22-e0-73-f2-50-23"
(188)   Airespace-Wlan-Id = 98
(188)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(188)   WLAN-Group-Cipher = 1027076
(188)   WLAN-Pairwise-Cipher = 1027076
(188)   WLAN-AKM-Suite = 1027075
(188) Restoring &session-state
(188)   &session-state:Framed-MTU = 1014
(188)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(188)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(188)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(188)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(188)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(188) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(188)   authorize {
(188)     policy rewrite_called_station_id {
(188)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(188)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(188)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(188)         update request {
(188)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(188)              --> 60-B9-C0-04-C4-40
(188)           &Called-Station-Id := 60-B9-C0-04-C4-40
(188)         } # update request = noop
(188)         if ("%{8}") {
(188)         EXPAND %{8}
(188)            --> eduroam
(188)         if ("%{8}")  -> TRUE
(188)         if ("%{8}")  {
(188)           update request {
(188)             EXPAND %{8}
(188)                --> eduroam
(188)             &Called-Station-SSID := eduroam
(188)             EXPAND %{Called-Station-Id}:%{8}
(188)                --> 60-B9-C0-04-C4-40:eduroam
(188)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(188)           } # update request = noop
(188)         } # if ("%{8}")  = noop
(188)         [updated] = updated
(188)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(188)       ... skipping else: Preceding "if" was taken
(188)     } # policy rewrite_called_station_id = updated
(188)     policy rewrite_calling_station_id {
(188)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(188)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(188)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(188)         update request {
(188)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(188)              --> 22-E0-73-F2-50-23
(188)           &Calling-Station-Id := 22-E0-73-F2-50-23
(188)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(188)              --> 22:E0:73:F2:50:23
(188)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(188)         } # update request = noop
(188)         [updated] = updated
(188)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(188)       ... skipping else: Preceding "if" was taken
(188)     } # policy rewrite_calling_station_id = updated
(188)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(188)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(188)     if (Service-Type == Call-Check) {
(188)     if (Service-Type == Call-Check)  -> FALSE
(188)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(188)     EXPAND Packet-Src-IP-Address
(188)        --> 9.9.9.9
(188)     EXPAND Packet-Src-IP-Address
(188)        --> 9.9.9.9
(188)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(188)     if (EAP-Message) {
(188)     if (EAP-Message)  -> TRUE
(188)     if (EAP-Message)  {
(188)       policy filter_username {
(188)         if (&User-Name) {
(188)         if (&User-Name)  -> TRUE
(188)         if (&User-Name)  {
(188)           if (&User-Name =~ / /) {
(188)           if (&User-Name =~ / /)  -> FALSE
(188)           if (&User-Name =~ /@[^@]*@/ ) {
(188)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(188)           if (&User-Name =~ /\.\./ ) {
(188)           if (&User-Name =~ /\.\./ )  -> FALSE
(188)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(188)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(188)           if (&User-Name =~ /\.$/)  {
(188)           if (&User-Name =~ /\.$/)   -> FALSE
(188)           if (&User-Name =~ /@\./)  {
(188)           if (&User-Name =~ /@\./)   -> FALSE
(188)         } # if (&User-Name)  = updated
(188)       } # policy filter_username = updated
(188) suffix: Checking for suffix after "@"
(188) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(188) suffix: Found realm "UNIBE.CH"
(188) suffix: Adding Realm = "UNIBE.CH"
(188) suffix: Authentication realm is LOCAL
(188)       [suffix] = ok
(188)       policy deny_no_realm {
(188)         if (User-Name && (User-Name !~ /@/)) {
(188)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(188)       } # policy deny_no_realm = updated
(188)       update request {
(188)         EXPAND %{toupper:%{Realm}}
(188)            --> UNIBE.CH
(188)         Realm := UNIBE.CH
(188)       } # update request = noop
(188) eap: Peer sent EAP Response (code 2) ID 7 length 136
(188) eap: Continuing tunnel setup
(188)       [eap] = ok
(188)     } # if (EAP-Message)  = ok
(188)   } # authorize = updated
(188) Found Auth-Type = eap
(188) # Executing group from file /etc/freeradius/sites-enabled/default
(188)   Auth-Type eap {
(188) eap: Removing EAP session with state 0xcf8ae573ca8dfce6
(188) eap: Previous EAP request found for state 0xcf8ae573ca8dfce6, released from the list
(188) eap: Peer sent packet with method EAP PEAP (25)
(188) eap: Calling submodule eap_peap to process data
(188) eap_peap: (TLS) EAP Peer says that the final record size will be 126 bytes
(188) eap_peap: (TLS) EAP Got all data (126 bytes)
(188) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS write server done
(188) eap_peap: (TLS) PEAP - recv TLS 1.2 Handshake, ClientKeyExchange
(188) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS read client key exchange
(188) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS read change cipher spec
(188) eap_peap: (TLS) PEAP - recv TLS 1.2 Handshake, Finished
(188) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS read finished
(188) eap_peap: (TLS) PEAP - send TLS 1.2 ChangeCipherSpec
(188) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS write change cipher spec
(188) eap_peap: (TLS) PEAP - send TLS 1.2 Handshake, Finished
(188) eap_peap: (TLS) PEAP - Handshake state - Server SSLv3/TLS write finished
(188) eap_peap: (TLS) PEAP - Handshake state - SSL negotiation finished successfully
(188) eap_peap: (TLS) PEAP - Connection Established
(188) eap_peap:   TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(188) eap_peap:   TLS-Session-Version = "TLS 1.2"
(188) eap: Sending EAP Request (code 1) ID 8 length 57
(188) eap: EAP session adding &reply:State = 0xcf8ae573c982fce6
(188)     [eap] = handled
(188)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(188)     EXPAND Response-Packet-Type
(188)        --> Access-Challenge
(188)     if (handled && (Response-Packet-Type == Access-Challenge))  -> TRUE
(188)     if (handled && (Response-Packet-Type == Access-Challenge))  {
(188) attr_filter.access_challenge: EXPAND %{User-Name}
(188) attr_filter.access_challenge:    --> xyz@unibe.ch
(188) attr_filter.access_challenge: Matched entry DEFAULT at line 12
(188)       [attr_filter.access_challenge.post-auth] = updated
(188)       [handled] = handled
(188)     } # if (handled && (Response-Packet-Type == Access-Challenge))  = handled
(188)   } # Auth-Type eap = handled
(188) Using Post-Auth-Type Challenge
(188) Post-Auth-Type sub-section not found.  Ignoring.
(188) # Executing group from file /etc/freeradius/sites-enabled/default
(188) session-state: Saving cached attributes
(188)   Framed-MTU = 1014
(188)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(188)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(188)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(188)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(188)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(188)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.2 Handshake, ClientKeyExchange"
(188)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.2 Handshake, Finished"
(188)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 ChangeCipherSpec"
(188)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Finished"
(188)   TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(188)   TLS-Session-Version = "TLS 1.2"
(188) Sent Access-Challenge Id 79 from 130.92.10.33:1812 to 9.9.9.9:60533 length 115
(188)   EAP-Message = 0x010800391900140303000101160303002804f99461d03fc2be43b472810aaccc1082398a50bfe278395884ee9a22cacc6e5f0aa86dc8a3021e
(188)   Message-Authenticator = 0x00000000000000000000000000000000
(188)   State = 0xcf8ae573c982fce6e3b6e72de6bf5cbc
(188) Finished request
Waking up in 2.0 seconds.
(189) Received Access-Request Id 87 from 9.9.9.9:60533 to 130.92.10.33:1812 length 441
(189)   User-Name = "xyz@unibe.ch"
(189)   Service-Type = Framed-User
(189)   Cisco-AVPair = "service-type=Framed"
(189)   Framed-MTU = 1485
(189)   EAP-Message = 0x020800061900
(189)   Message-Authenticator = 0xa5b00fd17fe7b04da57e577d073ddcf4
(189)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(189)   Cisco-AVPair = "method=dot1x"
(189)   Cisco-AVPair = "client-iif-id=3724547122"
(189)   Cisco-AVPair = "vlan-id=1876"
(189)   NAS-IP-Address = 9.9.9.9
(189)   NAS-Port-Type = Wireless-802.11
(189)   NAS-Port = 4211
(189)   State = 0xcf8ae573c982fce6e3b6e72de6bf5cbc
(189)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(189)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(189)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(189)   Calling-Station-Id = "22-e0-73-f2-50-23"
(189)   Airespace-Wlan-Id = 98
(189)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(189)   WLAN-Group-Cipher = 1027076
(189)   WLAN-Pairwise-Cipher = 1027076
(189)   WLAN-AKM-Suite = 1027075
(189) Restoring &session-state
(189)   &session-state:Framed-MTU = 1014
(189)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(189)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(189)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(189)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(189)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(189)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.2 Handshake, ClientKeyExchange"
(189)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.2 Handshake, Finished"
(189)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 ChangeCipherSpec"
(189)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Finished"
(189)   &session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(189)   &session-state:TLS-Session-Version = "TLS 1.2"
(189) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(189)   authorize {
(189)     policy rewrite_called_station_id {
(189)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(189)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(189)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(189)         update request {
(189)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(189)              --> 60-B9-C0-04-C4-40
(189)           &Called-Station-Id := 60-B9-C0-04-C4-40
(189)         } # update request = noop
(189)         if ("%{8}") {
(189)         EXPAND %{8}
(189)            --> eduroam
(189)         if ("%{8}")  -> TRUE
(189)         if ("%{8}")  {
(189)           update request {
(189)             EXPAND %{8}
(189)                --> eduroam
(189)             &Called-Station-SSID := eduroam
(189)             EXPAND %{Called-Station-Id}:%{8}
(189)                --> 60-B9-C0-04-C4-40:eduroam
(189)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(189)           } # update request = noop
(189)         } # if ("%{8}")  = noop
(189)         [updated] = updated
(189)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(189)       ... skipping else: Preceding "if" was taken
(189)     } # policy rewrite_called_station_id = updated
(189)     policy rewrite_calling_station_id {
(189)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(189)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(189)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(189)         update request {
(189)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(189)              --> 22-E0-73-F2-50-23
(189)           &Calling-Station-Id := 22-E0-73-F2-50-23
(189)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(189)              --> 22:E0:73:F2:50:23
(189)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(189)         } # update request = noop
(189)         [updated] = updated
(189)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(189)       ... skipping else: Preceding "if" was taken
(189)     } # policy rewrite_calling_station_id = updated
(189)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(189)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(189)     if (Service-Type == Call-Check) {
(189)     if (Service-Type == Call-Check)  -> FALSE
(189)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(189)     EXPAND Packet-Src-IP-Address
(189)        --> 9.9.9.9
(189)     EXPAND Packet-Src-IP-Address
(189)        --> 9.9.9.9
(189)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(189)     if (EAP-Message) {
(189)     if (EAP-Message)  -> TRUE
(189)     if (EAP-Message)  {
(189)       policy filter_username {
(189)         if (&User-Name) {
(189)         if (&User-Name)  -> TRUE
(189)         if (&User-Name)  {
(189)           if (&User-Name =~ / /) {
(189)           if (&User-Name =~ / /)  -> FALSE
(189)           if (&User-Name =~ /@[^@]*@/ ) {
(189)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(189)           if (&User-Name =~ /\.\./ ) {
(189)           if (&User-Name =~ /\.\./ )  -> FALSE
(189)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(189)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(189)           if (&User-Name =~ /\.$/)  {
(189)           if (&User-Name =~ /\.$/)   -> FALSE
(189)           if (&User-Name =~ /@\./)  {
(189)           if (&User-Name =~ /@\./)   -> FALSE
(189)         } # if (&User-Name)  = updated
(189)       } # policy filter_username = updated
(189) suffix: Checking for suffix after "@"
(189) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(189) suffix: Found realm "UNIBE.CH"
(189) suffix: Adding Realm = "UNIBE.CH"
(189) suffix: Authentication realm is LOCAL
(189)       [suffix] = ok
(189)       policy deny_no_realm {
(189)         if (User-Name && (User-Name !~ /@/)) {
(189)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(189)       } # policy deny_no_realm = updated
(189)       update request {
(189)         EXPAND %{toupper:%{Realm}}
(189)            --> UNIBE.CH
(189)         Realm := UNIBE.CH
(189)       } # update request = noop
(189) eap: Peer sent EAP Response (code 2) ID 8 length 6
(189) eap: Continuing tunnel setup
(189)       [eap] = ok
(189)     } # if (EAP-Message)  = ok
(189)   } # authorize = updated
(189) Found Auth-Type = eap
(189) # Executing group from file /etc/freeradius/sites-enabled/default
(189)   Auth-Type eap {
(189) eap: Removing EAP session with state 0xcf8ae573c982fce6
(189) eap: Previous EAP request found for state 0xcf8ae573c982fce6, released from the list
(189) eap: Peer sent packet with method EAP PEAP (25)
(189) eap: Calling submodule eap_peap to process data
(189) eap_peap: (TLS) Peer ACKed our handshake fragment.  handshake is finished
(189) eap_peap: Session established.  Decoding tunneled attributes
(189) eap_peap: PEAP state TUNNEL ESTABLISHED
(189) eap: Sending EAP Request (code 1) ID 9 length 40
(189) eap: EAP session adding &reply:State = 0xcf8ae573c883fce6
(189)     [eap] = handled
(189)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(189)     EXPAND Response-Packet-Type
(189)        --> Access-Challenge
(189)     if (handled && (Response-Packet-Type == Access-Challenge))  -> TRUE
(189)     if (handled && (Response-Packet-Type == Access-Challenge))  {
(189) attr_filter.access_challenge: EXPAND %{User-Name}
(189) attr_filter.access_challenge:    --> xyz@unibe.ch
(189) attr_filter.access_challenge: Matched entry DEFAULT at line 12
(189)       [attr_filter.access_challenge.post-auth] = updated
(189)       [handled] = handled
(189)     } # if (handled && (Response-Packet-Type == Access-Challenge))  = handled
(189)   } # Auth-Type eap = handled
(189) Using Post-Auth-Type Challenge
(189) Post-Auth-Type sub-section not found.  Ignoring.
(189) # Executing group from file /etc/freeradius/sites-enabled/default
(189) session-state: Saving cached attributes
(189)   Framed-MTU = 1014
(189)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(189)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(189)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(189)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(189)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(189)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.2 Handshake, ClientKeyExchange"
(189)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.2 Handshake, Finished"
(189)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 ChangeCipherSpec"
(189)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Finished"
(189)   TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(189)   TLS-Session-Version = "TLS 1.2"
(189) Sent Access-Challenge Id 87 from 130.92.10.33:1812 to 9.9.9.9:60533 length 98
(189)   EAP-Message = 0x010900281900170303001d04f99461d03fc2bfcba8de001c3d804bdee9841e17c66ad8e895cc716f
(189)   Message-Authenticator = 0x00000000000000000000000000000000
(189)   State = 0xcf8ae573c883fce6e3b6e72de6bf5cbc
(189) Finished request
Waking up in 2.0 seconds.
(190) Received Access-Request Id 95 from 9.9.9.9:60533 to 130.92.10.33:1812 length 495
(190)   User-Name = "xyz@unibe.ch"
(190)   Service-Type = Framed-User
(190)   Cisco-AVPair = "service-type=Framed"
(190)   Framed-MTU = 1485
(190)   EAP-Message = 0x0209003c19001703030031205b847b10fba1571aeefaf72e8f9d6bacb5c5b0c60ea6e48b4fbe8b47377db78af34cb6696f2d542aac549b9d859dfb64
(190)   Message-Authenticator = 0x4798ae57b2ed9970df767d1ac0b91c74
(190)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(190)   Cisco-AVPair = "method=dot1x"
(190)   Cisco-AVPair = "client-iif-id=3724547122"
(190)   Cisco-AVPair = "vlan-id=1876"
(190)   NAS-IP-Address = 9.9.9.9
(190)   NAS-Port-Type = Wireless-802.11
(190)   NAS-Port = 4211
(190)   State = 0xcf8ae573c883fce6e3b6e72de6bf5cbc
(190)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(190)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(190)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(190)   Calling-Station-Id = "22-e0-73-f2-50-23"
(190)   Airespace-Wlan-Id = 98
(190)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(190)   WLAN-Group-Cipher = 1027076
(190)   WLAN-Pairwise-Cipher = 1027076
(190)   WLAN-AKM-Suite = 1027075
(190) Restoring &session-state
(190)   &session-state:Framed-MTU = 1014
(190)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(190)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(190)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(190)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(190)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(190)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.2 Handshake, ClientKeyExchange"
(190)   &session-state:TLS-Session-Information = "(TLS) PEAP - recv TLS 1.2 Handshake, Finished"
(190)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 ChangeCipherSpec"
(190)   &session-state:TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Finished"
(190)   &session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(190)   &session-state:TLS-Session-Version = "TLS 1.2"
(190) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(190)   authorize {
(190)     policy rewrite_called_station_id {
(190)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(190)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(190)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(190)         update request {
(190)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(190)              --> 60-B9-C0-04-C4-40
(190)           &Called-Station-Id := 60-B9-C0-04-C4-40
(190)         } # update request = noop
(190)         if ("%{8}") {
(190)         EXPAND %{8}
(190)            --> eduroam
(190)         if ("%{8}")  -> TRUE
(190)         if ("%{8}")  {
(190)           update request {
(190)             EXPAND %{8}
(190)                --> eduroam
(190)             &Called-Station-SSID := eduroam
(190)             EXPAND %{Called-Station-Id}:%{8}
(190)                --> 60-B9-C0-04-C4-40:eduroam
(190)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(190)           } # update request = noop
(190)         } # if ("%{8}")  = noop
(190)         [updated] = updated
(190)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(190)       ... skipping else: Preceding "if" was taken
(190)     } # policy rewrite_called_station_id = updated
(190)     policy rewrite_calling_station_id {
(190)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(190)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(190)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(190)         update request {
(190)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(190)              --> 22-E0-73-F2-50-23
(190)           &Calling-Station-Id := 22-E0-73-F2-50-23
(190)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(190)              --> 22:E0:73:F2:50:23
(190)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(190)         } # update request = noop
(190)         [updated] = updated
(190)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(190)       ... skipping else: Preceding "if" was taken
(190)     } # policy rewrite_calling_station_id = updated
(190)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(190)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(190)     if (Service-Type == Call-Check) {
(190)     if (Service-Type == Call-Check)  -> FALSE
(190)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(190)     EXPAND Packet-Src-IP-Address
(190)        --> 9.9.9.9
(190)     EXPAND Packet-Src-IP-Address
(190)        --> 9.9.9.9
(190)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(190)     if (EAP-Message) {
(190)     if (EAP-Message)  -> TRUE
(190)     if (EAP-Message)  {
(190)       policy filter_username {
(190)         if (&User-Name) {
(190)         if (&User-Name)  -> TRUE
(190)         if (&User-Name)  {
(190)           if (&User-Name =~ / /) {
(190)           if (&User-Name =~ / /)  -> FALSE
(190)           if (&User-Name =~ /@[^@]*@/ ) {
(190)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(190)           if (&User-Name =~ /\.\./ ) {
(190)           if (&User-Name =~ /\.\./ )  -> FALSE
(190)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(190)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(190)           if (&User-Name =~ /\.$/)  {
(190)           if (&User-Name =~ /\.$/)   -> FALSE
(190)           if (&User-Name =~ /@\./)  {
(190)           if (&User-Name =~ /@\./)   -> FALSE
(190)         } # if (&User-Name)  = updated
(190)       } # policy filter_username = updated
(190) suffix: Checking for suffix after "@"
(190) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(190) suffix: Found realm "UNIBE.CH"
(190) suffix: Adding Realm = "UNIBE.CH"
(190) suffix: Authentication realm is LOCAL
(190)       [suffix] = ok
(190)       policy deny_no_realm {
(190)         if (User-Name && (User-Name !~ /@/)) {
(190)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(190)       } # policy deny_no_realm = updated
(190)       update request {
(190)         EXPAND %{toupper:%{Realm}}
(190)            --> UNIBE.CH
(190)         Realm := UNIBE.CH
(190)       } # update request = noop
(190) eap: Peer sent EAP Response (code 2) ID 9 length 60
(190) eap: Continuing tunnel setup
(190)       [eap] = ok
(190)     } # if (EAP-Message)  = ok
(190)   } # authorize = updated
(190) Found Auth-Type = eap
(190) # Executing group from file /etc/freeradius/sites-enabled/default
(190)   Auth-Type eap {
(190) eap: Removing EAP session with state 0xcf8ae573c883fce6
(190) eap: Previous EAP request found for state 0xcf8ae573c883fce6, released from the list
(190) eap: Peer sent packet with method EAP PEAP (25)
(190) eap: Calling submodule eap_peap to process data
(190) eap_peap: (TLS) EAP Done initial handshake
(190) eap_peap: Session established.  Decoding tunneled attributes
(190) eap_peap: PEAP state WAITING FOR INNER IDENTITY
(190) eap_peap: Identity - xyz@unibe.ch
(190) eap_peap: Got inner identity 'xyz@unibe.ch'
(190) eap_peap: Setting default EAP type for tunneled EAP session
(190) eap_peap: Got tunneled request
(190) eap_peap:   EAP-Message = 0x0209001d01646f6d696e69632e7374616c64657240756e6962652e6368
(190) eap_peap: Setting User-Name to xyz@unibe.ch
(190) eap_peap: Sending tunneled request to proxy-inner-tunnel
(190) eap_peap:   EAP-Message = 0x0209001d01646f6d696e69632e7374616c64657240756e6962652e6368
(190) eap_peap:   FreeRADIUS-Proxied-To = 127.0.0.1
(190) eap_peap:   User-Name = "xyz@unibe.ch"
(190) eap_peap:   Service-Type = Framed-User
(190) eap_peap:   Cisco-AVPair = "service-type=Framed"
(190) eap_peap:   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(190) eap_peap:   Cisco-AVPair = "method=dot1x"
(190) eap_peap:   Cisco-AVPair = "client-iif-id=3724547122"
(190) eap_peap:   Cisco-AVPair = "vlan-id=1876"
(190) eap_peap:   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(190) eap_peap:   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(190) eap_peap:   Framed-MTU = 1485
(190) eap_peap:   NAS-IP-Address = 9.9.9.9
(190) eap_peap:   NAS-Port-Type = Wireless-802.11
(190) eap_peap:   NAS-Port = 4211
(190) eap_peap:   Called-Station-Id := "60-B9-C0-04-C4-40:eduroam"
(190) eap_peap:   Calling-Station-Id := "22-E0-73-F2-50-23"
(190) eap_peap:   Airespace-Wlan-Id = 98
(190) eap_peap:   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(190) eap_peap:   WLAN-Group-Cipher = 1027076
(190) eap_peap:   WLAN-Pairwise-Cipher = 1027076
(190) eap_peap:   WLAN-AKM-Suite = 1027075
(190) Virtual server proxy-inner-tunnel received request
(190)   EAP-Message = 0x0209001d01646f6d696e69632e7374616c64657240756e6962652e6368
(190)   FreeRADIUS-Proxied-To = 127.0.0.1
(190)   User-Name = "xyz@unibe.ch"
(190)   Service-Type = Framed-User
(190)   Cisco-AVPair = "service-type=Framed"
(190)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(190)   Cisco-AVPair = "method=dot1x"
(190)   Cisco-AVPair = "client-iif-id=3724547122"
(190)   Cisco-AVPair = "vlan-id=1876"
(190)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(190)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(190)   Framed-MTU = 1485
(190)   NAS-IP-Address = 9.9.9.9
(190)   NAS-Port-Type = Wireless-802.11
(190)   NAS-Port = 4211
(190)   Called-Station-Id := "60-B9-C0-04-C4-40:eduroam"
(190)   Calling-Station-Id := "22-E0-73-F2-50-23"
(190)   Airespace-Wlan-Id = 98
(190)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(190)   WLAN-Group-Cipher = 1027076
(190)   WLAN-Pairwise-Cipher = 1027076
(190)   WLAN-AKM-Suite = 1027075
(190) WARNING: Outer and inner identities are the same.  User privacy is compromised.
(190) server proxy-inner-tunnel {
(190)   # Executing section authorize from file /etc/freeradius/sites-enabled/proxy-inner-tunnel
(190)     authorize {
(190)       if (User-Name !~ /^([\w-.]{1,}\.[\w-.]{1,}@((unibe\.ch)|(faculty\.unibe\.ch)|(students\.unibe\.ch)|(ext\.unibe\.ch)))|(^[\w-]{1,20}@((campus\.unibe\.ch)|(unibe\.ch)))/) {
(190)       if (User-Name !~ /^([\w-.]{1,}\.[\w-.]{1,}@((unibe\.ch)|(faculty\.unibe\.ch)|(students\.unibe\.ch)|(ext\.unibe\.ch)))|(^[\w-]{1,20}@((campus\.unibe\.ch)|(unibe\.ch)))/)  -> FALSE
(190)       if (!NAS-Port-Type){
(190)       if (!NAS-Port-Type) -> FALSE
(190)       update control {
(190)         &Proxy-To-Realm := REALM-NPS-DEV
(190)       } # update control = noop
(190)     } # authorize = noop
(190) } # server proxy-inner-tunnel
(190) Virtual server sending reply
(190) eap_peap: Got tunneled reply code 0
(190) eap_peap: Tunnelled authentication will be proxied to REALM-NPS-DEV
(190) eap: WARNING: Tunneled session will be proxied.  Not doing EAP
(190)     [eap] = handled
(190)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(190)     EXPAND Response-Packet-Type
(190)        -->
(190)     if (handled && (Response-Packet-Type == Access-Challenge))  -> FALSE
(190)   } # Auth-Type eap = handled
(190) Starting proxy to home server 130.92.14.27 port 1812
(190) server default {
(190)   # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default
(190)     pre-proxy {
(190) attr_filter.pre-proxy: EXPAND %{Realm}
(190) attr_filter.pre-proxy:    --> UNIBE.CH
(190) attr_filter.pre-proxy: Matched entry DEFAULT at line 58
(190)       [attr_filter.pre-proxy] = updated
(190)     } # pre-proxy = updated
(190) }
(190) Proxying request to home server 130.92.14.27 port 1812 timeout 20.000000
(190) Sent Access-Request Id 190 from 0.0.0.0:38376 to 130.92.14.27:1812 length 195
(190)   Operator-Name := "1unibe.ch"
(190)   EAP-Message = 0x0209001d01646f6d696e69632e7374616c64657240756e6962652e6368
(190)   User-Name = "xyz@unibe.ch"
(190)   NAS-IP-Address = 9.9.9.9
(190)   NAS-Port-Type = Wireless-802.11
(190)   Called-Station-Id := "60-B9-C0-04-C4-40:eduroam"
(190)   Calling-Station-Id := "22-E0-73-F2-50-23"
(190)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(190)   Message-Authenticator = 0x
(190)   Proxy-State = 0x3935
Waking up in 0.3 seconds.
(190) Clearing existing &reply: attributes
(190) Received Access-Challenge Id 190 from 130.92.14.27:1812 to 130.92.10.33:38376 length 127
(190)   Proxy-State = 0x3935
(190)   Session-Timeout = 60
(190)   EAP-Message = 0x010a00271a010a002210c83761488cca2718c679660556394dee4141492d4e50532d4544555632
(190)   State = 0x22df03070000013700010200825c0e1b000000000000000000000000000000043a958c65
(190)   Message-Authenticator = 0xa3812c370e044725e89c60fee08004f3
(190) server default {
(190)   # Executing section post-proxy from file /etc/freeradius/sites-enabled/default
(190)     post-proxy {
(190) attr_filter.post-proxy: EXPAND %{Realm}
(190) attr_filter.post-proxy:    --> UNIBE.CH
(190) attr_filter.post-proxy: Matched entry UNIBE.CH at line 102
(190)       [attr_filter.post-proxy] = updated
(190) eap: Doing post-proxy callback
(190) eap: Passing reply from proxy back into the tunnel
(190) eap: Got tunneled reply RADIUS code 11
(190) eap:   Tunnel-Type := VLAN
(190) eap:   Tunnel-Medium-Type := IEEE-802
(190) eap:   Proxy-State = 0x3935
(190) eap:   EAP-Message = 0x010a00271a010a002210c83761488cca2718c679660556394dee4141492d4e50532d4544555632
(190) eap:   State = 0x22df03070000013700010200825c0e1b000000000000000000000000000000043a958c65
(190) eap:   Message-Authenticator = 0xa3812c370e044725e89c60fee08004f3
(190) eap: Got tunneled Access-Challenge
(190) eap: Reply was handled
(190) eap: Sending EAP Request (code 1) ID 10 length 70
(190) eap: EAP session adding &reply:State = 0xcf8ae573c780fce6
(190)       [eap] = ok
(190)     } # post-proxy = updated
(190) }
(190) session-state: Saving cached attributes
(190)   Framed-MTU = 1014
(190)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.3 Handshake, ClientHello"
(190)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHello"
(190)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Certificate"
(190)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange"
(190)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone"
(190)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.2 Handshake, ClientKeyExchange"
(190)   TLS-Session-Information = "(TLS) PEAP - recv TLS 1.2 Handshake, Finished"
(190)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 ChangeCipherSpec"
(190)   TLS-Session-Information = "(TLS) PEAP - send TLS 1.2 Handshake, Finished"
(190)   TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(190)   TLS-Session-Version = "TLS 1.2"
(190) Using Post-Auth-Type Challenge
(190) Post-Auth-Type sub-section not found.  Ignoring.
(190) # Executing group from file /etc/freeradius/sites-enabled/default
(190) Sent Access-Challenge Id 95 from 130.92.10.33:1812 to 9.9.9.9:60533 length 128
(190)   EAP-Message = 0x010a00461900170303003b04f99461d03fc2c0ac23d67f4ddb067ebf0aab5a9c002f61bc4a0be3c85a32f413a556f4f955e47114a5bd3076e920126f217073cb89e19f73e9b7
(190)   Message-Authenticator = 0x00000000000000000000000000000000
(190)   State = 0xcf8ae573c780fce6e3b6e72de6bf5cbc
(190) Finished request
Waking up in 2.0 seconds.
(191) Received Access-Request Id 103 from 9.9.9.9:60533 to 130.92.10.33:1812 length 549
(191)   User-Name = "xyz@unibe.ch"
(191)   Service-Type = Framed-User
(191)   Cisco-AVPair = "service-type=Framed"
(191)   Framed-MTU = 1485
(191)   EAP-Message = 0x020a007219001703030067205b847b10fba1584559915251d4673e0abf889721cd70283f669b7bc2790a707ee10b32db67326f5dc5ff040d06c69d2abac6cc1d42f3121fd59414b1064d38037caa197e338ac30a55ba2f77cc8e976d46335a5dfb2dd86e2f89a299d8ea1d97945192b49dbe
(191)   Message-Authenticator = 0xf3f378571c227125d81046d457c56823
(191)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(191)   Cisco-AVPair = "method=dot1x"
(191)   Cisco-AVPair = "client-iif-id=3724547122"
(191)   Cisco-AVPair = "vlan-id=1876"
(191)   NAS-IP-Address = 9.9.9.9
(191)   NAS-Port-Type = Wireless-802.11
(191)   NAS-Port = 4211
(191)   State = 0xcf8ae573c780fce6e3b6e72de6bf5cbc
(191)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(191)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(191)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(191)   Calling-Station-Id = "22-e0-73-f2-50-23"
(191)   Airespace-Wlan-Id = 98
(191)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(191)   WLAN-Group-Cipher = 1027076
(191)   WLAN-Pairwise-Cipher = 1027076
(191)   WLAN-AKM-Suite = 1027075
(191) session-state: No cached attributes
(191) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(191)   authorize {
(191)     policy rewrite_called_station_id {
(191)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(191)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(191)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(191)         update request {
(191)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(191)              --> 60-B9-C0-04-C4-40
(191)           &Called-Station-Id := 60-B9-C0-04-C4-40
(191)         } # update request = noop
(191)         if ("%{8}") {
(191)         EXPAND %{8}
(191)            --> eduroam
(191)         if ("%{8}")  -> TRUE
(191)         if ("%{8}")  {
(191)           update request {
(191)             EXPAND %{8}
(191)                --> eduroam
(191)             &Called-Station-SSID := eduroam
(191)             EXPAND %{Called-Station-Id}:%{8}
(191)                --> 60-B9-C0-04-C4-40:eduroam
(191)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(191)           } # update request = noop
(191)         } # if ("%{8}")  = noop
(191)         [updated] = updated
(191)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(191)       ... skipping else: Preceding "if" was taken
(191)     } # policy rewrite_called_station_id = updated
(191)     policy rewrite_calling_station_id {
(191)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(191)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(191)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(191)         update request {
(191)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(191)              --> 22-E0-73-F2-50-23
(191)           &Calling-Station-Id := 22-E0-73-F2-50-23
(191)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(191)              --> 22:E0:73:F2:50:23
(191)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(191)         } # update request = noop
(191)         [updated] = updated
(191)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(191)       ... skipping else: Preceding "if" was taken
(191)     } # policy rewrite_calling_station_id = updated
(191)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(191)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(191)     if (Service-Type == Call-Check) {
(191)     if (Service-Type == Call-Check)  -> FALSE
(191)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(191)     EXPAND Packet-Src-IP-Address
(191)        --> 9.9.9.9
(191)     EXPAND Packet-Src-IP-Address
(191)        --> 9.9.9.9
(191)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(191)     if (EAP-Message) {
(191)     if (EAP-Message)  -> TRUE
(191)     if (EAP-Message)  {
(191)       policy filter_username {
(191)         if (&User-Name) {
(191)         if (&User-Name)  -> TRUE
(191)         if (&User-Name)  {
(191)           if (&User-Name =~ / /) {
(191)           if (&User-Name =~ / /)  -> FALSE
(191)           if (&User-Name =~ /@[^@]*@/ ) {
(191)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(191)           if (&User-Name =~ /\.\./ ) {
(191)           if (&User-Name =~ /\.\./ )  -> FALSE
(191)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(191)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(191)           if (&User-Name =~ /\.$/)  {
(191)           if (&User-Name =~ /\.$/)   -> FALSE
(191)           if (&User-Name =~ /@\./)  {
(191)           if (&User-Name =~ /@\./)   -> FALSE
(191)         } # if (&User-Name)  = updated
(191)       } # policy filter_username = updated
(191) suffix: Checking for suffix after "@"
(191) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(191) suffix: Found realm "UNIBE.CH"
(191) suffix: Adding Realm = "UNIBE.CH"
(191) suffix: Authentication realm is LOCAL
(191)       [suffix] = ok
(191)       policy deny_no_realm {
(191)         if (User-Name && (User-Name !~ /@/)) {
(191)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(191)       } # policy deny_no_realm = updated
(191)       update request {
(191)         EXPAND %{toupper:%{Realm}}
(191)            --> UNIBE.CH
(191)         Realm := UNIBE.CH
(191)       } # update request = noop
(191) eap: Peer sent EAP Response (code 2) ID 10 length 114
(191) eap: Continuing tunnel setup
(191)       [eap] = ok
(191)     } # if (EAP-Message)  = ok
(191)   } # authorize = updated
(191) Found Auth-Type = eap
(191) # Executing group from file /etc/freeradius/sites-enabled/default
(191)   Auth-Type eap {
(191) eap: Removing EAP session with state 0xcf8ae573c780fce6
(191) eap: Previous EAP request found for state 0xcf8ae573c780fce6, released from the list
(191) eap: Peer sent packet with method EAP PEAP (25)
(191) eap: Calling submodule eap_peap to process data
(191) eap_peap: (TLS) EAP Done initial handshake
(191) eap_peap: Session established.  Decoding tunneled attributes
(191) eap_peap: PEAP state phase2
(191) eap_peap: EAP method MSCHAPv2 (26)
(191) eap_peap: Got tunneled request
(191) eap_peap:   EAP-Message = 0x020a00531a020a004e3197d74d4a32fbacd2fa345e05a04b070700000000000000008c45061c2def02f04f327c8c1994b030c364f8a9115efe2a00646f6d696e69632e7374616c64657240756e6962652e6368
(191) eap_peap: Setting User-Name to xyz@unibe.ch
(191) eap_peap: Sending tunneled request to proxy-inner-tunnel
(191) eap_peap:   EAP-Message = 0x020a00531a020a004e3197d74d4a32fbacd2fa345e05a04b070700000000000000008c45061c2def02f04f327c8c1994b030c364f8a9115efe2a00646f6d696e69632e7374616c64657240756e6962652e6368
(191) eap_peap:   FreeRADIUS-Proxied-To = 127.0.0.1
(191) eap_peap:   User-Name = "xyz@unibe.ch"
(191) eap_peap:   State = 0x22df03070000013700010200825c0e1b000000000000000000000000000000043a958c65
(191) eap_peap:   Service-Type = Framed-User
(191) eap_peap:   Cisco-AVPair = "service-type=Framed"
(191) eap_peap:   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(191) eap_peap:   Cisco-AVPair = "method=dot1x"
(191) eap_peap:   Cisco-AVPair = "client-iif-id=3724547122"
(191) eap_peap:   Cisco-AVPair = "vlan-id=1876"
(191) eap_peap:   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(191) eap_peap:   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(191) eap_peap:   Framed-MTU = 1485
(191) eap_peap:   NAS-IP-Address = 9.9.9.9
(191) eap_peap:   NAS-Port-Type = Wireless-802.11
(191) eap_peap:   NAS-Port = 4211
(191) eap_peap:   Called-Station-Id := "60-B9-C0-04-C4-40:eduroam"
(191) eap_peap:   Calling-Station-Id := "22-E0-73-F2-50-23"
(191) eap_peap:   Airespace-Wlan-Id = 98
(191) eap_peap:   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(191) eap_peap:   WLAN-Group-Cipher = 1027076
(191) eap_peap:   WLAN-Pairwise-Cipher = 1027076
(191) eap_peap:   WLAN-AKM-Suite = 1027075
(191) Virtual server proxy-inner-tunnel received request
(191)   EAP-Message = 0x020a00531a020a004e3197d74d4a32fbacd2fa345e05a04b070700000000000000008c45061c2def02f04f327c8c1994b030c364f8a9115efe2a00646f6d696e69632e7374616c64657240756e6962652e6368
(191)   FreeRADIUS-Proxied-To = 127.0.0.1
(191)   User-Name = "xyz@unibe.ch"
(191)   State = 0x22df03070000013700010200825c0e1b000000000000000000000000000000043a958c65
(191)   Service-Type = Framed-User
(191)   Cisco-AVPair = "service-type=Framed"
(191)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(191)   Cisco-AVPair = "method=dot1x"
(191)   Cisco-AVPair = "client-iif-id=3724547122"
(191)   Cisco-AVPair = "vlan-id=1876"
(191)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(191)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(191)   Framed-MTU = 1485
(191)   NAS-IP-Address = 9.9.9.9
(191)   NAS-Port-Type = Wireless-802.11
(191)   NAS-Port = 4211
(191)   Called-Station-Id := "60-B9-C0-04-C4-40:eduroam"
(191)   Calling-Station-Id := "22-E0-73-F2-50-23"
(191)   Airespace-Wlan-Id = 98
(191)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(191)   WLAN-Group-Cipher = 1027076
(191)   WLAN-Pairwise-Cipher = 1027076
(191)   WLAN-AKM-Suite = 1027075
(191) WARNING: Outer and inner identities are the same.  User privacy is compromised.
(191) server proxy-inner-tunnel {
(191)   session-state: No cached attributes
(191)   # Executing section authorize from file /etc/freeradius/sites-enabled/proxy-inner-tunnel
(191)     authorize {
(191)       if (User-Name !~ /^([\w-.]{1,}\.[\w-.]{1,}@((unibe\.ch)|(faculty\.unibe\.ch)|(students\.unibe\.ch)|(ext\.unibe\.ch)))|(^[\w-]{1,20}@((campus\.unibe\.ch)|(unibe\.ch)))/) {
(191)       if (User-Name !~ /^([\w-.]{1,}\.[\w-.]{1,}@((unibe\.ch)|(faculty\.unibe\.ch)|(students\.unibe\.ch)|(ext\.unibe\.ch)))|(^[\w-]{1,20}@((campus\.unibe\.ch)|(unibe\.ch)))/)  -> FALSE
(191)       if (!NAS-Port-Type){
(191)       if (!NAS-Port-Type) -> FALSE
(191)       update control {
(191)         &Proxy-To-Realm := REALM-NPS-DEV
(191)       } # update control = noop
(191)     } # authorize = noop
(191) } # server proxy-inner-tunnel
(191) Virtual server sending reply
(191) eap_peap: Got tunneled reply code 0
(191) eap_peap: Tunnelled authentication will be proxied to REALM-NPS-DEV
(191) eap: WARNING: Tunneled session will be proxied.  Not doing EAP
(191)     [eap] = handled
(191)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(191)     EXPAND Response-Packet-Type
(191)        -->
(191)     if (handled && (Response-Packet-Type == Access-Challenge))  -> FALSE
(191)   } # Auth-Type eap = handled
(191) Starting proxy to home server 130.92.14.27 port 1812
(191) server default {
(191)   # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default
(191)     pre-proxy {
(191) attr_filter.pre-proxy: EXPAND %{Realm}
(191) attr_filter.pre-proxy:    --> UNIBE.CH
(191) attr_filter.pre-proxy: Matched entry DEFAULT at line 58
(191)       [attr_filter.pre-proxy] = updated
(191)     } # pre-proxy = updated
(191) }
(191) Proxying request to home server 130.92.14.27 port 1812 timeout 20.000000
(191) Sent Access-Request Id 191 from 0.0.0.0:38376 to 130.92.14.27:1812 length 288
(191)   Operator-Name := "1unibe.ch"
(191)   EAP-Message = 0x020a00531a020a004e3197d74d4a32fbacd2fa345e05a04b070700000000000000008c45061c2def02f04f327c8c1994b030c364f8a9115efe2a00646f6d696e69632e7374616c64657240756e6962652e6368
(191)   User-Name = "xyz@unibe.ch"
(191)   State = 0x22df03070000013700010200825c0e1b000000000000000000000000000000043a958c65
(191)   NAS-IP-Address = 9.9.9.9
(191)   NAS-Port-Type = Wireless-802.11
(191)   Called-Station-Id := "60-B9-C0-04-C4-40:eduroam"
(191)   Calling-Station-Id := "22-E0-73-F2-50-23"
(191)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(191)   Message-Authenticator = 0x
(191)   Proxy-State = 0x313033
Waking up in 0.3 seconds.
(191) Clearing existing &reply: attributes
(191) Received Access-Challenge Id 191 from 130.92.14.27:1812 to 130.92.10.33:38376 length 140
(191)   Proxy-State = 0x313033
(191)   Session-Timeout = 60
(191)   EAP-Message = 0x010b00331a030a002e533d36323537434330314631324434464143463944453131333631363541363935354444423345344438
(191)   State = 0x22df03070000013700010200825c0e1b000000000000000000000000000000043a958c65
(191)   Message-Authenticator = 0x8ca6aae399c7f203dc1a20ce85e5750b
(191) server default {
(191)   # Executing section post-proxy from file /etc/freeradius/sites-enabled/default
(191)     post-proxy {
(191) attr_filter.post-proxy: EXPAND %{Realm}
(191) attr_filter.post-proxy:    --> UNIBE.CH
(191) attr_filter.post-proxy: Matched entry UNIBE.CH at line 102
(191)       [attr_filter.post-proxy] = updated
(191) eap: Doing post-proxy callback
(191) eap: Passing reply from proxy back into the tunnel
(191) eap: Got tunneled reply RADIUS code 11
(191) eap:   Tunnel-Type := VLAN
(191) eap:   Tunnel-Medium-Type := IEEE-802
(191) eap:   Proxy-State = 0x313033
(191) eap:   EAP-Message = 0x010b00331a030a002e533d36323537434330314631324434464143463944453131333631363541363935354444423345344438
(191) eap:   State = 0x22df03070000013700010200825c0e1b000000000000000000000000000000043a958c65
(191) eap:   Message-Authenticator = 0x8ca6aae399c7f203dc1a20ce85e5750b
(191) eap: Got tunneled Access-Challenge
(191) eap: Reply was handled
(191) eap: Sending EAP Request (code 1) ID 11 length 82
(191) eap: EAP session adding &reply:State = 0xcf8ae573c681fce6
(191)       [eap] = ok
(191)     } # post-proxy = updated
(191) }
(191) Using Post-Auth-Type Challenge
(191) Post-Auth-Type sub-section not found.  Ignoring.
(191) # Executing group from file /etc/freeradius/sites-enabled/default
(191) Sent Access-Challenge Id 103 from 130.92.10.33:1812 to 9.9.9.9:60533 length 140
(191)   EAP-Message = 0x010b00521900170303004704f99461d03fc2c1394041037baef530edfd9b8bf3fa86b0e63dd7b2ccbec2333eb2a290f24dcaa4882575e6ace41e0ab2b5a7b86b753145bb360713633e4a7d4d11d21c93b2d4
(191)   Message-Authenticator = 0x00000000000000000000000000000000
(191)   State = 0xcf8ae573c681fce6e3b6e72de6bf5cbc
(191) Finished request
Waking up in 1.9 seconds.
(192) Received Access-Request Id 111 from 9.9.9.9:60533 to 130.92.10.33:1812 length 472
(192)   User-Name = "xyz@unibe.ch"
(192)   Service-Type = Framed-User
(192)   Cisco-AVPair = "service-type=Framed"
(192)   Framed-MTU = 1485
(192)   EAP-Message = 0x020b00251900170303001a205b847b10fba159867591b547327317b26e0f7da7607738977b
(192)   Message-Authenticator = 0x80bb23fad6417fe1677e1055aac4907e
(192)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(192)   Cisco-AVPair = "method=dot1x"
(192)   Cisco-AVPair = "client-iif-id=3724547122"
(192)   Cisco-AVPair = "vlan-id=1876"
(192)   NAS-IP-Address = 9.9.9.9
(192)   NAS-Port-Type = Wireless-802.11
(192)   NAS-Port = 4211
(192)   State = 0xcf8ae573c681fce6e3b6e72de6bf5cbc
(192)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(192)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(192)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(192)   Calling-Station-Id = "22-e0-73-f2-50-23"
(192)   Airespace-Wlan-Id = 98
(192)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(192)   WLAN-Group-Cipher = 1027076
(192)   WLAN-Pairwise-Cipher = 1027076
(192)   WLAN-AKM-Suite = 1027075
(192) session-state: No cached attributes
(192) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(192)   authorize {
(192)     policy rewrite_called_station_id {
(192)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(192)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(192)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(192)         update request {
(192)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(192)              --> 60-B9-C0-04-C4-40
(192)           &Called-Station-Id := 60-B9-C0-04-C4-40
(192)         } # update request = noop
(192)         if ("%{8}") {
(192)         EXPAND %{8}
(192)            --> eduroam
(192)         if ("%{8}")  -> TRUE
(192)         if ("%{8}")  {
(192)           update request {
(192)             EXPAND %{8}
(192)                --> eduroam
(192)             &Called-Station-SSID := eduroam
(192)             EXPAND %{Called-Station-Id}:%{8}
(192)                --> 60-B9-C0-04-C4-40:eduroam
(192)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(192)           } # update request = noop
(192)         } # if ("%{8}")  = noop
(192)         [updated] = updated
(192)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(192)       ... skipping else: Preceding "if" was taken
(192)     } # policy rewrite_called_station_id = updated
(192)     policy rewrite_calling_station_id {
(192)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(192)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(192)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(192)         update request {
(192)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(192)              --> 22-E0-73-F2-50-23
(192)           &Calling-Station-Id := 22-E0-73-F2-50-23
(192)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(192)              --> 22:E0:73:F2:50:23
(192)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(192)         } # update request = noop
(192)         [updated] = updated
(192)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(192)       ... skipping else: Preceding "if" was taken
(192)     } # policy rewrite_calling_station_id = updated
(192)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(192)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(192)     if (Service-Type == Call-Check) {
(192)     if (Service-Type == Call-Check)  -> FALSE
(192)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(192)     EXPAND Packet-Src-IP-Address
(192)        --> 9.9.9.9
(192)     EXPAND Packet-Src-IP-Address
(192)        --> 9.9.9.9
(192)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(192)     if (EAP-Message) {
(192)     if (EAP-Message)  -> TRUE
(192)     if (EAP-Message)  {
(192)       policy filter_username {
(192)         if (&User-Name) {
(192)         if (&User-Name)  -> TRUE
(192)         if (&User-Name)  {
(192)           if (&User-Name =~ / /) {
(192)           if (&User-Name =~ / /)  -> FALSE
(192)           if (&User-Name =~ /@[^@]*@/ ) {
(192)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(192)           if (&User-Name =~ /\.\./ ) {
(192)           if (&User-Name =~ /\.\./ )  -> FALSE
(192)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(192)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(192)           if (&User-Name =~ /\.$/)  {
(192)           if (&User-Name =~ /\.$/)   -> FALSE
(192)           if (&User-Name =~ /@\./)  {
(192)           if (&User-Name =~ /@\./)   -> FALSE
(192)         } # if (&User-Name)  = updated
(192)       } # policy filter_username = updated
(192) suffix: Checking for suffix after "@"
(192) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(192) suffix: Found realm "UNIBE.CH"
(192) suffix: Adding Realm = "UNIBE.CH"
(192) suffix: Authentication realm is LOCAL
(192)       [suffix] = ok
(192)       policy deny_no_realm {
(192)         if (User-Name && (User-Name !~ /@/)) {
(192)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(192)       } # policy deny_no_realm = updated
(192)       update request {
(192)         EXPAND %{toupper:%{Realm}}
(192)            --> UNIBE.CH
(192)         Realm := UNIBE.CH
(192)       } # update request = noop
(192) eap: Peer sent EAP Response (code 2) ID 11 length 37
(192) eap: Continuing tunnel setup
(192)       [eap] = ok
(192)     } # if (EAP-Message)  = ok
(192)   } # authorize = updated
(192) Found Auth-Type = eap
(192) # Executing group from file /etc/freeradius/sites-enabled/default
(192)   Auth-Type eap {
(192) eap: Removing EAP session with state 0xcf8ae573c681fce6
(192) eap: Previous EAP request found for state 0xcf8ae573c681fce6, released from the list
(192) eap: Peer sent packet with method EAP PEAP (25)
(192) eap: Calling submodule eap_peap to process data
(192) eap_peap: (TLS) EAP Done initial handshake
(192) eap_peap: Session established.  Decoding tunneled attributes
(192) eap_peap: PEAP state phase2
(192) eap_peap: EAP method MSCHAPv2 (26)
(192) eap_peap: Got tunneled request
(192) eap_peap:   EAP-Message = 0x020b00061a03
(192) eap_peap: Setting User-Name to xyz@unibe.ch
(192) eap_peap: Sending tunneled request to proxy-inner-tunnel
(192) eap_peap:   EAP-Message = 0x020b00061a03
(192) eap_peap:   FreeRADIUS-Proxied-To = 127.0.0.1
(192) eap_peap:   User-Name = "xyz@unibe.ch"
(192) eap_peap:   State = 0x22df03070000013700010200825c0e1b000000000000000000000000000000043a958c65
(192) eap_peap:   Service-Type = Framed-User
(192) eap_peap:   Cisco-AVPair = "service-type=Framed"
(192) eap_peap:   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(192) eap_peap:   Cisco-AVPair = "method=dot1x"
(192) eap_peap:   Cisco-AVPair = "client-iif-id=3724547122"
(192) eap_peap:   Cisco-AVPair = "vlan-id=1876"
(192) eap_peap:   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(192) eap_peap:   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(192) eap_peap:   Framed-MTU = 1485
(192) eap_peap:   NAS-IP-Address = 9.9.9.9
(192) eap_peap:   NAS-Port-Type = Wireless-802.11
(192) eap_peap:   NAS-Port = 4211
(192) eap_peap:   Called-Station-Id := "60-B9-C0-04-C4-40:eduroam"
(192) eap_peap:   Calling-Station-Id := "22-E0-73-F2-50-23"
(192) eap_peap:   Airespace-Wlan-Id = 98
(192) eap_peap:   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(192) eap_peap:   WLAN-Group-Cipher = 1027076
(192) eap_peap:   WLAN-Pairwise-Cipher = 1027076
(192) eap_peap:   WLAN-AKM-Suite = 1027075
(192) Virtual server proxy-inner-tunnel received request
(192)   EAP-Message = 0x020b00061a03
(192)   FreeRADIUS-Proxied-To = 127.0.0.1
(192)   User-Name = "xyz@unibe.ch"
(192)   State = 0x22df03070000013700010200825c0e1b000000000000000000000000000000043a958c65
(192)   Service-Type = Framed-User
(192)   Cisco-AVPair = "service-type=Framed"
(192)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(192)   Cisco-AVPair = "method=dot1x"
(192)   Cisco-AVPair = "client-iif-id=3724547122"
(192)   Cisco-AVPair = "vlan-id=1876"
(192)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(192)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(192)   Framed-MTU = 1485
(192)   NAS-IP-Address = 9.9.9.9
(192)   NAS-Port-Type = Wireless-802.11
(192)   NAS-Port = 4211
(192)   Called-Station-Id := "60-B9-C0-04-C4-40:eduroam"
(192)   Calling-Station-Id := "22-E0-73-F2-50-23"
(192)   Airespace-Wlan-Id = 98
(192)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(192)   WLAN-Group-Cipher = 1027076
(192)   WLAN-Pairwise-Cipher = 1027076
(192)   WLAN-AKM-Suite = 1027075
(192) WARNING: Outer and inner identities are the same.  User privacy is compromised.
(192) server proxy-inner-tunnel {
(192)   session-state: No cached attributes
(192)   # Executing section authorize from file /etc/freeradius/sites-enabled/proxy-inner-tunnel
(192)     authorize {
(192)       if (User-Name !~ /^([\w-.]{1,}\.[\w-.]{1,}@((unibe\.ch)|(faculty\.unibe\.ch)|(students\.unibe\.ch)|(ext\.unibe\.ch)))|(^[\w-]{1,20}@((campus\.unibe\.ch)|(unibe\.ch)))/) {
(192)       if (User-Name !~ /^([\w-.]{1,}\.[\w-.]{1,}@((unibe\.ch)|(faculty\.unibe\.ch)|(students\.unibe\.ch)|(ext\.unibe\.ch)))|(^[\w-]{1,20}@((campus\.unibe\.ch)|(unibe\.ch)))/)  -> FALSE
(192)       if (!NAS-Port-Type){
(192)       if (!NAS-Port-Type) -> FALSE
(192)       update control {
(192)         &Proxy-To-Realm := REALM-NPS-DEV
(192)       } # update control = noop
(192)     } # authorize = noop
(192) } # server proxy-inner-tunnel
(192) Virtual server sending reply
(192) eap_peap: Got tunneled reply code 0
(192) eap_peap: Tunnelled authentication will be proxied to REALM-NPS-DEV
(192) eap: WARNING: Tunneled session will be proxied.  Not doing EAP
(192)     [eap] = handled
(192)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(192)     EXPAND Response-Packet-Type
(192)        -->
(192)     if (handled && (Response-Packet-Type == Access-Challenge))  -> FALSE
(192)   } # Auth-Type eap = handled
(192) Starting proxy to home server 130.92.14.27 port 1812
(192) server default {
(192)   # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default
(192)     pre-proxy {
(192) attr_filter.pre-proxy: EXPAND %{Realm}
(192) attr_filter.pre-proxy:    --> UNIBE.CH
(192) attr_filter.pre-proxy: Matched entry DEFAULT at line 58
(192)       [attr_filter.pre-proxy] = updated
(192)     } # pre-proxy = updated
(192) }
(192) Proxying request to home server 130.92.14.27 port 1812 timeout 20.000000
(192) Sent Access-Request Id 192 from 0.0.0.0:38376 to 130.92.14.27:1812 length 211
(192)   Operator-Name := "1unibe.ch"
(192)   EAP-Message = 0x020b00061a03
(192)   User-Name = "xyz@unibe.ch"
(192)   State = 0x22df03070000013700010200825c0e1b000000000000000000000000000000043a958c65
(192)   NAS-IP-Address = 9.9.9.9
(192)   NAS-Port-Type = Wireless-802.11
(192)   Called-Station-Id := "60-B9-C0-04-C4-40:eduroam"
(192)   Calling-Station-Id := "22-E0-73-F2-50-23"
(192)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(192)   Message-Authenticator = 0x
(192)   Proxy-State = 0x313131
Waking up in 0.3 seconds.
(192) Clearing existing &reply: attributes
(192) Received Access-Accept Id 192 from 130.92.14.27:1812 to 130.92.10.33:38376 length 289
(192)   Proxy-State = 0x313131
(192)   Class = 0x7374616666
(192)   Filter-Id = "staff"
(192)   Framed-Protocol = PPP
(192)   Service-Type = Framed-User
(192)   Tunnel-Medium-Type:0 = IEEE-802
(192)   Tunnel-Private-Group-Id:0 = "1874"
(192)   Tunnel-Type:0 = VLAN
(192)   EAP-Message = 0x030b0004
(192)   Class = 0x577206960000013700010200825c0e1b00000000000000000000000001dac0032e975ae0000000000057c996
(192)   MS-CHAP-Domain = "\001CAMPUS"
(192)   MS-MPPE-Send-Key = 0xfe66eab21e8b02b3e1c4b4f57f508f7a
(192)   MS-MPPE-Recv-Key = 0x1d45747249960c52c1ceeaf9378ad8aa
(192)   MS-CHAP2-Success = 0x01533d36323537434330314631324434464143463944453131333631363541363935354444423345344438
(192)   Message-Authenticator = 0x332c0b8965d8c87621614cec5d9820b5
(192) server default {
(192)   # Executing section post-proxy from file /etc/freeradius/sites-enabled/default
(192)     post-proxy {
(192) attr_filter.post-proxy: EXPAND %{Realm}
(192) attr_filter.post-proxy:    --> UNIBE.CH
(192) attr_filter.post-proxy: Matched entry UNIBE.CH at line 102
(192)       [attr_filter.post-proxy] = updated
(192) eap: Doing post-proxy callback
(192) eap: Passing reply from proxy back into the tunnel
(192) eap: Got tunneled reply RADIUS code 2
(192) eap:   Tunnel-Type := VLAN
(192) eap:   Tunnel-Medium-Type := IEEE-802
(192) eap:   Proxy-State = 0x313131
(192) eap:   Class = 0x7374616666
(192) eap:   Filter-Id = "staff"
(192) eap:   Tunnel-Private-Group-Id:0 = "1874"
(192) eap:   EAP-Message = 0x030b0004
(192) eap:   Class = 0x577206960000013700010200825c0e1b00000000000000000000000001dac0032e975ae0000000000057c996
(192) eap:   MS-MPPE-Send-Key = 0xfe66eab21e8b02b3e1c4b4f57f508f7a
(192) eap:   MS-MPPE-Recv-Key = 0x1d45747249960c52c1ceeaf9378ad8aa
(192) eap:   Message-Authenticator = 0x332c0b8965d8c87621614cec5d9820b5
(192) eap: Tunneled authentication was successful
(192) eap: SUCCESS
(192) eap: Saving tunneled attributes for later
(192) eap: Reply was handled
(192) eap: Sending EAP Request (code 1) ID 12 length 46
(192) eap: EAP session adding &reply:State = 0xcf8ae573c586fce6
(192)       [eap] = ok
(192)     } # post-proxy = updated
(192) }
(192) Using Post-Auth-Type Challenge
(192) Post-Auth-Type sub-section not found.  Ignoring.
(192) # Executing group from file /etc/freeradius/sites-enabled/default
(192) Sent Access-Challenge Id 111 from 130.92.10.33:1812 to 9.9.9.9:60533 length 104
(192)   EAP-Message = 0x010c002e1900170303002304f99461d03fc2c2b4dd16ee98eb7b0ed3a137545de5ddc88bf5b3423c2b5f193225fc
(192)   Message-Authenticator = 0x00000000000000000000000000000000
(192)   State = 0xcf8ae573c586fce6e3b6e72de6bf5cbc
(192) Finished request
Waking up in 1.9 seconds.
(193) Received Access-Request Id 119 from 9.9.9.9:60533 to 130.92.10.33:1812 length 481
(193)   User-Name = "xyz@unibe.ch"
(193)   Service-Type = Framed-User
(193)   Cisco-AVPair = "service-type=Framed"
(193)   Framed-MTU = 1485
(193)   EAP-Message = 0x020c002e19001703030023205b847b10fba15afce16997166d4cb19322461fe577bbdaf9ad0ee9efac33751092a9
(193)   Message-Authenticator = 0xb4660f308f2de4f2c559a9a233219dd9
(193)   Cisco-AVPair = "audit-session-id=0F2A5C820000093C2FFBA7DF"
(193)   Cisco-AVPair = "method=dot1x"
(193)   Cisco-AVPair = "client-iif-id=3724547122"
(193)   Cisco-AVPair = "vlan-id=1876"
(193)   NAS-IP-Address = 9.9.9.9
(193)   NAS-Port-Type = Wireless-802.11
(193)   NAS-Port = 4211
(193)   State = 0xcf8ae573c586fce6e3b6e72de6bf5cbc
(193)   Cisco-AVPair = "cisco-wlan-ssid=eduroam"
(193)   Cisco-AVPair = "wlan-profile-name=eduroam-DEV"
(193)   Called-Station-Id = "60-b9-c0-04-c4-40:eduroam"
(193)   Calling-Station-Id = "22-e0-73-f2-50-23"
(193)   Airespace-Wlan-Id = 98
(193)   NAS-Identifier = "60-b9-c0-04-c4-40:eduroam"
(193)   WLAN-Group-Cipher = 1027076
(193)   WLAN-Pairwise-Cipher = 1027076
(193)   WLAN-AKM-Suite = 1027075
(193) session-state: No cached attributes
(193) # Executing section authorize from file /etc/freeradius/sites-enabled/default
(193)   authorize {
(193)     policy rewrite_called_station_id {
(193)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) {
(193)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  -> TRUE
(193)       if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  {
(193)         update request {
(193)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(193)              --> 60-B9-C0-04-C4-40
(193)           &Called-Station-Id := 60-B9-C0-04-C4-40
(193)         } # update request = noop
(193)         if ("%{8}") {
(193)         EXPAND %{8}
(193)            --> eduroam
(193)         if ("%{8}")  -> TRUE
(193)         if ("%{8}")  {
(193)           update request {
(193)             EXPAND %{8}
(193)                --> eduroam
(193)             &Called-Station-SSID := eduroam
(193)             EXPAND %{Called-Station-Id}:%{8}
(193)                --> 60-B9-C0-04-C4-40:eduroam
(193)             &Called-Station-Id := 60-B9-C0-04-C4-40:eduroam
(193)           } # update request = noop
(193)         } # if ("%{8}")  = noop
(193)         [updated] = updated
(193)       } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i))  = updated
(193)       ... skipping else: Preceding "if" was taken
(193)     } # policy rewrite_called_station_id = updated
(193)     policy rewrite_calling_station_id {
(193)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) {
(193)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  -> TRUE
(193)       if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  {
(193)         update request {
(193)           EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(193)              --> 22-E0-73-F2-50-23
(193)           &Calling-Station-Id := 22-E0-73-F2-50-23
(193)           EXPAND %{toupper:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}}
(193)              --> 22:E0:73:F2:50:23
(193)           &locMacAuth-Calling-Station-Id := 22:E0:73:F2:50:23
(193)         } # update request = noop
(193)         [updated] = updated
(193)       } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i))  = updated
(193)       ... skipping else: Preceding "if" was taken
(193)     } # policy rewrite_calling_station_id = updated
(193)     if (NAS-Identifier == "uvisrz0215.insel.ch") {
(193)     if (NAS-Identifier == "uvisrz0215.insel.ch")  -> FALSE
(193)     if (Service-Type == Call-Check) {
(193)     if (Service-Type == Call-Check)  -> FALSE
(193)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25) {
(193)     EXPAND Packet-Src-IP-Address
(193)        --> 9.9.9.9
(193)     EXPAND Packet-Src-IP-Address
(193)        --> 9.9.9.9
(193)     if (Packet-Src-IP-Address == 130.59.31.24 || Packet-Src-IP-Address == 130.59.31.25)  -> FALSE
(193)     if (EAP-Message) {
(193)     if (EAP-Message)  -> TRUE
(193)     if (EAP-Message)  {
(193)       policy filter_username {
(193)         if (&User-Name) {
(193)         if (&User-Name)  -> TRUE
(193)         if (&User-Name)  {
(193)           if (&User-Name =~ / /) {
(193)           if (&User-Name =~ / /)  -> FALSE
(193)           if (&User-Name =~ /@[^@]*@/ ) {
(193)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(193)           if (&User-Name =~ /\.\./ ) {
(193)           if (&User-Name =~ /\.\./ )  -> FALSE
(193)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(193)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(193)           if (&User-Name =~ /\.$/)  {
(193)           if (&User-Name =~ /\.$/)   -> FALSE
(193)           if (&User-Name =~ /@\./)  {
(193)           if (&User-Name =~ /@\./)   -> FALSE
(193)         } # if (&User-Name)  = updated
(193)       } # policy filter_username = updated
(193) suffix: Checking for suffix after "@"
(193) suffix: Looking up realm "unibe.ch" for User-Name = "xyz@unibe.ch"
(193) suffix: Found realm "UNIBE.CH"
(193) suffix: Adding Realm = "UNIBE.CH"
(193) suffix: Authentication realm is LOCAL
(193)       [suffix] = ok
(193)       policy deny_no_realm {
(193)         if (User-Name && (User-Name !~ /@/)) {
(193)         if (User-Name && (User-Name !~ /@/))  -> FALSE
(193)       } # policy deny_no_realm = updated
(193)       update request {
(193)         EXPAND %{toupper:%{Realm}}
(193)            --> UNIBE.CH
(193)         Realm := UNIBE.CH
(193)       } # update request = noop
(193) eap: Peer sent EAP Response (code 2) ID 12 length 46
(193) eap: Continuing tunnel setup
(193)       [eap] = ok
(193)     } # if (EAP-Message)  = ok
(193)   } # authorize = updated
(193) Found Auth-Type = eap
(193) # Executing group from file /etc/freeradius/sites-enabled/default
(193)   Auth-Type eap {
(193) eap: Removing EAP session with state 0xcf8ae573c586fce6
(193) eap: Previous EAP request found for state 0xcf8ae573c586fce6, released from the list
(193) eap: Peer sent packet with method EAP PEAP (25)
(193) eap: Calling submodule eap_peap to process data
(193) eap_peap: (TLS) EAP Done initial handshake
(193) eap_peap: Session established.  Decoding tunneled attributes
(193) eap_peap: PEAP state send tlv success
(193) eap_peap: Received EAP-TLV response
(193) eap_peap: Success
(193) eap_peap: Using saved attributes from the original Access-Accept
(193) eap_peap:   Tunnel-Type := VLAN
(193) eap_peap:   Tunnel-Medium-Type := IEEE-802
(193) eap_peap:   Class = 0x7374616666
(193) eap_peap:   Filter-Id = "staff"
(193) eap_peap:   Tunnel-Private-Group-Id:0 = "1874"
(193) eap_peap:   Class = 0x577206960000013700010200825c0e1b00000000000000000000000001dac0032e975ae0000000000057c996
(193) eap: Sending EAP Success (code 3) ID 12 length 4
(193) eap: Freeing handler
(193)     [eap] = ok
(193)     if (handled && (Response-Packet-Type == Access-Challenge)) {
(193)     if (handled && (Response-Packet-Type == Access-Challenge))  -> FALSE
(193)   } # Auth-Type eap = ok
(193) # Executing section post-auth from file /etc/freeradius/sites-enabled/default
(193)   post-auth {
(193)     update {
(193)       No attributes updated for RHS &session-state:
(193)     } # update = noop
(193) 802.1x_authz_log: EXPAND sp.%{%{reply:Packet-Type}:-format}
(193) 802.1x_authz_log:    --> sp.Access-Accept
(193) 802.1x_authz_log: EXPAND %t : AuthZ: (%I) Access-Accept: [%{%{reply:User-Name}:-%{User-Name}}] TLS-Version=%{%{session-state:TLS-Session-Version}:-NULL} TLS-Ciphers=%{%{session-state:TLS-Session-Cipher-Suite}:-NULL} SSID=%{%{request:Called-Station-SSID}:-NULL} Calling-Station-Id=%{%{request:Calling-Station-Id}:-Unknown} Called-Station-Id=%{%{request:Called-Station-Id}:-Unknown} Filter-ID=%{%{reply:Filter-Id}:-NULL} VLAN=%{%{reply:Tunnel-Private-Group-Id}:-NULL} Class=%{%{reply:Class}:-NULL} (from client %{Client-Shortname} port %{%{request:Nas-Port}:-0} operator-name %{%{request:Operator-Name}:-Unknown})
(193) 802.1x_authz_log:    --> Fri Nov 15 14:20:45 2024 : AuthZ: (119) Access-Accept: [xyz@unibe.ch] TLS-Version=NULL TLS-Ciphers=NULL SSID=eduroam Calling-Station-Id=22-E0-73-F2-50-23 Called-Station-Id=60-B9-C0-04-C4-40:eduroam Filter-ID=staff VLAN=1874 Class=0x7374616666 (from client cisco-wlc-9800-dev-mgmt.wifi.unibe.ch port 4211 operator-name Unknown)
(193) 802.1x_authz_log: EXPAND /var/log/freeradius/authz.log
(193) 802.1x_authz_log:    --> /var/log/freeradius/authz.log
(193)     [802.1x_authz_log] = ok
(193)     policy remove_reply_message_if_eap {
(193)       if (&reply:EAP-Message && &reply:Reply-Message) {
(193)       if (&reply:EAP-Message && &reply:Reply-Message)  -> FALSE
(193)       else {
(193)         [noop] = noop
(193)       } # else = noop
(193)     } # policy remove_reply_message_if_eap = noop
(193)   } # post-auth = ok
(193) Login OK: [xyz@unibe.ch] (from client cisco-wlc-9800-dev-mgmt.wifi.unibe.ch port 4211 cli 22-E0-73-F2-50-23)
(193) Sent Access-Accept Id 119 from 130.92.10.33:1812 to 9.9.9.9:60533 length 264
(193)   Tunnel-Type := VLAN
(193)   Tunnel-Medium-Type := IEEE-802
(193)   Class = 0x7374616666
(193)   Filter-Id = "staff"
(193)   Tunnel-Private-Group-Id:0 = "1874"
(193)   Class = 0x577206960000013700010200825c0e1b00000000000000000000000001dac0032e975ae0000000000057c996
(193)   MS-MPPE-Recv-Key = 0xa0c1ae0b7eeb1e5c11689f0921a1cd1bda85111a84912ecbbb853107fe90372a
(193)   MS-MPPE-Send-Key = 0x4f4bdb175d9d487f81ddf1e819a82c37de9d37605d47a226923fc335d3e805a4
(193)   EAP-Message = 0x030c0004
(193)   Message-Authenticator = 0x00000000000000000000000000000000
(193)   User-Name = "xyz@unibe.ch"
(193) Finished request
Waking up in 1.9 seconds.

If you look at src/main/tls.c, it adds that attribute when the debug output shows "Connection established". And, it prints out the attribute it's added.

(188) eap_peap: (TLS) PEAP - Connection Established
(188) eap_peap:   TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(188) eap_peap:   TLS-Session-Version = "TLS 1.2"

Why the f**k did I miss this in version 3.2.4? Or was it maybe "reintroduced" in 3.2.6 since I upgraded to this version lately; is is this another “SSL thing” patched by Nick?

- More debugging for SSL ciphers. Patch from Nick Porter.

Nonetheless, I am going to figure out how adjust my linelog module configuration to get it back into the logs, because at the moment I still see NULL (example):

linelog 802.1x_authz_log {
        filename = ${logdir}/authz.log
        reference = "sp.%{%{reply:Packet-Type}:-format}"

        sp {
                Access-Accept = "%t : AuthZ: (%I) Access-Accept: [%{%{reply:User-Name}:-%{User-Name}}] TLS-Version=%{%{session-state:TLS-Session-Version}:-NULL} TLS-Ciphers=%{%{session-state:TLS-Session-Cipher-Suite}:-NULL} SSID=%{%{request:Called-Station-SSID}:-NULL} Calling-Station-Id=%{%{request:Calling-Station-Id}:-Unknown} Called-Station-Id=%{%{request:Called-Station-Id}:-Unknown} Filter-ID=%{%{reply:Filter-Id}:-NULL} VLAN=%{%{reply:Tunnel-Private-Group-Id}:-NULL} Class=%{%{reply:Class}:-NULL} (from client %{Client-Shortname} port %{%{request:Nas-Port}:-0} operator-name %{%{request:Operator-Name}:-Unknown})"
        }
}

Fri Nov 15 14:25:34 2024 : AuthZ: (11) Access-Accept: [anonymous@unibe.ch] TLS-Version=NULL TLS-Ciphers=NULL SSID=eduroam Calling-Station-Id=02-00-00-00-00-01 Called-Station-Id=11-22-33-44-55-66:eduroam Filter-ID=external VLAN=1876 Class=0x65787465726e616c (from client localhost port 0 operator-name Unknown)

Re: Add TLS version to logs with linelog in FreeRADIUS 3.2.4

Dominic Stalder