[security][modsecurity][nginx] nginx 与 modsecurity

参考文档：

https://github.com/SpiderLabs/ModSecurity/wiki/Reference-Manual#installation-for-nginx

nginx不支持动态加载模块，所以需要重新编译，将modsecurity和nginx整合。

一： 软件准备：

　　ModSecurity-2.9.1.zip

　　nginx-1.10.1.tar.gz

　　根据文档所述，有一些依赖包需要安装。　　

yum install httpd httpd-devel pcre pcre-devel libxml2-devel 

二， 编译安装：

　　从 2.6开始，modsecurity的编译方式发生了调整。参考：

　　https://github.com/SpiderLabs/ModSecurity/wiki/Reference-Manual#GitHub_Access

[root@dpdk ModSecurity-2.9.1]# ./autogen.sh 
[root@dpdk ModSecurity-2.9.1]# ./configure --enable-standalone-module --disable-mlogc
[root@dpdk ModSecurity-2.9.1]# make

　　编译nginx

[root@dpdk nginx-1.10.1]# ./configure --prefix=/root/modsecurity/output --add-module=../ModSecurity-2.9.1/nginx/modsecurity/ 
[root@dpdk nginx-1.10.1]# make
[root@dpdk nginx-1.10.1]# make install

三， 运行nginx

　　1.  修改配置文件，conf/nginx.conf， 增加如下行：

user root;

　　2.  使用如下命令启动/停止：

[root@dpdk output]# ./sbin/nginx -c conf/nginx.conf
[root@dpdk output]# ./sbin/nginx -s stop

四，配置modsecurity

已经在nginx中设置了两个监听端口80,81,分别对应于两个静态页。

[root@dpdk conf]# cat nginx.conf

user root;
worker_processes  1;

#error_log  logs/error.log;
#error_log  logs/error.log  notice;
#error_log  logs/error.log  info;

#pid        logs/nginx.pid;


events {
    worker_connections  1024;
}


http {
    include       mime.types;
    default_type  application/octet-stream;

    #log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
    #                  '$status $body_bytes_sent "$http_referer" '
    #                  '"$http_user_agent" "$http_x_forwarded_for"';

    #access_log  logs/access.log  main;

    sendfile        on;
    #tcp_nopush     on;

    #keepalive_timeout  0;
    keepalive_timeout  65;

    #gzip  on;

        include custom.conf;
        include mod.conf;

    server {
        listen       80;
        server_name  localhost;

        #charset koi8-r;

        #access_log  logs/host.access.log  main;

        location / {
            root   html;
            index  index.html index.htm;
        }

        #error_page  404              /404.html;

        # redirect server error pages to the static page /50x.html
        #
        error_page   500 502 503 504  /50x.html;
        location = /50x.html {
            root   html;
        }

        # proxy the PHP scripts to Apache listening on 127.0.0.1:80
        #
        #location ~ .php$ {
        #    proxy_pass   http://127.0.0.1;
        #}

        # pass the PHP scripts to FastCGI server listening on 127.0.0.1:9000
        #
        #location ~ .php$ {
        #    root           html;
        #    fastcgi_pass   127.0.0.1:9000;
        #    fastcgi_index  index.php;
        #    fastcgi_param  SCRIPT_FILENAME  /scripts$fastcgi_script_name;
        #    include        fastcgi_params;
        #}

        # deny access to .htaccess files, if Apache's document root
        # concurs with nginx's one
        #
        #location ~ /.ht {
        #    deny  all;
        #}
    }


    # another virtual host using mix of IP-, name-, and port-based configuration
    #
    #server {
    #    listen       8000;
    #    listen       somename:8080;
    #    server_name  somename  alias  another.alias;

    #    location / {
    #        root   html;
    #        index  index.html index.htm;
    #    }
    #}


    # HTTPS server
    #
    #server {
    #    listen       443 ssl;
    #    server_name  localhost;

    #    ssl_certificate      cert.pem;
    #    ssl_certificate_key  cert.key;

    #    ssl_session_cache    shared:SSL:1m;
    #    ssl_session_timeout  5m;

    #    ssl_ciphers  HIGH:!aNULL:!MD5;
    #    ssl_prefer_server_ciphers  on;

    #    location / {
    #        root   html;
    #        index  index.html index.htm;
    #    }
    #}

}

[root@dpdk conf]# cat custom.conf 

    server {
        listen       81;
        server_name  localhost;

        #charset koi8-r;

        #access_log  logs/host.access.log  main;

        location / {
            root   /usr/share/nginx/html;
            index  index.html index.htm;
        }

        #error_page  404              /404.html;

        # redirect server error pages to the static page /50x.html
        #
        error_page   500 502 503 504  /50x.html;
        location = /50x.html {
            root   html;
        }

    }

　　增加配置文件 mod.conf 监听于端口82

[root@dpdk conf]# cat mod.conf 
    server {
        listen       82;
        server_name  localhost;
        location / {
                ModSecurityEnabled on;
                ModSecurityConfig modsecurity.conf;
                proxy_pass http://127.0.0.1:81;
                proxy_read_timeout 180s;
        }
    }
[root@dpdk conf]# 

　　其中引用了两个配置文件，模板如下：

　　https://raw.githubusercontent.com/SpiderLabs/ModSecurity/master/modsecurity.conf-recommended

　　https://raw.githubusercontent.com/SpiderLabs/ModSecurity/master/unicode.mapping

五： 规则/语法/配置

　　文档：

　　https://www.feistyduck.com/library/modsecurity-handbook-free/online/

Everything in ModSecurity revolves around two things: configuration and rules. 
The configuration tells ModSecurity how to process the data it sees; 
the rules decide what to do with the processed data. 

For example:

SecRule ARGS "<script>" log,deny,status:404
Even without further assistance, you can probably recognize the part in the rule that specifies what we wish to look for in input data (<script>). Similarly, you will easily figure out what will happen if we do find the desired pattern (log,deny,status:404). Things will become more clear if I tell you about the general rule syntax, which is the following:

SecRule VARIABLES OPERATOR ACTIONS
The three parts have the following meanings:

The VARIABLES part tells ModSecurity where to look. The ARGS variable, used in the example, means all request parameters.
The OPERATOR part tells ModSecurity how to look. In the example, we have a regular expression pattern, which will be matched against ARGS.
The ACTIONS part tells ModSecurity what to do on a match. The rule in the example gives three instructions: log problem, deny transaction and use the status 404 for the denial (status:404).

 　　手册：

　　https://github.com/SpiderLabs/ModSecurity/wiki/Reference-Manual

　　第三方规则：

　　OWASP: https://www.owasp.org/index.php/Main_Page

　　 Core Rules: https://www.owasp.org/index.php/Category:OWASP_ModSecurity_Core_Rule_Set_Project

　　例子里有大量的注释，很适合学习：

　　/home/tong/Src/thirdparty/github/owasp-modsecurity-crs [git::v3.0/master]/crs-setup.conf.example

　　5.1  精读 Reference-Manual

　　　　要想细致理解，必须精读一遍。

　　5.2  精读429条项目规则

六： 在Nginx中使用与测试

 　　如第四小节内容所示，将82端口配置成modsecurity，并重定向至81端口。然而并不好使。。。

　　设置 ModSecurityEnabled Off;

　　修改 mod/conf 的内容，将 127.0.0.1 改为 localhost。 重定向成功。打开了81所指向的页。

　　再修改为 proxy_pass http://192.168.10.209;  也可以成功。

　　说明也许是ModSecurity设置的问题。

　　6.1  做一个最简单的modsecurity配置

[root@dpdk output]# cat conf/mymod.conf 
SecRuleEngine DetectionOnly
SecRequestBodyAccess On
SecResponseBodyAccess On

SecDebugLogLevel 9
SecDebugLog /root/modsecurity/output/logs/modsec_debug.log

SecAuditEngine On
SecAuditLogType Serial
SecAuditLog /root/modsecurity/output/logs/modsec_audit.log
[root@dpdk output]# 

　　现象不变。

　　可以modsec_debug.log中有如下打印信息：

[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Initialising transaction (txid @cAcAcAcAcAAAcAcAcAcSGuc).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Transaction context created (dcfg 23ce7b8).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Starting phase REQUEST_HEADERS.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Second phase starting (dcfg 23ce7b8).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Input filter: This request does not have a body.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Starting phase REQUEST_BODY.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Hook insert_filter: Adding output filter (r 23b91e0).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][9] Output filter: Receiving output (f 23ba430, r 23b91e0).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Starting phase RESPONSE_HEADERS.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][9] Content Injection: Not enabled.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][9] Output filter: Bucket type POOL contains 612 bytes.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][9] Output filter: Bucket type EOS contains 0 bytes.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Output filter: Completed receiving response body (buffered full - 612 bytes).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Starting phase RESPONSE_BODY.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Output filter: Output forwarding complete.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Initialising transaction (txid AcizPcAcAc8c3gAcAcO@AcAc).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Transaction context created (dcfg 23ce7b8).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Starting phase REQUEST_HEADERS.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Second phase starting (dcfg 23ce7b8).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Input filter: This request does not have a body.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Starting phase REQUEST_BODY.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Hook insert_filter: Adding output filter (r 23b91e0).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][9] Output filter: Receiving output (f 23ba430, r 23b91e0).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Starting phase RESPONSE_HEADERS.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][9] Content Injection: Not enabled.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][9] Output filter: Bucket type POOL contains 612 bytes.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][9] Output filter: Bucket type EOS contains 0 bytes.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Output filter: Completed receiving response body (buffered full - 612 bytes).
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Starting phase RESPONSE_BODY.
[22/Jun/2017:10:29:14 +0800] [/sid#23cdee0][rid#23b91e0][/][4] Output filter: Output forwarding complete.

　　以及error.log

2017/06/22 10:30:01 [alert] 2544#0: worker process 2622 exited on signal 11
2017/06/22 10:31:01 [alert] 2544#0: worker process 2641 exited on signal 11
2017/06/22 10:36:01 [alert] 2544#0: worker process 2642 exited on signal 11

　　使用 curl 访问，显示server没有返回任何数据

/home/tong/Temp [tong@T7] [10:21]
> curl 192.168.7.4:82
curl: (52) Empty reply from server

　　6.2   启用nginx debug

　　参考 man nginx

DEBUGGING LOG
     To enable a debugging log, reconfigure nginx to build with debugging:

           ./configure --with-debug ...

     and then set the debug level of the error_log:

           error_log /path/to/log debug;

     It is also possible to enable the debugging for a particular IP address:

           events {
                   debug_connection 127.0.0.1;
           }

[root@dpdk nginx-1.10.1]# ./configure --prefix=/root/modsecurity/output --add-module=../ModSecurity-2.9.1/nginx/modsecurity/ 
　　--with-debug
[root@dpdk nginx-1.10.1]# make
[root@dpdk nginx-1.10.1]# make install

　　配置里加一行

error_log  logs/error.log debug;

　　在次使用curl访问，日志如下

2017/06/22 10:52:52 [debug] 5474#0: epoll: fd:9 ev:0001 d:00007FAB90C6D0E8
2017/06/22 10:52:52 [debug] 5474#0: accept on 0.0.0.0:82, ready: 0
2017/06/22 10:52:52 [debug] 5474#0: posix_memalign: 0000000001674800:512 @16
2017/06/22 10:52:52 [debug] 5474#0: *1 accept: 192.168.7.1:44908 fd:3
2017/06/22 10:52:52 [debug] 5474#0: *1 event timer add: 3: 60000:1498100032928
2017/06/22 10:52:52 [debug] 5474#0: *1 reusable connection: 1
2017/06/22 10:52:52 [debug] 5474#0: *1 epoll add event: fd:3 op:1 ev:80002001
2017/06/22 10:52:52 [debug] 5474#0: timer delta: 16519
2017/06/22 10:52:52 [debug] 5474#0: worker cycle
2017/06/22 10:52:52 [debug] 5474#0: epoll timer: 60000
2017/06/22 10:52:52 [debug] 5474#0: epoll: fd:3 ev:0001 d:00007FAB90C6D370
2017/06/22 10:52:52 [debug] 5474#0: *1 http wait request handler
2017/06/22 10:52:52 [debug] 5474#0: *1 malloc: 00000000016410C0:1024
2017/06/22 10:52:52 [debug] 5474#0: *1 recv: fd:3 78 of 1024
2017/06/22 10:52:52 [debug] 5474#0: *1 reusable connection: 0
2017/06/22 10:52:52 [debug] 5474#0: *1 posix_memalign: 00000000016414D0:4096 @16
2017/06/22 10:52:52 [debug] 5474#0: *1 http process request line
2017/06/22 10:52:52 [debug] 5474#0: *1 http request line: "GET / HTTP/1.1"
2017/06/22 10:52:52 [debug] 5474#0: *1 http uri: "/"
2017/06/22 10:52:52 [debug] 5474#0: *1 http args: ""
2017/06/22 10:52:52 [debug] 5474#0: *1 http exten: ""
2017/06/22 10:52:52 [debug] 5474#0: *1 http process request header line
2017/06/22 10:52:52 [debug] 5474#0: *1 http header: "Host: 192.168.7.4:82"
2017/06/22 10:52:52 [debug] 5474#0: *1 http header: "User-Agent: curl/7.54.1"
2017/06/22 10:52:52 [debug] 5474#0: *1 http header: "Accept: */*"
2017/06/22 10:52:52 [debug] 5474#0: *1 http header done
2017/06/22 10:52:52 [debug] 5474#0: *1 event timer del: 3: 1498100032928
2017/06/22 10:52:52 [debug] 5474#0: *1 rewrite phase: 0
2017/06/22 10:52:52 [debug] 5474#0: *1 test location: "/"
2017/06/22 10:52:52 [debug] 5474#0: *1 using configuration "/"
2017/06/22 10:52:52 [debug] 5474#0: *1 http cl:-1 max:1048576
2017/06/22 10:52:52 [debug] 5474#0: *1 rewrite phase: 2
2017/06/22 10:52:52 [debug] 5474#0: *1 post rewrite phase: 3
2017/06/22 10:52:52 [debug] 5474#0: *1 generic phase: 4
2017/06/22 10:52:52 [debug] 5474#0: *1 modSecurity: handler
2017/06/22 10:52:52 [debug] 5474#0: *1 add cleanup: 00000000016423E0
2017/06/22 10:52:52 [debug] 5474#0: *1 posix_memalign: 0000000001635120:4096 @16
2017/06/22 10:52:52 [debug] 5474#0: *1 add cleanup: 0000000001642430
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers in: "Host: 192.168.7.4:82"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers in: "User-Agent: curl/7.54.1"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers in: "Accept: */*"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers in done
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: status -1
2017/06/22 10:52:52 [debug] 5474#0: *1 generic phase: 5
2017/06/22 10:52:52 [debug] 5474#0: *1 generic phase: 6
2017/06/22 10:52:52 [debug] 5474#0: *1 access phase: 7
2017/06/22 10:52:52 [debug] 5474#0: *1 access phase: 8
2017/06/22 10:52:52 [debug] 5474#0: *1 post access phase: 9
2017/06/22 10:52:52 [debug] 5474#0: *1 http init upstream, client timer: 0
2017/06/22 10:52:52 [debug] 5474#0: *1 epoll add event: fd:3 op:3 ev:80002005
2017/06/22 10:52:52 [debug] 5474#0: *1 http script copy: "Host: "
2017/06/22 10:52:52 [debug] 5474#0: *1 http script var: "localhost:81"
2017/06/22 10:52:52 [debug] 5474#0: *1 http script copy: "
"
2017/06/22 10:52:52 [debug] 5474#0: *1 http script copy: "Connection: close
"
2017/06/22 10:52:52 [debug] 5474#0: *1 http script copy: ""
2017/06/22 10:52:52 [debug] 5474#0: *1 http script copy: ""
2017/06/22 10:52:52 [debug] 5474#0: *1 http script copy: ""
2017/06/22 10:52:52 [debug] 5474#0: *1 http script copy: ""
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header: "User-Agent: curl/7.54.1"
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header: "Accept: */*"
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header:
"GET / HTTP/1.0
Host: localhost:81
Connection: close
User-Agent: curl/7.54.1
Accept: */*

"
2017/06/22 10:52:52 [debug] 5474#0: *1 http cleanup add: 0000000001635928
2017/06/22 10:52:52 [debug] 5474#0: *1 get rr peer, try: 2
2017/06/22 10:52:52 [debug] 5474#0: *1 get rr peer, current: 000000000166BAD0 -1
2017/06/22 10:52:52 [debug] 5474#0: *1 stream socket 14
2017/06/22 10:52:52 [debug] 5474#0: *1 epoll add connection: fd:14 ev:80002005
2017/06/22 10:52:52 [debug] 5474#0: *1 connect to 127.0.0.1:81, fd:14 #2
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream connect: -2
2017/06/22 10:52:52 [debug] 5474#0: *1 posix_memalign: 0000000001674AE0:128 @16
2017/06/22 10:52:52 [debug] 5474#0: *1 event timer add: 14: 60000:1498100032928
2017/06/22 10:52:52 [debug] 5474#0: *1 http finalize request: -4, "/?" a:1, c:2
2017/06/22 10:52:52 [debug] 5474#0: *1 http request count:2 blk:0
2017/06/22 10:52:52 [debug] 5474#0: timer delta: 0
2017/06/22 10:52:52 [debug] 5474#0: worker cycle
2017/06/22 10:52:52 [debug] 5474#0: epoll timer: 60000
2017/06/22 10:52:52 [debug] 5474#0: epoll: fd:3 ev:0004 d:00007FAB90C6D370
2017/06/22 10:52:52 [debug] 5474#0: *1 http run request: "/?"
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream check client, write event:1, "/"
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream recv(): -1 (11: Resource temporarily unavailable)
2017/06/22 10:52:52 [debug] 5474#0: epoll: fd:14 ev:0004 d:00007FAB90C6D448
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream request: "/?"
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream send request handler
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream send request
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream send request body
2017/06/22 10:52:52 [debug] 5474#0: *1 chain writer buf fl:1 s:95
2017/06/22 10:52:52 [debug] 5474#0: *1 chain writer in: 0000000001635960
2017/06/22 10:52:52 [debug] 5474#0: *1 writev: 95 of 95
2017/06/22 10:52:52 [debug] 5474#0: *1 chain writer out: 0000000000000000
2017/06/22 10:52:52 [debug] 5474#0: *1 event timer del: 14: 1498100032928
2017/06/22 10:52:52 [debug] 5474#0: *1 event timer add: 14: 180000:1498100152928
2017/06/22 10:52:52 [debug] 5474#0: epoll: fd:6 ev:0001 d:00007FAB90C6D010
2017/06/22 10:52:52 [debug] 5474#0: accept on 0.0.0.0:81, ready: 0
2017/06/22 10:52:52 [debug] 5474#0: posix_memalign: 0000000001674B70:512 @16
2017/06/22 10:52:52 [debug] 5474#0: *3 accept: 127.0.0.1:36900 fd:15
2017/06/22 10:52:52 [debug] 5474#0: *3 event timer add: 15: 60000:1498100032928
2017/06/22 10:52:52 [debug] 5474#0: *3 reusable connection: 1
2017/06/22 10:52:52 [debug] 5474#0: *3 epoll add event: fd:15 op:1 ev:80002001
2017/06/22 10:52:52 [debug] 5474#0: timer delta: 0
2017/06/22 10:52:52 [debug] 5474#0: worker cycle
2017/06/22 10:52:52 [debug] 5474#0: epoll timer: 60000
2017/06/22 10:52:52 [debug] 5474#0: epoll: fd:15 ev:0001 d:00007FAB90C6D520
2017/06/22 10:52:52 [debug] 5474#0: *3 http wait request handler
2017/06/22 10:52:52 [debug] 5474#0: *3 malloc: 00000000016424E0:1024
2017/06/22 10:52:52 [debug] 5474#0: *3 recv: fd:15 95 of 1024
2017/06/22 10:52:52 [debug] 5474#0: *3 reusable connection: 0
2017/06/22 10:52:52 [debug] 5474#0: *3 posix_memalign: 0000000001638140:4096 @16
2017/06/22 10:52:52 [debug] 5474#0: *3 http process request line
2017/06/22 10:52:52 [debug] 5474#0: *3 http request line: "GET / HTTP/1.0"
2017/06/22 10:52:52 [debug] 5474#0: *3 http uri: "/"
2017/06/22 10:52:52 [debug] 5474#0: *3 http args: ""
2017/06/22 10:52:52 [debug] 5474#0: *3 http exten: ""
2017/06/22 10:52:52 [debug] 5474#0: *3 http process request header line
2017/06/22 10:52:52 [debug] 5474#0: *3 http header: "Host: localhost:81"
2017/06/22 10:52:52 [debug] 5474#0: *3 http header: "Connection: close"
2017/06/22 10:52:52 [debug] 5474#0: *3 http header: "User-Agent: curl/7.54.1"
2017/06/22 10:52:52 [debug] 5474#0: *3 http header: "Accept: */*"
2017/06/22 10:52:52 [debug] 5474#0: *3 http header done
2017/06/22 10:52:52 [debug] 5474#0: *3 event timer del: 15: 1498100032928
2017/06/22 10:52:52 [debug] 5474#0: *3 rewrite phase: 0
2017/06/22 10:52:52 [debug] 5474#0: *3 test location: "/"
2017/06/22 10:52:52 [debug] 5474#0: *3 using configuration "/"
2017/06/22 10:52:52 [debug] 5474#0: *3 http cl:-1 max:1048576
2017/06/22 10:52:52 [debug] 5474#0: *3 rewrite phase: 2
2017/06/22 10:52:52 [debug] 5474#0: *3 post rewrite phase: 3
2017/06/22 10:52:52 [debug] 5474#0: *3 generic phase: 4
2017/06/22 10:52:52 [debug] 5474#0: *3 generic phase: 5
2017/06/22 10:52:52 [debug] 5474#0: *3 generic phase: 6
2017/06/22 10:52:52 [debug] 5474#0: *3 access phase: 7
2017/06/22 10:52:52 [debug] 5474#0: *3 access phase: 8
2017/06/22 10:52:52 [debug] 5474#0: *3 post access phase: 9
2017/06/22 10:52:52 [debug] 5474#0: *3 content phase: 10
2017/06/22 10:52:52 [debug] 5474#0: *3 open index "/root/modsecurity/output/html/index.html"
2017/06/22 10:52:52 [debug] 5474#0: *3 internal redirect: "/index.html?"
2017/06/22 10:52:52 [debug] 5474#0: *3 rewrite phase: 0
2017/06/22 10:52:52 [debug] 5474#0: *3 test location: "/"
2017/06/22 10:52:52 [debug] 5474#0: *3 test location: "50x.html"
2017/06/22 10:52:52 [debug] 5474#0: *3 using configuration "/"
2017/06/22 10:52:52 [debug] 5474#0: *3 http cl:-1 max:1048576
2017/06/22 10:52:52 [debug] 5474#0: *3 rewrite phase: 2
2017/06/22 10:52:52 [debug] 5474#0: *3 post rewrite phase: 3
2017/06/22 10:52:52 [debug] 5474#0: *3 generic phase: 4
2017/06/22 10:52:52 [debug] 5474#0: *3 generic phase: 5
2017/06/22 10:52:52 [debug] 5474#0: *3 generic phase: 6
2017/06/22 10:52:52 [debug] 5474#0: *3 access phase: 7
2017/06/22 10:52:52 [debug] 5474#0: *3 access phase: 8
2017/06/22 10:52:52 [debug] 5474#0: *3 post access phase: 9
2017/06/22 10:52:52 [debug] 5474#0: *3 content phase: 10
2017/06/22 10:52:52 [debug] 5474#0: *3 content phase: 11
2017/06/22 10:52:52 [debug] 5474#0: *3 content phase: 12
2017/06/22 10:52:52 [debug] 5474#0: *3 http filename: "/root/modsecurity/output/html/index.html"
2017/06/22 10:52:52 [debug] 5474#0: *3 add cleanup: 0000000001639080
2017/06/22 10:52:52 [debug] 5474#0: *3 http static fd: 16
2017/06/22 10:52:52 [debug] 5474#0: *3 http set discard body
2017/06/22 10:52:52 [debug] 5474#0: *3 posix_memalign: 00000000016ABEA0:4096 @16
2017/06/22 10:52:52 [debug] 5474#0: *3 HTTP/1.1 200 OK
Server: nginx/1.10.1
Date: Thu, 22 Jun 2017 02:52:52 GMT
Content-Type: text/html
Content-Length: 612
Last-Modified: Tue, 13 Jun 2017 03:53:58 GMT
Connection: close
ETag: "593f61d6-264"
Accept-Ranges: bytes

2017/06/22 10:52:52 [debug] 5474#0: *3 write new buf t:1 f:0 00000000016ABFD8, pos 00000000016ABFD8, size: 233 file: 0, size: 0
2017/06/22 10:52:52 [debug] 5474#0: *3 http write filter: l:0 f:0 s:233
2017/06/22 10:52:52 [debug] 5474#0: *3 http output filter "/index.html?"
2017/06/22 10:52:52 [debug] 5474#0: *3 http copy filter: "/index.html?"
2017/06/22 10:52:52 [debug] 5474#0: *3 http postpone filter "/index.html?" 00007FFE272AE960
2017/06/22 10:52:52 [debug] 5474#0: *3 write old buf t:1 f:0 00000000016ABFD8, pos 00000000016ABFD8, size: 233 file: 0, size: 0
2017/06/22 10:52:52 [debug] 5474#0: *3 write new buf t:0 f:1 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 612
2017/06/22 10:52:52 [debug] 5474#0: *3 http write filter: l:1 f:0 s:845
2017/06/22 10:52:52 [debug] 5474#0: *3 http write filter limit 0
2017/06/22 10:52:52 [debug] 5474#0: *3 writev: 233 of 233
2017/06/22 10:52:52 [debug] 5474#0: *3 sendfile: @0 612
2017/06/22 10:52:52 [debug] 5474#0: *3 sendfile: 612 of 612 @0
2017/06/22 10:52:52 [debug] 5474#0: *3 http write filter 0000000000000000
2017/06/22 10:52:52 [debug] 5474#0: *3 http copy filter: 0 "/index.html?"
2017/06/22 10:52:52 [debug] 5474#0: *3 http finalize request: 0, "/index.html?" a:1, c:2
2017/06/22 10:52:52 [debug] 5474#0: *3 http request count:2 blk:0
2017/06/22 10:52:52 [debug] 5474#0: *3 http finalize request: -4, "/index.html?" a:1, c:1
2017/06/22 10:52:52 [debug] 5474#0: *3 event timer add: 15: 5000:1498099977928
2017/06/22 10:52:52 [debug] 5474#0: *3 http lingering close handler
2017/06/22 10:52:52 [debug] 5474#0: *3 recv: fd:15 -1 of 4096
2017/06/22 10:52:52 [debug] 5474#0: *3 recv() not ready (11: Resource temporarily unavailable)
2017/06/22 10:52:52 [debug] 5474#0: *3 lingering read: -2
2017/06/22 10:52:52 [debug] 5474#0: *3 event timer: 15, old: 1498099977928, new: 1498099977928
2017/06/22 10:52:52 [debug] 5474#0: timer delta: 0
2017/06/22 10:52:52 [debug] 5474#0: worker cycle
2017/06/22 10:52:52 [debug] 5474#0: epoll timer: 5000
2017/06/22 10:52:52 [debug] 5474#0: epoll: fd:14 ev:2005 d:00007FAB90C6D448
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream request: "/?"
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream process header
2017/06/22 10:52:52 [debug] 5474#0: *1 malloc: 00000000016ACEB0:4096
2017/06/22 10:52:52 [debug] 5474#0: *1 recv: fd:14 845 of 4096
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy status 200 "200 OK"
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header: "Server: nginx/1.10.1"
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header: "Date: Thu, 22 Jun 2017 02:52:52 GMT"
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header: "Content-Type: text/html"
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header: "Content-Length: 612"
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header: "Last-Modified: Tue, 13 Jun 2017 03:53:58 GMT"
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header: "Connection: close"
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header: "ETag: "593f61d6-264""
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header: "Accept-Ranges: bytes"
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy header done
2017/06/22 10:52:52 [debug] 5474#0: *1 modSecurity: header filter
2017/06/22 10:52:52 [debug] 5474#0: *1 http cacheable: 0
2017/06/22 10:52:52 [debug] 5474#0: *1 http proxy filter init s:200 h:0 c:0 l:612
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream process upstream
2017/06/22 10:52:52 [debug] 5474#0: *1 pipe read upstream: 1
2017/06/22 10:52:52 [debug] 5474#0: *1 pipe preread: 612
2017/06/22 10:52:52 [debug] 5474#0: *1 readv: 1, last:3251
2017/06/22 10:52:52 [debug] 5474#0: *1 pipe recv chain: 0
2017/06/22 10:52:52 [debug] 5474#0: *1 pipe buf free s:0 t:1 f:0 00000000016ACEB0, pos 00000000016ACF99, size: 612 file: 0, size: 0
2017/06/22 10:52:52 [debug] 5474#0: *1 pipe length: 612
2017/06/22 10:52:52 [debug] 5474#0: *1 input buf #0
2017/06/22 10:52:52 [debug] 5474#0: *1 pipe write downstream: 1
2017/06/22 10:52:52 [debug] 5474#0: *1 pipe write downstream flush in
2017/06/22 10:52:52 [debug] 5474#0: *1 http output filter "/?"
2017/06/22 10:52:52 [debug] 5474#0: *1 http copy filter: "/?"
2017/06/22 10:52:52 [debug] 5474#0: *1 modSecurity: body filter
2017/06/22 10:52:52 [debug] 5474#0: *1 http copy filter: -2 "/?"
2017/06/22 10:52:52 [debug] 5474#0: *1 pipe write downstream done
2017/06/22 10:52:52 [debug] 5474#0: *1 event timer: 14, old: 1498100152928, new: 1498100152928
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream exit: 0000000000000000
2017/06/22 10:52:52 [debug] 5474#0: *1 finalize http upstream request: 0
2017/06/22 10:52:52 [debug] 5474#0: *1 finalize http proxy request
2017/06/22 10:52:52 [debug] 5474#0: *1 free rr peer 2 0
2017/06/22 10:52:52 [debug] 5474#0: *1 close http upstream connection: 14
2017/06/22 10:52:52 [debug] 5474#0: *1 free: 0000000001674AE0, unused: 48
2017/06/22 10:52:52 [debug] 5474#0: *1 event timer del: 14: 1498100152928
2017/06/22 10:52:52 [debug] 5474#0: *1 reusable connection: 0
2017/06/22 10:52:52 [debug] 5474#0: *1 http upstream temp fd: -1
2017/06/22 10:52:52 [debug] 5474#0: *1 http output filter "/?"
2017/06/22 10:52:52 [debug] 5474#0: *1 http copy filter: "/?"
2017/06/22 10:52:52 [debug] 5474#0: *1 modSecurity: body filter
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers in: "Host: 192.168.7.4:82"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers in: "User-Agent: curl/7.54.1"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers in: "Accept: */*"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers in done
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers out: "Last-Modified: Tue, 13 Jun 2017 03:53:58 GMT"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers out: "ETag: "593f61d6-264""
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers out: "Accept-Ranges: bytes"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers out: "Content-Type: text/html"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers out: "Content-Length: 612"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers out: "Last-Modified: Tue, 13 Jun 2017 03:53:58 GMT"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers out: "Connection: keep-alive"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: load headers out done
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: status -1
2017/06/22 10:52:52 [debug] 5474#0: *1 posix_memalign: 00000000016ADEC0:4096 @16
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: save headers in: "Host: 192.168.7.4:82"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: save headers in: "User-Agent: curl/7.54.1"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: save headers in: "Accept: */*"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: save headers in done
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: save headers out: "Last-Modified: Tue, 13 Jun 2017 03:53:58 GMT"
2017/06/22 10:52:52 [debug] 5474#0: *1 ModSecurity: save headers out: "ETag: "593f61d6-264""
2017/06/22 10:52:52 [notice] 5473#0: signal 17 (SIGCHLD) received
2017/06/22 10:52:52 [alert] 5473#0: worker process 5474 exited on signal 11
2017/06/22 10:52:52 [debug] 5473#0: shmtx forced unlock
2017/06/22 10:52:52 [debug] 5473#0: wake up, sigio 0
2017/06/22 10:52:52 [debug] 5473#0: reap children
2017/06/22 10:52:52 [debug] 5473#0: child: 0 5474 e:0 t:1 d:0 r:1 j:0
2017/06/22 10:52:52 [debug] 5473#0: channel 3:11
2017/06/22 10:52:52 [notice] 5473#0: start worker process 5478
2017/06/22 10:52:52 [debug] 5473#0: sigsuspend
2017/06/22 10:52:52 [debug] 5478#0: notify eventfd: 13
2017/06/22 10:52:52 [debug] 5478#0: malloc: 000000000163F8B0:6144
2017/06/22 10:52:52 [debug] 5478#0: malloc: 00007FAB90C6D010:221184
2017/06/22 10:52:52 [debug] 5478#0: malloc: 0000000001677E60:98304
2017/06/22 10:52:52 [debug] 5478#0: malloc: 000000000168FE70:98304
2017/06/22 10:52:52 [debug] 5478#0: epoll add event: fd:6 op:1 ev:00002001
2017/06/22 10:52:52 [debug] 5478#0: epoll add event: fd:9 op:1 ev:00002001
2017/06/22 10:52:52 [debug] 5478#0: epoll add event: fd:10 op:1 ev:00002001
2017/06/22 10:52:52 [debug] 5478#0: epoll add event: fd:11 op:1 ev:00002001
2017/06/22 10:52:52 [debug] 5478#0: setproctitle: "nginx: worker process"
2017/06/22 10:52:52 [debug] 5478#0: worker cycle
2017/06/22 10:52:52 [debug] 5478#0: epoll timer: -1

　　这一条很有问题： 2017/06/22 10:52:52 [alert] 5473#0: worker process 5474 exited on signal 11

　　也许是modsecurity有什么bug。

　　回退两个版本至 ModSecurity-2.8.0

　　2.8.0 依然有这个问题。

这是一个BUG，https://github.com/SpiderLabs/ModSecurity/issues/839

在2.x版本里，作者们都不准备fix了。 

　　解决办法，设置 proxy_force_ranges on

　　http://nginx.org/en/docs/http/ngx_http_proxy_module.html#proxy_force_ranges

　　2.8.0 错误消失。

　　2.9.0  错误消失。

七：简单规则测试

 　　7.1  使用如下规则：

[root@dpdk output]# cat conf/mymod.conf 
#SecRuleEngine DetectionOnly
SecRuleEngine On
SecRequestBodyAccess On
SecResponseBodyAccess On

SecDebugLogLevel 3
SecDebugLog /root/modsecurity/output/logs/modsec_debug.log

#SecAuditEngine On
SecAuditEngine RelevantOnly
SecAuditLogType Serial
SecAuditLog /root/modsecurity/output/logs/modsec_audit.log

SecRule REQUEST_METHOD "GET" "phase:1,log,id:1001,msg:'test1'"
#SecRule REQUEST_METHOD "POST" "phase:1,log,id:1002,msg:'test2'"
#SecRule REQUEST_HEADERS:User-Agent "curl" "phase:1,log,id:1003,msg:'test3'"
SecRule REQUEST_BODY_LENGTH "@eq 5" "phase:2,log,id:1004,msg:'test4'"
[root@dpdk output]# 

　　7.2  每次修改后，使用如下命令重载：

[root@dpdk output]# ./sbin/nginx -s reload
[root@dpdk output]# 

　　7.3  生效后，使用如下命令测试：

/home/tong/Temp [tong@T7] [14:41]
> curl 192.168.7.4:82
/home/tong/Temp [tong@T7] [14:41]
> curl 192.168.7.4:82 -d xx
/home/tong/Temp [tong@T7] [14:41]
> curl 192.168.7.4:82 -d xxxxx

　　7.4  操作后，使用如下命令查看测试结果：

[root@dpdk output]# tailf logs/modsec_audit.log 
... ...
Message: Warning. Pattern match "POST" at REQUEST_METHOD. [file "/root/modsecurity/output/conf/mymod.conf"] [line "15"] [id "1002"] [msg "test2"]
Message: Warning. Pattern match "curl" at REQUEST_HEADERS:User-Agent. [file "/root/modsecurity/output/conf/mymod.conf"] [line "16"] [id "1003"] [msg "test3"]
Message: Warning. Operator EQ matched 5 at REQUEST_BODY_LENGTH. [file "/root/modsecurity/output/conf/mymod.conf"] [line "17"] [id "1004"] [msg "test4"]
... ...

八，看 ModSecurity-2.9.1 的代码

 　　传送门：[development][security][modsecurity][nginx] nginx / modsecurity development things