﻿id	summary	reporter	owner	description	type	status	priority	milestone	component	version	resolution	keywords	cc	uname	nginx_version
2238	Difference in ssl_verify_depth and ssl_verify_client optional_no_ca handling between 1.16 and 1.18?	Malte Schmidt		"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;
    }
[...]
}}}"	defect	closed	minor		nginx-core	1.18.x	invalid	nginx,verify,optional,depth	Malte Schmidt	"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 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"
