Problem with EAP-TLS
Guk Victor
v.guk at zaz.zp.ua
Wed Oct 1 13:10:37 CEST 2008
Hi all.
I have problem with EAP-TLS. Computer with OS Windows Vista, Freeradius
1.1.3.
Immediately access to the network exists after connection, but access is
forbidden through several minutes.
This is what it is obtained:
[root at localhost ~]# radiusd -X
Starting - reading configuration files ...
reread_config: reading radiusd.conf
Config: including file: /etc/raddb/proxy.conf
Config: including file: /etc/raddb/clients.conf
Config: including file: /etc/raddb/snmp.conf
Config: including file: /etc/raddb/eap.conf
main: prefix = "/usr"
main: localstatedir = "/var"
main: logdir = "/var/log/radius"
main: libdir = "/usr/lib"
main: radacctdir = "/var/log/radius/radacct"
main: hostname_lookups = no
main: snmp = no
main: max_request_time = 30
main: cleanup_delay = 5
main: max_requests = 1024
main: delete_blocked_requests = 0
main: port = 0
main: allow_core_dumps = no
main: log_stripped_names = yes
main: log_file = "/var/log/radius/radius.log"
main: log_auth = yes
main: log_auth_badpass = yes
main: log_auth_goodpass = yes
main: pidfile = "/var/run/radiusd/radiusd.pid"
main: user = "radiusd"
main: group = "radiusd"
main: usercollide = no
main: lower_user = "yes"
main: lower_pass = "yes"
main: nospace_user = "yes"
main: nospace_pass = "yes"
main: checkrad = "/usr/sbin/checkrad"
main: proxy_requests = yes
proxy: retry_delay = 5
proxy: retry_count = 3
proxy: synchronous = no
proxy: default_fallback = yes
proxy: dead_time = 120
proxy: post_proxy_authorize = no
proxy: wake_all_if_all_dead = no
security: max_attributes = 200
security: reject_delay = 1
security: status_server = no
main: debug_level = 0
read_config_files: reading dictionary
read_config_files: reading naslist
Using deprecated naslist file. Support for this will go away soon.
read_config_files: reading clients
read_config_files: reading realms
radiusd: entering modules setup
Module: Library search path is /usr/lib
Module: Loaded exec
exec: wait = yes
exec: program = "(null)"
exec: input_pairs = "request"
exec: output_pairs = "(null)"
exec: packet_type = "(null)"
rlm_exec: Wait=yes but no output defined. Did you mean output=none?
Module: Instantiated exec (exec)
Module: Loaded expr
Module: Instantiated expr (expr)
Module: Loaded PAP
pap: encryption_scheme = "crypt"
Module: Instantiated pap (pap)
Module: Loaded CHAP
Module: Instantiated chap (chap)
Module: Loaded MS-CHAP
mschap: use_mppe = yes
mschap: require_encryption = yes
mschap: require_strong = yes
mschap: with_ntdomain_hack = yes
mschap: passwd = "(null)"
mschap: ntlm_auth = "(null)"
Module: Instantiated mschap (mschap)
Module: Loaded System
unix: cache = yes
unix: passwd = "/etc/passwd"
unix: shadow = "/etc/raddb/shadow"
unix: group = "/etc/group"
unix: radwtmp = "/var/log/radius/radwtmp"
unix: usegroup = no
unix: cache_reload = 600
HASH: Reinitializing hash structures and lists for caching...
HASH: user root found in hashtable bucket 11726
HASH: user bin found in hashtable bucket 86651
HASH: user daemon found in hashtable bucket 11668
HASH: user adm found in hashtable bucket 26466
HASH: user lp found in hashtable bucket 54068
HASH: user sync found in hashtable bucket 42895
HASH: user shutdown found in hashtable bucket 71746
HASH: user halt found in hashtable bucket 7481
HASH: user mail found in hashtable bucket 79471
HASH: user news found in hashtable bucket 5375
HASH: user uucp found in hashtable bucket 38541
HASH: user operator found in hashtable bucket 21748
HASH: user games found in hashtable bucket 47657
HASH: user gopher found in hashtable bucket 47357
HASH: user ftp found in hashtable bucket 56226
HASH: user nobody found in hashtable bucket 99723
HASH: user rpm found in hashtable bucket 72383
HASH: user dbus found in hashtable bucket 68880
HASH: user avahi found in hashtable bucket 41645
HASH: user mailnull found in hashtable bucket 78086
HASH: user smmsp found in hashtable bucket 13600
HASH: user nscd found in hashtable bucket 36306
HASH: user vcsa found in hashtable bucket 25959
HASH: user rpc found in hashtable bucket 72373
HASH: user rpcuser found in hashtable bucket 552
HASH: user nfsnobody found in hashtable bucket 51830
HASH: user sshd found in hashtable bucket 71560
HASH: user pcap found in hashtable bucket 55326
HASH: user ntp found in hashtable bucket 21418
HASH: user haldaemon found in hashtable bucket 31187
HASH: user apache found in hashtable bucket 26582
HASH: user xfs found in hashtable bucket 17213
HASH: user gdm found in hashtable bucket 50360
HASH: user sabayon found in hashtable bucket 36231
HASH: user ldap found in hashtable bucket 45563
HASH: user radiusd found in hashtable bucket 55046
HASH: user admin found in hashtable bucket 45083
HASH: Stored 37 entries from /etc/passwd
HASH: Stored 48 entries from /etc/group
Module: Instantiated unix (unix)
Module: Loaded eap
eap: default_eap_type = "tls"
eap: timer_expire = 60
eap: ignore_unknown_eap_types = no
eap: cisco_accounting_username_bug = no
rlm_eap: Loaded and initialized type md5
rlm_eap: Loaded and initialized type leap
gtc: challenge = "Password: "
gtc: auth_type = "PAP"
rlm_eap: Loaded and initialized type gtc
tls: rsa_key_exchange = no
tls: dh_key_exchange = yes
tls: rsa_key_length = 512
tls: dh_key_length = 512
tls: verify_depth = 0
tls: CA_path = "(null)"
tls: pem_file_type = yes
tls: private_key_file = "/etc/raddb/certs/cert-srv.pem"
tls: certificate_file = "/etc/raddb/certs/cert-srv.pem"
tls: CA_file = "/etc/raddb/certs/demoCA/cacert.pem"
tls: private_key_password = "whatever"
tls: dh_file = "/etc/raddb/certs/dh"
tls: random_file = "/etc/raddb/certs/random"
tls: fragment_size = 1024
tls: include_length = yes
tls: check_crl = no
tls: check_cert_cn = "(null)"
tls: cipher_list = "(null)"
tls: check_cert_issuer = "(null)"
rlm_eap_tls: Loading the certificate file as a chain
rlm_eap: Loaded and initialized type tls
peap: default_eap_type = "mschapv2"
peap: copy_request_to_tunnel = no
peap: use_tunneled_reply = yes
peap: proxy_tunneled_request_as_eap = yes
rlm_eap: Loaded and initialized type peap
mschapv2: with_ntdomain_hack = no
rlm_eap: Loaded and initialized type mschapv2
Module: Instantiated eap (eap)
Module: Loaded realm
realm: format = "prefix"
realm: delimiter = "\"
realm: ignore_default = no
realm: ignore_null = no
Module: Instantiated realm (ntdomain)
Module: Loaded files
files: usersfile = "/etc/raddb/users"
files: acctusersfile = "/etc/raddb/acct_users"
files: preproxy_usersfile = "/etc/raddb/preproxy_users"
files: compat = "no"
[/etc/raddb/users]:216 WARNING! Changing 'Service-Type =' to
'Service-Type ==' ?for comparing RADIUS attribute in check item list for
user admin
Module: Instantiated files (files)
Module: Loaded preprocess
preprocess: huntgroups = "/etc/raddb/huntgroups"
preprocess: hints = "/etc/raddb/hints"
preprocess: with_ascend_hack = no
preprocess: ascend_channels_per_line = 23
preprocess: with_ntdomain_hack = no
preprocess: with_specialix_jetstream_hack = no
preprocess: with_cisco_vsa_hack = no
preprocess: with_alvarion_vsa_hack = no
Module: Instantiated preprocess (preprocess)
Module: Loaded Acct-Unique-Session-Id
acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address,
Client-IP-Address, NAS-Port"
Module: Instantiated acct_unique (acct_unique)
realm: format = "suffix"
realm: delimiter = "@"
realm: ignore_default = no
realm: ignore_null = no
Module: Instantiated realm (suffix)
Module: Loaded detail
detail: detailfile =
"/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
detail: detailperm = 384
detail: dirperm = 493
detail: locking = no
Module: Instantiated detail (detail)
Module: Loaded radutmp
radutmp: filename = "/var/log/radius/radutmp"
radutmp: username = "%{User-Name}"
radutmp: case_sensitive = yes
radutmp: check_with_nas = yes
radutmp: perm = 384
radutmp: callerid = yes
Module: Instantiated radutmp (radutmp)
Listening on authentication *:1812
Listening on accounting *:1813
Ready to process requests.
rad_recv: Access-Request packet from host 10.0.1.2:5007, id=131, length=214
User-Name = "test_user"
EAP-Message = 0x0202000e01746573745f75736572
Message-Authenticator = 0x1b8586c086b1949ff4ff4e65e2ab0e39
NAS-IP-Address = 10.0.1.2
NAS-Identifier = "001ac1d4ee42"
NAS-Port = 117604353
NAS-Port-Id = "unit=7;subslot=0;port=40;vlanid=1"
NAS-Port-Type = Ethernet
Service-Type = Framed-User
Framed-Protocol = PPP
Calling-Station-Id = "0013-7737-714e"
Vendor-25506-Attr-26 = 0x00000029
Vendor-25506-Attr-255 = 0x353530302d4549
Vendor-25506-Attr-60 =
0x302e302e302e302030303a31333a37373a33373a37313a3465
Vendor-25506-Attr-59 = 0x38e68c68
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
modcall[authorize]: module "mschap" returns noop for request 0
rlm_realm: No '\' in User-Name = "test_user", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "ntdomain" returns noop for request 0
rlm_eap: EAP packet type response id 2 length 14
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 0
users: Matched entry DEFAULT at line 152
users: Matched entry DEFAULT at line 171
users: Matched entry DEFAULT at line 183
modcall[authorize]: module "files" returns ok for request 0
modcall: leaving group authorize (returns updated) for request 0
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 0
rlm_eap: EAP Identity
rlm_eap: processing type tls
rlm_eap_tls: Requiring client certificate
rlm_eap_tls: Initiate
rlm_eap_tls: Start returned 1
modcall[authenticate]: module "eap" returns handled for request 0
modcall: leaving group authenticate (returns handled) for request 0
Sending Access-Challenge of id 131 to 10.0.1.2 port 5007
Framed-IP-Address = 255.255.255.254
Framed-MTU = 576
Service-Type = Framed-User
Framed-Protocol = PPP
Framed-Compression = Van-Jacobson-TCP-IP
EAP-Message = 0x010300060d20
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6f48fa08e12249461e835c0b48f47811
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 10.0.1.2:5007, id=132, length=370
User-Name = "test_user"
EAP-Message =
0x020300980d800000008e160301008901000085030148e33398cf612643dce87d17a75835909854655784d5fead9921013a69cd25e42042eae5e7218a3b678c826a0e8a907dd49e396e89b267dd63632257ac1bfe4a060018002f00350005000ac009c00ac013c0140032003800130004010000240000000e000c000009746573745f75736572000a00080006001700180019000b00020100
Message-Authenticator = 0x7fe5df0cc3def44f72f4e49d1507e300
NAS-IP-Address = 10.0.1.2
NAS-Identifier = "001ac1d4ee42"
NAS-Port = 117604353
NAS-Port-Id = "unit=7;subslot=0;port=40;vlanid=1"
NAS-Port-Type = Ethernet
Service-Type = Framed-User
Framed-Protocol = PPP
Calling-Station-Id = "0013-7737-714e"
State = 0x6f48fa08e12249461e835c0b48f47811
Vendor-25506-Attr-26 = 0x00000029
Vendor-25506-Attr-255 = 0x353530302d4549
Vendor-25506-Attr-60 =
0x302e302e302e302030303a31333a37373a33373a37313a3465
Vendor-25506-Attr-59 = 0x38e68c68
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 1
modcall[authorize]: module "mschap" returns noop for request 1
rlm_realm: No '\' in User-Name = "test_user", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "ntdomain" returns noop for request 1
rlm_eap: EAP packet type response id 3 length 152
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 1
users: Matched entry DEFAULT at line 152
users: Matched entry DEFAULT at line 171
users: Matched entry DEFAULT at line 183
modcall[authorize]: module "files" returns ok for request 1
modcall: leaving group authorize (returns updated) for request 1
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 1
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 0089], 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 056e], Certificate
TLS_accept: SSLv3 write certificate A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0074], CertificateRequest
TLS_accept: SSLv3 write certificate request A
TLS_accept: SSLv3 flush data
TLS_accept:error in SSLv3 read client certificate A
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
In SSL Handshake Phase
In SSL Accept mode
eaptls_process returned 13
modcall[authenticate]: module "eap" returns handled for request 1
modcall: leaving group authenticate (returns handled) for request 1
Sending Access-Challenge of id 132 to 10.0.1.2 port 5007
Framed-IP-Address = 255.255.255.254
Framed-MTU = 576
Service-Type = Framed-User
Framed-Protocol = PPP
Framed-Compression = Van-Jacobson-TCP-IP
EAP-Message =
0x0104040a0dc00000063b160301004a02000046030148e33557105b2e8f57896aa9d87d9e565f9c15edaf281bda32838fee59c01b9c20811700e761b89c04464662fa355d76242ba0767ba56c6141f4f43663d9332687002f00160301056e0b00056a0005670002503082024c308201b5a003020102020101300d06092a864886f70d01010505003063310b3009060355040613025541311330110603550408130a5a61706f726f7a736845310b3009060355040713025a50310c300a060355040a13035a415a310c300a060355040b13034d4953311630140603550403130d41646d696e6973747261746f72301e170d3038313030313037343430315a
EAP-Message =
0x170d3039313030313037343430315a305c310b3009060355040613025541311330110603550408130a5a61706f726f7a736865310b3009060355040713025a50310c300a060355040a13035a415a310c300a060355040b13034d4953310f300d0603550403130652414449555330819f300d06092a864886f70d010101050003818d0030818902818100ac35b8809afa0040f3ebc0af9fb56e2a4196f58fe6aee43df306d38e27a8d3da043dfffa300bf8e4b851e88612e6ddce19aaf601912a9a0cb400d736cef53ffdc07950598741653bd839b24e80399c02eaaa48627241d20b20be2df7311ce3b9f7524ffcb03045bcc56d3a0de7d3c382720512
EAP-Message =
0xbfb3d14e7b8418fcdd61f241930203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d01010505000381810037d0d8ed990d72b050cc7c62fb550e65ee8e6115634fa1cd470d344e19c5cf820e0de0c74db9da252d8c2dd9135c32311d9de10d77abe571ceb0c8e8451ba9f06a04aa12b18e917ccd85763f38d7daf3440f4c62c388019f79329d49fb8d2cae40d997db06a8ec8f5b02b92648fc7c9ebd8d75135e4fa4b804e33ec48db919400003113082030d30820276a003020102020900d603ee3f96fc604d300d06092a864886f70d01010505003063310b3009060355040613025541311330110603
EAP-Message =
0x550408130a5a61706f726f7a736845310b3009060355040713025a50310c300a060355040a13035a415a310c300a060355040b13034d4953311630140603550403130d41646d696e6973747261746f72301e170d3038313030313037343330345a170d3130313030313037343330345a3063310b3009060355040613025541311330110603550408130a5a61706f726f7a736845310b3009060355040713025a50310c300a060355040a13035a415a310c300a060355040b13034d4953311630140603550403130d41646d696e6973747261746f7230819f300d06092a864886f70d010101050003818d00308189028181009b2e0773ff8310e98addfa
EAP-Message = 0xb3458c421c935ca651f8f7ca3899d6506d065de4f53f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x4f8a9e9171ee9029400f09a30bcafb04
Finished request 1
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 10.0.1.2:5007, id=133, length=224
User-Name = "test_user"
EAP-Message = 0x020400060d00
Message-Authenticator = 0xfaef652a40d7640a666f521121c2ea8e
NAS-IP-Address = 10.0.1.2
NAS-Identifier = "001ac1d4ee42"
NAS-Port = 117604353
NAS-Port-Id = "unit=7;subslot=0;port=40;vlanid=1"
NAS-Port-Type = Ethernet
Service-Type = Framed-User
Framed-Protocol = PPP
Calling-Station-Id = "0013-7737-714e"
State = 0x4f8a9e9171ee9029400f09a30bcafb04
Vendor-25506-Attr-26 = 0x00000029
Vendor-25506-Attr-255 = 0x353530302d4549
Vendor-25506-Attr-60 =
0x302e302e302e302030303a31333a37373a33373a37313a3465
Vendor-25506-Attr-59 = 0x38e68c68
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 2
modcall[authorize]: module "mschap" returns noop for request 2
rlm_realm: No '\' in User-Name = "test_user", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "ntdomain" returns noop for request 2
rlm_eap: EAP packet type response id 4 length 6
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 2
users: Matched entry DEFAULT at line 152
users: Matched entry DEFAULT at line 171
users: Matched entry DEFAULT at line 183
modcall[authorize]: module "files" 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: 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 2
modcall: leaving group authenticate (returns handled) for request 2
Sending Access-Challenge of id 133 to 10.0.1.2 port 5007
Framed-IP-Address = 255.255.255.254
Framed-MTU = 576
Service-Type = Framed-User
Framed-Protocol = PPP
Framed-Compression = Van-Jacobson-TCP-IP
EAP-Message =
0x010502450d800000063b4837ac2b653e806f55c44239a6b0fb8de79a837bfe337e34804ee812673f27d00c28fb9735b2e7833b7a4211be3fbb997b2010c63c845b310be1ffd7226f4e9a7a238604f59873c29b47eb3a94fc3255baf8e09bc4580e685d6cef61016acd0203010001a381c83081c5301d0603551d0e041604144883dff930ad8def715cc306a93b716ed1dfa2f03081950603551d2304818d30818a80144883dff930ad8def715cc306a93b716ed1dfa2f0a167a4653063310b3009060355040613025541311330110603550408130a5a61706f726f7a736845310b3009060355040713025a50310c300a060355040a13035a415a310c30
EAP-Message =
0x0a060355040b13034d4953311630140603550403130d41646d696e6973747261746f72820900d603ee3f96fc604d300c0603551d13040530030101ff300d06092a864886f70d010105050003818100798409d24a31663705ea77a113da2d5283a687cc78561854f7205ff9e565cb2cbd7a133b1361b3bd93f58a0ac03872ca5fefccd451b7e1c7a5827ebe061ec2259436b5c3006895e8c49b356052161f6d3e4b9f7001397ca581bae2b178fc0da21f774a85f1290f71b82ee10bf23604613a0d354556ebf6d1937267a94f3a96ac16030100740d00006c020102006700653063310b3009060355040613025541311330110603550408130a5a61706f
EAP-Message =
0x726f7a736845310b3009060355040713025a50310c300a060355040a13035a415a310c300a060355040b13034d4953311630140603550403130d41646d696e6973747261746f720e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x15b748aa79357a594a6d17dceec16660
Finished request 2
Going to the next request
--- Walking the entire request list ---
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 10.0.1.2:5007, id=134, length=1176
User-Name = "test_user"
EAP-Message =
0x020503b80d80000003ae160301036e0b00025e00025b00025830820254308201bda003020102020104300d06092a864886f70d01010505003063310b3009060355040613025541311330110603550408130a5a61706f726f7a736845310b3009060355040713025a50310c300a060355040a13035a415a310c300a060355040b13034d4953311630140603550403130d41646d696e6973747261746f72301e170d3038313030313038313732395a170d3039313030313038313732395a3064310b3009060355040613025541311330110603550408130a5a61706f726f7a736865310b3009060355040713025a503110300e060355040a1307436f6d70
EAP-Message =
0x616e79310d300b060355040b1304556e69743112301006035504030c09746573745f7573657230819f300d06092a864886f70d010101050003818d0030818902818100a9ee71b5498f7bdf564f54cfa6baf8fed49b91898d4f44575921676b852648e7937be427797359b15233e95c9f2d13d7877c9ee036e1d8d836ee81e9d0207725ce279e36c78dd774597aaca40203d19858778edb4796da20871a567ede057416e3a70094e00961418020dce71371c2dcc9b169f2e907a1c209e41952917285e10203010001a317301530130603551d25040c300a06082b06010505070302300d06092a864886f70d01010505000381810048f90a4f3f55111eed
EAP-Message =
0xe345b10a9721c40f6694d4dde8168f3654b73f207ec39b5f84553abba36722188de5d30049c58989d59a140261e457e742f4dfc58dbfe38354ec8f4804f2116874cba1a55123b5ac0a497a6a402238e564dd183ab19d0b2b7fe293e64836808a11f0ce9c4992452b6fab72baf0e22c19599532ac73b4d31000008200800ace8ed81bd0e52139c80461ddb110b59da90912b8de54225803207816988467b36592760437f3fa426868fa39865bca083fe85ab2de57992f632a3a376d28ac1ce98f98b39c04e3fdfda043efa7915b96fd71f00295ba485a01aa0d5bd9b6cb365adf5d58428db14203854358d4a6fd84206eb358d6de45b3fa28309dcef1d8
EAP-Message =
0x0f000082008046823bbd7856b23283fbb758c31045b36c2fae082e316d785b8d6b1d5e754ae174af07c33267c4388094d6461a014b399566dd1e940797d9f3d1b05dd00f8bc4118897d9a286147ab2a393dcfd24c05ac82b045f425e326a2963b78fdee8c43839c36a0bef78583c3811130112ccf0526f0b5020404e2676b24ad22e986f007f1403010001011603010030da4c514cf7620cac74dfb42acc280cffc02da4cc9fead307c762cafb0bc6c70bd80d9ec997a26dc9621a41a04ef6edcc
Message-Authenticator = 0xd4511e3fe67c6f5460d17e37b0013f71
NAS-IP-Address = 10.0.1.2
NAS-Identifier = "001ac1d4ee42"
NAS-Port = 117604353
NAS-Port-Id = "unit=7;subslot=0;port=40;vlanid=1"
NAS-Port-Type = Ethernet
Service-Type = Framed-User
Framed-Protocol = PPP
Calling-Station-Id = "0013-7737-714e"
State = 0x15b748aa79357a594a6d17dceec16660
Vendor-25506-Attr-26 = 0x00000029
Vendor-25506-Attr-255 = 0x353530302d4549
Vendor-25506-Attr-60 =
0x302e302e302e302030303a31333a37373a33373a37313a3465
Vendor-25506-Attr-59 = 0x38e68c68
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 3
modcall[authorize]: module "mschap" returns noop for request 3
rlm_realm: No '\' in User-Name = "test_user", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "ntdomain" returns noop for request 3
rlm_eap: EAP packet type response id 5 length 253
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 3
users: Matched entry DEFAULT at line 152
users: Matched entry DEFAULT at line 171
users: Matched entry DEFAULT at line 183
modcall[authorize]: module "files" 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: Length Included
eaptls_verify returned 11
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0262], Certificate
chain-depth=1,
error=0
--> User-Name = test_user
--> BUF-Name = Administrator
--> subject = /C=UA/ST=ZaporozshE/L=ZP/O=ZAZ/OU=MIS/CN=Administrator
--> issuer = /C=UA/ST=ZaporozshE/L=ZP/O=ZAZ/OU=MIS/CN=Administrator
--> verify return:1
chain-depth=0,
error=0
--> User-Name = test_user
--> BUF-Name = test_user
--> subject = /C=UA/ST=Zaporozshe/L=ZP/O=Company/OU=Unit/CN=test_user
--> issuer = /C=UA/ST=ZaporozshE/L=ZP/O=ZAZ/OU=MIS/CN=Administrator
--> verify return:1
TLS_accept: SSLv3 read client certificate A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange
TLS_accept: SSLv3 read client key exchange A
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], CertificateVerify
TLS_accept: SSLv3 read certificate verify A
rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 read finished A
rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
TLS_accept: SSLv3 write change cipher spec A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 write finished A
TLS_accept: SSLv3 flush data
(other): SSL negotiation finished successfully
rlm_eap: SSL error error:00000000:lib(0):func(0):reason(0)
SSL Connection Established
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 134 to 10.0.1.2 port 5007
Framed-IP-Address = 255.255.255.254
Framed-MTU = 576
Service-Type = Framed-User
Framed-Protocol = PPP
Framed-Compression = Van-Jacobson-TCP-IP
EAP-Message =
0x010600450d800000003b140301000101160301003039b2085806fae2cc780147a6c5c6a148de142f57587022933ce20d28289c9c5b9c8d9177e937c4c617ea2f144cfcf594
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x772d4b5734ef3903668f83b084b488c6
Finished request 3
Going to the next request
Waking up in 5 seconds...
rad_recv: Access-Request packet from host 10.0.1.2:5007, id=135, length=224
User-Name = "test_user"
EAP-Message = 0x020600060d00
Message-Authenticator = 0xaf008159785a235658836c3e69ad6ff9
NAS-IP-Address = 10.0.1.2
NAS-Identifier = "001ac1d4ee42"
NAS-Port = 117604353
NAS-Port-Id = "unit=7;subslot=0;port=40;vlanid=1"
NAS-Port-Type = Ethernet
Service-Type = Framed-User
Framed-Protocol = PPP
Calling-Station-Id = "0013-7737-714e"
State = 0x772d4b5734ef3903668f83b084b488c6
Vendor-25506-Attr-26 = 0x00000029
Vendor-25506-Attr-255 = 0x353530302d4549
Vendor-25506-Attr-60 =
0x302e302e302e302030303a31333a37373a33373a37313a3465
Vendor-25506-Attr-59 = 0x38e68c68
Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 4
modcall[authorize]: module "mschap" returns noop for request 4
rlm_realm: No '\' in User-Name = "test_user", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[authorize]: module "ntdomain" returns noop for request 4
rlm_eap: EAP packet type response id 6 length 6
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
modcall[authorize]: module "eap" returns updated for request 4
users: Matched entry DEFAULT at line 152
users: Matched entry DEFAULT at line 171
users: Matched entry DEFAULT at line 183
modcall[authorize]: module "files" 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: Received EAP-TLS ACK message
rlm_eap_tls: ack handshake is finished
eaptls_verify returned 3
eaptls_process returned 3
rlm_eap: Freeing handler
modcall[authenticate]: module "eap" returns ok for request 4
modcall: leaving group authenticate (returns ok) for request 4
Login OK: [test_user/<no User-Password attribute>] (from client 10.0.1.2
port 117604353 cli 0013-7737-714e)
Sending Access-Accept of id 135 to 10.0.1.2 port 5007
Framed-IP-Address = 255.255.255.254
Framed-MTU = 576
Service-Type = Framed-User
Framed-Protocol = PPP
Framed-Compression = Van-Jacobson-TCP-IP
MS-MPPE-Recv-Key =
0xd9f6096ed691dd5ff7ca9ef552bb6ecb2721522c0cea2a8a60b2a15028dd0f1b
MS-MPPE-Send-Key =
0x984eb1cab0d9e759150b5294ead73e691bf647a7d61203f39e2c0d8b78272892
EAP-Message = 0x03060004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "test_user"
Finished request 4
Going to the next request
Waking up in 5 seconds...
rad_recv: Accounting-Request packet from host 10.0.1.2:5007, id=59,
length=217
User-Name = "test_user"
NAS-Identifier = "001ac1d4ee42"
NAS-Port = 117604353
NAS-Port-Id = "unit=7;subslot=0;port=40;vlanid=1"
NAS-Port-Type = Ethernet
Calling-Station-Id = "0013-7737-714e"
Acct-Status-Type = Start
Acct-Authentic = RADIUS
Acct-Session-Id = "71000302014213"
NAS-IP-Address = 10.0.1.2
Event-Timestamp = "Apr 2 2000 04:42:45 EEST"
Vendor-25506-Attr-26 = 0x00000029
Vendor-25506-Attr-1 = 0x00000000
Vendor-25506-Attr-2 = 0x00000000
Vendor-25506-Attr-4 = 0x00000000
Vendor-25506-Attr-5 = 0x00000000
Vendor-25506-Attr-22 = 0x00000000
Vendor-25506-Attr-60 =
0x302e302e302e302030303a31333a37373a33373a37313a3465
Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 5
modcall[preacct]: module "preprocess" returns noop for request 5
rlm_acct_unique: Hashing 'NAS-Port = 117604353,Client-IP-Address =
10.0.1.2,NAS-IP-Address = 10.0.1.2,Acct-Session-Id =
"71000302014213",User-Name = "test_user"'
rlm_acct_unique: Acct-Unique-Session-ID = "d6ce50f8bbb692bc".
modcall[preacct]: module "acct_unique" returns ok for request 5
rlm_realm: No '@' in User-Name = "test_user", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[preacct]: module "suffix" returns noop for request 5
modcall[preacct]: module "files" returns noop for request 5
modcall: leaving group preacct (returns ok) for request 5
Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 5
radius_xlat: '/var/log/radius/radacct/10.0.1.2/detail-20081001'
rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d
expands to /var/log/radius/radacct/10.0.1.2/detail-20081001
modcall[accounting]: module "detail" returns ok for request 5
modcall[accounting]: module "unix" returns ok for request 5
radius_xlat: '/var/log/radius/radutmp'
radius_xlat: 'test_user'
modcall[accounting]: module "radutmp" returns ok for request 5
modcall: leaving group accounting (returns ok) for request 5
Sending Accounting-Response of id 59 to 10.0.1.2 port 5007
Finished request 5
Going to the next request
Cleaning up request 5 ID 59 with timestamp 48e33558
Waking up in 5 seconds...
--- Walking the entire request list ---
Cleaning up request 0 ID 131 with timestamp 48e33557
Cleaning up request 1 ID 132 with timestamp 48e33557
Waking up in 1 seconds...
--- Walking the entire request list ---
Cleaning up request 2 ID 133 with timestamp 48e33558
Cleaning up request 3 ID 134 with timestamp 48e33558
Cleaning up request 4 ID 135 with timestamp 48e33558
Nothing to do. Sleeping until we see a request.
rad_recv: Accounting-Request packet from host 10.0.1.2:5007, id=60,
length=265
User-Name = "test_user"
NAS-Identifier = "001ac1d4ee42"
NAS-Port = 117604353
NAS-Port-Id = "unit=7;subslot=0;port=40;vlanid=1"
NAS-Port-Type = Ethernet
Calling-Station-Id = "0013-7737-714e"
Acct-Status-Type = Interim-Update
Acct-Authentic = RADIUS
Acct-Session-Id = "71000302014213"
NAS-IP-Address = 10.0.1.2
Event-Timestamp = "Apr 2 2000 04:43:44 EEST"
Acct-Session-Time = 59
Acct-Delay-Time = 1
Acct-Input-Octets = 16693
Acct-Input-Packets = 147
Acct-Output-Octets = 14624
Acct-Output-Packets = 162
Acct-Input-Gigawords = 0
Acct-Output-Gigawords = 0
Vendor-25506-Attr-26 = 0x00000029
Vendor-25506-Attr-1 = 0x00000000
Vendor-25506-Attr-2 = 0x00000000
Vendor-25506-Attr-4 = 0x00000000
Vendor-25506-Attr-5 = 0x00000000
Vendor-25506-Attr-22 = 0x00000000
Vendor-25506-Attr-60 =
0x302e302e302e302030303a31333a37373a33373a37313a3465
Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 6
modcall[preacct]: module "preprocess" returns noop for request 6
rlm_acct_unique: Hashing 'NAS-Port = 117604353,Client-IP-Address =
10.0.1.2,NAS-IP-Address = 10.0.1.2,Acct-Session-Id =
"71000302014213",User-Name = "test_user"'
rlm_acct_unique: Acct-Unique-Session-ID = "d6ce50f8bbb692bc".
modcall[preacct]: module "acct_unique" returns ok for request 6
rlm_realm: No '@' in User-Name = "test_user", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[preacct]: module "suffix" returns noop for request 6
modcall[preacct]: module "files" returns noop for request 6
modcall: leaving group preacct (returns ok) for request 6
Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 6
radius_xlat: '/var/log/radius/radacct/10.0.1.2/detail-20081001'
rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d
expands to /var/log/radius/radacct/10.0.1.2/detail-20081001
modcall[accounting]: module "detail" returns ok for request 6
modcall[accounting]: module "unix" returns noop for request 6
radius_xlat: '/var/log/radius/radutmp'
radius_xlat: 'test_user'
modcall[accounting]: module "radutmp" returns ok for request 6
modcall: leaving group accounting (returns ok) for request 6
Sending Accounting-Response of id 60 to 10.0.1.2 port 5007
Finished request 6
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 6 ID 60 with timestamp 48e33593
Nothing to do. Sleeping until we see a request.
rad_recv: Accounting-Request packet from host 10.0.1.2:5007, id=61,
length=271
User-Name = "test_user"
NAS-Identifier = "001ac1d4ee42"
NAS-Port = 117604353
NAS-Port-Id = "unit=7;subslot=0;port=40;vlanid=1"
NAS-Port-Type = Ethernet
Calling-Station-Id = "0013-7737-714e"
Acct-Status-Type = Stop
Acct-Authentic = RADIUS
Acct-Session-Id = "71000302014213"
NAS-IP-Address = 10.0.1.2
Event-Timestamp = "Apr 2 2000 04:44:45 EEST"
Acct-Session-Time = 120
Acct-Delay-Time = 0
Acct-Input-Octets = 23022
Acct-Input-Packets = 219
Acct-Output-Octets = 27604
Acct-Output-Packets = 322
Acct-Input-Gigawords = 0
Acct-Output-Gigawords = 0
Acct-Terminate-Cause = Lost-Carrier
Vendor-25506-Attr-26 = 0x00000029
Vendor-25506-Attr-1 = 0x00000000
Vendor-25506-Attr-2 = 0x00000000
Vendor-25506-Attr-4 = 0x00000000
Vendor-25506-Attr-5 = 0x00000000
Vendor-25506-Attr-22 = 0x00000000
Vendor-25506-Attr-60 =
0x302e302e302e302030303a31333a37373a33373a37313a3465
Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 7
modcall[preacct]: module "preprocess" returns noop for request 7
rlm_acct_unique: Hashing 'NAS-Port = 117604353,Client-IP-Address =
10.0.1.2,NAS-IP-Address = 10.0.1.2,Acct-Session-Id =
"71000302014213",User-Name = "test_user"'
rlm_acct_unique: Acct-Unique-Session-ID = "d6ce50f8bbb692bc".
modcall[preacct]: module "acct_unique" returns ok for request 7
rlm_realm: No '@' in User-Name = "test_user", looking up realm NULL
rlm_realm: No such realm "NULL"
modcall[preacct]: module "suffix" returns noop for request 7
modcall[preacct]: module "files" returns noop for request 7
modcall: leaving group preacct (returns ok) for request 7
Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 7
radius_xlat: '/var/log/radius/radacct/10.0.1.2/detail-20081001'
rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d
expands to /var/log/radius/radacct/10.0.1.2/detail-20081001
modcall[accounting]: module "detail" returns ok for request 7
modcall[accounting]: module "unix" returns ok for request 7
radius_xlat: '/var/log/radius/radutmp'
radius_xlat: 'test_user'
modcall[accounting]: module "radutmp" returns ok for request 7
modcall: leaving group accounting (returns ok) for request 7
Sending Accounting-Response of id 61 to 10.0.1.2 port 5007
Finished request 7
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 7 ID 61 with timestamp 48e335d0
Nothing to do. Sleeping until we see a request.
More information about the Freeradius-Users
mailing list