NGINX说“客户端在读取客户端请求标头时没有发送所需的SSL证书”我们如何排除故障？

我们已将NGINX配置为使用相互身份验证 . 当客户向我们发出请求时，我们会在NGINX日志中获得一条信息行，说“客户端在读取客户端请求标头时未发送任何SSL证书” . 我们认为客户实际上是在发送证书 .

证据是我们看到了客户端使用的curl命令并且它正在发送证书 . 我们将其调用与此日志消息相关联 . 此外，我们有一个配置为使用相互身份验证的F5代理，如果他们将其更改为命中F5，则会接受相同的curl命令 . 如果他们没有发送客户端证书，则会拒绝此呼叫 . 在F5日志中，我们看到F5正在接收客户端证书 . 客户端没有改变它的行为，我们正在改变DNS以指向F5和NGINX .

当我google for "client sent no required SSL certificate while reading client request headers"时，我找不到任何关于此消息的官方NGINX文档 . How can I troubleshoot this better? 现在我们用 nginx-debug 启动nginx，但调试输出没有看到这个问题't seem to clearly explain why we' . 以下是其中一些日志：

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 .