Additional EAP-TLS Logging Option
Ross, Michael
michael.ross2 at boeing.com
Tue Sep 7 17:31:14 CEST 2010
Alan DeKok wrote:
> Read raddb/sites-enabled/default. Look for "TLS-Cert".
>
> These are attributes that you can use in *any* logging. See the "log"
> section of radiusd.conf for custom log messages. See the "linelog"
> module for logging miscellaneous text.
Thanks. I've got it working now where it logs things correctly for successful authentications, but I'm not having any luck getting the logging to work when the authentication fails. The code that generates the attributes is being executed, but when it logs them they all show up as empty. Here is my post-auth configuration:
post-auth {
update reply {
x509_CA_Serial += "%{TLS-Cert-Serial}"
x509_CA_Expiration += "%{TLS-Cert-Expiration}"
x509_CA_Issuer += "%{TLS-Cert-Issuer}"
x509_CA_Subject += "%{TLS-Cert-Subject}"
x509_Client_Serial += "%{TLS-Client-Cert-Serial}"
x509_Client_Expiration += "%{TLS-Client-Cert-Expiration}"
x509_Client_Issuer += "%{TLS-Client-Cert-Issuer}"
x509_Client_Subject += "%{TLS-Client-Cert-Subject}"
}
post_auth_log
Post-Auth-Type REJECT {
update reply {
Failure_Reason += "%{Module-Failure-Message}"
x509_CA_Serial += "%{TLS-Cert-Serial}"
x509_CA_Expiration += "%{TLS-Cert-Expiration}"
x509_CA_Issuer += "%{TLS-Cert-Issuer}"
x509_CA_Subject += "%{TLS-Cert-Subject}"
x509_Client_Serial += "%{TLS-Client-Cert-Serial}"
x509_Client_Expiration += "%{TLS-Client-Cert-Expiration}"
x509_Client_Issuer += "%{TLS-Client-Cert-Issuer}"
x509_Client_Subject += "%{TLS-Client-Cert-Subject}"
}
post_auth_log
}
}
Here's an example log from a request where the common name check within cbtls_verify failed:
Mon Sep 6 21:32:59 2010
Packet-Type = Access-Reject
Failure_Reason = "TLS Alert write:fatal:certificate unknown"
x509_CA_Serial = ""
x509_CA_Expiration = ""
x509_CA_Issuer = ""
x509_CA_Subject = ""
x509_Client_Serial = ""
x509_Client_Expiration = ""
x509_Client_Issuer = ""
x509_Client_Subject = ""
Note: This is all with the patch submitted in the separate email.
Any suggestions or ideas?
Thanks,
Mike Ross
Here is the radiusd -X output:
FreeRADIUS Version 2.1.10, for host x86_64-unknown-linux-gnu, built on Sep 6 2010 at 21:00:35
Copyright (C) 1999-2009 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License v2.
Starting - reading configuration files ...
including configuration file /home/mross/Documents/FreeRadius/build/etc/raddb/radiusd.conf
including files in directory /home/mross/Documents/FreeRadius/build/etc/raddb/modules/
including configuration file /home/mross/Documents/FreeRadius/build/etc/raddb/modules/detail
including configuration file /home/mross/Documents/FreeRadius/build/etc/raddb/modules/expr
including configuration file /home/mross/Documents/FreeRadius/build/etc/raddb/eap.conf
including files in directory /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/
including configuration file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
including dictionary file /home/mross/Documents/FreeRadius/build/etc/raddb/dictionary
main {
prefix = "/home/mross/Documents/FreeRadius/build"
localstatedir = "/home/mross/Documents/FreeRadius/build/var"
logdir = "/home/mross/Documents/FreeRadius/build/var/log/radius"
libdir = "/home/mross/Documents/FreeRadius/build/lib"
radacctdir = "/home/mross/Documents/FreeRadius/build/var/log/radius/radacct"
hostname_lookups = no
max_request_time = 30
cleanup_delay = 5
max_requests = 1024
pidfile = "/home/mross/Documents/FreeRadius/build/var/run/radiusd/radiusd.pid"
checkrad = "/home/mross/Documents/FreeRadius/build/sbin/checkrad"
debug_level = 0
proxy_requests = no
log {
stripped_names = no
auth = no
auth_badpass = no
auth_goodpass = no
}
security {
max_attributes = 200
reject_delay = 1
status_server = yes
}
}
radiusd: #### Loading Realms and Home Servers ####
radiusd: #### Loading Clients ####
radiusd: #### Instantiating modules ####
instantiate {
Module: Linked to module rlm_expr
Module: Instantiating module "expr" from file /home/mross/Documents/FreeRadius/build/etc/raddb/modules/expr
}
radiusd: #### Loading Virtual Servers ####
server 802.1x { # from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
modules {
Module: Checking authenticate {...} for more modules to load
Module: Linked to module rlm_eap
Module: Instantiating module "eap" from file /home/mross/Documents/FreeRadius/build/etc/raddb/eap.conf
eap {
default_eap_type = "tls"
timer_expire = 60
ignore_unknown_eap_types = no
cisco_accounting_username_bug = no
max_sessions = 4096
}
Module: Linked to sub-module rlm_eap_tls
Module: Instantiating eap-tls
tls {
rsa_key_exchange = no
dh_key_exchange = yes
rsa_key_length = 512
dh_key_length = 512
verify_depth = 0
CA_path = "/home/mross/Documents/FreeRadius/build/etc/raddb/certs/crl"
pem_file_type = yes
private_key_file = "/home/mross/Documents/FreeRadius/build/etc/raddb/certs/server.pem"
certificate_file = "/home/mross/Documents/FreeRadius/build/etc/raddb/certs/server.pem"
CA_file = "/home/mross/Documents/FreeRadius/build/etc/raddb/certs/ca.pem"
private_key_password = "1234"
dh_file = "/home/mross/Documents/FreeRadius/build/etc/raddb/certs/dh"
random_file = "/home/mross/Documents/FreeRadius/build/etc/raddb/certs/random"
fragment_size = 1024
include_length = yes
check_crl = no
check_cert_cn = "valid.radius.client.boeing.com"
cipher_list = "DEFAULT"
check_cert_issuer = "/O=Boeing/OU=Integration Labs/CN=Test Issuing CA"
cache {
enable = no
lifetime = 24
max_entries = 255
}
}
Module: Checking authorize {...} for more modules to load
Module: Linked to module rlm_detail
Module: Instantiating module "auth_log" from file /home/mross/Documents/FreeRadius/build/etc/raddb/modules/detail
detail auth_log {
detailfile = "/home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
Module: Checking post-auth {...} for more modules to load
Module: Instantiating module "post_auth_log" from file /home/mross/Documents/FreeRadius/build/etc/raddb/modules/detail
detail post_auth_log {
detailfile = "/home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Certs.log"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
} # modules
} # server
server { # from file /home/mross/Documents/FreeRadius/build/etc/raddb/radiusd.conf
modules {
} # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = *
port = 0
client localhost {
ipaddr = 127.0.0.1
require_message_authenticator = yes
secret = "radius"
}
}
Listening on authentication address * port 1812 as server 802.1x
...
rad_recv: Access-Request packet from host 127.0.0.1 port 41736, id=0, length=122
User-Name = "revoked"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x0200000c017265766f6b6564
Message-Authenticator = 0x34b88010164dae08466e82105d6cc3b0
server 802.1x {
# Executing section authorize from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authorize {...}
[eap] EAP packet type response id 0 length 12
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[auth_log] expand: /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log -> /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log expands to /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] expand: %t -> Mon Sep 6 21:32:59 2010
++[auth_log] returns ok
Found Auth-Type = EAP
# Executing group from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type tls
[tls] Requiring client certificate
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
} # server 802.1x
Sending Access-Challenge of id 0 to 127.0.0.1 port 41736
EAP-Message = 0x010100060d20
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x93c976a093c87bf74064bdd70ea2ce5a
Finished request 7.
Going to the next request
Waking up in 3.6 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 41736, id=1, length=221
User-Name = "revoked"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x0201005d0d0016030100520100004e03014c85c07b6ef0254b1c5e67dcc7d434c8cf5dfbbb47e268059c980e3508a55d8b00002600390038003500160013000a00330032002f0005000400150012000900140011000800060003020100
State = 0x93c976a093c87bf74064bdd70ea2ce5a
Message-Authenticator = 0x642240c2ca740d3cc52481800fc0e2c4
server 802.1x {
# Executing section authorize from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authorize {...}
[eap] EAP packet type response id 1 length 93
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[auth_log] expand: /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log -> /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log expands to /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] expand: %t -> Mon Sep 6 21:32:59 2010
++[auth_log] returns ok
Found Auth-Type = EAP
# Executing group from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
[tls] eaptls_verify returned 7
[tls] Done initial handshake
[tls] (other): before/accept initialization
[tls] TLS_accept: before/accept initialization
[tls] <<< TLS 1.0 Handshake [length 0052], ClientHello
[tls] TLS_accept: SSLv3 read client hello A
[tls] >>> TLS 1.0 Handshake [length 002a], ServerHello
[tls] TLS_accept: SSLv3 write server hello A
[tls] >>> TLS 1.0 Handshake [length 0827], Certificate
[tls] TLS_accept: SSLv3 write certificate A
[tls] >>> TLS 1.0 Handshake [length 018d], ServerKeyExchange
[tls] TLS_accept: SSLv3 write key exchange A
[tls] >>> TLS 1.0 Handshake [length 00a1], CertificateRequest
[tls] TLS_accept: SSLv3 write certificate request A
[tls] TLS_accept: SSLv3 flush data
[tls] TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
[tls] eaptls_process returned 13
++[eap] returns handled
} # server 802.1x
Sending Access-Challenge of id 1 to 127.0.0.1 port 41736
EAP-Message = 0x010204000dc000000a93160301002a0200002603014c85c07b5541e9efd0b1a03acfcd769fd872efe79184b008930685ea565e65fd0000390116030108270b0008230008200002f4308202f030820259a0030201020203008002300d06092a864886f70d01010505003046310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311830160603550403130f546573742049737375696e67204341301e170d3130303632383230353335365a170d3131303632383230353335365a304f310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c61
EAP-Message = 0x62733121301f060355040313187261646975732e7365727665722e626f65696e672e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100d3155c38f186b00cf87885b31ff5917dbbd3c358c9f5db8f91510ed05c87bf6725763d4b0b982e042b9466129ca1bdc6e39eb90af1e7303b84d0d3754921420c173b1e7c6335e2c7c322adf2d542329976097435456db12144be332b75c96c0944f7f8faf9e689c9158d4c51257dd5144efc70f21a676ac6d2663af4e4ff54070203010001a381e23081df301d0603551d0e04160414209b0bac45d59fb4b4a9212855ca080fc804126b300e0603551d0f0101ff0404030205a030
EAP-Message = 0x2a0603551d1f04233021301fa01da01b8619687474703a2f2f7777772e626f65696e672e636f6d2f63726c306d0603551d2304663064801496c24ba1a2a1646c74e23852a2783042c7c1bde2a147a4453043310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311530130603550403130c5465737420526f6f74204341820300800130130603551d25040c300a06082b06010505070301300d06092a864886f70d0101050500038181000e0fc64d4594eb457bba4091d7a272ad91082d26477bbc0152d637e8264db614373f83a4399f7d32deeb87db12109acd8a3cbb8c75792832c7d37f
EAP-Message = 0x2e0668c457c2cffc12e5bdc83f709d9cc111ce75c50ac7b7f79ba6f07447e30a25de66aaec523dc2635821e5b5e9fc3a29cc678909fa30afe136be1b089c086a19a6fe3a690002903082028c308201f5a0030201020203008001300d06092a864886f70d01010505003043310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311530130603550403130c5465737420526f6f74204341301e170d3130303632383230353034345a170d3132303231383230353034345a3046310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c61627331
EAP-Message = 0x1830160603550403130f5465
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x93c976a092cb7bf74064bdd70ea2ce5a
Finished request 8.
Going to the next request
Waking up in 3.6 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 41736, id=2, length=134
User-Name = "revoked"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x020200060d00
State = 0x93c976a092cb7bf74064bdd70ea2ce5a
Message-Authenticator = 0xb053bb841c26283ad8f5c21c1e223043
server 802.1x {
# Executing section authorize from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authorize {...}
[eap] EAP packet type response id 2 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[auth_log] expand: /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log -> /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log expands to /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] expand: %t -> Mon Sep 6 21:32:59 2010
++[auth_log] returns ok
Found Auth-Type = EAP
# Executing group from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
[tls] Received TLS ACK
[tls] ACK handshake fragment handler
[tls] eaptls_verify returned 1
[tls] eaptls_process returned 13
++[eap] returns handled
} # server 802.1x
Sending Access-Challenge of id 2 to 127.0.0.1 port 41736
EAP-Message = 0x010304000dc000000a9373742049737375696e6720434130819f300d06092a864886f70d010101050003818d0030818902818100af2b2753c03e4a4b4a4cc484300d9c7f9b2f5c500ce3af01036eba55ba2e943ca1685a7f93413c5509a3b46658b561010bed73c11d85f8436040783ba03285917c5c5cde64e978758f53665588c0feb14d5c51f5d2ef864aff87d829660c19f6d638680c5c242c808866dc61eff9ecef058cd036d5162d84d5d2b69ca3b303870203010001a3818a308187300c0603551d13040530030101ff300b0603551d0f040403020186302a0603551d1f04233021301fa01da01b8619687474703a2f2f7777772e626f65696e
EAP-Message = 0x672e636f6d2f63726c301d0603551d0e0416041496c24ba1a2a1646c74e23852a2783042c7c1bde2301f0603551d23041830168014ca3a1f841d11917e92af5a133b829d1c19622225300d06092a864886f70d01010505000381810034907042242eb4977e8e97b9d2bbd5bb05535ea42c56f65ede6e85a48e8d1b60f89d832f1a892c56fd390c20dd3039cfeedb3590d7c3895faf89ab5b00464a33f522379707a4b44ed35b6c8c232ef8ec12878eab669e0fb25cfc0b61b8df749e311710a61ea4881b33b71d0f4ae832eec77b45b01978e578e1620dcb0179cd340002933082028f308201f8a003020102020900a04aeb4bb318e1b9300d06092a86
EAP-Message = 0x4886f70d01010505003043310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311530130603550403130c5465737420526f6f74204341301e170d3130303632383230343130355a170d3132303632373230343130355a3043310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311530130603550403130c5465737420526f6f7420434130819f300d06092a864886f70d010101050003818d0030818902818100d3e745a362bf42e0e655c26ec00210ea0d08cdb89b7770cdb6f614b24bc44d132ba21d513ad35cd024f32d3742
EAP-Message = 0xc62ac413603f5084a7e88c9399375f2063d07d2fa06dd0b2bd18c99da8c1b8208f762f68ec3e42c571a80eed00e8d7a04e09edd87cc62bfc231b391823cedca81dbab493babf896ee9ba35a6695ec640e2fef70203010001a3818a308187300c0603551d13040530030101ff300b0603551d0f040403020186302a0603551d1f04233021301fa01da01b8619687474703a2f2f7777772e626f65696e672e636f6d2f63726c301d0603551d0e04160414ca3a1f841d11917e92af5a133b829d1c19622225301f0603551d23041830168014ca3a1f841d11917e92af5a133b829d1c19622225300d06092a864886f70d0101050500038181005ed06447c7
EAP-Message = 0xaa67bc0b7a9a4c1b077c4c11
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x93c976a091ca7bf74064bdd70ea2ce5a
Finished request 9.
Going to the next request
Waking up in 3.6 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 41736, id=3, length=134
User-Name = "revoked"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x020300060d00
State = 0x93c976a091ca7bf74064bdd70ea2ce5a
Message-Authenticator = 0x46c759e73f4679f66cff50b898b33548
server 802.1x {
# Executing section authorize from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authorize {...}
[eap] EAP packet type response id 3 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[auth_log] expand: /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log -> /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log expands to /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] expand: %t -> Mon Sep 6 21:32:59 2010
++[auth_log] returns ok
Found Auth-Type = EAP
# Executing group from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
[tls] Received TLS ACK
[tls] ACK handshake fragment handler
[tls] eaptls_verify returned 1
[tls] eaptls_process returned 13
++[eap] returns handled
} # server 802.1x
Sending Access-Challenge of id 3 to 127.0.0.1 port 41736
EAP-Message = 0x010402b10d8000000a930cdd42b0902d3f9f6b44d919f7adc94c6f6cb988de1bf4fa8f6f63e852e176876520913ce4d258357b377b5344d335d1cf720e8e603a3bc031900650a0ae8cb08414d7ccff4d2586ef18b564f3f270036cf5fcec77fa71174ffa7a48da15708cd4f39c2f932b6364c716b150f536cf160301018d0c0001890080a8e2983a7e702cf8c9bf9ec8338205d62e2de224ae42cbfd7aaceae1732c5adc6e086a6a7cc4609bb3f3d68699c7ae503c4db864389293897bfc8cc33cba8055236a75f53c93c359bea6f6540967fee5d90e19b3e4a9e4a7d1850147556aa78a2c04061bec997b1d9fcd07af439844feb9039a9bdf4cb1f099
EAP-Message = 0xfd4806c510941b00010200802aa2c61f6f37f94430c4b3dbb279108ebb03a230b8b429a801b61197621af5c029700708e859b0e4b0db7e649821112ca5444602a0d93bf7d0265990a1ab646c31e16fb0a78a01e3deca9f3d2ba42f855ce39a8fbc8c9b1b0c305b45fc696e1b994d7cfd3a77fa660292ccc6126b8b4c86aad5e88705b6933d272c3eb2964c290080ccfa270f4cf40ad6dae99668f61a3c44d80b3e37b8dc0e07780e0716275834ff978c0380e1bb2136ad6c24ac96df4b4e3e9bce267152e538f7cc367fa10eed98bbdf1380f9e74d7d850da981934a5f1e4977374aa5f0cced621a471c862cc80b5bf8c7509f3e9aea6920d819c0ce50
EAP-Message = 0x9083c655c3984e607cde1f0e497c2b695d16030100a10d000099050304010240009100453043310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311530130603550403130c5465737420526f6f7420434100483046310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311830160603550403130f546573742049737375696e672043410e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x93c976a090cd7bf74064bdd70ea2ce5a
Finished request 10.
Going to the next request
Waking up in 3.6 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 41736, id=4, length=1546
User-Name = "revoked"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x020405800dc00000098d16030108370b0008330008300003043082030030820269a0030201020203008004300d06092a864886f70d01010505003046310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311830160603550403130f546573742049737375696e67204341301e170d3130303632383230353530385a170d3131303632383230353530385a3057310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c61627331293027060355040313207265766f6b65642e7261646975732e636c69656e742e626f65696e672e636f6d3081
EAP-Message = 0x9f300d06092a864886f70d010101050003818d0030818902818100c1723fe0a67647a9005d71c9e69e39dc05a73c48bf00a907e3cb2f0a68120aa1c6d36fca1a2012f273a32b11941ec18aaa0eb3dfe5d00598f704cef07aebfb04ead5e18a938b92b5731878a5ca35a79368deec65a2609df22c9e8bd65ed49189e4ba4256affe0370611b315bd8984af00966c906fafcc9d8e8a79cbdc4e4a01f0203010001a381ea3081e730090603551d1304023000300b0603551d0f0404030203a8302a0603551d1f04233021301fa01da01b8619687474703a2f2f7777772e626f65696e672e636f6d2f63726c301d0603551d0e04160414738d69ee7829458c
EAP-Message = 0x65f7106cd2397832bf35b3d0306d0603551d2304663064801496c24ba1a2a1646c74e23852a2783042c7c1bde2a147a4453043310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311530130603550403130c5465737420526f6f74204341820300800130130603551d25040c300a06082b06010505070302300d06092a864886f70d0101050500038181009ef238103cbbe445355f2784e348e4a61d740a7a2fbb39a176331bc745f0c3c96bb0f39a8a582d742765edfc32e1548d5d33a36a02bce52b3d0e0f4afed6418327a3b7fbf9e60455c4ad76492717b5504120e1369c20141c979b
EAP-Message = 0x16a17b2e922d4f35fce56ae2119828f2fa53a4371cabae11f31e1864ab56c4934b580767ff9c0002903082028c308201f5a0030201020203008001300d06092a864886f70d01010505003043310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311530130603550403130c5465737420526f6f74204341301e170d3130303632383230353034345a170d3132303231383230353034345a3046310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311830160603550403130f546573742049737375696e6720434130819f300d06
EAP-Message = 0x092a864886f70d010101050003818d0030818902818100af2b2753c03e4a4b4a4cc484300d9c7f9b2f5c500ce3af01036eba55ba2e943ca1685a7f93413c5509a3b46658b561010bed73c11d85f8436040783ba03285917c5c5cde64e978758f53665588c0feb14d5c51f5d2ef864aff87d829660c19f6d638680c5c242c808866dc61eff9ecef058cd036d5162d84d5d2b69ca3b303870203010001a3818a308187300c0603551d13040530030101ff300b0603551d0f040403020186302a0603551d1f04233021301fa01da01b8619687474703a2f2f7777772e626f65696e672e636f6d2f63726c301d0603551d0e0416041496c24ba1a2a1646c74
EAP-Message = 0xe23852a2783042c7c1bde2301f0603551d23041830168014ca3a1f841d11917e92af5a133b829d1c19622225300d06092a864886f70d01010505000381810034907042242eb4977e8e97b9d2bbd5bb05535ea42c56f65ede6e85a48e8d1b60f89d832f1a892c56fd390c20dd3039cfeedb3590d7c3895faf89ab5b00464a33f522379707a4b44ed35b6c8c232ef8ec
State = 0x93c976a090cd7bf74064bdd70ea2ce5a
Message-Authenticator = 0x9fdf113724143a85a8dd88c18a71bb19
server 802.1x {
# Executing section authorize from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authorize {...}
[eap] EAP packet type response id 4 length 253
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[auth_log] expand: /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log -> /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log expands to /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] expand: %t -> Mon Sep 6 21:32:59 2010
++[auth_log] returns ok
Found Auth-Type = EAP
# Executing group from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
TLS Length 2445
[tls] Received EAP-TLS First Fragment of the message
[tls] eaptls_verify returned 9
[tls] eaptls_process returned 13
++[eap] returns handled
} # server 802.1x
Sending Access-Challenge of id 4 to 127.0.0.1 port 41736
EAP-Message = 0x010500060d00
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x93c976a097cc7bf74064bdd70ea2ce5a
Finished request 11.
Going to the next request
Waking up in 3.5 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 41736, id=5, length=1189
User-Name = "revoked"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x0205041d0d0012878eab669e0fb25cfc0b61b8df749e311710a61ea4881b33b71d0f4ae832eec77b45b01978e578e1620dcb0179cd340002933082028f308201f8a003020102020900a04aeb4bb318e1b9300d06092a864886f70d01010505003043310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c616273311530130603550403130c5465737420526f6f74204341301e170d3130303632383230343130355a170d3132303632373230343130355a3043310f300d060355040a1306426f65696e6731193017060355040b1310496e746567726174696f6e204c61627331153013060355040313
EAP-Message = 0x0c5465737420526f6f7420434130819f300d06092a864886f70d010101050003818d0030818902818100d3e745a362bf42e0e655c26ec00210ea0d08cdb89b7770cdb6f614b24bc44d132ba21d513ad35cd024f32d3742c62ac413603f5084a7e88c9399375f2063d07d2fa06dd0b2bd18c99da8c1b8208f762f68ec3e42c571a80eed00e8d7a04e09edd87cc62bfc231b391823cedca81dbab493babf896ee9ba35a6695ec640e2fef70203010001a3818a308187300c0603551d13040530030101ff300b0603551d0f040403020186302a0603551d1f04233021301fa01da01b8619687474703a2f2f7777772e626f65696e672e636f6d2f63726c30
EAP-Message = 0x1d0603551d0e04160414ca3a1f841d11917e92af5a133b829d1c19622225301f0603551d23041830168014ca3a1f841d11917e92af5a133b829d1c19622225300d06092a864886f70d0101050500038181005ed06447c7aa67bc0b7a9a4c1b077c4c110cdd42b0902d3f9f6b44d919f7adc94c6f6cb988de1bf4fa8f6f63e852e176876520913ce4d258357b377b5344d335d1cf720e8e603a3bc031900650a0ae8cb08414d7ccff4d2586ef18b564f3f270036cf5fcec77fa71174ffa7a48da15708cd4f39c2f932b6364c716b150f536cf16030100861000008200807358dd170ee10d6ae05ef6268d9bcbddcaea4600807449c1fd34ccc0209581c3
EAP-Message = 0x3c970de15d3183933176296ad5c12c08c86d006478bb7756125697ca4a657366e291867ba4c75d89ef8bc482be6fb168f2f15ead669e21e008a7d09fefef76dc5c7bb8c72e50a40b2f9e1d4cbfff97638818fcaee912881ee39914f7471a44bf16030100860f0000820080619ad4903355db107a056da0c4cc926dfb0e2c4b3d1c4493a769bd6fe106295dff843919d955edd22afb0b73015c7b7d6e8e782ba1c10fb0690659d76a84c7e8d1a9d51fdb00855d662e12b59d52d3b1353b2ce94add122dca8bd3de1e10468b7e9f97a17f6c56c8489df968a86392f496bc2028b3f6a68e7bbf1488176ee1fb1403010001011603010030b8cb62a16164bf
EAP-Message = 0x18190bd8efa1c701add0b5bf12043b254b726c309b1819add1aac148c88372b442fee43eb26ceb668c
State = 0x93c976a097cc7bf74064bdd70ea2ce5a
Message-Authenticator = 0xde36629679b88d12fd0c9dc5ee83ef1c
server 802.1x {
# Executing section authorize from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authorize {...}
[eap] EAP packet type response id 5 length 253
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
[auth_log] expand: /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log -> /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log expands to /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Packets.log
[auth_log] expand: %t -> Mon Sep 6 21:32:59 2010
++[auth_log] returns ok
Found Auth-Type = EAP
# Executing group from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/tls
[eap] processing type tls
[tls] Authenticate
[tls] processing EAP-TLS
[tls] eaptls_verify returned 7
[tls] Done initial handshake
[tls] <<< TLS 1.0 Handshake [length 0837], Certificate
[tls] chain-depth=2,
[tls] error=0
[tls] --> User-Name = revoked
[tls] --> BUF-Name = ?
[tls] --> subject = ùeÊ_
[tls] --> issuer = `W?ßÿ
[tls] --> verify return:1
[tls] chain-depth=1,
[tls] error=0
[tls] --> User-Name = revoked
[tls] --> BUF-Name = Test Issuing CA
[tls] --> subject = /O=Boeing/OU=Integration Labs/CN=Test Issuing CA
[tls] --> issuer = /O=Boeing/OU=Integration Labs/CN=Test Root CA
[tls] --> verify return:1
[tls] expand: valid.radius.client.boeing.com -> valid.radius.client.boeing.com
[tls] checking certificate CN (revoked.radius.client.boeing.com) with xlat'ed value (valid.radius.client.boeing.com)
rlm_eap_tls: Certificate CN (revoked.radius.client.boeing.com) does not match specified value (valid.radius.client.boeing.com)!
[tls] chain-depth=0,
[tls] error=0
[tls] --> User-Name = revoked
[tls] --> BUF-Name = revoked.radius.client.boeing.com
[tls] --> subject = /O=Boeing/OU=Integration Labs/CN=revoked.radius.client.boeing.com
[tls] --> issuer = /O=Boeing/OU=Integration Labs/CN=Test Issuing CA
[tls] --> verify return:0
[tls] >>> TLS 1.0 Alert [length 0002], fatal certificate_unknown
TLS Alert write:fatal:certificate unknown
TLS_accept: error in SSLv3 read client certificate B
rlm_eap: SSL error error:140890B2:SSL routines:SSL3_GET_CLIENT_CERTIFICATE:no certificate returned
SSL: SSL_read failed in a system call (-1), TLS session fails.
TLS receive handshake failed during operation
[tls] eaptls_process returned 4
[eap] Handler failed in EAP/tls
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
} # server 802.1x
Using Post-Auth-Type Reject
# Executing group from file /home/mross/Documents/FreeRadius/build/etc/raddb/sites-enabled/802.1x
+- entering group REJECT {...}
expand: %{Module-Failure-Message} -> TLS Alert write:fatal:certificate unknown
expand: %{TLS-Cert-Serial} ->
expand: %{TLS-Cert-Expiration} ->
expand: %{TLS-Cert-Issuer} ->
expand: %{TLS-Cert-Subject} ->
expand: %{TLS-Client-Cert-Serial} ->
expand: %{TLS-Client-Cert-Expiration} ->
expand: %{TLS-Client-Cert-Issuer} ->
expand: %{TLS-Client-Cert-Subject} ->
++[reply] returns noop
[post_auth_log] expand: /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Certs.log -> /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Certs.log
[post_auth_log] /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Certs.log expands to /home/mross/Documents/FreeRadius/build/var/log/radius/radacct/Certs.log
[post_auth_log] expand: %t -> Mon Sep 6 21:32:59 2010
++[post_auth_log] returns ok
Delaying reject of request 12 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 12
Sending Access-Reject of id 5 to 127.0.0.1 port 41736
EAP-Message = 0x04050004
Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 2.5 seconds.
More information about the Freeradius-Devel
mailing list