Autz-Type New-TLS-Connection : tcp sessions stalled in close_wait state
Alan DeKok
aland at deployingradius.com
Tue Jan 18 12:49:15 UTC 2022
On Jan 13, 2022, at 10:12 AM, Arnaud LAURIOU <arnaud.lauriou at renater.fr> wrote:
> TCP sessions rejected by the tls virtual server (certificate expired, TLS protocol
> version, no certificate, ...) are in TIME_WAIT state and associated socket seems
> to be in closing process. Fine.
If they're rejected, then the socket should be closed. Using "-Xx" will give more information.
Or, you could add more debug information yourself to src/main/tls_listen.c Look for "sock->state", which tracks this.
> TCP sessions accepted by the tls virtual server and processed by 'Autz-Type
> New-TLS-Connection' seems to be stalled in CLOSE_WAIT state and we quickly
> reach the 'client max_connections' limit.
Rejected sockets should be closed pretty much immediately, and removed from the list of listeners, and from the list of active sockets for a client.
> Is the 'lifetime' parameter define for
> the client responsible of this behavior ?
> Even if Autz-Type New-TLS-Connection = reject ?
>
> With an external 'openssl verify', we don't have any tcp session in CLOSE_WAIT
> state.
>
> Here are the debug logs :
> FreeRADIUS Version 3.0.25
> ...
> radiusd: #### Loading Virtual Servers ####
> server { # from file /etc/freeradius/radiusd.conf
> } # server
> server default { # from file /etc/freeradius/sites-enabled/default
> # Loading authorize {...}
> Compiling Autz-Type New-TLS-Connection for attr Autz-Type
> # Loading preacct {...}
> # Loading pre-proxy {...}
> # Loading post-proxy {...}
> # Loading post-auth {...}
> Compiling Post-Auth-Type REJECT for attr Post-Auth-Type
> Compiling Post-Auth-Type Challenge for attr Post-Auth-Type
> } # server default
> server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel
> # Loading authenticate {...}
> Compiling Auth-Type PAP for attr Auth-Type
> Compiling Auth-Type CHAP for attr Auth-Type
> Compiling Auth-Type MS-CHAP for attr Auth-Type
> # Loading authorize {...}
> Ignoring "sql" (see raddb/mods-available/README.rst)
> Ignoring "ldap" (see raddb/mods-available/README.rst)
> # Loading session {...}
> # Loading post-proxy {...}
> # Loading post-auth {...}
> # Skipping contents of 'if' as it is always 'false' -- /etc/freeradius/sites-enabled/inner-tunnel:335
> Compiling Post-Auth-Type REJECT for attr Post-Auth-Type
> } # server inner-tunnel
> server auth-reject { # from file /etc/freeradius/sites-enabled/auth-reject
> # Loading authorize {...}
> } # server auth-reject
> server monitoring { # from file /etc/freeradius/sites-enabled/monitoring
> # Loading authenticate {...}
> Compiling Auth-Type PAP for attr Auth-Type
> # Loading authorize {...}
> } # server monitoring
> thread pool {
> start_servers = 5
> max_servers = 32
> min_spare_servers = 3
> max_spare_servers = 10
> max_requests_per_server = 0
> cleanup_delay = 5
> max_queue_size = 65536
> auto_limit_acct = no
> }
> Thread spawned new child 1. Total threads in pool: 1
> Thread spawned new child 2. Total threads in pool: 2
> Thread spawned new child 3. Total threads in pool: 3
> Thread 1 waiting to be assigned a request
> Thread spawned new child 4. Total threads in pool: 4
> Thread 2 waiting to be assigned a request
> Thread spawned new child 5. Total threads in pool: 5
> Thread 3 waiting to be assigned a request
> Thread pool initialized
> radiusd: #### Opening IP addresses and Ports ####
> Thread 4 waiting to be assigned a request
> Thread 5 waiting to be assigned a request
> listen {
> type = "auth"
> virtual_server = "default"
> ipaddr = 194.57.7.78
> port = 2083
> proto = "tcp"
> tls {
> verify_depth = 0
> ca_path = "/etc/freeradius/certs"
> pem_file_type = yes
> private_key_file = "/etc/freeradius/certs/ix1-pv-u18-eduroamradiusnational-02.renater.fr-key.pem"
> certificate_file = "/etc/freeradius/certs/ix1-pv-u18-eduroamradiusnational-02.renater.fr.crt"
> ca_file = "/etc/freeradius/certs/eduPKICA.crt"
> dh_file = "/etc/freeradius/certs/dh"
> random_file = "/dev/urandom"
> fragment_size = 8192
> include_length = yes
> auto_chain = yes
> check_crl = no
> check_all_crl = no
> ca_path_reload_interval = 0
> cipher_list = "DEFAULT"
> cipher_server_preference = no
> require_client_cert = yes
> reject_unknown_intermediate_ca = no
> ecdh_curve = "prime256v1"
> tls_max_version = "1.3"
> tls_min_version = "1.2"
> cache {
> enable = no
> lifetime = 24
> max_entries = 255
> }
> verify {
> skip_if_ocsp_ok = no
> tmpdir = "/var/cache/freeradius"
> }
> ocsp {
> enable = yes
> override_cert_url = yes
> url = "http://ocsp.edupki.org/OCSP-Server/OCSP"
> use_nonce = no
> timeout = 0
> softfail = yes
> }
> }
> check_client_connections = yes
> limit {
> max_connections = 32
> lifetime = 0
> idle_timeout = 30
> }
> clients = "radsec"
> client 127.0.0.1 {
> ipaddr = 127.0.0.1
> require_message_authenticator = no
> secret = <<< secret >>>
> proto = "tls"
> limit {
> max_connections = 16
> lifetime = 0
> idle_timeout = 30
> }
> }
> client others-radsec-client {
> ipaddr = *
> require_message_authenticator = no
> secret = <<< secret >>>
> proto = "tls"
> limit {
> max_connections = 32
> lifetime = 0
> idle_timeout = 30
> }
> }
> }
> listen {
> type = "auth"
> ipaddr = 127.0.0.1
> port = 18120
> }
> Listening on auth proto tcp address 194.57.7.78 port 2083 (TLS) bound to server default
> Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel
> Listening on proxy address * port 34023
> Ready to process requests
> ... new connection request on TCP socket
> Listening on auth from client (145.100.191.84, 48448) -> (194.57.7.78, 2083, virtual-server=default)
> Waking up in 0.1 seconds.
> (0) (TLS) Initiating new session
> (0) (TLS) Setting verify mode to require certificate from client
> (0) (TLS) Handshake state - before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) recv TLS 1.3 Handshake, ClientHello
> (0) (TLS) Handshake state - Server SSLv3/TLS read client hello
> (0) (TLS) send TLS 1.2 Handshake, ServerHello
> (0) (TLS) Handshake state - Server SSLv3/TLS write server hello
> (0) (TLS) send TLS 1.2 Handshake, Certificate
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate
> (0) (TLS) send TLS 1.2 Handshake, ServerKeyExchange
> (0) (TLS) Handshake state - Server SSLv3/TLS write key exchange
> (0) (TLS) send TLS 1.2 Handshake, CertificateRequest
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate request
> (0) (TLS) send TLS 1.2 Handshake, ServerHelloDone
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) Server : Need to read more data: SSLv3/TLS write server done
> (0) (TLS) In Handshake Phase
> Waking up in 0.1 seconds.
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) recv TLS 1.2 Handshake, Certificate
> (0) (TLS) send TLS 1.2 Alert, fatal handshake_failure
> (0) ERROR: (TLS) Alert write:fatal:handshake failure
> (0) ERROR: (TLS) Server : Error in error
> (0) ERROR: (TLS) Failed reading from OpenSSL: error:1417C0C7:SSL routines:tls_process_client_certificate:peer did not return a certificate
> (0) ERROR: (TLS) System call (I/O) error (-1)
> (0) (TLS) Failed in TLS handshake receive
> (TLS) Closing socket from client port 48448
> (TLS) Client has closed connection
> ... shutting down socket auth from client (145.100.191.84, 48448) -> (194.57.7.78, 2083, virtual-server=default)
> Waking up in 2.9 seconds.
> ... new connection request on TCP socket
> Listening on auth from client (145.100.191.84, 48452) -> (194.57.7.78, 2083, virtual-server=default)
> (0) (TLS) Initiating new session
> (0) (TLS) Setting verify mode to require certificate from client
> (0) (TLS) Handshake state - before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) recv TLS 1.3 Handshake, ClientHello
> (0) (TLS) Handshake state - Server SSLv3/TLS read client hello
> (0) (TLS) send TLS 1.2 Handshake, ServerHello
> (0) (TLS) Handshake state - Server SSLv3/TLS write server hello
> (0) (TLS) send TLS 1.2 Handshake, Certificate
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate
> (0) (TLS) send TLS 1.2 Handshake, ServerKeyExchange
> (0) (TLS) Handshake state - Server SSLv3/TLS write key exchange
> (0) (TLS) send TLS 1.2 Handshake, CertificateRequest
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate request
> (0) (TLS) send TLS 1.2 Handshake, ServerHelloDone
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) Server : Need to read more data: SSLv3/TLS write server done
> (0) (TLS) In Handshake Phase
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) recv TLS 1.2 Handshake, Certificate
> (0) (TLS) Creating attributes from server certificate
> (0) TLS-Cert-Serial := "01"
> (0) TLS-Cert-Expiration := "301103101536Z"
> (0) TLS-Cert-Valid-Since := "101108101536Z"
> (0) TLS-Cert-Subject := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Cert-Issuer := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Cert-Common-Name := "eduPKI CA G 01"
> (0) (TLS) Creating attributes from client certificate
> (0) TLS-Client-Cert-Serial := "1ee403d633fa3f40dfc949f6"
> (0) TLS-Client-Cert-Expiration := "230403080110Z"
> (0) TLS-Client-Cert-Valid-Since := "180404080110Z"
> (0) TLS-Client-Cert-Subject := "/DC=net/DC=geant/DC=eduroam/C=HR/O=University of Zagreb University Computing Centre/CN=cat.eduroam.org"
> (0) TLS-Client-Cert-Issuer := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Client-Cert-Common-Name := "cat.eduroam.org"
> (0) TLS-Client-Cert-Subject-Alt-Name-Dns := "cat.eduroam.org"
> (0) TLS-Client-Cert-Subject-Alt-Name-Email := "monitor at eduroam.org"
> (0) TLS-Client-Cert-X509v3-Basic-Constraints += "CA:FALSE"
> (0) TLS-Client-Cert-X509v3-Extended-Key-Usage += "TLS Web Client Authentication, TLS Web Server Authentication"
> (0) TLS-Client-Cert-X509v3-Subject-Key-Identifier += "82:3E:E7:DE:31:73:F6:6D:A5:C9:FE:AE:DC:21:93:7E:F4:03:5B:F5"
> (0) TLS-Client-Cert-X509v3-Authority-Key-Identifier += "keyid:D2:F2:23:BD:4A:A1:7F:CF:A0:58:84:EB:FC:E6:5B:08:B3:CD:B4:E4\n"
> (0) TLS-Client-Cert-X509v3-Certificate-Policies += "Policy: 1.3.6.1.4.1.27262.1.13.1.1\nPolicy: 1.3.6.1.4.1.27262.1.13.1.1.1.4\nPolicy: 1.3.6.1.4.1.25178.3.1.1\nPolicy: 1.3.6.1.4.1.25178.3.1.2\nPolicy: 1.3.6.1.4.1.27262.1.13.2.1.1.7\n"
> (0) TLS-Client-Cert-X509v3-Extended-Key-Usage-OID += "1.3.6.1.5.5.7.3.2"
> (0) TLS-Client-Cert-X509v3-Extended-Key-Usage-OID += "1.3.6.1.5.5.7.3.1"
> Certificate chain - 1 cert(s) untrusted
> (TLS) untrusted certificate with depth [1] subject name /DC=org/DC=edupki/CN=eduPKI CA G 01
> (TLS) untrusted certificate with depth [0] subject name /DC=net/DC=geant/DC=eduroam/C=HR/O=University of Zagreb University Computing Centre/CN=cat.eduroam.org
> (0) Starting OCSP Request
> (0) ocsp: Using responder URL "http://ocsp.edupki.org:80/OCSP-Server/OCSP"
> This Update: Jan 13 05:42:04 2022 GMT
> Next Update: Jan 20 05:42:04 2022 GMT
> (0) ocsp: Cert status: good
> (0) ocsp: Certificate is valid
> (0) (TLS) Handshake state - Server SSLv3/TLS read client certificate
> (0) (TLS) recv TLS 1.2 Handshake, ClientKeyExchange
> (0) (TLS) Handshake state - Server SSLv3/TLS read client key exchange
> (0) (TLS) recv TLS 1.2 Handshake, CertificateVerify
> (0) (TLS) Handshake state - Server SSLv3/TLS read certificate verify
> (0) (TLS) Handshake state - Server SSLv3/TLS read change cipher spec
> (0) (TLS) recv TLS 1.2 Handshake, Finished
> (0) (TLS) Handshake state - Server SSLv3/TLS read finished
> (0) (TLS) send TLS 1.2 ChangeCipherSpec
> (0) (TLS) Handshake state - Server SSLv3/TLS write change cipher spec
> (0) (TLS) send TLS 1.2 Handshake, Finished
> (0) (TLS) Handshake state - Server SSLv3/TLS write finished
> (0) (TLS) Handshake state - SSL negotiation finished successfully
> (0) (TLS) Connection Established
> (0) TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
> (0) TLS-Session-Version = "TLS 1.2"
> Waking up in 2.8 seconds.
> Threads: total/active/spare threads = 5/0/5
> Thread 4 got semaphore
> Thread 4 handling request 0, (1 handled so far)
> (0) (TLS) Checking connection to see if it is authorized.
> (0) # Executing group from file /etc/freeradius/sites-enabled/default
> (0) Autz-Type New-TLS-Connection {
> (0) if ("%{TLS-Client-Cert-X509v3-Certificate-Policies}" =~ /1\.3\.6\.1\.4\.1\.25178\.3\.1\.1/) {
> (0) EXPAND %{TLS-Client-Cert-X509v3-Certificate-Policies}
> (0) --> Policy: 1.3.6.1.4.1.27262.1.13.1.1 Policy: 1.3.6.1.4.1.27262.1.13.1.1.1.4 Policy: 1.3.6.1.4.1.25178.3.1.1 Policy: 1.3.6.1.4.1.25178.3.1.2 Policy: 1.3.6.1.4.1.27262.1.13.2.1.1.7
> (0) if ("%{TLS-Client-Cert-X509v3-Certificate-Policies}" =~ /1\.3\.6\.1\.4\.1\.25178\.3\.1\.1/) -> TRUE
> (0) if ("%{TLS-Client-Cert-X509v3-Certificate-Policies}" =~ /1\.3\.6\.1\.4\.1\.25178\.3\.1\.1/) {
> (0) [ok] = ok
> (0) } # if ("%{TLS-Client-Cert-X509v3-Certificate-Policies}" =~ /1\.3\.6\.1\.4\.1\.25178\.3\.1\.1/) = ok
> (0) ... skipping else: Preceding "if" was taken
> (0) } # Autz-Type New-TLS-Connection = ok
> (0) (TLS) Connection is authorized
> (0) Sent Access-Accept Id 4294967295 from 194.57.7.78:2083 to 145.100.191.84:48452 length 0
> (0) Finished request
> Thread 4 waiting to be assigned a request
> Waking up in 0.3 seconds.
> ... new connection request on TCP socket
> Listening on auth from client (145.100.191.84, 48462) -> (194.57.7.78, 2083, virtual-server=default)
> Waking up in 0.2 seconds.
> (0) (TLS) Initiating new session
> (0) (TLS) Setting verify mode to require certificate from client
> (0) (TLS) Handshake state - before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) recv TLS 1.3 Handshake, ClientHello
> (0) (TLS) Handshake state - Server SSLv3/TLS read client hello
> (0) (TLS) send TLS 1.2 Handshake, ServerHello
> (0) (TLS) Handshake state - Server SSLv3/TLS write server hello
> (0) (TLS) send TLS 1.2 Handshake, Certificate
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate
> (0) (TLS) send TLS 1.2 Handshake, ServerKeyExchange
> (0) (TLS) Handshake state - Server SSLv3/TLS write key exchange
> (0) (TLS) send TLS 1.2 Handshake, CertificateRequest
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate request
> (0) (TLS) send TLS 1.2 Handshake, ServerHelloDone
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) Server : Need to read more data: SSLv3/TLS write server done
> (0) (TLS) In Handshake Phase
> Waking up in 0.2 seconds.
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) recv TLS 1.2 Handshake, Certificate
> (0) (TLS) Creating attributes from server certificate
> (0) TLS-Cert-Serial := "01"
> (0) TLS-Cert-Expiration := "301103101536Z"
> (0) TLS-Cert-Valid-Since := "101108101536Z"
> (0) TLS-Cert-Subject := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Cert-Issuer := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Cert-Common-Name := "eduPKI CA G 01"
> (0) (TLS) Creating attributes from client certificate
> (0) TLS-Client-Cert-Serial := "1ee403d8e5301110403e8ae6"
> (0) TLS-Client-Cert-Expiration := "230403080112Z"
> (0) TLS-Client-Cert-Valid-Since := "180404080112Z"
> (0) TLS-Client-Cert-Subject := "/DC=net/DC=geant/DC=eduroam/C=HR/O=University of Zagreb University Computing Centre/CN=cat.eduroam.org"
> (0) TLS-Client-Cert-Issuer := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Client-Cert-Common-Name := "cat.eduroam.org"
> (0) TLS-Client-Cert-Subject-Alt-Name-Dns := "cat.eduroam.org"
> (0) TLS-Client-Cert-Subject-Alt-Name-Email := "monitor at eduroam.org"
> (0) TLS-Client-Cert-X509v3-Basic-Constraints += "CA:FALSE"
> (0) TLS-Client-Cert-X509v3-Extended-Key-Usage += "TLS Web Client Authentication, TLS Web Server Authentication"
> (0) TLS-Client-Cert-X509v3-Subject-Key-Identifier += "71:52:CB:61:81:12:A1:83:89:56:89:70:07:19:35:DA:D6:8C:78:9F"
> (0) TLS-Client-Cert-X509v3-Authority-Key-Identifier += "keyid:D2:F2:23:BD:4A:A1:7F:CF:A0:58:84:EB:FC:E6:5B:08:B3:CD:B4:E4\n"
> (0) TLS-Client-Cert-X509v3-Certificate-Policies += "Policy: 1.3.6.1.4.1.27262.1.13.1.1\nPolicy: 1.3.6.1.4.1.27262.1.13.1.1.1.4\nPolicy: 1.3.6.1.4.1.25178.3.1.2\nPolicy: 1.3.6.1.4.1.27262.1.13.2.1.1.7\n"
> (0) TLS-Client-Cert-X509v3-Extended-Key-Usage-OID += "1.3.6.1.5.5.7.3.2"
> (0) TLS-Client-Cert-X509v3-Extended-Key-Usage-OID += "1.3.6.1.5.5.7.3.1"
> Certificate chain - 1 cert(s) untrusted
> (TLS) untrusted certificate with depth [1] subject name /DC=org/DC=edupki/CN=eduPKI CA G 01
> (TLS) untrusted certificate with depth [0] subject name /DC=net/DC=geant/DC=eduroam/C=HR/O=University of Zagreb University Computing Centre/CN=cat.eduroam.org
> (0) Starting OCSP Request
> (0) ocsp: Using responder URL "http://ocsp.edupki.org:80/OCSP-Server/OCSP"
> This Update: Jan 13 02:04:27 2022 GMT
> Next Update: Jan 20 02:04:27 2022 GMT
> (0) ocsp: Cert status: good
> (0) ocsp: Certificate is valid
> (0) (TLS) Handshake state - Server SSLv3/TLS read client certificate
> (0) (TLS) recv TLS 1.2 Handshake, ClientKeyExchange
> (0) (TLS) Handshake state - Server SSLv3/TLS read client key exchange
> (0) (TLS) recv TLS 1.2 Handshake, CertificateVerify
> (0) (TLS) Handshake state - Server SSLv3/TLS read certificate verify
> (0) (TLS) Handshake state - Server SSLv3/TLS read change cipher spec
> (0) (TLS) recv TLS 1.2 Handshake, Finished
> (0) (TLS) Handshake state - Server SSLv3/TLS read finished
> (0) (TLS) send TLS 1.2 ChangeCipherSpec
> (0) (TLS) Handshake state - Server SSLv3/TLS write change cipher spec
> (0) (TLS) send TLS 1.2 Handshake, Finished
> (0) (TLS) Handshake state - Server SSLv3/TLS write finished
> (0) (TLS) Handshake state - SSL negotiation finished successfully
> (0) (TLS) Connection Established
> (0) TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
> (0) TLS-Session-Version = "TLS 1.2"
> Waking up in 0.1 seconds.
> Thread 5 got semaphore
> Thread 5 handling request 1, (1 handled so far)
> (1) (TLS) Checking connection to see if it is authorized.
> (1) # Executing group from file /etc/freeradius/sites-enabled/default
> (1) Autz-Type New-TLS-Connection {
> (1) if ("%{TLS-Client-Cert-X509v3-Certificate-Policies}" =~ /1\.3\.6\.1\.4\.1\.25178\.3\.1\.1/) {
> (1) EXPAND %{TLS-Client-Cert-X509v3-Certificate-Policies}
> (1) --> Policy: 1.3.6.1.4.1.27262.1.13.1.1 Policy: 1.3.6.1.4.1.27262.1.13.1.1.1.4 Policy: 1.3.6.1.4.1.25178.3.1.2 Policy: 1.3.6.1.4.1.27262.1.13.2.1.1.7
> (1) if ("%{TLS-Client-Cert-X509v3-Certificate-Policies}" =~ /1\.3\.6\.1\.4\.1\.25178\.3\.1\.1/) -> FALSE
> (1) else {
> (1) update request {
> (1) &Module-Failure-Message += "Your certificate policy does not contain eduroam SP OID"
> (1) } # update request = noop
> (1) [reject] = reject
> (1) } # else = reject
> (1) } # Autz-Type New-TLS-Connection = reject
> (1) WARNING: (TLS) Connection is not authorized - closing TCP socket.
> (1) Sent Access-Reject Id 4294967295 from 194.57.7.78:2083 to 145.100.191.84:48462 length 0
> (1) Finished request
> Thread 5 waiting to be assigned a request
> Waking up in 0.1 seconds.
> ... new connection request on TCP socket
> Listening on auth from client (145.100.191.84, 48476) -> (194.57.7.78, 2083, virtual-server=default)
> Waking up in 0.1 seconds.
> (0) (TLS) Initiating new session
> (0) (TLS) Setting verify mode to require certificate from client
> (0) (TLS) Handshake state - before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) recv TLS 1.3 Handshake, ClientHello
> (0) (TLS) Handshake state - Server SSLv3/TLS read client hello
> (0) (TLS) send TLS 1.2 Handshake, ServerHello
> (0) (TLS) Handshake state - Server SSLv3/TLS write server hello
> (0) (TLS) send TLS 1.2 Handshake, Certificate
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate
> (0) (TLS) send TLS 1.2 Handshake, ServerKeyExchange
> (0) (TLS) Handshake state - Server SSLv3/TLS write key exchange
> (0) (TLS) send TLS 1.2 Handshake, CertificateRequest
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate request
> (0) (TLS) send TLS 1.2 Handshake, ServerHelloDone
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) Server : Need to read more data: SSLv3/TLS write server done
> (0) (TLS) In Handshake Phase
> Waking up in 0.1 seconds.
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) recv TLS 1.2 Handshake, Certificate
> (0) (TLS) Creating attributes from server certificate
> (0) TLS-Cert-Serial := "01"
> (0) TLS-Cert-Expiration := "301103101536Z"
> (0) TLS-Cert-Valid-Since := "101108101536Z"
> (0) TLS-Cert-Subject := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Cert-Issuer := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Cert-Common-Name := "eduPKI CA G 01"
> (0) (TLS) Creating attributes from client certificate
> (0) TLS-Client-Cert-Serial := "1469696cfe7d84"
> (0) TLS-Client-Cert-Expiration := "120908124308Z"
> (0) TLS-Client-Cert-Valid-Since := "120907124308Z"
> (0) TLS-Client-Cert-Subject := "/DC=net/DC=geant/DC=eduroam/C=PL/O=Uniwersytet Mikolaja Kopernika/CN=test-bogus-2.cat.eduroam.pl"
> (0) TLS-Client-Cert-Issuer := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Client-Cert-Common-Name := "test-bogus-2.cat.eduroam.pl"
> (0) TLS-Client-Cert-Subject-Alt-Name-Dns := "test-bogus-2.cat.eduroam.pl"
> (0) ERROR: (TLS) OpenSSL says error 10 : certificate has expired
> (0) (TLS) send TLS 1.2 Alert, fatal certificate_expired
> (0) ERROR: (TLS) Alert write:fatal:certificate expired
> (0) ERROR: (TLS) Server : Error in error
> (0) ERROR: (TLS) Failed reading from OpenSSL: error:1417C086:SSL routines:tls_process_client_certificate:certificate verify failed
> (0) ERROR: (TLS) System call (I/O) error (-1)
> (0) (TLS) Failed in TLS handshake receive
> (TLS) Closing socket from client port 48476
> (TLS) Client has closed connection
> ... shutting down socket auth from client (145.100.191.84, 48476) -> (194.57.7.78, 2083, virtual-server=default)
> Waking up in 0.1 seconds.
> ... new connection request on TCP socket
> Listening on auth from client (145.100.191.84, 48480) -> (194.57.7.78, 2083, virtual-server=default)
> (0) (TLS) Initiating new session
> (0) (TLS) Setting verify mode to require certificate from client
> (0) (TLS) Handshake state - before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) recv TLS 1.3 Handshake, ClientHello
> (0) (TLS) Handshake state - Server SSLv3/TLS read client hello
> (0) (TLS) send TLS 1.2 Handshake, ServerHello
> (0) (TLS) Handshake state - Server SSLv3/TLS write server hello
> (0) (TLS) send TLS 1.2 Handshake, Certificate
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate
> (0) (TLS) send TLS 1.2 Handshake, ServerKeyExchange
> (0) (TLS) Handshake state - Server SSLv3/TLS write key exchange
> (0) (TLS) send TLS 1.2 Handshake, CertificateRequest
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate request
> (0) (TLS) send TLS 1.2 Handshake, ServerHelloDone
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) Server : Need to read more data: SSLv3/TLS write server done
> (0) (TLS) In Handshake Phase
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) recv TLS 1.2 Handshake, Certificate
> (0) (TLS) Creating attributes from server certificate
> (0) TLS-Cert-Serial := "01"
> (0) TLS-Cert-Expiration := "301103101536Z"
> (0) TLS-Cert-Valid-Since := "101108101536Z"
> (0) TLS-Cert-Subject := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Cert-Issuer := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Cert-Common-Name := "eduPKI CA G 01"
> (0) (TLS) Creating attributes from client certificate
> (0) TLS-Client-Cert-Serial := "1ee403d708c743865c7d7cab"
> (0) TLS-Client-Cert-Expiration := "230403080111Z"
> (0) TLS-Client-Cert-Valid-Since := "180404080111Z"
> (0) TLS-Client-Cert-Subject := "/DC=net/DC=geant/DC=eduroam/C=HR/O=University of Zagreb University Computing Centre/CN=cat.eduroam.org"
> (0) TLS-Client-Cert-Issuer := "/DC=org/DC=edupki/CN=eduPKI CA G 01"
> (0) TLS-Client-Cert-Common-Name := "cat.eduroam.org"
> (0) TLS-Client-Cert-Subject-Alt-Name-Dns := "cat.eduroam.org"
> (0) TLS-Client-Cert-Subject-Alt-Name-Email := "monitor at eduroam.org"
> (0) TLS-Client-Cert-X509v3-Basic-Constraints += "CA:FALSE"
> (0) TLS-Client-Cert-X509v3-Extended-Key-Usage += "TLS Web Client Authentication, TLS Web Server Authentication"
> (0) TLS-Client-Cert-X509v3-Subject-Key-Identifier += "62:93:8D:BD:FA:7A:FA:42:34:A6:4D:7C:CB:8A:F6:89:15:1A:EF:69"
> (0) TLS-Client-Cert-X509v3-Authority-Key-Identifier += "keyid:D2:F2:23:BD:4A:A1:7F:CF:A0:58:84:EB:FC:E6:5B:08:B3:CD:B4:E4\n"
> (0) TLS-Client-Cert-X509v3-Certificate-Policies += "Policy: 1.3.6.1.4.1.27262.1.13.1.1\nPolicy: 1.3.6.1.4.1.27262.1.13.1.1.1.4\nPolicy: 1.3.6.1.4.1.25178.3.1.1\nPolicy: 1.3.6.1.4.1.25178.3.1.2\nPolicy: 1.3.6.1.4.1.27262.1.13.2.1.1.7\n"
> (0) TLS-Client-Cert-X509v3-Extended-Key-Usage-OID += "1.3.6.1.5.5.7.3.2"
> (0) TLS-Client-Cert-X509v3-Extended-Key-Usage-OID += "1.3.6.1.5.5.7.3.1"
> Certificate chain - 1 cert(s) untrusted
> (TLS) untrusted certificate with depth [1] subject name /DC=org/DC=edupki/CN=eduPKI CA G 01
> (TLS) untrusted certificate with depth [0] subject name /DC=net/DC=geant/DC=eduroam/C=HR/O=University of Zagreb University Computing Centre/CN=cat.eduroam.org
> (0) Starting OCSP Request
> (0) ocsp: Using responder URL "http://ocsp.edupki.org:80/OCSP-Server/OCSP"
> This Update: Jan 13 05:14:45 2022 GMT
> Next Update: Jan 20 05:14:45 2022 GMT
> (0) ERROR: ocsp: Cert status: revoked
> Revocation Time: Apr 4 08:03:09 2018 GMT
> (0) ERROR: (TLS) ocsp: Certificate has been expired/revoked
> (0) (TLS) send TLS 1.2 Alert, fatal internal_error
> (0) ERROR: (TLS) Alert write:fatal:internal error
> (0) ERROR: (TLS) Server : Error in error
> (0) ERROR: (TLS) Failed reading from OpenSSL: error:1417C086:SSL routines:tls_process_client_certificate:certificate verify failed
> (0) ERROR: (TLS) System call (I/O) error (-1)
> (0) (TLS) Failed in TLS handshake receive
> (TLS) Closing socket from client port 48480
> (TLS) Client has closed connection
> ... shutting down socket auth from client (145.100.191.84, 48480) -> (194.57.7.78, 2083, virtual-server=default)
> Waking up in 0.1 seconds.
> ... new connection request on TCP socket
> Listening on auth from client (145.100.191.84, 48490) -> (194.57.7.78, 2083, virtual-server=default)
> (0) (TLS) Initiating new session
> (0) (TLS) Setting verify mode to require certificate from client
> (0) (TLS) Handshake state - before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) recv TLS 1.3 Handshake, ClientHello
> (0) (TLS) Handshake state - Server SSLv3/TLS read client hello
> (0) (TLS) send TLS 1.2 Handshake, ServerHello
> (0) (TLS) Handshake state - Server SSLv3/TLS write server hello
> (0) (TLS) send TLS 1.2 Handshake, Certificate
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate
> (0) (TLS) send TLS 1.2 Handshake, ServerKeyExchange
> (0) (TLS) Handshake state - Server SSLv3/TLS write key exchange
> (0) (TLS) send TLS 1.2 Handshake, CertificateRequest
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate request
> (0) (TLS) send TLS 1.2 Handshake, ServerHelloDone
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) Server : Need to read more data: SSLv3/TLS write server done
> (0) (TLS) In Handshake Phase
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) recv TLS 1.2 Handshake, Certificate
> (0) (TLS) Creating attributes from client certificate
> (0) TLS-Client-Cert-Serial := "01"
> (0) TLS-Client-Cert-Expiration := "230317094729Z"
> (0) TLS-Client-Cert-Valid-Since := "130319094729Z"
> (0) TLS-Client-Cert-Subject := "/C=HR/ST=Zagreb/L=Zagreb/O=Srce test/OU=eduroam/CN=mali.pero.eduroam.hr"
> (0) TLS-Client-Cert-Issuer := "/C=HR/ST=Zagreb/L=Zagreb/O=Srce test/OU=eduroam/CN=CA Root certificate dc=hr/dc=eduroam/dc=MaliPero PKI 1"
> (0) TLS-Client-Cert-Common-Name := "mali.pero.eduroam.hr"
> (0) ERROR: (TLS) OpenSSL says error 20 : unable to get local issuer certificate
> (0) (TLS) send TLS 1.2 Alert, fatal unknown_ca
> (0) ERROR: (TLS) Alert write:fatal:unknown CA
> (0) ERROR: (TLS) Server : Error in error
> (0) ERROR: (TLS) Failed reading from OpenSSL: error:1417C086:SSL routines:tls_process_client_certificate:certificate verify failed
> (0) ERROR: (TLS) System call (I/O) error (-1)
> (0) (TLS) Failed in TLS handshake receive
> (TLS) Closing socket from client port 48490
> (TLS) Client has closed connection
> ... shutting down socket auth from client (145.100.191.84, 48490) -> (194.57.7.78, 2083, virtual-server=default)
> Waking up in 0.4 seconds.
> Waking up in 1.9 seconds.
> ... cleaning up socket auth from client (145.100.191.84, 48448) -> (194.57.7.78, 2083, virtual-server=default)
> Waking up in 0.3 seconds.
> ... cleaning up socket auth from client (145.100.191.84, 48476) -> (194.57.7.78, 2083, virtual-server=default)
> Waking up in 0.1 seconds.
> ... cleaning up socket auth from client (145.100.191.84, 48480) -> (194.57.7.78, 2083, virtual-server=default)
> ... cleaning up socket auth from client (145.100.191.84, 48490) -> (194.57.7.78, 2083, virtual-server=default)
> Waking up in 1.5 seconds.
> (0) Cleaning up request packet ID 4294967295 with timestamp +57
> Waking up in 0.1 seconds.
> (1) Cleaning up request packet ID 4294967295 with timestamp +57
> Waking up in 24.2 seconds.
> ... new connection request on TCP socket
> Listening on auth from client (145.100.191.84, 48886) -> (194.57.7.78, 2083, virtual-server=default)
> (0) (TLS) Initiating new session
> (0) (TLS) Setting verify mode to require certificate from client
> (0) (TLS) Handshake state - before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) Handshake state - Server before SSL initialization
> (0) (TLS) recv TLS 1.3 Handshake, ClientHello
> (0) (TLS) Handshake state - Server SSLv3/TLS read client hello
> (0) (TLS) send TLS 1.2 Handshake, ServerHello
> (0) (TLS) Handshake state - Server SSLv3/TLS write server hello
> (0) (TLS) send TLS 1.2 Handshake, Certificate
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate
> (0) (TLS) send TLS 1.2 Handshake, ServerKeyExchange
> (0) (TLS) Handshake state - Server SSLv3/TLS write key exchange
> (0) (TLS) send TLS 1.2 Handshake, CertificateRequest
> (0) (TLS) Handshake state - Server SSLv3/TLS write certificate request
> (0) (TLS) send TLS 1.2 Handshake, ServerHelloDone
> (0) (TLS) Handshake state - Server SSLv3/TLS write server done
> (0) (TLS) Server : Need to read more data: SSLv3/TLS write server done
> (0) (TLS) In Handshake Phase
> (0) (TLS) Server : Need to read more data: SSLv3/TLS write server done
> (0) (TLS) In Handshake Phase
> (0) (TLS) Application data.
> (0) (TLS) OpenSSL says that the TLS session is still negotiating, but there's no more data to send!
That looks like an issue with OpenSSL. Which version are you using?
Alan DeKok.
More information about the Freeradius-Users
mailing list