Autz-Type New-TLS-Connection : tcp sessions stalled in close_wait state
Hi, I'm back to a topic from last summer: for RadSec, we would like to check clients certicate properties without an 'openssl verify' external command. So we try 'Autz-Type New-TLS-Connection'. 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. 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. 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@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@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@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! (TLS) Closing socket from client port 48886 (TLS) Client has closed connection ... shutting down socket auth from client (145.100.191.84, 48886) -> (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, 48888) -> (194.57.7.78, 2083, virtual-server=default) Waking up in 0.9 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.9 seconds. (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 48888 (TLS) Client has closed connection ... shutting down socket auth from client (145.100.191.84, 48888) -> (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, 48892) -> (194.57.7.78, 2083, virtual-server=default) Waking up in 0.8 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.8 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 48892 (TLS) Client has closed connection ... shutting down socket auth from client (145.100.191.84, 48892) -> (194.57.7.78, 2083, virtual-server=default) Waking up in 2.8 seconds. ... cleaning up socket auth from client (145.100.191.84, 48886) -> (194.57.7.78, 2083, virtual-server=default) ... cleaning up socket auth from client (145.100.191.84, 48888) -> (194.57.7.78, 2083, virtual-server=default) ... cleaning up socket auth from client (145.100.191.84, 48892) -> (194.57.7.78, 2083, virtual-server=default) Waking up in 8.3 seconds. Ready to process requests ... new connection request on TCP socket Listening on auth from client (145.100.191.84, 49646) -> (194.57.7.78, 2083, virtual-server=default) Waking up in 0.6 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.6 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 49646 (TLS) Client has closed connection ... shutting down socket auth from client (145.100.191.84, 49646) -> (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, 49684) -> (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 := "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@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 01:41:56 2022 GMT Next Update: Jan 20 01:41:56 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 3 got semaphore Thread 3 handling request 2, (1 handled so far) (2) (TLS) Checking connection to see if it is authorized. (2) # Executing group from file /etc/freeradius/sites-enabled/default (2) Autz-Type New-TLS-Connection { (2) if ("%{TLS-Client-Cert-X509v3-Certificate-Policies}" =~ /1\.3\.6\.1\.4\.1\.25178\.3\.1\.1/) { (2) EXPAND %{TLS-Client-Cert-X509v3-Certificate-Policies} (2) --> 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 (2) if ("%{TLS-Client-Cert-X509v3-Certificate-Policies}" =~ /1\.3\.6\.1\.4\.1\.25178\.3\.1\.1/) -> TRUE (2) if ("%{TLS-Client-Cert-X509v3-Certificate-Policies}" =~ /1\.3\.6\.1\.4\.1\.25178\.3\.1\.1/) { (2) [ok] = ok (2) } # if ("%{TLS-Client-Cert-X509v3-Certificate-Policies}" =~ /1\.3\.6\.1\.4\.1\.25178\.3\.1\.1/) = ok (2) ... skipping else: Preceding "if" was taken (2) } # Autz-Type New-TLS-Connection = ok (2) (TLS) Connection is authorized (2) Sent Access-Accept Id 4294967295 from 194.57.7.78:2083 to 145.100.191.84:49684 length 0 (2) Finished request Thread 3 waiting to be assigned a request ... new connection request on TCP socket Regards, Arnaud
On Jan 13, 2022, at 10:12 AM, Arnaud LAURIOU <arnaud.lauriou@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@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@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@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.
participants (2)
-
Alan DeKok -
Arnaud LAURIOU