authing clients - Debug Mode !!!!
emerson
emerson at mslink.com.br
Fri May 26 22:45:24 CEST 2006
Pessoal,
i have a server linux running slackware 10.1, with freeradius 1.1.1 with auth
eap/tls/ttls + openssl-0.97d
+ mysql.
My freeradius client is a ap wl-5460AP. When i try to authenticate any user on my freeradius, in debug MODE appear this messages:
I'm can not to stabilished connections.....
Message-Authenticator = 0x59373d130f801019b116e042690ff3e1
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 2
modcall[authorize]: module "preprocess" returns ok for request 2
rlm_eap: EAP packet type response id 2 length 106
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 2
radius_xlat: 'mobile'
rlm_sql (sql): sql_set_user escaped user --> 'mobile'
radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'mobile' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 2
radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'mobile' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'mobile' ORDER BY id'
radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'mobile' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql): Released sql socket id: 2
modcall[authorize]: module "sql" returns ok for request 2
modcall: leaving group authorize (returns updated) for request 2
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 2
rlm_eap: Request found, released from the list
rlm_eap: EAP/tls
rlm_eap: processing type tls
rlm_eap_tls: Authenticate
rlm_eap_tls: processing TLS
rlm_eap_tls: Length Included
eaptls_verify returned 11
(other): before/accept initialization
TLS_accept: before/accept initialization
rlm_eap_tls: <<< TLS 1.0 Handshake [length 005b], ClientHello
TLS_accept: SSLv3 read client hello A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello
TLS_accept: SSLv3 write server hello A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0694], Certificate
TLS_accept: SSLv3 write certificate A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 00b1], CertificateRequest
TLS_accept: SSLv3 write certificate request A
TLS_accept: SSLv3 flush data
TLS_accept:error in SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 2
modcall: leaving group authenticate (returns handled) for request 2
Sending Access-Challenge of id 112 to 10.254.0.2 port 2048
Password == "teste"
Framed-Protocol := PPP
EAP-Message = 0x0103040a0dc00000079e160301004a020000460301447767ef3e6132404c0c6c02a315774554397970ac027074a9f45e5248c032e820822e232b79be2b75ef379cf751e7d12d6b25d4b841b1c2655efa85382cc1e66000350016030106940b00069000068d0002cd308202c930820232a003020102020102300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e74206365
EAP-Message = 0x7274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d301e170d3034303132353133323631305a170d3035303132343133323631305a30819b310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f73743119301706035504031310526f6f74206365727469666963617465311f301d06092a864886f70d0109011610726f6f74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003
EAP-Message = 0x818d0030818902818100dac525422bfedb082629a2cba44b3449c90d0ab462fb72c8434a782098863d7eb7d7e70028c2b7ad555a51cc756cf4fa1d7091615ab450d5289553ae6616aff014a55085d6b8fb4aee98638e426175cdd36c665c63cda177d34920eb30585edc8773999c2980f81ad4638bbbea1c82d054023db7ef24a3ec1c3f6241a903d7f30203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101040500038181007a2d921b1cf13bf2982a9178ec9ede6d88edc178a2e8bd40a0a06fb6f0769957884cd7084537083496fd184165293f583c8e8240eb68e042c94b15752e4c07e80d09
EAP-Message = 0x779afa3dd55c24fa54ac292d77205d1c2477ed30d59f57caf9bd21ff2a8d16cc0911c50e4f295763fcb60efa3c3d2d0e43850f6e6fbe284902f6e83503650003ba308203b63082031fa003020102020100300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c
EAP-Message = 0x652e636f6d301e170d3034303132353133323630375a
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xcbde73c73ebd72307d8bcd5336508bf1
Finished request 2
Going to the next request
Thread 3 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.254.0.2:2048, id=113, length=176
Waking up in 31 seconds...
Thread 4 got semaphore
Thread 4 handling request 3, (1 handled so far)
User-Name = "mobile"
NAS-IP-Address = 10.254.0.2
NAS-Port = 0
Called-Station-Id = "004f6207b40c"
Calling-Station-Id = "0014a53c478d"
NAS-Identifier = "Realtek Access Point. 8181"
NAS-Port-Type = Wireless-802.11
Service-Type = Framed-User
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x020300060d00
State = 0xcbde73c73ebd72307d8bcd5336508bf1
Message-Authenticator = 0xf8b549edcba04ccf14c3a35cd5e00886
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 3
modcall[authorize]: module "preprocess" returns ok for request 3
rlm_eap: EAP packet type response id 3 length 6
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 3
radius_xlat: 'mobile'
rlm_sql (sql): sql_set_user escaped user --> 'mobile'
radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'mobile' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 1
radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'mobile' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'mobile' ORDER BY id'
radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'mobile' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql): Released sql socket id: 1
modcall[authorize]: module "sql" returns ok for request 3
modcall: leaving group authorize (returns updated) for request 3
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 3
rlm_eap: Request found, released from the list
rlm_eap: EAP/tls
rlm_eap: processing type tls
rlm_eap_tls: Authenticate
rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
rlm_eap_tls: ack handshake fragment handler
eaptls_verify returned 1
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 3
modcall: leaving group authenticate (returns handled) for request 3
Sending Access-Challenge of id 113 to 10.254.0.2 port 2048
Password == "teste"
Framed-Protocol := PPP
EAP-Message = 0x010403a80d800000079e170d3036303132343133323630375a30819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100d4c5b19724f164acf1ffb189db1c8fbff4f14396ea7cb1e90f78d69451725377895dfe52cc
EAP-Message = 0xb99b41e80ddeb58b127a943f4f58cbc562878192fbdc6fece9f871e7c130d35cf5188817e9b133249edd2a1c75d31043ae87553cec7a77ef26aa7d74281db9b77e17c6446c5dd9b188b43250ca0229963722a123a726b00b4027fd0203010001a381ff3081fc301d0603551d0e0416041468d36d3e1ee7bc9d5a057021c363da1365d1ade33081cc0603551d230481c43081c1801468d36d3e1ee7bc9d5a057021c363da1365d1ade3a181a5a481a230819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e
EAP-Message = 0x31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d820100300c0603551d13040530030101ff300d06092a864886f70d01010405000381810033c00b66b1e579ef73a06798252dab8d5e5511fc00fd276d80d12f834777c6743fdc2743fca1507704e4bc0979e4f60ac3ad9ee83e6f347369229d1f77229ba2e982359da563024a00163dba6d6c986c0bad28af85132ff8f0d76501bf1b7c2dff658ce1e62c01997b6e64e3e8d4373354ce9912847651539063b85bbc5485c516030100b1
EAP-Message = 0x0d0000a902010200a400a230819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d0e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x125b8a5ad0f76e326bbc4e2087260bbe
Finished request 3
Going to the next request
Thread 4 waiting to be assigned a request
rad_recv: Access-Request packet from host 10.254.0.2:2048, id=114, length=187
Waking up in 31 seconds...
Thread 5 got semaphore
Thread 5 handling request 4, (1 handled so far)
User-Name = "mobile"
NAS-IP-Address = 10.254.0.2
NAS-Port = 0
Called-Station-Id = "004f6207b40c"
Calling-Station-Id = "0014a53c478d"
NAS-Identifier = "Realtek Access Point. 8181"
NAS-Port-Type = Wireless-802.11
Service-Type = Framed-User
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x020400110d800000000715030100020230
State = 0x125b8a5ad0f76e326bbc4e2087260bbe
Message-Authenticator = 0x1c5b117a3ea7e7026abb5ec89890adc2
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 4
modcall[authorize]: module "preprocess" returns ok for request 4
rlm_eap: EAP packet type response id 4 length 17
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 4
radius_xlat: 'mobile'
rlm_sql (sql): sql_set_user escaped user --> 'mobile'
radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'mobile' ORDER BY id'
rlm_sql (sql): Reserving sql socket id: 0
radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'mobile' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id'
radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'mobile' ORDER BY id'
radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'mobile' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id'
rlm_sql (sql): Released sql socket id: 0
modcall[authorize]: module "sql" returns ok for request 4
modcall: leaving group authorize (returns updated) for request 4
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 4
rlm_eap: Request found, released from the list
rlm_eap: EAP/tls
rlm_eap: processing type tls
rlm_eap_tls: Authenticate
rlm_eap_tls: processing TLS
rlm_eap_tls: Length Included
eaptls_verify returned 11
rlm_eap_tls: <<< TLS 1.0 Alert [length 0002], fatal unknown_ca
TLS Alert read:fatal:unknown CA
TLS_accept:failed in SSLv3 read client certificate A
22289:error:14094418:SSL routines:SSL3_READ_BYTES:tlsv1 alert unknown ca:s3_pkt.c:1052:SSL alert number 48
22289:error:140940E5:SSL routines:SSL3_READ_BYTES:ssl handshake failure:s3_pkt.c:837:
rlm_eap_tls: SSL_read failed in a system call (-1), TLS session fails.
In SSL Handshake Phase
In SSL Accept mode
rlm_eap_tls: BIO_read failed in a system call (-1), TLS session fails.
eaptls_process returned 13
rlm_eap: Freeing handler
modcall[authenticate]: module "eap" returns reject for request 4
modcall: leaving group authenticate (returns reject) for request 4
auth: Failed to validate the user.
Login incorrect: [mobile/<no User-Password attribute>] (from client mslink-radius port 0 cli 0014a53c478d)
Delaying request 4 for 1 seconds
Finished request 4
Going to the next request
Thread 5 waiting to be assigned a request
--- Walking the entire request list ---
Cleaning up request 0 ID 110 with timestamp 447767ef
Cleaning up request 1 ID 111 with timestamp 447767ef
Cleaning up request 2 ID 112 with timestamp 447767ef
Cleaning up request 3 ID 113 with timestamp 447767ef
Sending Access-Reject of id 114 to 10.254.0.2 port 2048
EAP-Message = 0x04040004
Message-Authenticator = 0x00000000000000000000000000000000
Cleaning up request 4 ID 114 with timestamp 447767ef
Nothing to do. Sleeping until we see a request.
More information about the Freeradius-Users
mailing list