Opened 3 years ago
Closed 3 years ago
#2238 closed defect (invalid)
Difference in ssl_verify_depth and ssl_verify_client optional_no_ca handling between 1.16 and 1.18?
| Reported by: | Malte Schmidt | Owned by: | |
|---|---|---|---|
| Priority: | minor | Milestone: | |
| Component: | nginx-core | Version: | 1.18.x |
| Keywords: | nginx, verify, optional, depth | Cc: | Malte Schmidt |
| uname -a: |
Linux hostname 4.4.0-210-generic #242-Ubuntu SMP Fri Apr 16 09:57:56 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
Linux hostname 5.4.0-81-generic #91-Ubuntu SMP Thu Jul 15 19:09:17 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux |
||
| nginx -V: |
nginx version: nginx/1.16.1
built with OpenSSL 1.0.2g 1 Mar 2016 TLS SNI support enabled configure arguments: --with-cc-opt='-g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security -fPIC -Wdate-time -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now -fPIC' --prefix=/usr/share/nginx --conf-path=/etc/nginx/nginx.conf --http-log-path=/var/log/nginx/access.log --error-log-path=/var/log/nginx/error.log --lock-path=/var/lock/nginx.lock --pid-path=/run/nginx.pid --modules-path=/usr/lib/nginx/modules --http-client-body-temp-path=/var/lib/nginx/body --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-proxy-temp-path=/var/lib/nginx/proxy --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --with-compat --with-debug --with-pcre-jit --with-http_ssl_module --with-http_stub_status_module --with-http_realip_module --with-http_auth_request_module --with-http_v2_module --with-http_dav_module --with-http_slice_module --with-threads --with-http_addition_module --with-http_flv_module --with-http_geoip_module=dynamic --with-http_gunzip_module --with-http_gzip_static_module --with-http_image_filter_module=dynamic --with-http_mp4_module --with-http_perl_module=dynamic --with-http_random_index_module --with-http_secure_link_module --with-http_sub_module --with-http_xslt_module=dynamic --with-mail=dynamic --with-mail_ssl_module --with-stream=dynamic --with-stream_ssl_module --with-stream_ssl_preread_module --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-headers-more-filter --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-auth-pam --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-cache-purge --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-dav-ext --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-ndk --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-echo --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-fancyindex --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/nchan --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-lua --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/rtmp --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-uploadprogress --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-upstream-fair --add-dynamic-module=/build/nginx-IP2kgO/nginx-1.16.1/debian/modules/http-subs-filter nginx version: nginx/1.18.0 (Ubuntu) built with OpenSSL 1.1.1f 31 Mar 2020 TLS SNI support enabled configure arguments: --with-cc-opt='-g -O2 -fdebug-prefix-map=/build/nginx-BUo7Uw/nginx-1.18.0=. -fstack-protector-strong -Wformat -Werror=format-security -fPIC -Wdate-time -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -Wl,-z,relro -Wl,-z,now -fPIC' --prefix=/usr/share/nginx --conf-path=/etc/nginx/nginx.conf --http-log-path=/var/log/nginx/access.log --error-log-path=/var/log/nginx/error.log --lock-path=/var/lock/nginx.lock --pid-path=/run/nginx.pid --modules-path=/usr/lib/nginx/modules --http-client-body-temp-path=/var/lib/nginx/body --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-proxy-temp-path=/var/lib/nginx/proxy --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --with-compat --with-debug --with-pcre-jit --with-http_ssl_module --with-http_stub_status_module --with-http_realip_module --with-http_auth_request_module --with-http_v2_module --with-http_dav_module --with-http_slice_module --with-threads --with-http_addition_module --with-http_flv_module --with-http_geoip_module=dynamic --with-http_gunzip_module --with-http_gzip_static_module --with-http_image_filter_module=dynamic --with-http_mp4_module --with-http_perl_module=dynamic --with-http_random_index_module --with-http_secure_link_module --with-http_sub_module --with-http_xslt_module=dynamic --with-mail=dynamic --with-mail_ssl_module --with-stream=dynamic --with-stream_geoip_module=dynamic --with-stream_ssl_module --with-stream_ssl_preread_module --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-headers-more-filter --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-auth-pam --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-cache-purge --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-dav-ext --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-ndk --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-echo --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-fancyindex --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-geoip2 --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/nchan --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-lua --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/rtmp --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-uploadprogress --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-upstream-fair --add-dynamic-module=/build/nginx-BUo7Uw/nginx-1.18.0/debian/modules/http-subs-filter |
||
Description
Hello,
upgrading from Ubuntu 16.04 to 20.04 (meaning nginx 1.16 to 1.18 and OpenSSL 1.0.2g to 1.1.1f) I noticed different behaviour with ssl client certificate verification.
As it seems, 1.18 errors out with a 495/400 Bad Request because of OpenSSL error 22 "X509_V_ERR_CERT_CHAIN_TOO_LONG". Changing ssl_verify_depth from 1 to 2/3/4 does not change this behaviour as I would expect. The SSL cert chain is rather simple: Root CA -> Intermediate CA -> Leaf Cert
This is set up as "ssl_verify_client optional_no_ca". The old version correctly processes the request and adds the "FAILED:..." variable in $ssl_client_verify. The newer version errors out before any proxying takes place.
I tried to search HG-commits as well as TRAC-tickets but could not find anything related. Is this expected behaviour or a bug? And if it is expected: How could I restore the old functionality with the newer nginx?
Working example (16.04, 1.16, 1.0.2g):
2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http header: "Host: hostname" 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http header: "Accept: application/json, application/*+json" 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http alloc large header buffer 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 posix_memalign: 000055EA6AE62260:512 @16 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 malloc: 000055EA6B75B610:8192 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http large header alloc: 000055EA6B75B610 8192 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http large header copy: 790 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 SSL_read: 1040 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 SSL_read: -1 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 SSL_get_error: 2 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http header: "Content-Length: 519" 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http header: "Connection: close" 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http header: "Content-Type: application/json" 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http header done 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 event timer del: 91: 194954484 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 generic phase: 0 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 rewrite phase: 1 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 test location: "/" 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 test location: "resource" 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 using configuration "/resource" 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http cl:519 max:157286400 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 rewrite phase: 3 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 upload-progress: get_tracking_id 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 upload-progress: get_tracking_id no header found 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 upload-progress: get_tracking_id no id found 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 trackuploads no id found in POST upload req 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 rewrite phase: 4 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 post rewrite phase: 5 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 generic phase: 6 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 generic phase: 7 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 generic phase: 8 [...] 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http script copy: "X-SSL-Client-verify" 2021/08/26 16:12:07 [debug] 21471#21471: *1404287 http script var: "FAILED:unable to get local issuer certificate"
Non-working example (20.04, 1.18, 1.1.1f):
Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 accept: ip:port fd:114 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 event timer add: 114: 60000:98621637 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 reusable connection: 1 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 epoll add event: fd:114 op:1 ev:80002001 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http check ssl handshake Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http recv(): 1 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 https ssl handshake: 0x16 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 tcp_nodelay Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 reusable connection: 0 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 ssl get session: AA9FAD00:32 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL_do_handshake: -1 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL_get_error: 2 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL handshake handler: 0 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 verify:0, error:22, depth:2, subject:"subject of a root CA", issuer:"subject of a root CA" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 verify:1, error:22, depth:2, subject:"subject of a root CA", issuer:"subject of a root CA" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 verify:1, error:22, depth:1, subject:"subject of an intermediate CA", issuer:"subject of a root CA" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 verify:1, error:22, depth:0, subject:"subject of a leaf cert", issuer:"subject of an intermediate CA" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL_do_handshake: 1 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL: TLSv1.2, cipher: "ECDHE-RSA-AES256-SHA TLSv1 Kx=ECDH Au=RSA Enc=AES(256) Mac=SHA1" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 reusable connection: 1 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http wait request handler Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 malloc: 000055B7FB5D61B0:1024 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL_read: -1 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL_get_error: 2 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 free: 000055B7FB5D61B0 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http wait request handler Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 malloc: 000055B7FB5D61B0:1024 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL_read: 1024 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL_read: avail:0 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 reusable connection: 0 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 posix_memalign: 000055B7FB804AC0:4096 @16 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http process request line Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http request line: "POST /resource HTTP/1.1" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http uri: "/resource" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http args: "" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http exten: "" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 posix_memalign: 000055B7FB7F5ED0:4096 @16 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http process request header line Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http header: "Host: hostname" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http header: "Accept: application/json, application/*+json" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http alloc large header buffer Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 posix_memalign: 000055B7FB82D280:512 @16 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 malloc: 000055B7FB827480:8192 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http large header alloc: 000055B7FB827480 8192 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http large header copy: 790 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL_read: 1042 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL_read: -1 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 SSL_get_error: 2 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http header: "Content-Length: 521" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http header: "Connection: close" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http header: "Content-Type: application/json" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http header done Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http finalize request: 495, "/resource?" a:1, c:1 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 event timer del: 114: 98621637 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http special response: 495, "/resource?" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 http set discard body Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 uploadprogress error-tracker error: 400 Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 uploadprogress error-tracker not tracking in this location Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 headers more header filter, uri "/resource" Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 xslt filter header Aug 26 14:28:14 nginx: 2021/08/26 14:28:14 [debug] 366273#366273: *2176 HTTP/1.1 400 Bad Request#015#012Date: Thu, 26 Aug 2021 12:28:14 GMT#015#012Content-Type: text/html#015#012Content-Length: 208#015#012Connection: close#015 [...]
A minimal config would be:
server {
listen 10.0.0.1:443 ssl;
server_name hostname;
ssl_protocols TLSv1 TLSv1.1 TLSv1.2;
ssl_dhparam /etc/ssl/private/dhparams.pem;
ssl_prefer_server_ciphers on;
ssl_certificate cert.pem;
ssl_certificate_key key.key;
ssl_verify_client optional_no_ca;
[...]
location /resource {
proxy_set_header Host $host ;
proxy_set_header X-SSL-Client-verify $ssl_client_verify ;
proxy_pass http://upstream;
}
[...]
Change History (3)
comment:1 by , 3 years ago
comment:2 by , 3 years ago
Hello,
I re-evaluated the configs and found that the ssl_verify_depth setting I had set before was not applied due to a different virtual host (read: server-block) serving on the same IP+port combination not having the ssl_verify_depth setting and therefore using "1" instead of "2". The setting of the first processed virtual host was used, which I believe is expected behaviour?
The ticket is therefore invalid.
comment:3 by , 3 years ago
| Resolution: | → invalid |
|---|---|
| Status: | new → closed |
Thanks for confirming, closing this.
Note:
See TracTickets
for help on using tickets.
In OpenSSL 1.1.0, verification of certificates was changed. In particular, if more than one error applies, now it can return a different error. Likely you are facing issues due the change in the verification.
I've just tested, and indeed OpenSSL 1.1.1f returns X509_V_ERR_CERT_CHAIN_TOO_LONG (22), while OpenSSL 1.0.2 used to return X509_V_ERR_UNABLE_TO_GET_ISSUER_CERT_LOCALLY (20) when the depth limit is hit but no trusted certificates are found locally (for example, when the client provides a long enough certificate chain).
Using large enough
ssl_verify_depthis expected to fix this though, and does so in my tests with OpenSSL 1.1.1f. In particular, a test with thessl_verify_depth 1;fails as in your logs:But with
ssl_verify_depth 2;the request is permitted as it should:Could you please confirm you are still seeing the error with
ssl_verify_depth 2;(or more) and double-check it is set correctly?