That worked. thx.
rad_recv: Access-Request packet from host 127.0.0.1:50067, id=101,
length=79
User-Name = "edwinvanzyl"
Called-Station-Id = "internet"
EAP-Message = 0x0200001001656477696e76616e7a796c
Message-Authenticator = 0xd649ab055e13bef1b25863bcab47f81e
Wed Feb 13 11:22:56 2008 : Debug: Processing the authorize section
of radiusd.conf
Wed Feb 13 11:22:56 2008 : Debug: modcall: entering group authorize
for request 4
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 4
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: EAP packet type response
id 0 length 16
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: No EAP Start, assuming
it's an on-going EAP conversation
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: returned
from eap (rlm_eap) for request 4
Wed Feb 13 11:22:56 2008 : Debug: modcall[authorize]: module "eap"
returns updated for request 4
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: calling
files (rlm_files) for request 4
Wed Feb 13 11:22:56 2008 : Debug: users: Matched entry edwinvanzyl
at line 80
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: returned
from files (rlm_files) for request 4
Wed Feb 13 11:22:56 2008 : Debug: modcall[authorize]: module "files"
returns ok for request 4
Wed Feb 13 11:22:56 2008 : Debug: modcall: leaving group authorize
(returns updated) for request 4
Wed Feb 13 11:22:56 2008 : Debug: rad_check_password: Found Auth-
Type EAP
Wed Feb 13 11:22:56 2008 : Debug: auth: type "EAP"
Wed Feb 13 11:22:56 2008 : Debug: Processing the authenticate
section of radiusd.conf
Wed Feb 13 11:22:56 2008 : Debug: modcall: entering group authenticate
for request 4
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authenticate]: calling
eap (rlm_eap) for request 4
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: EAP Identity
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: processing type tls
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: Initiate
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: Start returned 1
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authenticate]: returned
from eap (rlm_eap) for request 4
Wed Feb 13 11:22:56 2008 : Debug: modcall[authenticate]: module
"eap" returns handled for request 4
Wed Feb 13 11:22:56 2008 : Debug: modcall: leaving group authenticate
(returns handled) for request 4
Sending Access-Challenge of id 101 to 127.0.0.1 port 50067
EAP-Message = 0x010100061520
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xad2f0e60790267d123b90ade481ecca5
Wed Feb 13 11:22:56 2008 : Debug: Finished request 4
Wed Feb 13 11:22:56 2008 : Debug: Going to the next request
Wed Feb 13 11:22:56 2008 : Debug: --- Walking the entire request list
---
Wed Feb 13 11:22:56 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:50067, id=102,
length=145
User-Name = "edwinvanzyl"
Called-Station-Id = "internet"
State = 0xad2f0e60790267d123b90ade481ecca5
EAP-Message =
0x0201004015800000003a16030100310100002d030147b2b6f06db8377eae44af2b54c47b7c102f291a22bb62187200777ccdf66216000006002f003300320100
Message-Authenticator = 0x21c075be78867ae66bd77f002e447701
Wed Feb 13 11:22:56 2008 : Debug: Processing the authorize section
of radiusd.conf
Wed Feb 13 11:22:56 2008 : Debug: modcall: entering group authorize
for request 5
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 5
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: EAP packet type response
id 1 length 64
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: No EAP Start, assuming
it's an on-going EAP conversation
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: returned
from eap (rlm_eap) for request 5
Wed Feb 13 11:22:56 2008 : Debug: modcall[authorize]: module "eap"
returns updated for request 5
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: calling
files (rlm_files) for request 5
Wed Feb 13 11:22:56 2008 : Debug: users: Matched entry edwinvanzyl
at line 80
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: returned
from files (rlm_files) for request 5
Wed Feb 13 11:22:56 2008 : Debug: modcall[authorize]: module "files"
returns ok for request 5
Wed Feb 13 11:22:56 2008 : Debug: modcall: leaving group authorize
(returns updated) for request 5
Wed Feb 13 11:22:56 2008 : Debug: rad_check_password: Found Auth-
Type EAP
Wed Feb 13 11:22:56 2008 : Debug: auth: type "EAP"
Wed Feb 13 11:22:56 2008 : Debug: Processing the authenticate
section of radiusd.conf
Wed Feb 13 11:22:56 2008 : Debug: modcall: entering group authenticate
for request 5
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authenticate]: calling
eap (rlm_eap) for request 5
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: Request found, released
from the list
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: EAP/ttls
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: processing type ttls
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_ttls: Authenticate
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: processing TLS
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: Length Included
Wed Feb 13 11:22:56 2008 : Debug: eaptls_verify returned 11
Wed Feb 13 11:22:56 2008 : Debug: (other): before/accept
initialization
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: before/accept
initialization
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake
[length 0031], ClientHello
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: SSLv3 read client
hello A
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake
[length 004a], ServerHello
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: SSLv3 write server
hello A
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake
[length 024f], Certificate
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: SSLv3 write
certificate A
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake
[length 0004], ServerHelloDone
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: SSLv3 write server
done A
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: SSLv3 flush data
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: Need to read more
data: SSLv3 read client certificate A
Wed Feb 13 11:22:56 2008 : Debug: In SSL Handshake Phase
Wed Feb 13 11:22:56 2008 : Debug: In SSL Accept mode
Wed Feb 13 11:22:56 2008 : Debug: eaptls_process returned 13
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authenticate]: returned
from eap (rlm_eap) for request 5
Wed Feb 13 11:22:56 2008 : Debug: modcall[authenticate]: module
"eap" returns handled for request 5
Wed Feb 13 11:22:56 2008 : Debug: modcall: leaving group authenticate
(returns handled) for request 5
Sending Access-Challenge of id 102 to 127.0.0.1 port 50067
EAP-Message =
0x010202b21500160301004a02000046030147b2b6f05cb491bf2deb1d0bb035590d20dc810639878320773425fd0c84dba4201fa66fa4064e36e8fcf4da3971bb0e26ecb0c26b42041474485586703259d4fe002f00160301024f0b00024b00024800024530820241308201aa0203100001300d06092a864886f70d0101040500307431173015060355040a130e616c636174656c2d6c7563656e74310e300c060355040b130557694d4158310c300a06035504071303465344310f300d0603550408130670756e6a6162310b300906035504061302706b311d301b060355040313146161617365727665722e616c636174656c2e706b301e170d303730
EAP-Message =
0x3531343131353334365a170d3038303531333131353334365a305c310b300906035504061302706b310f300d0603550408130670756e6a616231173015060355040a130e616c636174656c2d6c7563656e74310e300c060355040b130557694d4158311330110603550403130a7a7978656c2e7573657230819f300d06092a864886f70d010101050003818d0030818902818100baaf122e60946da7ee1dc1101854e1836e848c0f3d5372be31e29eef2566a673f138809b9a118846e6846280408d822960c6345a6ce922155463fe3a267bc8d047aa8a435f506d9df7670e9d5dcc381f48d99662943546c4acca0db93665023181924fa574b52fb8ec
EAP-Message =
0x7a05a85edf77fc408350e82f41536fb4584afe6671fd5f0203010001300d06092a864886f70d01010405000381810065c020869992c43b685a15a53ffee8ea31743ac9fe71a741b5265dbc1caa2d01e614820b4d05d2f5bd5bf04804259abfdad4d492877574946c10afba0c07a04304876701ac9e29a8297b2a9f1d6bb5e080d2fc5b633d63433f63e4be896dc4bd9db1606e80af636c2a1eabba9e0c3d73059bfc66efc9d06b8af35a8d2862971416030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xa906824b1c0687f85073022f0177c03d
Wed Feb 13 11:22:56 2008 : Debug: Finished request 5
Wed Feb 13 11:22:56 2008 : Debug: Going to the next request
Wed Feb 13 11:22:56 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:50067, id=103,
length=289
User-Name = "edwinvanzyl"
Called-Station-Id = "internet"
State = 0xa906824b1c0687f85073022f0177c03d
EAP-Message =
0x020200d01580000000ca1603010086100000820080a7846d9c489947c24ca5fe72f8894e2a00f06ffa6628b5f779f2fdeac11978a11438e8102bc929c7ebbc26d09514408471ee6a7ed9faba03c7986cf2a2e8a47603d15f927257e90fac15026e83aef21f1621ba13edafa3c7539647c6582f5413d9c84af5172853966b80b3e26165ce3963faecec04a6da531079c633ffc36dcc14030100010116030100308646fe17348800449f912361f8f22d58b1f0a921533e0ec562c2a034735a723074d7deb42440e08a36d06c81b4273add
Message-Authenticator = 0xccf19c9005bab3b128e6dbfb8624d438
Wed Feb 13 11:22:56 2008 : Debug: Processing the authorize section
of radiusd.conf
Wed Feb 13 11:22:56 2008 : Debug: modcall: entering group authorize
for request 6
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 6
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: EAP packet type response
id 2 length 208
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: No EAP Start, assuming
it's an on-going EAP conversation
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: returned
from eap (rlm_eap) for request 6
Wed Feb 13 11:22:56 2008 : Debug: modcall[authorize]: module "eap"
returns updated for request 6
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: calling
files (rlm_files) for request 6
Wed Feb 13 11:22:56 2008 : Debug: users: Matched entry edwinvanzyl
at line 80
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: returned
from files (rlm_files) for request 6
Wed Feb 13 11:22:56 2008 : Debug: modcall[authorize]: module "files"
returns ok for request 6
Wed Feb 13 11:22:56 2008 : Debug: modcall: leaving group authorize
(returns updated) for request 6
Wed Feb 13 11:22:56 2008 : Debug: rad_check_password: Found Auth-
Type EAP
Wed Feb 13 11:22:56 2008 : Debug: auth: type "EAP"
Wed Feb 13 11:22:56 2008 : Debug: Processing the authenticate
section of radiusd.conf
Wed Feb 13 11:22:56 2008 : Debug: modcall: entering group authenticate
for request 6
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authenticate]: calling
eap (rlm_eap) for request 6
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: Request found, released
from the list
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: EAP/ttls
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: processing type ttls
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_ttls: Authenticate
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: processing TLS
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: Length Included
Wed Feb 13 11:22:56 2008 : Debug: eaptls_verify returned 11
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake
[length 0086], ClientKeyExchange
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: SSLv3 read client
key exchange A
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: <<< TLS 1.0
ChangeCipherSpec [length 0001]
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake
[length 0010], Finished
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: SSLv3 read finished A
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: >>> TLS 1.0
ChangeCipherSpec [length 0001]
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: SSLv3 write change
cipher spec A
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake
[length 0010], Finished
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: SSLv3 write finished A
Wed Feb 13 11:22:56 2008 : Debug: TLS_accept: SSLv3 flush data
Wed Feb 13 11:22:56 2008 : Debug: (other): SSL negotiation
finished successfully
Wed Feb 13 11:22:56 2008 : Debug: SSL Connection Established
Wed Feb 13 11:22:56 2008 : Debug: eaptls_process returned 13
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authenticate]: returned
from eap (rlm_eap) for request 6
Wed Feb 13 11:22:56 2008 : Debug: modcall[authenticate]: module
"eap" returns handled for request 6
Wed Feb 13 11:22:56 2008 : Debug: modcall: leaving group authenticate
(returns handled) for request 6
Sending Access-Challenge of id 103 to 127.0.0.1 port 50067
EAP-Message =
0x01030041150014030100010116030100306e67219d42247698b9a3a37e6205bbf5432619a2c997a30809f82412d93286b9410636ff327ff3b62df678e540bae2bc
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x868bf596b4e632edce8c663e4ff20895
Wed Feb 13 11:22:56 2008 : Debug: Finished request 6
Wed Feb 13 11:22:56 2008 : Debug: Going to the next request
Wed Feb 13 11:22:56 2008 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 127.0.0.1:50067, id=104,
length=160
User-Name = "edwinvanzyl"
Called-Station-Id = "internet"
State = 0x868bf596b4e632edce8c663e4ff20895
EAP-Message =
0x0203004f158000000049170301004092cf380f7dcc8e70a90786295ec7d8501d9b66debb6c833e413c3e97d1de6575a0946e29604e8e5c918a430d8abe24a8fb902e747e8564a530aa3cf4d9c45bf3
Message-Authenticator = 0x2f5fa680eb9fd89cebdbc5f34e07eaa6
Wed Feb 13 11:22:56 2008 : Debug: Processing the authorize section
of radiusd.conf
Wed Feb 13 11:22:56 2008 : Debug: modcall: entering group authorize
for request 7
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 7
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: EAP packet type response
id 3 length 79
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: No EAP Start, assuming
it's an on-going EAP conversation
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: returned
from eap (rlm_eap) for request 7
Wed Feb 13 11:22:56 2008 : Debug: modcall[authorize]: module "eap"
returns updated for request 7
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: calling
files (rlm_files) for request 7
Wed Feb 13 11:22:56 2008 : Debug: users: Matched entry edwinvanzyl
at line 80
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authorize]: returned
from files (rlm_files) for request 7
Wed Feb 13 11:22:56 2008 : Debug: modcall[authorize]: module "files"
returns ok for request 7
Wed Feb 13 11:22:56 2008 : Debug: modcall: leaving group authorize
(returns updated) for request 7
Wed Feb 13 11:22:56 2008 : Debug: rad_check_password: Found Auth-
Type EAP
Wed Feb 13 11:22:56 2008 : Debug: auth: type "EAP"
Wed Feb 13 11:22:56 2008 : Debug: Processing the authenticate
section of radiusd.conf
Wed Feb 13 11:22:56 2008 : Debug: modcall: entering group authenticate
for request 7
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authenticate]: calling
eap (rlm_eap) for request 7
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: Request found, released
from the list
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: EAP/ttls
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: processing type ttls
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_ttls: Authenticate
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: processing TLS
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_tls: Length Included
Wed Feb 13 11:22:56 2008 : Debug: eaptls_verify returned 11
Wed Feb 13 11:22:56 2008 : Debug: eaptls_process returned 7
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_ttls: Session
established. Proceeding to decode tunneled attributes.
TTLS tunnel data in 0000: 01 0d 65 64 77 69 6e 76 61 6e 7a 79 6c 02
09 74
TTLS tunnel data in 0010: 65 73 74 69 6e 67 1e 0a 69 6e 74 65 72 6e
65 74
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap_ttls: Non-RADIUS
attribute in tunneled authentication is not supported
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: Handler failed in EAP/ttls
Wed Feb 13 11:22:56 2008 : Debug: rlm_eap: Failed in EAP select
Wed Feb 13 11:22:56 2008 : Debug: modsingle[authenticate]: returned
from eap (rlm_eap) for request 7
Wed Feb 13 11:22:56 2008 : Debug: modcall[authenticate]: module
"eap" returns invalid for request 7
Wed Feb 13 11:22:56 2008 : Debug: modcall: leaving group authenticate
(returns invalid) for request 7
Wed Feb 13 11:22:56 2008 : Debug: auth: Failed to validate the user.
Wed Feb 13 11:22:56 2008 : Debug: Delaying request 7 for 1 seconds
Wed Feb 13 11:22:56 2008 : Debug: Finished request 7
Wed Feb 13 11:22:56 2008 : Debug: Going to the next request
Wed Feb 13 11:22:56 2008 : Debug: Waking up in 6 seconds...
Wed Feb 13 11:23:02 2008 : Debug: --- Walking the entire reques
On 13 Feb 2008, at 11:09 AM, Alan DeKok wrote:
Edwin van Zyl wrote:
I've configured with the following options: ./configure --enable-
debug
--enable-developer and re-build, but still don't see the raw data.
I've
looked at the binary traces and can see that the EAP message contains
encrypted application data and the size is less then 100bytes. Am I
configuring with the wrong options?
Hmm... try running with with -Xxx
Alan DeKok.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
