issues with running freeradius3.0.8 certificate authentication

10 Jun 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

issues with running freeradius3.0.8 certificate authentication

syed latheef