Hi,
I'm trying FreeRADIUS Version 3.0.10.
I've realized that quite often when users fail authentication due to wrong
password this does not result in a "Login incorrect" message in the logs.
When the password is set to the correct value again a "Login OK" appears in
the logs.
It looks like the session hangs.
I was able to reproduce the behaviour on an android phone and this is the
output of radiusd -X (NT and SHA1 hashes obscured).
Any help would be greatly appreciated.
Thanks,
Stefano
(0) Received Access-Request Id 175 from 147.162.234.209:32776 to
147.162.57.7:1812 length 288
(0) User-Name = "stefano.zanmarchi(a)unipd.it"
(0) Chargeable-User-Identity = 0x00
(0) Location-Capable = Civix-Location
(0) Calling-Station-Id = "64-89-9a-1f-93-d6"
(0) Called-Station-Id = "AP-GROUP-CSIA"
(0) NAS-Port = 1
(0) Cisco-AVPair = "audit-session-id=93a2ead100012e6456fa7c31"
(0) Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(0) NAS-IP-Address = 147.162.234.209
(0) NAS-Identifier = "WLC"
(0) Airespace-Wlan-Id = 6
(0) Service-Type = Framed-User
(0) Framed-MTU = 1300
(0) NAS-Port-Type = Wireless-802.11
(0) Tunnel-Type:0 = VLAN
(0) Tunnel-Medium-Type:0 = IEEE-802
(0) Tunnel-Private-Group-Id:0 = "83"
(0) EAP-Message =
0x0201001f0173746566616e6f2e7a616e6d617263686940756e6970642e6974
(0) Message-Authenticator = 0xccfded3b06bc9f6779fc4d3a25cd8c28
(0) # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam
(0) authorize {
(0) policy filter_username {
(0) if (!&User-Name) {
(0) if (!&User-Name) -> FALSE
(0) if (&User-Name =~ / /) {
(0) if (&User-Name =~ / /) -> FALSE
(0) if (&User-Name =~ /@.*@/ ) {
(0) if (&User-Name =~ /@.*@/ ) -> FALSE
(0) if (&User-Name =~ /\.\./ ) {
(0) if (&User-Name =~ /\.\./ ) -> FALSE
(0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(0) if (&User-Name =~ /\.$/) {
(0) if (&User-Name =~ /\.$/) -> FALSE
(0) if (&User-Name =~ /(a)\./) {
(0) if (&User-Name =~ /(a)\./) -> FALSE
(0) } # policy filter_username = notfound
(0) [preprocess] = ok
(0) suffix: Checking for suffix after "@"
(0) suffix: Looking up realm "unipd.it" for User-Name = "
stefano.zanmarchi(a)unipd.it"
(0) suffix: Found realm "unipd.it"
(0) suffix: Adding Realm = "unipd.it"
(0) suffix: Authentication realm is LOCAL
(0) [suffix] = ok
(0) eap: Peer sent EAP Response (code 2) ID 1 length 31
(0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the
rest of authorize
(0) [eap] = ok
(0) } # authorize = ok
(0) Found Auth-Type = EAP
(0) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(0) authenticate {
(0) eap: Peer sent packet with method EAP Identity (1)
(0) eap: Calling submodule eap_peap to process data
(0) eap_peap: Initiating new EAP-TLS session
(0) eap_peap: [eaptls start] = request
(0) eap: Sending EAP Request (code 1) ID 2 length 6
(0) eap: EAP session adding &reply:State = 0x3adf3a9e3add23ab
(0) [eap] = handled
(0) } # authenticate = handled
(0) Using Post-Auth-Type Challenge
(0) Post-Auth-Type sub-section not found. Ignoring.
(0) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(0) Sent Access-Challenge Id 175 from 147.162.57.7:1812 to
147.162.234.209:32776 length 0
(0) EAP-Message = 0x010200061920
(0) Message-Authenticator = 0x00000000000000000000000000000000
(0) State = 0x3adf3a9e3add23abadde1d2911153d2e
(0) Finished request
Waking up in 4.9 seconds.
(1) Received Access-Request Id 176 from 147.162.234.209:32776 to
147.162.57.7:1812 length 483
(1) User-Name = "stefano.zanmarchi(a)unipd.it"
(1) Chargeable-User-Identity = 0x00
(1) Location-Capable = Civix-Location
(1) Calling-Station-Id = "64-89-9a-1f-93-d6"
(1) Called-Station-Id = "AP-GROUP-CSIA"
(1) NAS-Port = 1
(1) Cisco-AVPair = "audit-session-id=93a2ead100012e6456fa7c31"
(1) Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(1) NAS-IP-Address = 147.162.234.209
(1) NAS-Identifier = "WLC"
(1) Airespace-Wlan-Id = 6
(1) Service-Type = Framed-User
(1) Framed-MTU = 1300
(1) NAS-Port-Type = Wireless-802.11
(1) Tunnel-Type:0 = VLAN
(1) Tunnel-Medium-Type:0 = IEEE-802
(1) Tunnel-Private-Group-Id:0 = "83"
(1) EAP-Message =
0x020200d01980000000c616030100c1010000bd0301969c67acc968dbc4ad3c8d94b9ae9db616fe9fb1316dcdff20d19c913c051c90000054c014c00ac022c02100390038c00fc0050035c012c008c01cc01b00160013c00dc003000ac013c009c01fc01e00330032c00ec004002fc011c007c00cc00200
(1) State = 0x3adf3a9e3add23abadde1d2911153d2e
(1) Message-Authenticator = 0xb3a4502bf04b94541918ffd352911106
(1) session-state: No cached attributes
(1) # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam
(1) authorize {
(1) policy filter_username {
(1) if (!&User-Name) {
(1) if (!&User-Name) -> FALSE
(1) if (&User-Name =~ / /) {
(1) if (&User-Name =~ / /) -> FALSE
(1) if (&User-Name =~ /@.*@/ ) {
(1) if (&User-Name =~ /@.*@/ ) -> FALSE
(1) if (&User-Name =~ /\.\./ ) {
(1) if (&User-Name =~ /\.\./ ) -> FALSE
(1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(1) if (&User-Name =~ /\.$/) {
(1) if (&User-Name =~ /\.$/) -> FALSE
(1) if (&User-Name =~ /(a)\./) {
(1) if (&User-Name =~ /(a)\./) -> FALSE
(1) } # policy filter_username = notfound
(1) [preprocess] = ok
(1) suffix: Checking for suffix after "@"
(1) suffix: Looking up realm "unipd.it" for User-Name = "
stefano.zanmarchi(a)unipd.it"
(1) suffix: Found realm "unipd.it"
(1) suffix: Adding Realm = "unipd.it"
(1) suffix: Authentication realm is LOCAL
(1) [suffix] = ok
(1) eap: Peer sent EAP Response (code 2) ID 2 length 208
(1) eap: Continuing tunnel setup
(1) [eap] = ok
(1) } # authorize = ok
(1) Found Auth-Type = EAP
(1) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(1) authenticate {
(1) eap: Expiring EAP session with state 0x3adf3a9e3add23ab
(1) eap: Finished EAP session with state 0x3adf3a9e3add23ab
(1) eap: Previous EAP request found for state 0x3adf3a9e3add23ab, released
from the list
(1) eap: Peer sent packet with method EAP PEAP (25)
(1) eap: Calling submodule eap_peap to process data
(1) eap_peap: Continuing EAP-TLS
(1) eap_peap: Peer indicated complete TLS record size will be 198 bytes
(1) eap_peap: Got complete TLS record (198 bytes)
(1) eap_peap: [eaptls verify] = length included
(1) eap_peap: (other): before/accept initialization
(1) eap_peap: TLS_accept: before/accept initialization
(1) eap_peap: <<< TLS 1.0 Handshake [length 00c1], ClientHello
(1) eap_peap: TLS_accept: unknown state
(1) eap_peap: >>> TLS 1.0 Handshake [length 0039], ServerHello
(1) eap_peap: TLS_accept: unknown state
(1) eap_peap: >>> TLS 1.0 Handshake [length 0872], Certificate
(1) eap_peap: TLS_accept: unknown state
(1) eap_peap: >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange
(1) eap_peap: TLS_accept: unknown state
(1) eap_peap: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
(1) eap_peap: TLS_accept: unknown state
(1) eap_peap: TLS_accept: unknown state
(1) eap_peap: TLS_accept: Need to read more data: unknown state
(1) eap_peap: TLS_accept: Need to read more data: unknown state
(1) eap_peap: In SSL Handshake Phase
(1) eap_peap: In SSL Accept mode
(1) eap_peap: [eaptls process] = handled
(1) eap: Sending EAP Request (code 1) ID 3 length 1004
(1) eap: EAP session adding &reply:State = 0x3adf3a9e3bdc23ab
(1) [eap] = handled
(1) } # authenticate = handled
(1) Using Post-Auth-Type Challenge
(1) Post-Auth-Type sub-section not found. Ignoring.
(1) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(1) Sent Access-Challenge Id 176 from 147.162.57.7:1812 to
147.162.234.209:32776 length 0
(1) EAP-Message =
0x010303ec19c000000a0e1603010039020000350301b7177f6d9e3032797230a6f3413574a730725e60992ed9d439c00a787b088f4000c01400000dff01000100000b00040300010216030108720b00086e00086b0003cf308203cb308202b3a003020102020101300d06092a864886f70d010105050030
(1) Message-Authenticator = 0x00000000000000000000000000000000
(1) State = 0x3adf3a9e3bdc23abadde1d2911153d2e
(1) Finished request
Waking up in 4.9 seconds.
(2) Received Access-Request Id 177 from 147.162.234.209:32776 to
147.162.57.7:1812 length 281
(2) User-Name = "stefano.zanmarchi(a)unipd.it"
(2) Chargeable-User-Identity = 0x00
(2) Location-Capable = Civix-Location
(2) Calling-Station-Id = "64-89-9a-1f-93-d6"
(2) Called-Station-Id = "AP-GROUP-CSIA"
(2) NAS-Port = 1
(2) Cisco-AVPair = "audit-session-id=93a2ead100012e6456fa7c31"
(2) Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(2) NAS-IP-Address = 147.162.234.209
(2) NAS-Identifier = "WLC"
(2) Airespace-Wlan-Id = 6
(2) Service-Type = Framed-User
(2) Framed-MTU = 1300
(2) NAS-Port-Type = Wireless-802.11
(2) Tunnel-Type:0 = VLAN
(2) Tunnel-Medium-Type:0 = IEEE-802
(2) Tunnel-Private-Group-Id:0 = "83"
(2) EAP-Message = 0x020300061900
(2) State = 0x3adf3a9e3bdc23abadde1d2911153d2e
(2) Message-Authenticator = 0xcb6416eeff83d20ed4309fb25316a8ba
(2) session-state: No cached attributes
(2) # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam
(2) authorize {
(2) policy filter_username {
(2) if (!&User-Name) {
(2) if (!&User-Name) -> FALSE
(2) if (&User-Name =~ / /) {
(2) if (&User-Name =~ / /) -> FALSE
(2) if (&User-Name =~ /@.*@/ ) {
(2) if (&User-Name =~ /@.*@/ ) -> FALSE
(2) if (&User-Name =~ /\.\./ ) {
(2) if (&User-Name =~ /\.\./ ) -> FALSE
(2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(2) if (&User-Name =~ /\.$/) {
(2) if (&User-Name =~ /\.$/) -> FALSE
(2) if (&User-Name =~ /(a)\./) {
(2) if (&User-Name =~ /(a)\./) -> FALSE
(2) } # policy filter_username = notfound
(2) [preprocess] = ok
(2) suffix: Checking for suffix after "@"
(2) suffix: Looking up realm "unipd.it" for User-Name = "
stefano.zanmarchi(a)unipd.it"
(2) suffix: Found realm "unipd.it"
(2) suffix: Adding Realm = "unipd.it"
(2) suffix: Authentication realm is LOCAL
(2) [suffix] = ok
(2) eap: Peer sent EAP Response (code 2) ID 3 length 6
(2) eap: Continuing tunnel setup
(2) [eap] = ok
(2) } # authorize = ok
(2) Found Auth-Type = EAP
(2) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(2) authenticate {
(2) eap: Expiring EAP session with state 0x3adf3a9e3bdc23ab
(2) eap: Finished EAP session with state 0x3adf3a9e3bdc23ab
(2) eap: Previous EAP request found for state 0x3adf3a9e3bdc23ab, released
from the list
(2) eap: Peer sent packet with method EAP PEAP (25)
(2) eap: Calling submodule eap_peap to process data
(2) eap_peap: Continuing EAP-TLS
(2) eap_peap: Peer ACKed our handshake fragment
(2) eap_peap: [eaptls verify] = request
(2) eap_peap: [eaptls process] = handled
(2) eap: Sending EAP Request (code 1) ID 4 length 1000
(2) eap: EAP session adding &reply:State = 0x3adf3a9e38db23ab
(2) [eap] = handled
(2) } # authenticate = handled
(2) Using Post-Auth-Type Challenge
(2) Post-Auth-Type sub-section not found. Ignoring.
(2) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(2) Sent Access-Challenge Id 177 from 147.162.57.7:1812 to
147.162.234.209:32776 length 0
(2) EAP-Message =
0x010403e81940615303759f86db56d0ef434ad84d7a3cce7a6d343f735f2bd9e8b9a3f70dc23d640220814ec749af6bb5e9396a38d2ca58f5809013a17ee10414000496308204923082037aa003020102020900e844f7302b8c478a300d06092a864886f70d010105050030818c310b3009060355040613
(2) Message-Authenticator = 0x00000000000000000000000000000000
(2) State = 0x3adf3a9e38db23abadde1d2911153d2e
(2) Finished request
Waking up in 4.9 seconds.
(3) Received Access-Request Id 178 from 147.162.234.209:32776 to
147.162.57.7:1812 length 281
(3) User-Name = "stefano.zanmarchi(a)unipd.it"
(3) Chargeable-User-Identity = 0x00
(3) Location-Capable = Civix-Location
(3) Calling-Station-Id = "64-89-9a-1f-93-d6"
(3) Called-Station-Id = "AP-GROUP-CSIA"
(3) NAS-Port = 1
(3) Cisco-AVPair = "audit-session-id=93a2ead100012e6456fa7c31"
(3) Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(3) NAS-IP-Address = 147.162.234.209
(3) NAS-Identifier = "WLC"
(3) Airespace-Wlan-Id = 6
(3) Service-Type = Framed-User
(3) Framed-MTU = 1300
(3) NAS-Port-Type = Wireless-802.11
(3) Tunnel-Type:0 = VLAN
(3) Tunnel-Medium-Type:0 = IEEE-802
(3) Tunnel-Private-Group-Id:0 = "83"
(3) EAP-Message = 0x020400061900
(3) State = 0x3adf3a9e38db23abadde1d2911153d2e
(3) Message-Authenticator = 0xb50359a22e2e95a9ed46f832e08cf9a8
(3) session-state: No cached attributes
(3) # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam
(3) authorize {
(3) policy filter_username {
(3) if (!&User-Name) {
(3) if (!&User-Name) -> FALSE
(3) if (&User-Name =~ / /) {
(3) if (&User-Name =~ / /) -> FALSE
(3) if (&User-Name =~ /@.*@/ ) {
(3) if (&User-Name =~ /@.*@/ ) -> FALSE
(3) if (&User-Name =~ /\.\./ ) {
(3) if (&User-Name =~ /\.\./ ) -> FALSE
(3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(3) if (&User-Name =~ /\.$/) {
(3) if (&User-Name =~ /\.$/) -> FALSE
(3) if (&User-Name =~ /(a)\./) {
(3) if (&User-Name =~ /(a)\./) -> FALSE
(3) } # policy filter_username = notfound
(3) [preprocess] = ok
(3) suffix: Checking for suffix after "@"
(3) suffix: Looking up realm "unipd.it" for User-Name = "
stefano.zanmarchi(a)unipd.it"
(3) suffix: Found realm "unipd.it"
(3) suffix: Adding Realm = "unipd.it"
(3) suffix: Authentication realm is LOCAL
(3) [suffix] = ok
(3) eap: Peer sent EAP Response (code 2) ID 4 length 6
(3) eap: Continuing tunnel setup
(3) [eap] = ok
(3) } # authorize = ok
(3) Found Auth-Type = EAP
(3) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(3) authenticate {
(3) eap: Expiring EAP session with state 0x3adf3a9e38db23ab
(3) eap: Finished EAP session with state 0x3adf3a9e38db23ab
(3) eap: Previous EAP request found for state 0x3adf3a9e38db23ab, released
from the list
(3) eap: Peer sent packet with method EAP PEAP (25)
(3) eap: Calling submodule eap_peap to process data
(3) eap_peap: Continuing EAP-TLS
(3) eap_peap: Peer ACKed our handshake fragment
(3) eap_peap: [eaptls verify] = request
(3) eap_peap: [eaptls process] = handled
(3) eap: Sending EAP Request (code 1) ID 5 length 592
(3) eap: EAP session adding &reply:State = 0x3adf3a9e39da23ab
(3) [eap] = handled
(3) } # authenticate = handled
(3) Using Post-Auth-Type Challenge
(3) Post-Auth-Type sub-section not found. Ignoring.
(3) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(3) Sent Access-Challenge Id 178 from 147.162.57.7:1812 to
147.162.234.209:32776 length 0
(3) EAP-Message =
0x010502501900a7a684baf97aecd2eef8b0b44514c7b507c8c995b89e7c83bb3292aeb1f67239bbc928d8e50658a7a80c78c2945dc51c0ba44f51309774b01f659149de4dcd6430808a20c7523d614c1d02cb6f6ba3dc82bd6ea4a9f63a732b9b14735f36ebb571b865d1c72a2f432f105721c3a46fe07b
(3) Message-Authenticator = 0x00000000000000000000000000000000
(3) State = 0x3adf3a9e39da23abadde1d2911153d2e
(3) Finished request
Waking up in 4.9 seconds.
(4) Received Access-Request Id 179 from 147.162.234.209:32776 to
147.162.57.7:1812 length 419
(4) User-Name = "stefano.zanmarchi(a)unipd.it"
(4) Chargeable-User-Identity = 0x00
(4) Location-Capable = Civix-Location
(4) Calling-Station-Id = "64-89-9a-1f-93-d6"
(4) Called-Station-Id = "AP-GROUP-CSIA"
(4) NAS-Port = 1
(4) Cisco-AVPair = "audit-session-id=93a2ead100012e6456fa7c31"
(4) Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(4) NAS-IP-Address = 147.162.234.209
(4) NAS-Identifier = "WLC"
(4) Airespace-Wlan-Id = 6
(4) Service-Type = Framed-User
(4) Framed-MTU = 1300
(4) NAS-Port-Type = Wireless-802.11
(4) Tunnel-Type:0 = VLAN
(4) Tunnel-Medium-Type:0 = IEEE-802
(4) Tunnel-Private-Group-Id:0 = "83"
(4) EAP-Message =
0x0205009019800000008616030100461000004241043cb671ee52940994f9ae05ab5f95057965c697c47d43e1c34c9db46bb5182aded07390f3724cb801ec35e1408259434863a3de860d5a7c421271b4f179bd07701403010001011603010030b7a729bde9c569be42d4661a37622f9750281f9c3b911e
(4) State = 0x3adf3a9e39da23abadde1d2911153d2e
(4) Message-Authenticator = 0x676371211b581d2118426440bdb98377
(4) session-state: No cached attributes
(4) # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam
(4) authorize {
(4) policy filter_username {
(4) if (!&User-Name) {
(4) if (!&User-Name) -> FALSE
(4) if (&User-Name =~ / /) {
(4) if (&User-Name =~ / /) -> FALSE
(4) if (&User-Name =~ /@.*@/ ) {
(4) if (&User-Name =~ /@.*@/ ) -> FALSE
(4) if (&User-Name =~ /\.\./ ) {
(4) if (&User-Name =~ /\.\./ ) -> FALSE
(4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(4) if (&User-Name =~ /\.$/) {
(4) if (&User-Name =~ /\.$/) -> FALSE
(4) if (&User-Name =~ /(a)\./) {
(4) if (&User-Name =~ /(a)\./) -> FALSE
(4) } # policy filter_username = notfound
(4) [preprocess] = ok
(4) suffix: Checking for suffix after "@"
(4) suffix: Looking up realm "unipd.it" for User-Name = "
stefano.zanmarchi(a)unipd.it"
(4) suffix: Found realm "unipd.it"
(4) suffix: Adding Realm = "unipd.it"
(4) suffix: Authentication realm is LOCAL
(4) [suffix] = ok
(4) eap: Peer sent EAP Response (code 2) ID 5 length 144
(4) eap: Continuing tunnel setup
(4) [eap] = ok
(4) } # authorize = ok
(4) Found Auth-Type = EAP
(4) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(4) authenticate {
(4) eap: Expiring EAP session with state 0x3adf3a9e39da23ab
(4) eap: Finished EAP session with state 0x3adf3a9e39da23ab
(4) eap: Previous EAP request found for state 0x3adf3a9e39da23ab, released
from the list
(4) eap: Peer sent packet with method EAP PEAP (25)
(4) eap: Calling submodule eap_peap to process data
(4) eap_peap: Continuing EAP-TLS
(4) eap_peap: Peer indicated complete TLS record size will be 134 bytes
(4) eap_peap: Got complete TLS record (134 bytes)
(4) eap_peap: [eaptls verify] = length included
(4) eap_peap: <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange
(4) eap_peap: TLS_accept: unknown state
(4) eap_peap: <<< TLS 1.0 ChangeCipherSpec [length 0001]
(4) eap_peap: <<< TLS 1.0 Handshake [length 0010], Finished
(4) eap_peap: TLS_accept: unknown state
(4) eap_peap: >>> TLS 1.0 ChangeCipherSpec [length 0001]
(4) eap_peap: TLS_accept: unknown state
(4) eap_peap: >>> TLS 1.0 Handshake [length 0010], Finished
(4) eap_peap: TLS_accept: unknown state
(4) eap_peap: TLS_accept: unknown state
(4) eap_peap: (other): SSL negotiation finished successfully
(4) eap_peap: SSL Connection Established
(4) eap_peap: [eaptls process] = handled
(4) eap: Sending EAP Request (code 1) ID 6 length 65
(4) eap: EAP session adding &reply:State = 0x3adf3a9e3ed923ab
(4) [eap] = handled
(4) } # authenticate = handled
(4) Using Post-Auth-Type Challenge
(4) Post-Auth-Type sub-section not found. Ignoring.
(4) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(4) Sent Access-Challenge Id 179 from 147.162.57.7:1812 to
147.162.234.209:32776 length 0
(4) EAP-Message =
0x0106004119001403010001011603010030f9ed23944a88a71125eaa9f3b8f579c9e15adf58c096171f3f63c08c7a2b846273684b3d6a012fba87f33e21250ae4c5
(4) Message-Authenticator = 0x00000000000000000000000000000000
(4) State = 0x3adf3a9e3ed923abadde1d2911153d2e
(4) Finished request
Waking up in 4.9 seconds.
(5) Received Access-Request Id 180 from 147.162.234.209:32776 to
147.162.57.7:1812 length 281
(5) User-Name = "stefano.zanmarchi(a)unipd.it"
(5) Chargeable-User-Identity = 0x00
(5) Location-Capable = Civix-Location
(5) Calling-Station-Id = "64-89-9a-1f-93-d6"
(5) Called-Station-Id = "AP-GROUP-CSIA"
(5) NAS-Port = 1
(5) Cisco-AVPair = "audit-session-id=93a2ead100012e6456fa7c31"
(5) Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(5) NAS-IP-Address = 147.162.234.209
(5) NAS-Identifier = "WLC"
(5) Airespace-Wlan-Id = 6
(5) Service-Type = Framed-User
(5) Framed-MTU = 1300
(5) NAS-Port-Type = Wireless-802.11
(5) Tunnel-Type:0 = VLAN
(5) Tunnel-Medium-Type:0 = IEEE-802
(5) Tunnel-Private-Group-Id:0 = "83"
(5) EAP-Message = 0x020600061900
(5) State = 0x3adf3a9e3ed923abadde1d2911153d2e
(5) Message-Authenticator = 0x4ef8dfdfb188820743371d8a471ebf95
(5) session-state: No cached attributes
(5) # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam
(5) authorize {
(5) policy filter_username {
(5) if (!&User-Name) {
(5) if (!&User-Name) -> FALSE
(5) if (&User-Name =~ / /) {
(5) if (&User-Name =~ / /) -> FALSE
(5) if (&User-Name =~ /@.*@/ ) {
(5) if (&User-Name =~ /@.*@/ ) -> FALSE
(5) if (&User-Name =~ /\.\./ ) {
(5) if (&User-Name =~ /\.\./ ) -> FALSE
(5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(5) if (&User-Name =~ /\.$/) {
(5) if (&User-Name =~ /\.$/) -> FALSE
(5) if (&User-Name =~ /(a)\./) {
(5) if (&User-Name =~ /(a)\./) -> FALSE
(5) } # policy filter_username = notfound
(5) [preprocess] = ok
(5) suffix: Checking for suffix after "@"
(5) suffix: Looking up realm "unipd.it" for User-Name = "
stefano.zanmarchi(a)unipd.it"
(5) suffix: Found realm "unipd.it"
(5) suffix: Adding Realm = "unipd.it"
(5) suffix: Authentication realm is LOCAL
(5) [suffix] = ok
(5) eap: Peer sent EAP Response (code 2) ID 6 length 6
(5) eap: Continuing tunnel setup
(5) [eap] = ok
(5) } # authorize = ok
(5) Found Auth-Type = EAP
(5) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(5) authenticate {
(5) eap: Expiring EAP session with state 0x3adf3a9e3ed923ab
(5) eap: Finished EAP session with state 0x3adf3a9e3ed923ab
(5) eap: Previous EAP request found for state 0x3adf3a9e3ed923ab, released
from the list
(5) eap: Peer sent packet with method EAP PEAP (25)
(5) eap: Calling submodule eap_peap to process data
(5) eap_peap: Continuing EAP-TLS
(5) eap_peap: Peer ACKed our handshake fragment. handshake is finished
(5) eap_peap: [eaptls verify] = success
(5) eap_peap: [eaptls process] = success
(5) eap_peap: Session established. Decoding tunneled attributes
(5) eap_peap: PEAP state TUNNEL ESTABLISHED
(5) eap: Sending EAP Request (code 1) ID 7 length 43
(5) eap: EAP session adding &reply:State = 0x3adf3a9e3fd823ab
(5) [eap] = handled
(5) } # authenticate = handled
(5) Using Post-Auth-Type Challenge
(5) Post-Auth-Type sub-section not found. Ignoring.
(5) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(5) Sent Access-Challenge Id 180 from 147.162.57.7:1812 to
147.162.234.209:32776 length 0
(5) EAP-Message =
0x0107002b19001703010020f3c9c2b8099d88fb8a5a17e92339b071361f4512552aa935b8f2c1d2a5e999e4
(5) Message-Authenticator = 0x00000000000000000000000000000000
(5) State = 0x3adf3a9e3fd823abadde1d2911153d2e
(5) Finished request
Waking up in 4.8 seconds.
(6) Received Access-Request Id 181 from 147.162.234.209:32776 to
147.162.57.7:1812 length 334
(6) User-Name = "stefano.zanmarchi(a)unipd.it"
(6) Chargeable-User-Identity = 0x00
(6) Location-Capable = Civix-Location
(6) Calling-Station-Id = "64-89-9a-1f-93-d6"
(6) Called-Station-Id = "AP-GROUP-CSIA"
(6) NAS-Port = 1
(6) Cisco-AVPair = "audit-session-id=93a2ead100012e6456fa7c31"
(6) Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(6) NAS-IP-Address = 147.162.234.209
(6) NAS-Identifier = "WLC"
(6) Airespace-Wlan-Id = 6
(6) Service-Type = Framed-User
(6) Framed-MTU = 1300
(6) NAS-Port-Type = Wireless-802.11
(6) Tunnel-Type:0 = VLAN
(6) Tunnel-Medium-Type:0 = IEEE-802
(6) Tunnel-Private-Group-Id:0 = "83"
(6) EAP-Message =
0x0207003b19001703010030b781fe68e1dc489c935b9b06c89fbc7155e55c6ba11b13ef4513cc5fc511461936c348ab414f8ad33403ea7f4726b46e
(6) State = 0x3adf3a9e3fd823abadde1d2911153d2e
(6) Message-Authenticator = 0x8d3ff642d9fd28b6988d9f0d24a13e0c
(6) session-state: No cached attributes
(6) # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam
(6) authorize {
(6) policy filter_username {
(6) if (!&User-Name) {
(6) if (!&User-Name) -> FALSE
(6) if (&User-Name =~ / /) {
(6) if (&User-Name =~ / /) -> FALSE
(6) if (&User-Name =~ /@.*@/ ) {
(6) if (&User-Name =~ /@.*@/ ) -> FALSE
(6) if (&User-Name =~ /\.\./ ) {
(6) if (&User-Name =~ /\.\./ ) -> FALSE
(6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(6) if (&User-Name =~ /\.$/) {
(6) if (&User-Name =~ /\.$/) -> FALSE
(6) if (&User-Name =~ /(a)\./) {
(6) if (&User-Name =~ /(a)\./) -> FALSE
(6) } # policy filter_username = notfound
(6) [preprocess] = ok
(6) suffix: Checking for suffix after "@"
(6) suffix: Looking up realm "unipd.it" for User-Name = "
stefano.zanmarchi(a)unipd.it"
(6) suffix: Found realm "unipd.it"
(6) suffix: Adding Realm = "unipd.it"
(6) suffix: Authentication realm is LOCAL
(6) [suffix] = ok
(6) eap: Peer sent EAP Response (code 2) ID 7 length 59
(6) eap: Continuing tunnel setup
(6) [eap] = ok
(6) } # authorize = ok
(6) Found Auth-Type = EAP
(6) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(6) authenticate {
(6) eap: Expiring EAP session with state 0x3adf3a9e3fd823ab
(6) eap: Finished EAP session with state 0x3adf3a9e3fd823ab
(6) eap: Previous EAP request found for state 0x3adf3a9e3fd823ab, released
from the list
(6) eap: Peer sent packet with method EAP PEAP (25)
(6) eap: Calling submodule eap_peap to process data
(6) eap_peap: Continuing EAP-TLS
(6) eap_peap: [eaptls verify] = ok
(6) eap_peap: Done initial handshake
(6) eap_peap: [eaptls process] = ok
(6) eap_peap: Session established. Decoding tunneled attributes
(6) eap_peap: PEAP state WAITING FOR INNER IDENTITY
(6) eap_peap: Identity - stefano.zanmarchi(a)unipd.it
(6) eap_peap: Got inner identity 'stefano.zanmarchi(a)unipd.it'
(6) eap_peap: Setting default EAP type for tunneled EAP session
(6) eap_peap: Got tunneled request
(6) eap_peap: EAP-Message =
0x0207001f0173746566616e6f2e7a616e6d617263686940756e6970642e6974
(6) eap_peap: Setting User-Name to stefano.zanmarchi(a)unipd.it
(6) eap_peap: Sending tunneled request to eduroam-inner-tunnel
(6) eap_peap: EAP-Message =
0x0207001f0173746566616e6f2e7a616e6d617263686940756e6970642e6974
(6) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1
(6) eap_peap: User-Name = "stefano.zanmarchi(a)unipd.it"
(6) eap_peap: Chargeable-User-Identity = 0x00
(6) eap_peap: Location-Capable = Civix-Location
(6) eap_peap: Calling-Station-Id = "64-89-9a-1f-93-d6"
(6) eap_peap: Called-Station-Id = "AP-GROUP-CSIA"
(6) eap_peap: NAS-Port = 1
(6) eap_peap: Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(6) eap_peap: NAS-IP-Address = 147.162.234.209
(6) eap_peap: NAS-Identifier = "WLC"
(6) eap_peap: Service-Type = Framed-User
(6) eap_peap: Framed-MTU = 1300
(6) eap_peap: NAS-Port-Type = Wireless-802.11
(6) eap_peap: Tunnel-Type:0 = VLAN
(6) eap_peap: Tunnel-Medium-Type:0 = IEEE-802
(6) eap_peap: Tunnel-Private-Group-Id:0 = "83"
(6) eap_peap: Event-Timestamp = "Mar 29 2016 14:59:28 CEST"
(6) Virtual server eduroam-inner-tunnel received request
(6) EAP-Message =
0x0207001f0173746566616e6f2e7a616e6d617263686940756e6970642e6974
(6) FreeRADIUS-Proxied-To = 127.0.0.1
(6) User-Name = "stefano.zanmarchi(a)unipd.it"
(6) Chargeable-User-Identity = 0x00
(6) Location-Capable = Civix-Location
(6) Calling-Station-Id = "64-89-9a-1f-93-d6"
(6) Called-Station-Id = "AP-GROUP-CSIA"
(6) NAS-Port = 1
(6) Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(6) NAS-IP-Address = 147.162.234.209
(6) NAS-Identifier = "WLC"
(6) Service-Type = Framed-User
(6) Framed-MTU = 1300
(6) NAS-Port-Type = Wireless-802.11
(6) Tunnel-Type:0 = VLAN
(6) Tunnel-Medium-Type:0 = IEEE-802
(6) Tunnel-Private-Group-Id:0 = "83"
(6) Event-Timestamp = "Mar 29 2016 14:59:28 CEST"
(6) server eduroam-inner-tunnel {
(6) # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam-inner-tunnel
(6) authorize {
(6) SZ_test: EXPAND TEST: %{User-Name} da client %{client:shortname} cli
%{Calling-Station-Id} con Framed IP address %{Framed-IP-Address} e
NAS-IP-Address %{NAS-IP-Address} e NAS-Identifier %{NAS-Identifier}
(6) SZ_test: --> TEST: stefano.zanmarchi(a)unipd.it da client
eduroam.cca.unipd.it cli 64-89-9a-1f-93-d6 con Framed IP address e
NAS-IP-Address 147.162.234.209 e NAS-Identifier WLC
(6) [SZ_test] = ok
(6) [preprocess] = ok
(6) policy rewrite_calling_station_id {
(6) 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))
{
(6) 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
(6) 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))
{
(6) update request {
(6) EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(6) --> 64-89-9A-1F-93-D6
(6) &Calling-Station-Id := 64-89-9A-1F-93-D6
(6) } # update request = noop
(6) [updated] = updated
(6) } # 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
(6) ... skipping else for request 6: Preceding "if" was taken
(6) } # policy rewrite_calling_station_id = updated
(6) if ("%{client:shortname}" =~ /radius_garr_(.*)/i) {
(6) EXPAND %{client:shortname}
(6) --> eduroam.cca.unipd.it
(6) if ("%{client:shortname}" =~ /radius_garr_(.*)/i) -> FALSE
(6) elsif ("%{sql:SELECT count(*) FROM eduroam_mac_registrati m,
eduroam_diritto_uso d WHERE m.username = d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),3,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),5,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),7,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),9,2)
|| '-'
||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '%{User-Name}'}"
>= 1) {
(6) EXPAND %{User-Name}
(6) --> stefano.zanmarchi(a)unipd.it
(6) SQL-User-Name set to 'stefano.zanmarchi(a)unipd.it'
rlm_sql (sql): Reserved connection (0)
(6) Executing select query: SELECT count(*) FROM
eduroam_mac_registrati m, eduroam_diritto_uso d WHERE m.username =
d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),3,2) ||
'-' ||SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),5,2) || '-'
||SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),7,2) || '-'
||SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),9,2) || '-'
||SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '
stefano.zanmarchi(a)unipd.it'
rlm_sql (sql): Released connection (0)
rlm_sql (sql): Need 5 more connections to reach 10 spares
rlm_sql (sql): Opening additional connection (5), 1 of 27 pending slots used
(6) EXPAND %{sql:SELECT count(*) FROM eduroam_mac_registrati m,
eduroam_diritto_uso d WHERE m.username = d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),3,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),5,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),7,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),9,2)
|| '-'
||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '%{User-Name}'}
(6) --> 1
(6) elsif ("%{sql:SELECT count(*) FROM eduroam_mac_registrati m,
eduroam_diritto_uso d WHERE m.username = d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),3,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),5,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),7,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),9,2)
|| '-'
||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '%{User-Name}'}"
>= 1) -> TRUE
(6) elsif ("%{sql:SELECT count(*) FROM eduroam_mac_registrati m,
eduroam_diritto_uso d WHERE m.username = d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),3,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),5,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),7,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),9,2)
|| '-'
||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '%{User-Name}'}"
>= 1) {
(6) [ok] = ok
(6) } # elsif ("%{sql:SELECT count(*) FROM eduroam_mac_registrati m,
eduroam_diritto_uso d WHERE m.username = d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),3,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),5,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),7,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),9,2)
|| '-'
||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '%{User-Name}'}"
>= 1) = ok
(6) ... skipping else for request 6: Preceding "if" was taken
(6) [mschap] = noop
(6) eap: Peer sent EAP Response (code 2) ID 7 length 31
(6) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the
rest of authorize
(6) [eap] = ok
(6) } # authorize = ok
(6) Found Auth-Type = EAP
(6) # Executing group from file
/etc/freeradius/sites-enabled/eduroam-inner-tunnel
(6) authenticate {
(6) eap: Peer sent packet with method EAP Identity (1)
(6) eap: Calling submodule eap_mschapv2 to process data
(6) eap_mschapv2: Issuing Challenge
(6) eap: Sending EAP Request (code 1) ID 8 length 43
(6) eap: EAP session adding &reply:State = 0x8b88ae478b80b4f4
(6) [eap] = handled
(6) } # authenticate = handled
(6) } # server eduroam-inner-tunnel
(6) Virtual server sending reply
(6) EAP-Message =
0x0108002b1a01080026104244889bc21c473d54ace02c5eccd042667265657261646975732d332e302e3130
(6) Message-Authenticator = 0x00000000000000000000000000000000
(6) State = 0x8b88ae478b80b4f47def8c61a94495e0
(6) eap_peap: Got tunneled reply code 11
(6) eap_peap: EAP-Message =
0x0108002b1a01080026104244889bc21c473d54ace02c5eccd042667265657261646975732d332e302e3130
(6) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000
(6) eap_peap: State = 0x8b88ae478b80b4f47def8c61a94495e0
(6) eap_peap: Got tunneled reply RADIUS code 11
(6) eap_peap: EAP-Message =
0x0108002b1a01080026104244889bc21c473d54ace02c5eccd042667265657261646975732d332e302e3130
(6) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000
(6) eap_peap: State = 0x8b88ae478b80b4f47def8c61a94495e0
(6) eap_peap: Got tunneled Access-Challenge
(6) eap: Sending EAP Request (code 1) ID 8 length 75
(6) eap: EAP session adding &reply:State = 0x3adf3a9e3cd723ab
(6) [eap] = handled
(6) } # authenticate = handled
(6) Using Post-Auth-Type Challenge
(6) Post-Auth-Type sub-section not found. Ignoring.
(6) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(6) Sent Access-Challenge Id 181 from 147.162.57.7:1812 to
147.162.234.209:32776 length 0
(6) EAP-Message =
0x0108004b19001703010040dd631c1b0d9bf69f9ffa222f96176fbd96b7bcc6b35f99549a24fbf18be5308d359e9a85b105e8a37ae982ec48907653f14569e954ac7c0043cbd9f37eccae8f
(6) Message-Authenticator = 0x00000000000000000000000000000000
(6) State = 0x3adf3a9e3cd723abadde1d2911153d2e
(6) Finished request
Waking up in 4.8 seconds.
(7) Received Access-Request Id 182 from 147.162.234.209:32776 to
147.162.57.7:1812 length 398
(7) User-Name = "stefano.zanmarchi(a)unipd.it"
(7) Chargeable-User-Identity = 0x00
(7) Location-Capable = Civix-Location
(7) Calling-Station-Id = "64-89-9a-1f-93-d6"
(7) Called-Station-Id = "AP-GROUP-CSIA"
(7) NAS-Port = 1
(7) Cisco-AVPair = "audit-session-id=93a2ead100012e6456fa7c31"
(7) Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(7) NAS-IP-Address = 147.162.234.209
(7) NAS-Identifier = "WLC"
(7) Airespace-Wlan-Id = 6
(7) Service-Type = Framed-User
(7) Framed-MTU = 1300
(7) NAS-Port-Type = Wireless-802.11
(7) Tunnel-Type:0 = VLAN
(7) Tunnel-Medium-Type:0 = IEEE-802
(7) Tunnel-Private-Group-Id:0 = "83"
(7) EAP-Message =
0x0208007b190017030100705610816905db6adcfe969b807a18738075bc096ab28b380a093f4e40ce422da1693ca7095dd7e1a0915d2a90de9c93931a2a65325bac062a343567297e088bfe6d62442e0107a51e1cbbfa2f6b376956c8ec250b445f6bb672ccae875a34aff4c5ee6269e83ce423dd14fedf
(7) State = 0x3adf3a9e3cd723abadde1d2911153d2e
(7) Message-Authenticator = 0x0d1b0904bfd3b74235a0f88a643e4344
(7) session-state: No cached attributes
(7) # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam
(7) authorize {
(7) policy filter_username {
(7) if (!&User-Name) {
(7) if (!&User-Name) -> FALSE
(7) if (&User-Name =~ / /) {
(7) if (&User-Name =~ / /) -> FALSE
(7) if (&User-Name =~ /@.*@/ ) {
(7) if (&User-Name =~ /@.*@/ ) -> FALSE
(7) if (&User-Name =~ /\.\./ ) {
(7) if (&User-Name =~ /\.\./ ) -> FALSE
(7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(7) if (&User-Name =~ /\.$/) {
(7) if (&User-Name =~ /\.$/) -> FALSE
(7) if (&User-Name =~ /(a)\./) {
(7) if (&User-Name =~ /(a)\./) -> FALSE
(7) } # policy filter_username = notfound
(7) [preprocess] = ok
(7) suffix: Checking for suffix after "@"
(7) suffix: Looking up realm "unipd.it" for User-Name = "
stefano.zanmarchi(a)unipd.it"
(7) suffix: Found realm "unipd.it"
(7) suffix: Adding Realm = "unipd.it"
(7) suffix: Authentication realm is LOCAL
(7) [suffix] = ok
(7) eap: Peer sent EAP Response (code 2) ID 8 length 123
(7) eap: Continuing tunnel setup
(7) [eap] = ok
(7) } # authorize = ok
(7) Found Auth-Type = EAP
(7) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(7) authenticate {
(7) eap: Expiring EAP session with state 0x8b88ae478b80b4f4
(7) eap: Finished EAP session with state 0x3adf3a9e3cd723ab
(7) eap: Previous EAP request found for state 0x3adf3a9e3cd723ab, released
from the list
(7) eap: Peer sent packet with method EAP PEAP (25)
(7) eap: Calling submodule eap_peap to process data
(7) eap_peap: Continuing EAP-TLS
(7) eap_peap: [eaptls verify] = ok
(7) eap_peap: Done initial handshake
(7) eap_peap: [eaptls process] = ok
(7) eap_peap: Session established. Decoding tunneled attributes
(7) eap_peap: PEAP state phase2
(7) eap_peap: EAP method MSCHAPv2 (26)
(7) eap_peap: Got tunneled request
(7) eap_peap: EAP-Message =
0x020800551a0208005031c4b0987b86deb1ab0391deeed5b7e9060000000000000000ec36fb4662c854a92a2b7834c29eab13b273957b7c32cbd60073746566616e6f2e7a616e6d617263686940756e6970642e6974
(7) eap_peap: Setting User-Name to stefano.zanmarchi(a)unipd.it
(7) eap_peap: Sending tunneled request to eduroam-inner-tunnel
(7) eap_peap: EAP-Message =
0x020800551a0208005031c4b0987b86deb1ab0391deeed5b7e9060000000000000000ec36fb4662c854a92a2b7834c29eab13b273957b7c32cbd60073746566616e6f2e7a616e6d617263686940756e6970642e6974
(7) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1
(7) eap_peap: User-Name = "stefano.zanmarchi(a)unipd.it"
(7) eap_peap: State = 0x8b88ae478b80b4f47def8c61a94495e0
(7) eap_peap: Chargeable-User-Identity = 0x00
(7) eap_peap: Location-Capable = Civix-Location
(7) eap_peap: Calling-Station-Id = "64-89-9a-1f-93-d6"
(7) eap_peap: Called-Station-Id = "AP-GROUP-CSIA"
(7) eap_peap: NAS-Port = 1
(7) eap_peap: Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(7) eap_peap: NAS-IP-Address = 147.162.234.209
(7) eap_peap: NAS-Identifier = "WLC"
(7) eap_peap: Service-Type = Framed-User
(7) eap_peap: Framed-MTU = 1300
(7) eap_peap: NAS-Port-Type = Wireless-802.11
(7) eap_peap: Tunnel-Type:0 = VLAN
(7) eap_peap: Tunnel-Medium-Type:0 = IEEE-802
(7) eap_peap: Tunnel-Private-Group-Id:0 = "83"
(7) eap_peap: Event-Timestamp = "Mar 29 2016 14:59:28 CEST"
(7) Virtual server eduroam-inner-tunnel received request
(7) EAP-Message =
0x020800551a0208005031c4b0987b86deb1ab0391deeed5b7e9060000000000000000ec36fb4662c854a92a2b7834c29eab13b273957b7c32cbd60073746566616e6f2e7a616e6d617263686940756e6970642e6974
(7) FreeRADIUS-Proxied-To = 127.0.0.1
(7) User-Name = "stefano.zanmarchi(a)unipd.it"
(7) State = 0x8b88ae478b80b4f47def8c61a94495e0
(7) Chargeable-User-Identity = 0x00
(7) Location-Capable = Civix-Location
(7) Calling-Station-Id = "64-89-9a-1f-93-d6"
(7) Called-Station-Id = "AP-GROUP-CSIA"
(7) NAS-Port = 1
(7) Acct-Session-Id = "56fa7c31/64:89:9a:1f:93:d6/84429"
(7) NAS-IP-Address = 147.162.234.209
(7) NAS-Identifier = "WLC"
(7) Service-Type = Framed-User
(7) Framed-MTU = 1300
(7) NAS-Port-Type = Wireless-802.11
(7) Tunnel-Type:0 = VLAN
(7) Tunnel-Medium-Type:0 = IEEE-802
(7) Tunnel-Private-Group-Id:0 = "83"
(7) Event-Timestamp = "Mar 29 2016 14:59:28 CEST"
(7) server eduroam-inner-tunnel {
(7) session-state: No cached attributes
(7) # Executing section authorize from file
/etc/freeradius/sites-enabled/eduroam-inner-tunnel
(7) authorize {
(7) SZ_test: EXPAND TEST: %{User-Name} da client %{client:shortname} cli
%{Calling-Station-Id} con Framed IP address %{Framed-IP-Address} e
NAS-IP-Address %{NAS-IP-Address} e NAS-Identifier %{NAS-Identifier}
(7) SZ_test: --> TEST: stefano.zanmarchi(a)unipd.it da client
eduroam.cca.unipd.it cli 64-89-9a-1f-93-d6 con Framed IP address e
NAS-IP-Address 147.162.234.209 e NAS-Identifier WLC
(7) [SZ_test] = ok
(7) [preprocess] = ok
(7) policy rewrite_calling_station_id {
(7) 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))
{
(7) 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
(7) 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))
{
(7) update request {
(7) EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}}
(7) --> 64-89-9A-1F-93-D6
(7) &Calling-Station-Id := 64-89-9A-1F-93-D6
(7) } # update request = noop
(7) [updated] = updated
(7) } # 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
(7) ... skipping else for request 7: Preceding "if" was taken
(7) } # policy rewrite_calling_station_id = updated
(7) if ("%{client:shortname}" =~ /radius_garr_(.*)/i) {
(7) EXPAND %{client:shortname}
(7) --> eduroam.cca.unipd.it
(7) if ("%{client:shortname}" =~ /radius_garr_(.*)/i) -> FALSE
(7) elsif ("%{sql:SELECT count(*) FROM eduroam_mac_registrati m,
eduroam_diritto_uso d WHERE m.username = d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),3,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),5,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),7,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),9,2)
|| '-'
||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '%{User-Name}'}"
>= 1) {
(7) EXPAND %{User-Name}
(7) --> stefano.zanmarchi(a)unipd.it
(7) SQL-User-Name set to 'stefano.zanmarchi(a)unipd.it'
rlm_sql (sql): Reserved connection (1)
(7) Executing select query: SELECT count(*) FROM
eduroam_mac_registrati m, eduroam_diritto_uso d WHERE m.username =
d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),3,2) ||
'-' ||SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),5,2) || '-'
||SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),7,2) || '-'
||SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),9,2) || '-'
||SUBSTR(REGEXP_REPLACE('64-89-9A-1F-93-D6','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '
stefano.zanmarchi(a)unipd.it'
rlm_sql (sql): Released connection (1)
(7) EXPAND %{sql:SELECT count(*) FROM eduroam_mac_registrati m,
eduroam_diritto_uso d WHERE m.username = d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),3,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),5,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),7,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),9,2)
|| '-'
||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '%{User-Name}'}
(7) --> 1
(7) elsif ("%{sql:SELECT count(*) FROM eduroam_mac_registrati m,
eduroam_diritto_uso d WHERE m.username = d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),3,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),5,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),7,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),9,2)
|| '-'
||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '%{User-Name}'}"
>= 1) -> TRUE
(7) elsif ("%{sql:SELECT count(*) FROM eduroam_mac_registrati m,
eduroam_diritto_uso d WHERE m.username = d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),3,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),5,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),7,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),9,2)
|| '-'
||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '%{User-Name}'}"
>= 1) {
(7) [ok] = ok
(7) } # elsif ("%{sql:SELECT count(*) FROM eduroam_mac_registrati m,
eduroam_diritto_uso d WHERE m.username = d.username AND
m.mac=LOWER(SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),1,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),3,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),5,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),7,2)
|| '-' ||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),9,2)
|| '-'
||SUBSTR(REGEXP_REPLACE('%{Calling-Station-Id}','(-|\.|:)',''),11,2)) AND
m.data_cancell IS NULL AND d.diritto='S' AND d.username = '%{User-Name}'}"
>= 1) = ok
(7) ... skipping else for request 7: Preceding "if" was taken
(7) [mschap] = noop
(7) eap: Peer sent EAP Response (code 2) ID 8 length 85
(7) eap: No EAP Start, assuming it's an on-going EAP conversation
(7) [eap] = updated
rlm_ldap (ldap): Reserved connection (0)
(7) ldap: EXPAND (uid=%{%{Stripped-User-Name}:-%{User-Name}})
(7) ldap: --> (uid=stefano.zanmarchi(a)unipd.it)
(7) ldap: Performing search in "dc=unipd,dc=it" with filter "(uid=
stefano.zanmarchi(a)unipd.it)", scope "sub"
(7) ldap: Waiting for search result...
(7) ldap: User object found at DN "uid=stefano.zanmarchi(a)unipd.it
,ou=people,dc=unipd,dc=it"
(7) ldap: Processing user attributes
(7) ldap: control:Password-With-Header +=
'{SSHA}daAb5hYqd57iqIj0r06v1EAbt9jJ45Ab'
(7) ldap: control:NT-Password =
0x3664184078903237303639104460024333383932463938343041010385285232
rlm_ldap (ldap): Released connection (0)
rlm_ldap (ldap): Need 5 more connections to reach 10 spares
rlm_ldap (ldap): Opening additional connection (5), 1 of 27 pending slots
used
rlm_ldap (ldap): Connecting to ldap://directory.cca.unipd.it:12316
rlm_ldap (ldap): Waiting for bind result...
rlm_ldap (ldap): Bind successful
(7) [ldap] = updated
(7) [expiration] = noop
(7) [logintime] = noop
(7) pap: Converted: Password-With-Header -> SSHA1-Password
(7) pap: Removing &control:Password-With-Header
(7) pap: Normalizing NT-Password from hex encoding, 32 bytes -> 16 bytes
(7) pap: Normalizing SSHA1-Password from base64 encoding, 32 bytes -> 24
bytes
(7) pap: WARNING: Auth-Type already set. Not setting to PAP
(7) [pap] = noop
(7) } # authorize = updated
(7) Found Auth-Type = EAP
(7) # Executing group from file
/etc/freeradius/sites-enabled/eduroam-inner-tunnel
(7) authenticate {
(7) eap: Expiring EAP session with state 0x8b88ae478b80b4f4
(7) eap: Finished EAP session with state 0x8b88ae478b80b4f4
(7) eap: Previous EAP request found for state 0x8b88ae478b80b4f4, released
from the list
(7) eap: Peer sent packet with method EAP MSCHAPv2 (26)
(7) eap: Calling submodule eap_mschapv2 to process data
(7) eap_mschapv2: # Executing group from file
/etc/freeradius/sites-enabled/eduroam-inner-tunnel
(7) eap_mschapv2: Auth-Type MS-CHAP {
(7) SZ_BBB: EXPAND BBB: %{User-Name} da client %{client:shortname} cli
%{Calling-Station-Id} con Framed IP address %{Framed-IP-Address} e
NAS-IP-Address %{NAS-IP-Address} e NAS-Identifier %{NAS-Identifier}
(7) SZ_BBB: --> BBB: stefano.zanmarchi(a)unipd.it da client
eduroam.cca.unipd.it cli 64-89-9A-1F-93-D6 con Framed IP address e
NAS-IP-Address 147.162.234.209 e NAS-Identifier WLC
(7) [SZ_BBB] = ok
(7) mschap: Found NT-Password
(7) mschap: Creating challenge hash with username:
stefano.zanmarchi(a)unipd.it
(7) mschap: Client is using MS-CHAPv2
(7) mschap: ERROR: MS-CHAP2-Response is incorrect
(7) [mschap] = reject
(7) } # Auth-Type MS-CHAP = reject
(7) MSCHAP-Error: ?E=691 R=1 C=6e8acc35f6597bba35a458c113c9cb09 V=3
M=Authentication failed
(7) Found new challenge from MS-CHAP-Error: err=691 retry=1
challenge=6e8acc35f6597bba35a458c113c9cb09
(7) ERROR: MSCHAP Failure
(7) eap: Sending EAP Request (code 1) ID 9 length 81
(7) eap: EAP session adding &reply:State = 0x8b88ae478a81b4f4
(7) [eap] = handled
(7) } # authenticate = handled
(7) } # server eduroam-inner-tunnel
(7) Virtual server sending reply
(7) EAP-Message =
0x010900511a0408004c453d36393120523d3120433d366538616363333566363539376262613335613435386331313363396362303920563d33204d3d41757468656e7469636174696f6e206661696c6564
(7) Message-Authenticator = 0x00000000000000000000000000000000
(7) State = 0x8b88ae478a81b4f47def8c61a94495e0
(7) eap_peap: Got tunneled reply code 11
(7) eap_peap: EAP-Message =
0x010900511a0408004c453d36393120523d3120433d366538616363333566363539376262613335613435386331313363396362303920563d33204d3d41757468656e7469636174696f6e206661696c6564
(7) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000
(7) eap_peap: State = 0x8b88ae478a81b4f47def8c61a94495e0
(7) eap_peap: Got tunneled reply RADIUS code 11
(7) eap_peap: EAP-Message =
0x010900511a0408004c453d36393120523d3120433d366538616363333566363539376262613335613435386331313363396362303920563d33204d3d41757468656e7469636174696f6e206661696c6564
(7) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000
(7) eap_peap: State = 0x8b88ae478a81b4f47def8c61a94495e0
(7) eap_peap: Got tunneled Access-Challenge
(7) eap: Sending EAP Request (code 1) ID 9 length 123
(7) eap: EAP session adding &reply:State = 0x3adf3a9e3dd623ab
(7) [eap] = handled
(7) } # authenticate = handled
(7) Using Post-Auth-Type Challenge
(7) Post-Auth-Type sub-section not found. Ignoring.
(7) # Executing group from file /etc/freeradius/sites-enabled/eduroam
(7) Sent Access-Challenge Id 182 from 147.162.57.7:1812 to
147.162.234.209:32776 length 0
(7) EAP-Message =
0x0109007b190017030100705a4b4e13a23f3d9f94ddfedb9e691bf9b8099e093560fbbcb0bc0ea1ea2d0c63a6c7ed0292643cc99b5e1f2113026e70d751ada6850ffee66fd821d4a16c3f918b1d1763b3e958d5c7bfd01db00287630429d6b7efa719c09595b87a65fa13162ad0d664cf4f63cbdec7583a
(7) Message-Authenticator = 0x00000000000000000000000000000000
(7) State = 0x3adf3a9e3dd623abadde1d2911153d2e
(7) Finished request
Waking up in 4.8 seconds.
