issues with running freeradius3.0.8 certificate authentication
syed latheef
syedlat at gmail.com
Wed Jun 10 13:06:23 CEST 2015
Hi
We had installed the freeradius 3.0.8 in our redhat machine but
the certificate is not getting authenticated . the logs are in line
along with this mail .this machine previously was running freeradius
older version which was working fine .please help us resolve this issue .
Thanks
Latheef.S
logs attached
===========
n Jun 8 05:57:20 2015 : Debug: (151) EAP-Message =
0x019603ec19c00000093416030100510200004d030155756700e53bdacb99665df630bde73d39d1c5c6fce32ea9d05be3e568648039201e7488ca35449034fe49d15fb01baa51f3c1aa01f3a3c21555b9c302f338fbc20035000005ff0100010016030108d00b0008cc0008c90003de308203da308202c2
Mon Jun 8 05:57:20 2015 : Debug: (151) Message-Authenticator =
0x00000000000000000000000000000000
Mon Jun 8 05:57:20 2015 : Debug: (151) State =
0x209817dc210e0ee756ad6df1b14e725e
Mon Jun 8 05:57:20 2015 : Debug: (151) Finished request
Mon Jun 8 05:57:20 2015 : Debug: Waking up in 4.9 seconds.
Mon Jun 8 05:57:20 2015 : Debug: (152) Received Access-Request Id 48 from
192.168.3.201:1024 to 192.168.3.48:1812 length 225
Mon Jun 8 05:57:20 2015 : Debug: (152) Framed-MTU = 1480
Mon Jun 8 05:57:20 2015 : Debug: (152) NAS-IP-Address = 192.168.3.201
Mon Jun 8 05:57:20 2015 : Debug: (152) NAS-Identifier = 'HP ProCurve
Switch 2824'
Mon Jun 8 05:57:20 2015 : Debug: (152) User-Name = 'ctc'
Mon Jun 8 05:57:20 2015 : Debug: (152) Service-Type = Framed-User
Mon Jun 8 05:57:20 2015 : Debug: (152) Framed-Protocol = PPP
Mon Jun 8 05:57:20 2015 : Debug: (152) NAS-Port = 2
Mon Jun 8 05:57:20 2015 : Debug: (152) NAS-Port-Type = Ethernet
Mon Jun 8 05:57:20 2015 : Debug: (152) NAS-Port-Id = '2'
Mon Jun 8 05:57:20 2015 : Debug: (152) Called-Station-Id =
'00-0e-7f-c4-98-60'
Mon Jun 8 05:57:20 2015 : Debug: (152) Calling-Station-Id =
'50-65-f3-5c-e9-ed'
Mon Jun 8 05:57:20 2015 : Debug: (152) Connect-Info = 'CONNECT Ethernet
1000Mbps Full duplex'
Mon Jun 8 05:57:20 2015 : Debug: (152) Tunnel-Type:0 = VLAN
Mon Jun 8 05:57:20 2015 : Debug: (152) Tunnel-Medium-Type:0 = IEEE-802
Mon Jun 8 05:57:20 2015 : Debug: (152) Tunnel-Private-Group-Id:0 = '1'
Mon Jun 8 05:57:20 2015 : Debug: (152) State =
0x209817dc210e0ee756ad6df1b14e725e
Mon Jun 8 05:57:20 2015 : Debug: (152) EAP-Message = 0x029600061900
Mon Jun 8 05:57:20 2015 : Debug: (152) Message-Authenticator =
0x39b1ce0cd6391f6f3c41fa7b4bb58913
Mon Jun 8 05:57:20 2015 : Debug: (152) session-state: No cached attributes
Mon Jun 8 05:57:20 2015 : Debug: (152) # Executing section authorize from
file /root/etc/raddb/sites-enabled/default
Mon Jun 8 05:57:20 2015 : Debug: (152) authorize {
Mon Jun 8 05:57:20 2015 : Debug: (152) policy filter_username {
Mon Jun 8 05:57:20 2015 : Debug: (152) if (!&User-Name) {
Mon Jun 8 05:57:20 2015 : Debug: (152) if (!&User-Name) -> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (152) if (&User-Name =~ / /) {
Mon Jun 8 05:57:20 2015 : Debug: (152) if (&User-Name =~ / /) ->
FALSE
Mon Jun 8 05:57:20 2015 : Debug: (152) if (&User-Name =~ /@.*@/ ) {
Mon Jun 8 05:57:20 2015 : Debug: (152) if (&User-Name =~ /@.*@/ )
-> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (152) if (&User-Name =~ /\.\./ ) {
Mon Jun 8 05:57:20 2015 : Debug: (152) if (&User-Name =~ /\.\./ )
-> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (152) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) {
Mon Jun 8 05:57:20 2015 : Debug: (152) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (152) if (&User-Name =~ /\.$/) {
Mon Jun 8 05:57:20 2015 : Debug: (152) if (&User-Name =~ /\.$/) ->
FALSE
Mon Jun 8 05:57:20 2015 : Debug: (152) if (&User-Name =~ /@\./) {
Mon Jun 8 05:57:20 2015 : Debug: (152) if (&User-Name =~ /@\./) ->
FALSE
Mon Jun 8 05:57:20 2015 : Debug: (152) } # policy filter_username =
notfound
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) [preprocess] = ok
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: calling
chap (rlm_chap) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: returned
from chap (rlm_chap) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) [chap] = noop
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: calling
mschap (rlm_mschap) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: returned
from mschap (rlm_mschap) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) [mschap] = noop
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: calling
digest (rlm_digest) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: returned
from digest (rlm_digest) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) [digest] = noop
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: calling
suffix (rlm_realm) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) suffix: Checking for suffix after
"@"
Mon Jun 8 05:57:20 2015 : Debug: (152) suffix: No '@' in User-Name =
"ctc", looking up realm NULL
Mon Jun 8 05:57:20 2015 : Debug: (152) suffix: No such realm "NULL"
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: returned
from suffix (rlm_realm) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) [suffix] = noop
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: calling
eap (rlm_eap) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) eap: Peer sent code Response (2) ID
150 length 6
Mon Jun 8 05:57:20 2015 : Debug: (152) eap: Continuing tunnel setup
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authorize]: returned
from eap (rlm_eap) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) [eap] = ok
Mon Jun 8 05:57:20 2015 : Debug: (152) } # authorize = ok
Mon Jun 8 05:57:20 2015 : Debug: (152) Found Auth-Type = EAP
Mon Jun 8 05:57:20 2015 : Debug: (152) # Executing group from file
/root/etc/raddb/sites-enabled/default
Mon Jun 8 05:57:20 2015 : Debug: (152) authenticate {
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authenticate]:
calling eap (rlm_eap) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) eap: Expiring EAP session with
state 0x209817dc210e0ee7
Mon Jun 8 05:57:20 2015 : Debug: (152) eap: Finished EAP session with
state 0x209817dc210e0ee7
Mon Jun 8 05:57:20 2015 : Debug: (152) eap: Previous EAP request found for
state 0x209817dc210e0ee7, released from the list
Mon Jun 8 05:57:20 2015 : Debug: (152) eap: Peer sent method PEAP (25)
Mon Jun 8 05:57:20 2015 : Debug: (152) eap: EAP PEAP (25)
Mon Jun 8 05:57:20 2015 : Debug: (152) eap: Calling eap_peap to process
EAP data
Mon Jun 8 05:57:20 2015 : Debug: (152) eap_peap: processing EAP-TLS
Mon Jun 8 05:57:20 2015 : Debug: (152) eap_peap: Received TLS ACK
Mon Jun 8 05:57:20 2015 : Debug: (152) eap_peap: Received TLS ACK
Mon Jun 8 05:57:20 2015 : Debug: (152) eap_peap: ACK handshake fragment
handler
Mon Jun 8 05:57:20 2015 : Debug: (152) eap_peap: eaptls_verify returned 1
Mon Jun 8 05:57:20 2015 : Debug: (152) eap_peap: eaptls_process returned
13
Mon Jun 8 05:57:20 2015 : Debug: (152) eap_peap: FR_TLS_HANDLED
Mon Jun 8 05:57:20 2015 : Debug: (152) eap: EAP session adding
&reply:State = 0x209817dc220f0ee7
Mon Jun 8 05:57:20 2015 : Debug: (152) modsingle[authenticate]:
returned from eap (rlm_eap) for request 152
Mon Jun 8 05:57:20 2015 : Debug: (152) [eap] = handled
Mon Jun 8 05:57:20 2015 : Debug: (152) } # authenticate = handled
Mon Jun 8 05:57:20 2015 : Debug: (152) Using Post-Auth-Type Challenge
Mon Jun 8 05:57:20 2015 : Debug: (152) Post-Auth-Type sub-section not
found. Ignoring.
Mon Jun 8 05:57:20 2015 : Debug: (152) # Executing group from file
/root/etc/raddb/sites-enabled/default
Mon Jun 8 05:57:20 2015 : Debug: (152) session-state: Nothing to cache
Mon Jun 8 05:57:20 2015 : Debug: (152) Sent Access-Challenge Id 48 from
192.168.3.48:1812 to 192.168.3.201:1024 length 0
Mon Jun 8 05:57:20 2015 : Debug: (152) EAP-Message =
0x019703e81940d027670910cd24815ce68c509691a6027d4d32c742fd2152db96203c01477e40e1fb397b2d854dadef536faac0190c02f09dadbd8c92c64b0f874bc4cd223be761823ab9c83910b648daf987435b98be5aca01f12238ff7c9651390663cfd2b91b0004e5308204e1308203c9a003020102
Mon Jun 8 05:57:20 2015 : Debug: (152) Message-Authenticator =
0x00000000000000000000000000000000
Mon Jun 8 05:57:20 2015 : Debug: (152) State =
0x209817dc220f0ee756ad6df1b14e725e
Mon Jun 8 05:57:20 2015 : Debug: (152) Finished request
Mon Jun 8 05:57:20 2015 : Debug: Waking up in 4.9 seconds.
Mon Jun 8 05:57:20 2015 : Debug: (153) Received Access-Request Id 49 from
192.168.3.201:1024 to 192.168.3.48:1812 length 225
Mon Jun 8 05:57:20 2015 : Debug: (153) Framed-MTU = 1480
Mon Jun 8 05:57:20 2015 : Debug: (153) NAS-IP-Address = 192.168.3.201
Mon Jun 8 05:57:20 2015 : Debug: (153) NAS-Identifier = 'HP ProCurve
Switch 2824'
Mon Jun 8 05:57:20 2015 : Debug: (153) User-Name = 'ctc'
Mon Jun 8 05:57:20 2015 : Debug: (153) Service-Type = Framed-User
Mon Jun 8 05:57:20 2015 : Debug: (153) Framed-Protocol = PPP
Mon Jun 8 05:57:20 2015 : Debug: (153) NAS-Port = 2
Mon Jun 8 05:57:20 2015 : Debug: (153) NAS-Port-Type = Ethernet
Mon Jun 8 05:57:20 2015 : Debug: (153) NAS-Port-Id = '2'
Mon Jun 8 05:57:20 2015 : Debug: (153) Called-Station-Id =
'00-0e-7f-c4-98-60'
Mon Jun 8 05:57:20 2015 : Debug: (153) Calling-Station-Id =
'50-65-f3-5c-e9-ed'
Mon Jun 8 05:57:20 2015 : Debug: (153) Connect-Info = 'CONNECT Ethernet
1000Mbps Full duplex'
Mon Jun 8 05:57:20 2015 : Debug: (153) Tunnel-Type:0 = VLAN
Mon Jun 8 05:57:20 2015 : Debug: (153) Tunnel-Medium-Type:0 = IEEE-802
Mon Jun 8 05:57:20 2015 : Debug: (153) Tunnel-Private-Group-Id:0 = '1'
Mon Jun 8 05:57:20 2015 : Debug: (153) State =
0x209817dc220f0ee756ad6df1b14e725e
Mon Jun 8 05:57:20 2015 : Debug: (153) EAP-Message = 0x029700061900
Mon Jun 8 05:57:20 2015 : Debug: (153) Message-Authenticator =
0xdc642a3312c2b7a0bf5c5700b86cc72f
Mon Jun 8 05:57:20 2015 : Debug: (153) session-state: No cached attributes
Mon Jun 8 05:57:20 2015 : Debug: (153) # Executing section authorize from
file /root/etc/raddb/sites-enabled/default
Mon Jun 8 05:57:20 2015 : Debug: (153) authorize {
Mon Jun 8 05:57:20 2015 : Debug: (153) policy filter_username {
Mon Jun 8 05:57:20 2015 : Debug: (153) if (!&User-Name) {
Mon Jun 8 05:57:20 2015 : Debug: (153) if (!&User-Name) -> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (153) if (&User-Name =~ / /) {
Mon Jun 8 05:57:20 2015 : Debug: (153) if (&User-Name =~ / /) ->
FALSE
Mon Jun 8 05:57:20 2015 : Debug: (153) if (&User-Name =~ /@.*@/ ) {
Mon Jun 8 05:57:20 2015 : Debug: (153) if (&User-Name =~ /@.*@/ )
-> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (153) if (&User-Name =~ /\.\./ ) {
Mon Jun 8 05:57:20 2015 : Debug: (153) if (&User-Name =~ /\.\./ )
-> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (153) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) {
Mon Jun 8 05:57:20 2015 : Debug: (153) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (153) if (&User-Name =~ /\.$/) {
Mon Jun 8 05:57:20 2015 : Debug: (153) if (&User-Name =~ /\.$/) ->
FALSE
Mon Jun 8 05:57:20 2015 : Debug: (153) if (&User-Name =~ /@\./) {
Mon Jun 8 05:57:20 2015 : Debug: (153) if (&User-Name =~ /@\./) ->
FALSE
Mon Jun 8 05:57:20 2015 : Debug: (153) } # policy filter_username =
notfound
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) [preprocess] = ok
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: calling
chap (rlm_chap) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: returned
from chap (rlm_chap) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) [chap] = noop
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: calling
mschap (rlm_mschap) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: returned
from mschap (rlm_mschap) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) [mschap] = noop
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: calling
digest (rlm_digest) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: returned
from digest (rlm_digest) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) [digest] = noop
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: calling
suffix (rlm_realm) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) suffix: Checking for suffix after
"@"
Mon Jun 8 05:57:20 2015 : Debug: (153) suffix: No '@' in User-Name =
"ctc", looking up realm NULL
Mon Jun 8 05:57:20 2015 : Debug: (153) suffix: No such realm "NULL"
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: returned
from suffix (rlm_realm) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) [suffix] = noop
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: calling
eap (rlm_eap) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) eap: Peer sent code Response (2) ID
151 length 6
Mon Jun 8 05:57:20 2015 : Debug: (153) eap: Continuing tunnel setup
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authorize]: returned
from eap (rlm_eap) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) [eap] = ok
Mon Jun 8 05:57:20 2015 : Debug: (153) } # authorize = ok
Mon Jun 8 05:57:20 2015 : Debug: (153) Found Auth-Type = EAP
Mon Jun 8 05:57:20 2015 : Debug: (153) # Executing group from file
/root/etc/raddb/sites-enabled/default
Mon Jun 8 05:57:20 2015 : Debug: (153) authenticate {
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authenticate]:
calling eap (rlm_eap) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) eap: Expiring EAP session with
state 0x209817dc220f0ee7
Mon Jun 8 05:57:20 2015 : Debug: (153) eap: Finished EAP session with
state 0x209817dc220f0ee7
Mon Jun 8 05:57:20 2015 : Debug: (153) eap: Previous EAP request found for
state 0x209817dc220f0ee7, released from the list
Mon Jun 8 05:57:20 2015 : Debug: (153) eap: Peer sent method PEAP (25)
Mon Jun 8 05:57:20 2015 : Debug: (153) eap: EAP PEAP (25)
Mon Jun 8 05:57:20 2015 : Debug: (153) eap: Calling eap_peap to process
EAP data
Mon Jun 8 05:57:20 2015 : Debug: (153) eap_peap: processing EAP-TLS
Mon Jun 8 05:57:20 2015 : Debug: (153) eap_peap: Received TLS ACK
Mon Jun 8 05:57:20 2015 : Debug: (153) eap_peap: Received TLS ACK
Mon Jun 8 05:57:20 2015 : Debug: (153) eap_peap: ACK handshake fragment
handler
Mon Jun 8 05:57:20 2015 : Debug: (153) eap_peap: eaptls_verify returned 1
Mon Jun 8 05:57:20 2015 : Debug: (153) eap_peap: eaptls_process returned
13
Mon Jun 8 05:57:20 2015 : Debug: (153) eap_peap: FR_TLS_HANDLED
Mon Jun 8 05:57:20 2015 : Debug: (153) eap: EAP session adding
&reply:State = 0x209817dc23000ee7
Mon Jun 8 05:57:20 2015 : Debug: (153) modsingle[authenticate]:
returned from eap (rlm_eap) for request 153
Mon Jun 8 05:57:20 2015 : Debug: (153) [eap] = handled
Mon Jun 8 05:57:20 2015 : Debug: (153) } # authenticate = handled
Mon Jun 8 05:57:20 2015 : Debug: (153) Using Post-Auth-Type Challenge
Mon Jun 8 05:57:20 2015 : Debug: (153) Post-Auth-Type sub-section not
found. Ignoring.
Mon Jun 8 05:57:20 2015 : Debug: (153) # Executing group from file
/root/etc/raddb/sites-enabled/default
Mon Jun 8 05:57:20 2015 : Debug: (153) session-state: Nothing to cache
Mon Jun 8 05:57:20 2015 : Debug: (153) Sent Access-Challenge Id 49 from
192.168.3.48:1812 to 192.168.3.201:1024 length 0
Mon Jun 8 05:57:20 2015 : Debug: (153) EAP-Message =
0x0198017619007479820900c7ba6febe19fb88e300c0603551d13040530030101ff30360603551d1f042f302d302ba029a0278625687474703a2f2f7777772e6578616d706c652e636f6d2f6578616d706c655f63612e63726c300d06092a864886f70d010105050003820101004aeb0a79893906ef633d
Mon Jun 8 05:57:20 2015 : Debug: (153) Message-Authenticator =
0x00000000000000000000000000000000
Mon Jun 8 05:57:20 2015 : Debug: (153) State =
0x209817dc23000ee756ad6df1b14e725e
Mon Jun 8 05:57:20 2015 : Debug: (153) Finished request
Mon Jun 8 05:57:20 2015 : Debug: Waking up in 4.9 seconds.
Mon Jun 8 05:57:20 2015 : Debug: (154) Received Access-Request Id 50 from
192.168.3.201:1024 to 192.168.3.48:1812 length 225
Mon Jun 8 05:57:20 2015 : Debug: (154) Framed-MTU = 1480
Mon Jun 8 05:57:20 2015 : Debug: (154) NAS-IP-Address = 192.168.3.201
Mon Jun 8 05:57:20 2015 : Debug: (154) NAS-Identifier = 'HP ProCurve
Switch 2824'
Mon Jun 8 05:57:20 2015 : Debug: (154) User-Name = 'ctc'
Mon Jun 8 05:57:20 2015 : Debug: (154) Service-Type = Framed-User
Mon Jun 8 05:57:20 2015 : Debug: (154) Framed-Protocol = PPP
Mon Jun 8 05:57:20 2015 : Debug: (154) NAS-Port = 2
Mon Jun 8 05:57:20 2015 : Debug: (154) NAS-Port-Type = Ethernet
Mon Jun 8 05:57:20 2015 : Debug: (154) NAS-Port-Id = '2'
Mon Jun 8 05:57:20 2015 : Debug: (154) Called-Station-Id =
'00-0e-7f-c4-98-60'
Mon Jun 8 05:57:20 2015 : Debug: (154) Calling-Station-Id =
'50-65-f3-5c-e9-ed'
Mon Jun 8 05:57:20 2015 : Debug: (154) Connect-Info = 'CONNECT Ethernet
1000Mbps Full duplex'
Mon Jun 8 05:57:20 2015 : Debug: (154) Tunnel-Type:0 = VLAN
Mon Jun 8 05:57:20 2015 : Debug: (154) Tunnel-Medium-Type:0 = IEEE-802
Mon Jun 8 05:57:20 2015 : Debug: (154) Tunnel-Private-Group-Id:0 = '1'
Mon Jun 8 05:57:20 2015 : Debug: (154) State =
0x209817dc23000ee756ad6df1b14e725e
Mon Jun 8 05:57:20 2015 : Debug: (154) EAP-Message = 0x029800060319
Mon Jun 8 05:57:20 2015 : Debug: (154) Message-Authenticator =
0xb4daff305fd89d80c104cb751486a1d1
Mon Jun 8 05:57:20 2015 : Debug: (154) session-state: No cached attributes
Mon Jun 8 05:57:20 2015 : Debug: (154) # Executing section authorize from
file /root/etc/raddb/sites-enabled/default
Mon Jun 8 05:57:20 2015 : Debug: (154) authorize {
Mon Jun 8 05:57:20 2015 : Debug: (154) policy filter_username {
Mon Jun 8 05:57:20 2015 : Debug: (154) if (!&User-Name) {
Mon Jun 8 05:57:20 2015 : Debug: (154) if (!&User-Name) -> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&User-Name =~ / /) {
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&User-Name =~ / /) ->
FALSE
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&User-Name =~ /@.*@/ ) {
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&User-Name =~ /@.*@/ )
-> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&User-Name =~ /\.\./ ) {
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&User-Name =~ /\.\./ )
-> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (154) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) {
Mon Jun 8 05:57:20 2015 : Debug: (154) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&User-Name =~ /\.$/) {
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&User-Name =~ /\.$/) ->
FALSE
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&User-Name =~ /@\./) {
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&User-Name =~ /@\./) ->
FALSE
Mon Jun 8 05:57:20 2015 : Debug: (154) } # policy filter_username =
notfound
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [preprocess] = ok
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: calling
chap (rlm_chap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: returned
from chap (rlm_chap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [chap] = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: calling
mschap (rlm_mschap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: returned
from mschap (rlm_mschap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [mschap] = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: calling
digest (rlm_digest) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: returned
from digest (rlm_digest) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [digest] = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: calling
suffix (rlm_realm) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) suffix: Checking for suffix after
"@"
Mon Jun 8 05:57:20 2015 : Debug: (154) suffix: No '@' in User-Name =
"ctc", looking up realm NULL
Mon Jun 8 05:57:20 2015 : Debug: (154) suffix: No such realm "NULL"
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: returned
from suffix (rlm_realm) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [suffix] = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: calling
eap (rlm_eap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) eap: Peer sent code Response (2) ID
152 length 6
Mon Jun 8 05:57:20 2015 : Debug: (154) eap: No EAP Start, assuming it's an
on-going EAP conversation
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: returned
from eap (rlm_eap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [eap] = updated
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: calling
files (rlm_files) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) files: users: Matched entry DEFAULT
at line 182
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: returned
from files (rlm_files) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [files] = ok
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: calling
expiration (rlm_expiration) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: returned
from expiration (rlm_expiration) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [expiration] = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: calling
logintime (rlm_logintime) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: returned
from logintime (rlm_logintime) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [logintime] = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: calling
pap (rlm_pap) for request 154
Mon Jun 8 05:57:20 2015 : WARNING: (154) pap: No "known good" password
found for the user. Not setting Auth-Type
Mon Jun 8 05:57:20 2015 : WARNING: (154) pap: Authentication will fail
unless a "known good" password is available
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authorize]: returned
from pap (rlm_pap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [pap] = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) } # authorize = updated
Mon Jun 8 05:57:20 2015 : Debug: (154) Found Auth-Type = EAP
Mon Jun 8 05:57:20 2015 : Debug: (154) # Executing group from file
/root/etc/raddb/sites-enabled/default
Mon Jun 8 05:57:20 2015 : Debug: (154) authenticate {
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authenticate]:
calling eap (rlm_eap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) eap: Expiring EAP session with
state 0x209817dc23000ee7
Mon Jun 8 05:57:20 2015 : Debug: (154) eap: Finished EAP session with
state 0x209817dc23000ee7
Mon Jun 8 05:57:20 2015 : Debug: (154) eap: Previous EAP request found for
state 0x209817dc23000ee7, released from the list
Mon Jun 8 05:57:20 2015 : Debug: (154) eap: Peer sent method NAK (3)
Mon Jun 8 05:57:20 2015 : Debug: (154) eap: Peer NAK'd our request for
PEAP (25) with a request for PEAP (25), skipping...
Mon Jun 8 05:57:20 2015 : ERROR: (154) eap: No mutually acceptable types
found
Mon Jun 8 05:57:20 2015 : Debug: (154) eap: Failed in EAP select
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[authenticate]:
returned from eap (rlm_eap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [eap] = invalid
Mon Jun 8 05:57:20 2015 : Debug: (154) } # authenticate = invalid
Mon Jun 8 05:57:20 2015 : Debug: (154) Failed to authenticate the user
Mon Jun 8 05:57:20 2015 : Debug: (154) Using Post-Auth-Type Reject
Mon Jun 8 05:57:20 2015 : Debug: (154) # Executing group from file
/root/etc/raddb/sites-enabled/default
Mon Jun 8 05:57:20 2015 : Debug: (154) Post-Auth-Type REJECT {
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[post-auth]: calling
attr_filter.access_reject (rlm_attr_filter) for request 154
Mon Jun 8 05:57:20 2015 : Debug: %{User-Name}
Mon Jun 8 05:57:20 2015 : Debug: Parsed xlat tree:
Mon Jun 8 05:57:20 2015 : Debug: attribute --> User-Name
Mon Jun 8 05:57:20 2015 : Debug: (154) attr_filter.access_reject: EXPAND
%{User-Name}
Mon Jun 8 05:57:20 2015 : Debug: (154) attr_filter.access_reject: -->
ctc
Mon Jun 8 05:57:20 2015 : Debug: (154) attr_filter.access_reject: Matched
entry DEFAULT at line 18
Mon Jun 8 05:57:20 2015 : Debug: (154) attr_filter.access_reject:
Attribute "Framed-Protocol" allowed by 0 rules, disallowed by 0 rules
Mon Jun 8 05:57:20 2015 : Debug: (154) attr_filter.access_reject:
Attribute "Framed-Compression" allowed by 0 rules, disallowed by 0 rules
Mon Jun 8 05:57:20 2015 : Debug: (154) attr_filter.access_reject:
EAP-Message = 0x04980004 allowed by EAP-Message =* 0x
Mon Jun 8 05:57:20 2015 : Debug: (154) attr_filter.access_reject:
Attribute "EAP-Message" allowed by 1 rules, disallowed by 0 rules
Mon Jun 8 05:57:20 2015 : Debug: (154) attr_filter.access_reject:
Message-Authenticator = 0x00000000000000000000000000000000 allowed by
Message-Authenticator =* 0x
Mon Jun 8 05:57:20 2015 : Debug: (154) attr_filter.access_reject:
Attribute "Message-Authenticator" allowed by 1 rules, disallowed by 0 rules
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[post-auth]: returned
from attr_filter.access_reject (rlm_attr_filter) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [attr_filter.access_reject] =
updated
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[post-auth]: calling
eap (rlm_eap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[post-auth]: returned
from eap (rlm_eap) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [eap] = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) policy
remove_reply_message_if_eap {
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&reply:EAP-Message &&
&reply:Reply-Message) {
Mon Jun 8 05:57:20 2015 : Debug: (154) if (&reply:EAP-Message &&
&reply:Reply-Message) -> FALSE
Mon Jun 8 05:57:20 2015 : Debug: (154) else {
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[post-auth]:
calling noop (rlm_always) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) modsingle[post-auth]:
returned from noop (rlm_always) for request 154
Mon Jun 8 05:57:20 2015 : Debug: (154) [noop] = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) } # else = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) } # policy
remove_reply_message_if_eap = noop
Mon Jun 8 05:57:20 2015 : Debug: (154) } # Post-Auth-Type REJECT =
updated
Mon Jun 8 05:57:20 2015 : Debug: (154) Delaying response for 1.000000
seconds
Mon Jun 8 05:57:20 2015 : Debug: Waking up in 0.3 seconds.
Mon Jun 8 05:57:20 2015 : Debug: Waking up in 0.6 seconds.
Mon Jun 8 05:57:21 2015 : Debug: (154) <delay>: Sending delayed response
Mon Jun 8 05:57:21 2015 : Debug: (154) <delay>: Sent Access-Reject Id 50
from 192.168.3.48:1812 to 192.168.3.201:1024 length 44
Mon Jun 8 05:57:21 2015 : Debug: (154) <delay>: EAP-Message = 0x04980004
Mon Jun 8 05:57:21 2015 : Debug: (154) <delay>: Message-Authenticator =
0x00000000000000000000000000000000
Mon Jun 8 05:57:21 2015 : Debug: Waking up in 3.9 seconds.
Mon Jun 8 05:57:25 2015 : Debug: (151) <done>: Cleaning up request packet
ID 47 with timestamp +1844
Mon Jun 8 05:57:25 2015 : Debug: (152) <done>: Cleaning up request packet
ID 48 with timestamp +1844
Mon Jun 8 05:57:25 2015 : Debug: (153) <done>: Cleaning up request packet
ID 49 with timestamp +1844
Mon Jun 8 05:57:25 2015 : Debug: (154) <delay>: Cleaning up request packet
ID 50 with timestamp +1844
Mon Jun 8 05:57:25 2015 : Debug: Waking up in 4.7 seconds.
Mon Jun 8 05:57:29 2015 : Debug: (150) <done>: Cleaning up request packet
ID 46 with timestamp +1838
Mon Jun 8 05:57:29 2015 : Info: Ready to process requests
More information about the Freeradius-Users
mailing list