NGINX говорит, что «клиент не запрашивал SSL-сертификат при чтении заголовков запросов клиентов», как устранить неполадки?

Question

Мы настроили NGINX для использования взаимной аутентификации. Когда клиент делает запрос к нам, мы получаем информационную строку в журнале NGINX: «клиент не запрашивал сертификат SSL при чтении заголовков запросов клиентов». Мы считаем, что клиент фактически отправляет сертификат.

Доказательством является то, что мы видели команду curl, которую использовал клиент, и она отправляла сертификат. Мы соотносили их призыв к этому сообщению журнала. Кроме того, у нас есть прокси-сервер F5, который настроен на использование взаимного auth, и их же команда curl принимается, если они меняют ее, чтобы попасть в F5. Этот вызов будет отклонен, если они не отправили сертификат клиента. В журналах F5 мы видим, что F5 получает клиентский сертификат. Клиент не меняет свое поведение, мы меняем DNS на точку между F5 и NGINX.

Когда я отправляю Google для «отправки клиентом не требуемого SSL-сертификата при чтении заголовков запросов клиента», я не могу найти официальную документацию NGINX об этом сообщении. Как я могу устранить это лучше? Прямо сейчас мы начинаем nginx с nginx-debug, но выход отладки, похоже, не ясно объясняет, почему мы видим эту проблему. Вот некоторые из этих журналов:

2016/12/19 23:27:59 [debug] 179#179: epoll: fd:6 ev:0001 d:0000000000C7AEB0 
2016/12/19 23:27:59 [debug] 179#179: accept on 0.0.0.0:443, ready: 0 
2016/12/19 23:27:59 [debug] 179#179: posix_memalign: 0000000000B8D530:512 @16 
2016/12/19 23:27:59 [debug] 179#179: *4539 accept: 172.20.72.125:23211 fd:3 
2016/12/19 23:27:59 [debug] 179#179: *4539 event timer add: 3: 60000:1482190139859 
2016/12/19 23:27:59 [debug] 179#179: *4539 reusable connection: 1 
2016/12/19 23:27:59 [debug] 179#179: *4539 epoll add event: fd:3 op:1 ev:80002001 
2016/12/19 23:27:59 [debug] 179#179: timer delta: 873 
2016/12/19 23:27:59 [debug] 179#179: worker cycle 
2016/12/19 23:27:59 [debug] 179#179: epoll timer: 60000 
2016/12/19 23:27:59 [debug] 179#179: epoll: fd:3 ev:0001 d:0000000000C7B360 
2016/12/19 23:27:59 [debug] 179#179: *4539 http check ssl handshake 
2016/12/19 23:27:59 [debug] 179#179: *4539 http recv(): 1 
2016/12/19 23:27:59 [debug] 179#179: *4539 https ssl handshake: 0x16 
2016/12/19 23:27:59 [debug] 181#181: accept on 0.0.0.0:443, ready: 0 
2016/12/19 23:27:59 [debug] 181#181: accept() not ready (11: Resource temporarily unavailable) 
2016/12/19 23:27:59 [debug] 179#179: *4539 ssl get session: DB2C8809:32 
2016/12/19 23:27:59 [debug] 179#179: shmtx lock 
2016/12/19 23:27:59 [debug] 179#179: shmtx unlock 
2016/12/19 23:27:59 [debug] 181#181: timer delta: 873 
2016/12/19 23:27:59 [debug] 181#181: worker cycle 
2016/12/19 23:27:59 [debug] 181#181: epoll timer: -1 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_do_handshake: -1 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_get_error: 2 
2016/12/19 23:27:59 [debug] 179#179: *4539 reusable connection: 0 
2016/12/19 23:27:59 [debug] 179#179: timer delta: 0 
2016/12/19 23:27:59 [debug] 179#179: worker cycle 
2016/12/19 23:27:59 [debug] 179#179: epoll timer: 60000 
2016/12/19 23:27:59 [debug] 179#179: epoll: fd:3 ev:0001 d:0000000000C7B360 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL handshake handler: 0 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_do_handshake: -1 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_get_error: 2 
2016/12/19 23:27:59 [debug] 179#179: timer delta: 29 
2016/12/19 23:27:59 [debug] 179#179: worker cycle 
2016/12/19 23:27:59 [debug] 179#179: epoll timer: 59971 
2016/12/19 23:27:59 [debug] 179#179: epoll: fd:3 ev:0001 d:0000000000C7B360 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL handshake handler: 0 
2016/12/19 23:27:59 [debug] 179#179: shmtx lock 
2016/12/19 23:27:59 [debug] 179#179: slab alloc: 136 slot: 5 
2016/12/19 23:27:59 [debug] 179#179: slab alloc: 00007FF33D86B000 
2016/12/19 23:27:59 [debug] 179#179: slab alloc: 128 slot: 4 
2016/12/19 23:27:59 [debug] 179#179: slab alloc: 00007FF33D869080 
2016/12/19 23:27:59 [debug] 179#179: *4539 ssl new session: B0945ECD:32:136 
2016/12/19 23:27:59 [debug] 179#179: shmtx unlock 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_do_handshake: 1 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL: TLSv1.1, cipher: "ECDHE-RSA-AES256-SHA SSLv3 Kx=ECDH Au=RSA Enc=AES(256) Mac=SHA1" 
2016/12/19 23:27:59 [debug] 179#179: *4539 reusable connection: 1 
2016/12/19 23:27:59 [debug] 179#179: *4539 http wait request handler 
2016/12/19 23:27:59 [debug] 179#179: *4539 malloc: 0000000000B89230:1024 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_read: -1 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_get_error: 2 
2016/12/19 23:27:59 [debug] 179#179: *4539 free: 0000000000B89230 
2016/12/19 23:27:59 [debug] 179#179: timer delta: 3 
2016/12/19 23:27:59 [debug] 179#179: worker cycle 
2016/12/19 23:27:59 [debug] 179#179: epoll timer: 59968 
2016/12/19 23:27:59 [debug] 179#179: epoll: fd:3 ev:0001 d:0000000000C7B360 
2016/12/19 23:27:59 [debug] 179#179: *4539 http wait request handler 
2016/12/19 23:27:59 [debug] 179#179: *4539 malloc: 0000000000B89230:1024 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_read: 172 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_read: -1 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_get_error: 2 
2016/12/19 23:27:59 [debug] 179#179: *4539 reusable connection: 0 
2016/12/19 23:27:59 [debug] 179#179: *4539 posix_memalign: 0000000000C71800:4096 @16 
2016/12/19 23:27:59 [debug] 179#179: *4539 http process request line 
2016/12/19 23:27:59 [debug] 179#179: *4539 http request line: "GET /myapp-myapi/v2/id12345/endpoint HTTP/1.1" 
2016/12/19 23:27:59 [debug] 179#179: *4539 http uri: "/myapp-myapi/v2/id12345/endpoint" 
2016/12/19 23:27:59 [debug] 179#179: *4539 http args: "" 
2016/12/19 23:27:59 [debug] 179#179: *4539 http exten: "" 
2016/12/19 23:27:59 [debug] 179#179: *4539 http process request header line 
2016/12/19 23:27:59 [debug] 179#179: *4539 http header: "a-request-header: client-qa" 
2016/12/19 23:27:59 [debug] 179#179: *4539 posix_memalign: 0000000000B9C640:4096 @16 
2016/12/19 23:27:59 [debug] 179#179: *4539 http header: "User-Agent: Jakarta Commons-HttpClient/3.1" 
2016/12/19 23:27:59 [debug] 179#179: *4539 http header: "Host: pre.myapp.com" 
2016/12/19 23:27:59 [debug] 179#179: *4539 http header done 
2016/12/19 23:27:59 [info] 179#179: *4539 client sent no required SSL certificate while reading client request headers, client: 172.20.72.125, server: pre.myapp.com, request: "GET /myapp-myapi/v2/id12345/endpoint HTTP/1.1", host: "pre.myapp.com" 
2016/12/19 23:27:59 [debug] 179#179: ssl remove session: B0945ECD:32 
2016/12/19 23:27:59 [debug] 179#179: shmtx lock 
2016/12/19 23:27:59 [debug] 179#179: slab free: 00007FF33D86B000 
2016/12/19 23:27:59 [debug] 179#179: slab free: 00007FF33D869080 
2016/12/19 23:27:59 [debug] 179#179: shmtx unlock 
2016/12/19 23:27:59 [debug] 179#179: *4539 http finalize request: 496, "/myapp-myapi/v2/id12345/endpoint?" a:1, c:1 
2016/12/19 23:27:59 [debug] 179#179: *4539 event timer del: 3: 1482190139859 
2016/12/19 23:27:59 [debug] 179#179: *4539 http special response: 496, "/myapp-myapi/v2/id12345/endpoint?" 
2016/12/19 23:27:59 [debug] 179#179: *4539 http set discard body 
2016/12/19 23:27:59 [debug] 179#179: *4539 HTTP/1.1 400 Bad Request 
Server: nginx/1.11.4 
Date: Mon, 19 Dec 2016 23:27:59 GMT 
Content-Type: text/html 
Content-Length: 253 
Connection: close 

2016/12/19 23:27:59 [debug] 179#179: *4539 write new buf t:1 f:0 0000000000B9C6C0, pos 0000000000B9C6C0, size: 152 file: 0, size: 0 
2016/12/19 23:27:59 [debug] 179#179: *4539 http write filter: l:0 f:0 s:152 
2016/12/19 23:27:59 [debug] 179#179: *4539 http output filter "/myapp-myapi/v2/id12345/endpoint?" 
2016/12/19 23:27:59 [debug] 179#179: *4539 http copy filter: "/myapp-myapi/v2/id12345/endpoint?" 
2016/12/19 23:27:59 [debug] 179#179: *4539 http postpone filter "/myapp-myapi/v2/id12345/endpoint?" 0000000000B9C8A0 
2016/12/19 23:27:59 [debug] 179#179: *4539 write old buf t:1 f:0 0000000000B9C6C0, pos 0000000000B9C6C0, size: 152 file: 0, size: 0 
2016/12/19 23:27:59 [debug] 179#179: *4539 write new buf t:0 f:0 0000000000000000, pos 0000000000711B80, size: 200 file: 0, size: 0 
2016/12/19 23:27:59 [debug] 179#179: *4539 write new buf t:0 f:0 0000000000000000, pos 0000000000712DE0, size: 53 file: 0, size: 0 
2016/12/19 23:27:59 [debug] 179#179: *4539 http write filter: l:1 f:0 s:405 
2016/12/19 23:27:59 [debug] 179#179: *4539 http write filter limit 0 
2016/12/19 23:27:59 [debug] 179#179: *4539 posix_memalign: 0000000000BF6100:512 @16 
2016/12/19 23:27:59 [debug] 179#179: *4539 malloc: 0000000000C01FE0:16384 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL buf copy: 152 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL buf copy: 200 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL buf copy: 53 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL to write: 405 
2016/12/19 23:27:59 [debug] 179#179: *4539 SSL_write: 405 
2016/12/19 23:27:59 [debug] 179#179: *4539 http write filter 0000000000000000 
2016/12/19 23:27:59 [debug] 179#179: *4539 http copy filter: 0 "/myapp-myapi/v2/id12345/endpoint?" 
2016/12/19 23:27:59 [debug] 179#179: *4539 http finalize request: 0, "/myapp-myapi/v2/id12345/endpoint?" a:1, c:1 
2016/12/19 23:27:59 [debug] 179#179: *4539 http request count:1 blk:0 
2016/12/19 23:27:59 [debug] 179#179: *4539 http close request 
2016/12/19 23:27:59 [debug] 179#179: *4539 http log handler 
172.20.72.125 - - [19/Dec/2016:23:27:59 +0000] https "GET /myapp-myapi/v2/id12345/endpoint HTTP/1.1" 400 253 "-" "Jakarta Commons-HttpClient/3.1" "-" "-" "NONE" "" "client-qa" 

Это наш nginx.conf файл:

#daemon off; 
user nginx; 
worker_processes 4; 

error_log /var/log/nginx/error.log debug; 
pid  /var/run/nginx.pid; 

events { 
    worker_connections 1024; 
    use epoll; 
} 

http { 
    index index.php index.htm index.html; 
    include /etc/nginx/mime.types; 

    upstream backend-myapi { 
     server myapp-myapi:8087 max_fails=0 fail_timeout=0s; 
     server myapp-myapi:8087 max_fails=0 fail_timeout=0s; 
    } 

    map $a_request_header|$ssl_client_verify $ssl_common_name { 
     default  $ssl_client_s_dn; 
     40011|NONE CN=mycn; 
    } 

    ssl_protocols    TLSv1 TLSv1.1; 
    ssl_prefer_server_ciphers on; 
    ssl_session_cache   shared:SSL:10m; 
    ssl_session_timeout  10m; 
    ssl_certificate   /etc/secrets/servercert-legacy; 
    ssl_certificate_key  /etc/secrets/serverkey-legacy; 
    ssl_client_certificate /etc/nginx/ca.crt; 

    proxy_set_header Host     $host; 
    proxy_set_header SSL-COMMON-NAME  $ssl_common_name; # TODO change this header to just DN 
    proxy_set_header VERIFIED    $ssl_client_verify; 
    proxy_set_header X-Real-IP    $remote_addr; 
    proxy_set_header X-Forwarded-For  $proxy_add_x_forwarded_for; 
    proxy_set_header X-Forwarded-Proto  $scheme; 

    proxy_max_temp_file_size 0; 
    proxy_connect_timeout  30; 
    proxy_send_timeout   30; 
    proxy_read_timeout   300; 
    proxy_buffer_size   4k; 
    proxy_buffers    4 32k; 
    proxy_busy_buffers_size 64k; 
    proxy_next_upstream  error http_502; 
    proxy_temp_file_write_size 64k; 

    default_type application/octet-stream; 

    log_format main '$remote_addr - $remote_user [$time_local] $scheme "$request" ' 
         '$status $body_bytes_sent "$http_referer" ' 
         '"$http_user_agent" "$http_x_forwarded_for" ' 
         '"$ssl_client_s_dn" "$ssl_client_verify" ' 
         '"$ssl_common_name" "$a_request_header"'; 

    access_log /var/log/nginx/access.log main; 

    sendfile  on; 
    #tcp_nopush  on; 

    client_max_body_size 10m; 
    client_body_buffer_size 128k; 
    large_client_header_buffers 4 16k; 

    # gzip on; 
    # gzip_buffers 16 8k; 
    # gzip_comp_level 3; 
    # gzip_disable "msie6"; 
    # gzip_http_version 1.0; 
    # gzip_min_length 1024; 
    # gzip_proxied any; 
    # gzip_types text/plain text/css text/xml text/javascript application/xml application/xml+rss application/javascript application/json; 
    # gzip_vary on; 

    include /etc/nginx/conf.d/*.conf; 
} 

Мы используем Nginx/1.11.4.

Answer 1

Я не вижу там конфигурации, требующей авторизации клиента ssl. Попробуйте добавить

ssl_verify_client on 
ssl_verify_depth 3; 
ssl_client_certificate /path/to/accepted/CAs.pem; 

(от http://nginx.org/en/docs/http/ngx_http_ssl_module.html#ssl_verify_client)