SSLVerifyClient Not Working with New OpenSSL and Apache on Debian 10

apache-2.4openssl

SSLVerifyClient option works in terms it requests user for certificate, but then browser shows an error and server don't pass request to the ProxyPass .. server.

following config code (SSLVerifyClient option) do work OK on debian 8 – apache 2.4.10+openssl 1.0.1t (may 2016)

following config code (SSLVerifyClient option) do work OK on debian 9 – apache 2.4.25+openssl 1.1.0l (10 Sep 2019)

following config code (SSLVerifyClient option) does NOT works on debian 10 – apache 2.4.38+openssl 1.1.1d (10 Sep 2019)

  SSLCertificateFile ....crt
  SSLCertificateKeyFile ...key
  SSLCACertificateFile ../root_...crt
  SSLCARevocationFile ..crl.pem

  ProxyPass / balancer://...
  ProxyPassReverse / balancer://...
..
  <Location /test>
    SSLVerifyClient optional
    SSLOptions +StdEnvVars +ExportCertData
    ..
    RequestHeader set X-SSL-CLIENT-S-DN-O "%{SSL_CLIENT_S_DN_O}s"

things get broken somewhere at the middle of apache 2.4.38+openssl 1.1.1d and apache 2.4.25+openssl 1.1.0l, why this happen?

Apache logs:

firefox 43.0.2
An error occurred during a connection to test.mytesthost. SSL peer cannot verify your certificate. (Error code: ssl_error_bad_cert_alert) 
apache log level set to debug 

==> /var/log/apache2/test.mytesthost.error.log <==
[Mon Dec 28 05:05:22.392282 2020] [ssl:info] [pid 2001:tid 140129775593216] [client 127.0.0.1:57716] AH01964: Connection to child 16 established (server test.mytesthost:443)
[Mon Dec 28 05:05:22.392535 2020] [ssl:debug] [pid 2001:tid 140129775593216] ssl_engine_kernel.c(2319): [client 127.0.0.1:57716] AH02043: SSL virtual host for servername test.mytesthost found
[Mon Dec 28 05:05:22.392567 2020] [ssl:debug] [pid 2001:tid 140129775593216] ssl_engine_kernel.c(2319): [client 127.0.0.1:57716] AH02043: SSL virtual host for servername test.mytesthost found
[Mon Dec 28 05:05:22.392572 2020] [core:debug] [pid 2001:tid 140129775593216] protocol.c(2314): [client 127.0.0.1:57716] AH03155: select protocol from , choices=h2,spdy/3.1,http/1.1 for server test.mytesthost
[Mon Dec 28 05:05:22.443004 2020] [ssl:debug] [pid 2001:tid 140129775593216] ssl_engine_kernel.c(2235): [client 127.0.0.1:57716] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)
[Mon Dec 28 05:05:22.533306 2020] [ssl:debug] [pid 2001:tid 140129775593216] ssl_engine_kernel.c(383): [client 127.0.0.1:57716] AH02034: Initial (No.1) HTTPS request received for child 16 (server test.mytesthost:443)
[Mon Dec 28 05:05:22.533374 2020] [ssl:debug] [pid 2001:tid 140129775593216] ssl_engine_kernel.c(746): [client 127.0.0.1:57716] AH02255: Changed client verification type will force renegotiation
[Mon Dec 28 05:05:22.533379 2020] [ssl:info] [pid 2001:tid 140129775593216] [client 127.0.0.1:57716] AH02221: Requesting connection re-negotiation
[Mon Dec 28 05:05:22.533404 2020] [ssl:debug] [pid 2001:tid 140129775593216] ssl_engine_kernel.c(975): [client 127.0.0.1:57716] AH02260: Performing full renegotiation: complete handshake protocol (client does support secure renegotiation)
[Mon Dec 28 05:05:22.533461 2020] [ssl:debug] [pid 2001:tid 140129775593216] ssl_engine_kernel.c(2235): [client 127.0.0.1:57716] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)
[Mon Dec 28 05:05:22.533476 2020] [ssl:info] [pid 2001:tid 140129775593216] [client 127.0.0.1:57716] AH02226: Awaiting re-negotiation handshake
[Mon Dec 28 05:05:22.533604 2020] [ssl:debug] [pid 2001:tid 140129775593216] ssl_engine_kernel.c(2319): [client 127.0.0.1:57716] AH02043: SSL virtual host for servername test.mytesthost found
[Mon Dec 28 05:05:24.962762 2020] [ssl:debug] [pid 2001:tid 140129775593216] ssl_engine_kernel.c(1740): [client 127.0.0.1:57716] AH02275: Certificate Verification, depth 0, CRL checking mode: none (0) [subject: emailAddress=Company.ru2@not-yet-named.com,CN=Pers id: 433837686,OU=Company Certification Center,O=Company Transfer / issuer: CN=Company Transfer Root CA,O=WM Transfer Ltd,OU=WM Transfer Certification Services / serial: 1A209C2E0000000B042A / notbefore: Jan 16 13:36:07 2020 GMT / notafter: Jan 16 13:46:07 2022 GMT]
[Mon Dec 28 05:05:24.964246 2020] [ssl:info] [pid 2001:tid 140129775593216] [client 127.0.0.1:57716] AH02276: Certificate Verification: Error (68): CA signature digest algorithm too weak [subject: emailAddress=Company.ru2@not-yet-named.com,CN=Pers id: 433837686,OU=Company Certification Center,O=Company Transfer / issuer: CN=Company Transfer Root CA,O=WM Transfer Ltd,OU=WM Transfer Certification Services / serial: 1A209C2E0000000B042A / notbefore: Jan 16 13:36:07 2020 GMT / notafter: Jan 16 13:46:07 2022 GMT]
[Mon Dec 28 05:05:24.964287 2020] [socache_shmcb:debug] [pid 2001:tid 140129775593216] mod_socache_shmcb.c(557): AH00837: socache_shmcb_remove (0x60 -> subcache 0)
[Mon Dec 28 05:05:24.964299 2020] [socache_shmcb:debug] [pid 2001:tid 140129775593216] mod_socache_shmcb.c(571): AH00839: leaving socache_shmcb_remove successfully
[Mon Dec 28 05:05:24.964344 2020] [ssl:error] [pid 2001:tid 140129775593216] [client 127.0.0.1:57716] AH02261: Re-negotiation handshake failed
[Mon Dec 28 05:05:24.964363 2020] [ssl:error] [pid 2001:tid 140129775593216] SSL Library Error: error:1417C086:SSL routines:tls_process_client_certificate:certificate verify failed
[Mon Dec 28 05:05:24.964402 2020] [ssl:debug] [pid 2001:tid 140129775593216] ssl_engine_io.c(1372): [client 127.0.0.1:57716] AH02007: SSL handshake interrupted by system [Hint: Stop button pressed in browser?!]
[Mon Dec 28 05:05:24.964407 2020] [ssl:info] [pid 2001:tid 140129775593216] [client 127.0.0.1:57716] AH01998: Connection closed to child 16 with abortive shutdown (server test.mytesthost:443)

with
firefox 78.6.0esr
output:
Forbidden
You don't have permission to access this resource.Reason: Cannot perform Post-Handshake Authentication.

==> /var/log/apache2/test.mytesthost.error.log <==
[Tue Dec 29 03:11:47.553633 2020] [ssl:info] [pid 8218:tid 140339011598080] [client 127.0.0.1:58060] AH01964: Connection to child 65 established (server test.mytesthost:443)
[Tue Dec 29 03:11:47.554092 2020] [ssl:debug] [pid 8218:tid 140339011598080] ssl_engine_kernel.c(2319): [client 127.0.0.1:58060] AH02043: SSL virtual host for servername test.mytesthost found
[Tue Dec 29 03:11:47.554113 2020] [ssl:debug] [pid 8218:tid 140339011598080] ssl_engine_kernel.c(2319): [client 127.0.0.1:58060] AH02043: SSL virtual host for servername test.mytesthost found
[Tue Dec 29 03:11:47.554118 2020] [core:debug] [pid 8218:tid 140339011598080] protocol.c(2314): [client 127.0.0.1:58060] AH03155: select protocol from , choices=h2,http/1.1 for server test.mytesthost
[Tue Dec 29 03:11:47.638499 2020] [ssl:debug] [pid 8218:tid 140339011598080] ssl_engine_kernel.c(2235): [client 127.0.0.1:58060] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_128_GCM_SHA256 (128/128 bits)
[Tue Dec 29 03:11:47.638596 2020] [socache_shmcb:debug] [pid 8218:tid 140339011598080] mod_socache_shmcb.c(495): AH00831: socache_shmcb_store (0x92 -> subcache 18)
[Tue Dec 29 03:11:47.638617 2020] [socache_shmcb:debug] [pid 8218:tid 140339011598080] mod_socache_shmcb.c(849): AH00847: insert happened at idx=0, data=(0:32)
[Tue Dec 29 03:11:47.638621 2020] [socache_shmcb:debug] [pid 8218:tid 140339011598080] mod_socache_shmcb.c(854): AH00848: finished insert, subcache: idx_pos/idx_used=0/1, data_pos/data_used=0/204
[Tue Dec 29 03:11:47.638623 2020] [socache_shmcb:debug] [pid 8218:tid 140339011598080] mod_socache_shmcb.c(516): AH00834: leaving socache_shmcb_store successfully
[Tue Dec 29 03:11:47.638699 2020] [socache_shmcb:debug] [pid 8218:tid 140339011598080] mod_socache_shmcb.c(495): AH00831: socache_shmcb_store (0x2f -> subcache 15)
[Tue Dec 29 03:11:47.638721 2020] [socache_shmcb:debug] [pid 8218:tid 140339011598080] mod_socache_shmcb.c(849): AH00847: insert happened at idx=0, data=(0:32)
[Tue Dec 29 03:11:47.638724 2020] [socache_shmcb:debug] [pid 8218:tid 140339011598080] mod_socache_shmcb.c(854): AH00848: finished insert, subcache: idx_pos/idx_used=0/1, data_pos/data_used=0/203
[Tue Dec 29 03:11:47.638726 2020] [socache_shmcb:debug] [pid 8218:tid 140339011598080] mod_socache_shmcb.c(516): AH00834: leaving socache_shmcb_store successfully
[Tue Dec 29 03:11:47.638824 2020] [ssl:debug] [pid 8218:tid 140339011598080] ssl_engine_kernel.c(383): [client 127.0.0.1:58060] AH02034: Initial (No.1) HTTPS request received for child 65 (server test.mytesthost:443)
[Tue Dec 29 03:11:47.638862 2020] [ssl:error] [pid 8218:tid 140339011598080] [client 127.0.0.1:58060] AH10129: verify client post handshake
[Tue Dec 29 03:11:47.638866 2020] [ssl:error] [pid 8218:tid 140339011598080] [client 127.0.0.1:58060] AH10158: cannot perform post-handshake authentication
[Tue Dec 29 03:11:47.638885 2020] [ssl:error] [pid 8218:tid 140339011598080] SSL Library Error: error:14268117:SSL routines:SSL_verify_client_post_handshake:extension not received
[Tue Dec 29 03:11:52.640565 2020] [ssl:debug] [pid 8218:tid 140338928809728] ssl_engine_io.c(1106): [client 127.0.0.1:58060] AH02001: Connection closed to child 66 with standard shutdown (server test.mytesthost:443)

Best Answer

Your problem with FF43 is, as Gerald Schneider spotted, "CA signature digest algorithm too weak". But this is not a problem with the browser, it is a problem with the client certificate's trust chain, which was accepted under older and laxer versions of Debian and OpenSSL but no longer; see https://wiki.debian.org/ContinuousIntegration/TriagingTips/openssl-1.1.1 . Compare https://github.com/symless/synergy-core/issues/6561 and https://stackoverflow.com/questions/52218876/how-to-fix-ssl-issue-ssl-ctx-use-certificate-ca-md-too-weak-on-python-zeep (although that's for the server's own cert not a client cert). Specifically, if I've read the code right, one of the CA certs in the chain (other than the root, which isn't checked) has a signature using a hash weaker than SHA256 (aka SHA-2), which has been the minimum required by most browsers and the CA/Brower forum since 2015. You need to either configure your server to accept a lower @SECLEVEL (which potentially reduces security on all connections to it) or change the client to have a stronger cert chain. Depending on the cert and the CA where you got it, this may require a new EE (end-entity=client) cert as well, or there may be a better chain for the same EE cert.

The problem with FF78.6 is different: "SSL_verify_client_post_handshake:extension not received". OpenSSL 1.1.1 supports TLS 1.3, which changes the way client authentication is done; specifically it is now a 'post-handshake' operation rather than a 'renegotiation' (see your first log). My copy of FF78.6 does support this capability, so this error should indicate that your browser instance either doesn't have the client cert installed correctly or the user didn't select/approve it.

Related Topic