Opened 5 weeks ago

Closed 4 weeks 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 Maxim Dounin, 4 weeks ago

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_depth is expected to fix this though, and does so in my tests with OpenSSL 1.1.1f. In particular, a test with the ssl_verify_depth 1; fails as in your logs:

...
2021/08/28 00:52:42 [debug] 93206#100080: *4 SSL handshake handler: 0
2021/08/28 00:52:42 [debug] 93206#100080: *4 verify:0, error:22, depth:2, subject:"/CN=root", issuer:"/CN=root"
2021/08/28 00:52:42 [debug] 93206#100080: *4 verify:1, error:22, depth:2, subject:"/CN=root", issuer:"/CN=root"
2021/08/28 00:52:42 [debug] 93206#100080: *4 verify:1, error:22, depth:1, subject:"/CN=int", issuer:"/CN=root"
2021/08/28 00:52:42 [debug] 93206#100080: *4 verify:1, error:22, depth:0, subject:"/CN=end", issuer:"/CN=int"
2021/08/28 00:52:42 [debug] 93206#100080: *4 SSL_do_handshake: 1
2021/08/28 00:52:42 [debug] 93206#100080: *4 SSL: TLSv1.2, cipher: "ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(128) Mac=
AEAD"
2021/08/28 00:52:42 [debug] 93206#100080: *4 reusable connection: 1
2021/08/28 00:52:42 [debug] 93206#100080: *4 http wait request handler
2021/08/28 00:52:42 [debug] 93206#100080: *4 posix_memalign: 29326800:256 @16
2021/08/28 00:52:42 [debug] 93206#100080: *4 malloc: 29253000:1024
2021/08/28 00:52:42 [debug] 93206#100080: *4 SSL_read: -1
2021/08/28 00:52:42 [debug] 93206#100080: *4 SSL_get_error: 2
2021/08/28 00:52:42 [debug] 93206#100080: *4 free: 29253000
2021/08/28 00:52:42 [debug] 93206#100080: timer delta: 9
2021/08/28 00:52:42 [debug] 93206#100080: worker cycle
2021/08/28 00:52:42 [debug] 93206#100080: kevent timer: 59991, changes: 0
2021/08/28 00:52:42 [debug] 93206#100080: kevent events: 1
2021/08/28 00:52:42 [debug] 93206#100080: kevent: 3: ft:-1 fl:0020 ff:00000000 d:75 ud:293035A1
2021/08/28 00:52:42 [debug] 93206#100080: *4 http wait request handler
2021/08/28 00:52:42 [debug] 93206#100080: *4 malloc: 29253000:1024
2021/08/28 00:52:42 [debug] 93206#100080: *4 SSL_read: 46
2021/08/28 00:52:42 [debug] 93206#100080: *4 SSL_read: -1
2021/08/28 00:52:42 [debug] 93206#100080: *4 SSL_get_error: 2
2021/08/28 00:52:42 [debug] 93206#100080: *4 reusable connection: 0
2021/08/28 00:52:42 [debug] 93206#100080: *4 posix_memalign: 29260000:4096 @16
2021/08/28 00:52:42 [debug] 93206#100080: *4 http process request line
2021/08/28 00:52:42 [debug] 93206#100080: *4 http request line: "GET /t?end-int-root HTTP/1.0"
2021/08/28 00:52:42 [debug] 93206#100080: *4 http uri: "/t"
2021/08/28 00:52:42 [debug] 93206#100080: *4 http args: "end-int-root"
2021/08/28 00:52:42 [debug] 93206#100080: *4 http exten: ""
2021/08/28 00:52:42 [debug] 93206#100080: *4 http process request header line
2021/08/28 00:52:42 [debug] 93206#100080: *4 http header: "Host: localhost"
2021/08/28 00:52:42 [debug] 93206#100080: *4 http header done
2021/08/28 00:52:42 [info] 93206#100080: *4 client SSL certificate verify error: (22:certificate chain too long) while reading client request headers, client: 127.0.0.1, server: localhost, request: "GET /t?end-int-root HTTP/1.0", host: "localhost"
2021/08/28 00:52:42 [debug] 93206#100080: *4 http finalize request: 495, "/t?end-int-root" a:1, c:1
...

But with ssl_verify_depth 2; the request is permitted as it should:

...
2021/08/28 00:52:42 [debug] 93206#100080: *2 SSL handshake handler: 0
2021/08/28 00:52:42 [debug] 93206#100080: *2 verify:0, error:19, depth:2, subject:"/CN=root", issuer:"/CN=root"
2021/08/28 00:52:42 [debug] 93206#100080: *2 verify:1, error:19, depth:2, subject:"/CN=root", issuer:"/CN=root"
2021/08/28 00:52:42 [debug] 93206#100080: *2 verify:1, error:19, depth:1, subject:"/CN=int", issuer:"/CN=root"
2021/08/28 00:52:42 [debug] 93206#100080: *2 verify:1, error:19, depth:0, subject:"/CN=end", issuer:"/CN=int"
2021/08/28 00:52:42 [debug] 93206#100080: *2 SSL_do_handshake: 1
2021/08/28 00:52:42 [debug] 93206#100080: *2 SSL: TLSv1.2, cipher: "ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(128) Mac=
AEAD"
2021/08/28 00:52:42 [debug] 93206#100080: *2 reusable connection: 1
2021/08/28 00:52:42 [debug] 93206#100080: *2 http wait request handler
2021/08/28 00:52:42 [debug] 93206#100080: *2 posix_memalign: 29326500:256 @16
2021/08/28 00:52:42 [debug] 93206#100080: *2 malloc: 29253000:1024
2021/08/28 00:52:42 [debug] 93206#100080: *2 SSL_read: -1
2021/08/28 00:52:42 [debug] 93206#100080: *2 SSL_get_error: 2
2021/08/28 00:52:42 [debug] 93206#100080: *2 free: 29253000
2021/08/28 00:52:42 [debug] 93206#100080: timer delta: 10
2021/08/28 00:52:42 [debug] 93206#100080: worker cycle
2021/08/28 00:52:42 [debug] 93206#100080: kevent timer: 59990, changes: 0
2021/08/28 00:52:42 [debug] 93206#100080: kevent events: 1
2021/08/28 00:52:42 [debug] 93206#100080: kevent: 3: ft:-1 fl:0020 ff:00000000 d:75 ud:293035A1
2021/08/28 00:52:42 [debug] 93206#100080: *2 http wait request handler
2021/08/28 00:52:42 [debug] 93206#100080: *2 malloc: 29253000:1024
2021/08/28 00:52:42 [debug] 93206#100080: *2 SSL_read: 46
2021/08/28 00:52:42 [debug] 93206#100080: *2 SSL_read: -1
2021/08/28 00:52:42 [debug] 93206#100080: *2 SSL_get_error: 2
2021/08/28 00:52:42 [debug] 93206#100080: *2 reusable connection: 0
2021/08/28 00:52:42 [debug] 93206#100080: *2 posix_memalign: 29260000:4096 @16
2021/08/28 00:52:42 [debug] 93206#100080: *2 http process request line
2021/08/28 00:52:42 [debug] 93206#100080: *2 http request line: "GET /t?end-int-root HTTP/1.0"
2021/08/28 00:52:42 [debug] 93206#100080: *2 http uri: "/t"
2021/08/28 00:52:42 [debug] 93206#100080: *2 http args: "end-int-root"
2021/08/28 00:52:42 [debug] 93206#100080: *2 http exten: ""
2021/08/28 00:52:42 [debug] 93206#100080: *2 http process request header line
2021/08/28 00:52:42 [debug] 93206#100080: *2 http header: "Host: localhost"
2021/08/28 00:52:42 [debug] 93206#100080: *2 http header done
2021/08/28 00:52:42 [debug] 93206#100080: *2 event timer del: 3: 277450497
2021/08/28 00:52:42 [debug] 93206#100080: *2 generic phase: 0
2021/08/28 00:52:42 [debug] 93206#100080: *2 rewrite phase: 1
2021/08/28 00:52:42 [debug] 93206#100080: *2 using configuration ""
2021/08/28 00:52:42 [debug] 93206#100080: *2 http cl:-1 max:1048576
2021/08/28 00:52:42 [debug] 93206#100080: *2 rewrite phase: 3
2021/08/28 00:52:42 [debug] 93206#100080: *2 post rewrite phase: 4
2021/08/28 00:52:42 [debug] 93206#100080: *2 generic phase: 5
2021/08/28 00:52:42 [debug] 93206#100080: *2 generic phase: 6
2021/08/28 00:52:42 [debug] 93206#100080: *2 generic phase: 7
2021/08/28 00:52:42 [debug] 93206#100080: *2 generic phase: 8
2021/08/28 00:52:42 [debug] 93206#100080: *2 generic phase: 9
2021/08/28 00:52:42 [debug] 93206#100080: *2 access phase: 10
2021/08/28 00:52:42 [debug] 93206#100080: *2 access phase: 11
2021/08/28 00:52:42 [debug] 93206#100080: *2 access phase: 12
2021/08/28 00:52:42 [debug] 93206#100080: *2 post access phase: 13
2021/08/28 00:52:42 [debug] 93206#100080: *2 generic phase: 14
2021/08/28 00:52:42 [debug] 93206#100080: *2 generic phase: 15
2021/08/28 00:52:42 [debug] 93206#100080: *2 content phase: 16
2021/08/28 00:52:42 [debug] 93206#100080: *2 content phase: 17
2021/08/28 00:52:42 [debug] 93206#100080: *2 content phase: 18
2021/08/28 00:52:42 [debug] 93206#100080: *2 content phase: 19
2021/08/28 00:52:42 [debug] 93206#100080: *2 content phase: 20
2021/08/28 00:52:42 [debug] 93206#100080: *2 content phase: 21
2021/08/28 00:52:42 [debug] 93206#100080: *2 http filename: "/tmp/nginx-test-eimVLSRVuy/t"
2021/08/28 00:52:42 [debug] 93206#100080: *2 add cleanup: 2926090C
2021/08/28 00:52:42 [debug] 93206#100080: *2 http static fd: 11
2021/08/28 00:52:42 [debug] 93206#100080: *2 http set discard body
2021/08/28 00:52:42 [debug] 93206#100080: *2 http script var: "CN=end"
2021/08/28 00:52:42 [debug] 93206#100080: *2 http script var: "FAILED:self signed certificate in certificate chain"
2021/08/28 00:52:42 [debug] 93206#100080: *2 xslt filter header
2021/08/28 00:52:42 [debug] 93206#100080: *2 HTTP/1.1 200 OK
...

Could you please confirm you are still seeing the error with ssl_verify_depth 2; (or more) and double-check it is set correctly?

comment:2 by Malte Schmidt, 4 weeks 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 Maxim Dounin, 4 weeks ago

Resolution: invalid
Status: newclosed

Thanks for confirming, closing this.

Note: See TracTickets for help on using tickets.