How long it take to auth in 802.1X/WPA-enterprise?

I set up 802.1X/WPA-Enterprise network simply as follows.

Free radius 2.1.8

server

ubunt on VMware

10.10.20.14

|EAP-TLS(wired. 802.3)

Belkin 54g

WPA-Enterprise

Tkip

:EAP-TLS(wireless 802.11)

Client :

Laptop

Windows 7

(Self certification)

kkk@xxxx.yyy.zz.vv

In this simple network model, I have tried to auth using

EAP-TLS(self-certification) and it works good.

By the way, about 18 seconds are taken to auth as follow debug logs.

(confer the timestamp (1) and (2))

.......

Wed Feb 17 21:36:29 2010 : Info: Ready to process requests.

rad_recv: Access-Request packet from host 10.10.20.14 port 3072, id=0,

length=157

User-Name = "kkk@xxxx.yyy.zz.vv"

NAS-IP-Address = 10.10.20.14

Called-Station-Id = "001150624dc1"

Calling-Station-Id = "00242bc8fe6a"

NAS-Identifier = "001150624dc1"

NAS-Port = 28

Framed-MTU = 1400

NAS-Port-Type = Wireless-802.11

EAP-Message = 0x0200001b016a6a624063636c61622e796f6e7365692e61632e6b72

Message-Authenticator = 0x3d4a5b810f49d3bc390d39406a300eda

Wed Feb 17 21:36:42 2010 : Info: +- entering group authorize {...}

Wed Feb 17 21:36:42 2010 : Info: ++[preprocess] returns ok

Wed Feb 17 21:36:42 2010 : Info: ++[chap] returns noop

Wed Feb 17 21:36:42 2010 : Info: ++[mschap] returns noop

Wed Feb 17 21:36:42 2010 : Info: [suffix] Looking up realm

"xxxx.yyy.zz.vv" for User-Name = "kkk@xxxx.yyy.zz.vv"

Wed Feb 17 21:36:42 2010 : Info: [suffix] No such realm "xxxx.yyy.zz.vv"

Wed Feb 17 21:36:42 2010 : Info: ++[suffix] returns noop

Wed Feb 17 21:36:42 2010 : Info: [eap] EAP packet type response id 0 length 27

Wed Feb 17 21:36:42 2010 : Info: [eap] No EAP Start, assuming it's an

on-going EAP conversation

Wed Feb 17 21:36:42 2010 : Info: ++[eap] returns updated

Wed Feb 17 21:36:42 2010 : Info: ++[unix] returns notfound

Wed Feb 17 21:36:42 2010 : Info: ++[files] returns noop

Wed Feb 17 21:36:42 2010 : Info: ++[expiration] returns noop

Wed Feb 17 21:36:42 2010 : Info: ++[logintime] returns noop

Wed Feb 17 21:36:42 2010 : Info: [pap] WARNING! No "known good"

password found for the user. Authentication may fail because of this.

Wed Feb 17 21:36:42 2010 : Info: ++[pap] returns noop

Wed Feb 17 21:36:42 2010 : Info: Found Auth-Type = EAP

Wed Feb 17 21:36:42 2010 : Info: +- entering group authenticate {...}

Wed Feb 17 21:36:42 2010 : Info: [eap] EAP Identity

Wed Feb 17 21:36:42 2010 : Info: [eap] processing type tls

Wed Feb 17 21:36:42 2010 : Info: [tls] Requiring client certificate

Wed Feb 17 21:36:42 2010 : Info: [tls] Initiate

Wed Feb 17 21:36:42 2010 : Info: [tls] Start returned 1

Wed Feb 17 21:36:42 2010 : Info: ++[eap] returns handled

Sending Access-Challenge of id 0 to 10.10.20.14 port 3072

EAP-Message = 0x010100060d20

Message-Authenticator = 0x00000000000000000000000000000000

State = 0x897eb023897fbdcff6383e26a1b0eb16

Wed Feb 17 21:36:42 2010 : Info: Finished request 0.

Wed Feb 17 21:36:42 2010 : Debug: Going to the next request

Wed Feb 17 21:36:42 2010 : Debug: Waking up in 4.9 seconds.

rad_recv: Access-Request packet from host 10.10.20.14 port 3072, id=0,

length=157

Wed Feb 17 21:36:42 2010 : Info: Cleaning up request 0 ID 0 with timestamp +13

User-Name = "kkk@xxxx.yyy.zz.vv"

NAS-IP-Address = 10.10.20.14

Called-Station-Id = "001150624dc1"

Calling-Station-Id = "00242bc8fe6a"

NAS-Identifier = "001150624dc1"

NAS-Port = 28

Framed-MTU = 1400

NAS-Port-Type = Wireless-802.11

EAP-Message = 0x0200001b016a6a624063636c61622e796f6e7365692e61632e6b72

Message-Authenticator = 0x6bba537330b0a4ceeb559fdbf62726fa

Wed Feb 17 21:36:42 2010 : Info: +- entering group authorize {...}

Wed Feb 17 21:36:42 2010 : Info: ++[preprocess] returns ok

Wed Feb 17 21:36:42 2010 : Info: ++[chap] returns noop

Wed Feb 17 21:36:42 2010 : Info: ++[mschap] returns noop

Wed Feb 17 21:36:42 2010 : Info: [suffix] Looking up realm

"xxxx.yyy.zz.vv" for User-Name = "kkk@xxxx.yyy.zz.vv"

Wed Feb 17 21:36:42 2010 : Info: [suffix] No such realm "xxxx.yyy.zz.vv"

Wed Feb 17 21:36:42 2010 : Info: ++[suffix] returns noop

Wed Feb 17 21:36:42 2010 : Info: [eap] EAP packet type response id 0 length 27

Wed Feb 17 21:36:42 2010 : Info: [eap] No EAP Start, assuming it's an

on-going EAP conversation

Wed Feb 17 21:36:42 2010 : Info: ++[eap] returns updated

Wed Feb 17 21:36:42 2010 : Info: ++[unix] returns notfound

Wed Feb 17 21:36:42 2010 : Info: ++[files] returns noop

Wed Feb 17 21:36:42 2010 : Info: ++[expiration] returns noop

Wed Feb 17 21:36:42 2010 : Info: ++[logintime] returns noop

Wed Feb 17 21:36:42 2010 : Info: [pap] WARNING! No "known good"

password found for the user. Authentication may fail because of this.

Wed Feb 17 21:36:42 2010 : Info: ++[pap] returns noop

Wed Feb 17 21:36:42 2010 : Info: Found Auth-Type = EAP

Wed Feb 17 21:36:42 2010 : Info: +- entering group authenticate {...}

Wed Feb 17 21:36:42 2010 : Info: [eap] EAP Identity

Wed Feb 17 21:36:42 2010 : Info: [eap] processing type tls

Wed Feb 17 21:36:42 2010 : Info: [tls] Requiring client certificate

Wed Feb 17 21:36:42 2010 : Info: [tls] Initiate

Wed Feb 17 21:36:42 2010 : Info: [tls] Start returned 1

Wed Feb 17 21:36:42 2010 : Info: ++[eap] returns handled

Sending Access-Challenge of id 0 to 10.10.20.14 port 3072

EAP-Message = 0x010100060d20

Message-Authenticator = 0x00000000000000000000000000000000

State = 0x4ec97f554ec8722ce642d653e0f84a11

Wed Feb 17 21:36:42 2010 : Info: Finished request 1.

Wed Feb 17 21:36:42 2010 : Debug: Going to the next request

Wed Feb 17 21:36:42 2010 : Debug: Waking up in 4.9 seconds.

rad_recv: Access-Request packet from host 10.10.20.14 port 3072, id=0,

length=157

Wed Feb 17 21:36:47 2010 : Info: Cleaning up request 1 ID 0 with timestamp +13

^^^^^^^^^^^^^^(1)

Wed Feb 17 21:36:47 2010 : Info: Ready to process requests.

rad_recv: Access-Request packet from host 10.10.20.14 port 3072, id=0,

length=157

User-Name = "kkk@xxxx.yyy.zz.vv"

NAS-IP-Address = 10.10.20.14

Called-Station-Id = "001150624dc1"

Calling-Station-Id = "00242bc8fe6a"

NAS-Identifier = "001150624dc1"

NAS-Port = 28

Framed-MTU = 1400

NAS-Port-Type = Wireless-802.11

EAP-Message = 0x0201001b016a6a624063636c61622e796f6e7365692e61632e6b72

Message-Authenticator = 0x03977f17a87e73640019845a87fca910

Wed Feb 17 21:37:00 2010 : Info: +- entering group authorize {...}

Wed Feb 17 21:37:00 2010 : Info: ++[preprocess] returns ok

Wed Feb 17 21:37:00 2010 : Info: ++[chap] returns noop

Wed Feb 17 21:37:00 2010 : Info: ++[mschap] returns noop

Wed Feb 17 21:37:00 2010 : Info: [suffix] Looking up realm

"xxxx.yyy.zz.vv" for User-Name = "kkk@xxxx.yyy.zz.vv"

Wed Feb 17 21:37:00 2010 : Info: [suffix] No such realm "xxxx.yyy.zz.vv"

Wed Feb 17 21:37:00 2010 : Info: ++[suffix] returns noop

Wed Feb 17 21:37:00 2010 : Info: [eap] EAP packet type response id 1 length 27

Wed Feb 17 21:37:00 2010 : Info: [eap] No EAP Start, assuming it's an

on-going EAP conversation

Wed Feb 17 21:37:00 2010 : Info: ++[eap] returns updated

Wed Feb 17 21:37:00 2010 : Info: ++[unix] returns notfound

Wed Feb 17 21:37:00 2010 : Info: ++[files] returns noop

Wed Feb 17 21:37:00 2010 : Info: ++[expiration] returns noop

Wed Feb 17 21:37:00 2010 : Info: ++[logintime] returns noop

Wed Feb 17 21:37:00 2010 : Info: [pap] WARNING! No "known good"

password found for the user. Authentication may fail because of this.

Wed Feb 17 21:37:00 2010 : Info: ++[pap] returns noop

Wed Feb 17 21:37:00 2010 : Info: Found Auth-Type = EAP

Wed Feb 17 21:37:00 2010 : Info: +- entering group authenticate {...}

Wed Feb 17 21:37:00 2010 : Info: [eap] EAP Identity

Wed Feb 17 21:37:00 2010 : Info: [eap] processing type tls

Wed Feb 17 21:37:00 2010 : Info: [tls] Requiring client certificate

Wed Feb 17 21:37:00 2010 : Info: [tls] Initiate

Wed Feb 17 21:37:00 2010 : Info: [tls] Start returned 1

Wed Feb 17 21:37:00 2010 : Info: ++[eap] returns handled

Sending Access-Challenge of id 0 to 10.10.20.14 port 3072

EAP-Message = 0x010200060d20

Message-Authenticator = 0x00000000000000000000000000000000

State = 0x5e8be3495e89ee006f9068a0260d02b1

Wed Feb 17 21:37:00 2010 : Info: Finished request 2.

Wed Feb 17 21:37:00 2010 : Debug: Going to the next request

Wed Feb 17 21:37:00 2010 : Debug: Waking up in 4.9 seconds.

rad_recv: Access-Request packet from host 10.10.20.14 port 3072, id=0,

length=279

Wed Feb 17 21:37:00 2010 : Info: Cleaning up request 2 ID 0 with timestamp +31

^^^^^^^^^^^^^^^(2)

User-Name = "kkk@xxxx.yyy.zz.vv"

NAS-IP-Address = 10.10.20.14

Called-Station-Id = "001150624dc1"

Calling-Station-Id = "00242bc8fe6a"

NAS-Identifier = "001150624dc1"

NAS-Port = 28

Framed-MTU = 1400

State = 0x5e8be3495e89ee006f9068a0260d02b1

NAS-Port-Type = Wireless-802.11

EAP-Message = 0x020200830d800000007916030100740100007003014b7be2f6f44552f530788e05c2c2f20051ba0547a8df2ede6aabb38fae71fd8f000018002f00350005000ac013c014c009c00a00320038001300040100002f0000001b00190000166a6a624063636c61622e796f6e7365692e61632e6b72000a0006000400170018000b00020100

Message-Authenticator = 0x1da810154c90aa4a028de1eaebee971c

.......

Is it right?

I can't understand the taken time 18 seconds. it's too long.

Can you explain what is wrong?

I don't think it due to system performance or network throughput.

Maybe configuration file problems...

Thanks in advance.^^

Best,

Jaejong Baek