search

wandenberg / nginx-selective-cache-purge-module

127 stars 20 forks source link

io_destroy() error everytime nginx starts #2

Closed rfnx closed 4 years ago

rfnx commented 8 years ago

Hello !

First, thanks for your amazing project. I'm testing it with nginx 1.9.9 and everytime nginx starts, this error is written in the error_log :

[alert] 1514#0: io_destroy() failed (22: Invalid argument)

But the plugin seems to work fine at the moment. I still want to know what this mean but there is not enough information. What can I try to debug this ?

EDIT : more info about my configuration :

wandenberg commented 8 years ago

@rfnx can you share your nginx -V output and your nginx.conf ? This function call is not present on the module code, it make part on the nginx epoll event structure. I was not able to reproduce the error, and will need your help to investigate the problem, and check if it is really on the module on in some interaction it has.

rfnx commented 8 years ago

Hello, sorry for the late reply.

First, there is 2 things I forgot to say in my first post : I'm using your plugin with uwsgi_cache (not proxy or fastcgi) and my cache is on tmpfs (on RAM).

I also tried to remove all the other plugins I use except yours, but there is still the same error message.

my nginx -V : 

nginx version: nginx/1.9.9
built with OpenSSL 1.0.2e 3 Dec 2015
TLS SNI support enabled
configure arguments: --prefix=/etc/nginx --conf-path=/etc/nginx/nginx.conf --sbin-path=/usr/bin/nginx --pid-path=/run/nginx.pid --lock-path=/run/lock/nginx.lock --user=http --group=http --http-log-path=/var/log/nginx/access.log --error-log-path=stderr --http-client-body-temp-path=/var/lib/nginx/client-body --http-proxy-temp-path=/var/lib/nginx/proxy --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --with-mail --with-mail_ssl_module --with-ipv6 --with-pcre-jit --with-file-aio --with-http_addition_module --with-http_auth_request_module --with-http_dav_module --with-http_degradation_module --with-http_flv_module --with-http_geoip_module --with-http_gunzip_module --with-http_gzip_static_module --with-http_mp4_module --with-http_realip_module --with-http_secure_link_module --with-http_ssl_module --with-http_stub_status_module --with-http_sub_module --with-http_v2_module --add-module=../ngx_select_cachepurge --add-module=../ngx_pagespeed

my nginx conf : 

user http http;
worker_processes auto;

pcre_jit on;

events {
    worker_connections  1024;
}

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

    access_log  /var/log/nginx/access.log combined buffer=64k flush=5m;

    sendfile       on;
    tcp_nopush     on;
    tcp_nodelay    on;

    keepalive_timeout  65;

    server_tokens off;

    gzip  on;
    gzip_disable        "msie6";
    gzip_vary  on;
    gzip_comp_level 3;
    gzip_min_length 1000;
    gzip_proxied any;
    gzip_types  [...];

    ssl_session_cache   shared:SSL:10m;
    ssl_session_timeout 10m;
    ssl_session_tickets off;
    ssl_certificate     [...];
    ssl_certificate_key [...];
    ssl_dhparam         [...];

    ssl_stapling                on;
    ssl_stapling_verify         on;
    ssl_trusted_certificate     [...];

    index index.php index.html;

    # Redis cache options
    selective_cache_purge_redis_unix_socket "/run/redis-nginx-cache/redis.sock";
    selective_cache_purge_redis_database 0;

    uwsgi_cache_path /var/cache/nginx/uwsgi_cachezone levels=1:2 keys_zone=uwsgi_cachezone:10m max_size=200m
                 inactive=60m use_temp_path=off;

server {
        listen [...]:443   ssl http2;
        listen [...]:443   ssl http2;
        server_name  [...];

        client_max_body_size 100M;
        root    [...];
        error_page 404 /404.html;

        location ~ ^/purge(/.*) {
                allow [...];
                deny all;
#              access_log /tmp/debugnginx.log;
                selective_cache_purge_query "$host$1";
        }

        location / {
                try_files $uri $uri/ /index.php$is_args$args;
        }

        location ~ \.php$ {
                include uwsgi_params;

                uwsgi_intercept_errors on;

                uwsgi_cache_key "$host$request_uri";
                uwsgi_cache_use_stale error timeout http_500 http_503;
                # urls with a query string should always go to PHP
                uwsgi_cache_bypass $query_string;
                uwsgi_no_cache $query_string;
                uwsgi_cache uwsgi_cachezone;
                uwsgi_cache_valid 30m;
                add_header X-LD-Cache-Status $upstream_cache_status;
                # Fin de la configuration du cache

                uwsgi_modifier1 14;
                uwsgi_pass unix:///run/uwsgi/phpsite/phpsite.sock;
        }
}
}

Do you need more info ?

wandenberg commented 8 years ago

@rfnx I was not able to reproduce this error message. Can you give me access to your server or help me to setup a basic environment where the problem be reproducible (can be a vagrant) ?

vedranf commented 8 years ago

Hello,

I'm seeing this too. It's easy to reproduce (redis_nginx_adapter is already installed btw):

# tar xvf nginx-1.8.1.tar.gz
# git clone https://github.com/wandenberg/nginx-selective-cache-purge-module.git
# ./configure --with-ld-opt=-Wl,-z,relro --with-cc-opt='-D_FORTIFY_SOURCE=2 -Ofast -march=native' --prefix=/usr/local/nginx --pid-path=/var/run --lock-path=/var/run --with-file-aio --with-ipv6 --with-rtsig_module --with-threads --with-http_addition_module --with-http_sub_module --with-http_dav_module --with-http_flv_module --with-http_stub_status_module --with-http_realip_module --with-http_secure_link_module --with-http_ssl_module --with-http_geoip_module --with-http_gzip_static_module --with-http_random_index_module --with-http_secure_link_module --with-http_degradation_module --with-http_gunzip_module --with-http_spdy_module --with-http_mp4_module --with-http_flv_module --with-pcre-jit --with-debug --add-module=./nginx-selective-cache-purge-module/

# make -j8
# cat /tmp/nginx.conf
daemon off;
events { use epoll; }
pid /var/run/nginx.pid;
error_log stderr debug;

http {
    error_log stderr debug;
    selective_cache_purge_redis_host localhost;
}

# objs/nginx -c /tmp/nginx.conf                                                                                     [=][h:4130][pts/2][Fri 16-03-11 15:00]
2016/03/11 15:00:05 [notice] 28854#28854: using the "epoll" event method
2016/03/11 15:00:05 [debug] 28854#28854: counter: 00002B2A3B374080, 1
2016/03/11 15:00:05 [notice] 28854#28854: nginx/1.8.1
2016/03/11 15:00:05 [notice] 28854#28854: built by gcc 4.9.3 (Debian 4.9.3-5) 
2016/03/11 15:00:05 [notice] 28854#28854: OS: Linux 4.1.0-2-amd64
2016/03/11 15:00:05 [notice] 28854#28854: sysctl(KERN_RTSIGMAX): 0
2016/03/11 15:00:05 [notice] 28854#28854: getrlimit(RLIMIT_NOFILE): 65536:65536
2016/03/11 15:00:05 [debug] 28854#28854: write: 4, 00007FFE64E49C90, 6, 0
2016/03/11 15:00:05 [debug] 28854#28854: setproctitle: "nginx: master process objs/nginx -c /tmp/nginx.conf"
2016/03/11 15:00:05 [notice] 28854#28854: start worker processes
2016/03/11 15:00:05 [debug] 28854#28854: channel 3:4
2016/03/11 15:00:05 [notice] 28854#28854: start worker process 28855
2016/03/11 15:00:05 [debug] 28854#28854: sigsuspend
2016/03/11 15:00:05 [debug] 28855#28855: notify eventfd: 6
2016/03/11 15:00:05 [debug] 28855#28855: eventfd: 7
2016/03/11 15:00:05 [debug] 28855#28855: malloc: 00000000011C34D0:6144
2016/03/11 15:00:05 [debug] 28855#28855: malloc: 00000000011D5E80:114688
2016/03/11 15:00:05 [debug] 28855#28855: malloc: 00000000011F1E90:53248
2016/03/11 15:00:05 [debug] 28855#28855: malloc: 00000000011FEEA0:53248
2016/03/11 15:00:05 [debug] 28855#28855: malloc: 00000000011B9210:80
2016/03/11 15:00:05 [debug] 28856#28856: setproctitle: "nginx: cache synchronizer"
2016/03/11 15:00:05 [alert] 28856#28856: io_destroy() failed (22: Invalid argument)
2016/03/11 15:00:05 [debug] 28856#28856: posix_memalign: 00000000011BE4B0:16384 @16
2016/03/11 15:00:05 [debug] 28856#28856: notify eventfd: 6
2016/03/11 15:00:05 [debug] 28856#28856: eventfd: 7
2016/03/11 15:00:05 [debug] 28856#28856: malloc: 00000000011C34D0:6144
2016/03/11 15:00:05 [debug] 28856#28856: malloc: 000000000120BEB0:114688
2016/03/11 15:00:05 [debug] 28856#28856: malloc: 0000000001227EC0:53248
2016/03/11 15:00:05 [debug] 28856#28856: malloc: 0000000001234ED0:53248
2016/03/11 15:00:05 [notice] 28856#28856: ngx_selective_cache_purge: sync process started
2016/03/11 15:00:05 [debug] 28856#28856: malloc: 00000000011B8E70:80
2016/03/11 15:00:05 [debug] 28856#28856: posix_memalign: 00000000011C4CE0:4096 @16
2016/03/11 15:00:05 [debug] 28856#28856: epoll timer: -1
2016/03/11 15:00:06 [notice] 28854#28854: signal 17 (SIGCHLD) received
2016/03/11 15:00:06 [alert] 28854#28854: worker process 28855 exited on signal 11
2016/03/11 15:00:06 [debug] 28854#28854: shmtx forced unlock
2016/03/11 15:00:06 [debug] 28854#28854: shmtx forced unlock
2016/03/11 15:00:06 [debug] 28854#28854: wake up, sigio 0
2016/03/11 15:00:06 [debug] 28854#28854: reap children
2016/03/11 15:00:06 [debug] 28854#28854: child: 0 28855 e:0 t:1 d:0 r:1 j:0
2016/03/11 15:00:06 [debug] 28854#28854: channel 3:4
2016/03/11 15:00:06 [notice] 28854#28854: start worker process 28857
2016/03/11 15:00:06 [debug] 28854#28854: sigsuspend
2016/03/11 15:00:06 [debug] 28857#28857: notify eventfd: 6
2016/03/11 15:00:06 [debug] 28857#28857: eventfd: 7
2016/03/11 15:00:06 [debug] 28857#28857: malloc: 00000000011C34D0:6144
2016/03/11 15:00:06 [debug] 28857#28857: malloc: 00000000011D5E80:114688
2016/03/11 15:00:06 [debug] 28857#28857: malloc: 00000000011F1E90:53248
2016/03/11 15:00:06 [debug] 28857#28857: malloc: 00000000011FEEA0:53248
2016/03/11 15:00:06 [debug] 28857#28857: malloc: 00000000011B9210:80
2016/03/11 15:00:06 [debug] 28857#28857: epoll add event: fd:4 op:1 ev:00002001
2016/03/11 15:00:06 [debug] 28857#28857: setproctitle: "nginx: worker process"
2016/03/11 15:00:06 [debug] 28857#28857: worker cycle
2016/03/11 15:00:06 [debug] 28857#28857: epoll timer: -1

What worries me is this segfault:

2016/03/11 15:00:06 [alert] 28854#28854: worker process 28855 exited on signal 11

Without the selective_cache_purge_redis_host log looks like this:

2016/03/11 15:17:14 [notice] 29418#29418: using the "epoll" event method 2016/03/11 15:17:14 [debug] 29418#29418: counter: 00002B084115F080, 1 2016/03/11 15:17:14 [notice] 29418#29418: nginx/1.8.1 2016/03/11 15:17:14 [notice] 29418#29418: built by gcc 4.9.3 (Debian 4.9.3-5) 2016/03/11 15:17:14 [notice] 29418#29418: OS: Linux 4.1.0-2-amd64 2016/03/11 15:17:14 [notice] 29418#29418: sysctl(KERN_RTSIGMAX): 0 2016/03/11 15:17:14 [notice] 29418#29418: getrlimit(RLIMIT_NOFILE): 65536:65536 2016/03/11 15:17:14 [debug] 29418#29418: write: 4, 00007FFEF5D004B0, 6, 0 2016/03/11 15:17:14 [debug] 29418#29418: setproctitle: "nginx: master process objs/nginx -c /tmp/nginx.conf" 2016/03/11 15:17:14 [notice] 29418#29418: start worker processes 2016/03/11 15:17:14 [debug] 29418#29418: channel 3:4 2016/03/11 15:17:14 [notice] 29418#29418: start worker process 29419 2016/03/11 15:17:14 [debug] 29418#29418: sigsuspend 2016/03/11 15:17:14 [debug] 29419#29419: notify eventfd: 6 2016/03/11 15:17:14 [debug] 29419#29419: eventfd: 7 2016/03/11 15:17:14 [debug] 29419#29419: malloc: 0000000001A294D0:6144 2016/03/11 15:17:14 [debug] 29419#29419: malloc: 0000000001A3BE80:114688 2016/03/11 15:17:14 [debug] 29419#29419: malloc: 0000000001A57E90:53248 2016/03/11 15:17:14 [debug] 29419#29419: malloc: 0000000001A64EA0:53248 2016/03/11 15:17:14 [debug] 29419#29419: epoll add event: fd:4 op:1 ev:00002001 2016/03/11 15:17:14 [debug] 29419#29419: setproctitle: "nginx: worker process" 2016/03/11 15:17:14 [debug] 29419#29419: worker cycle 2016/03/11 15:17:14 [debug] 29419#29419: epoll timer: -1

No segfault and no io_destroy error.

Regards, Vedran

wandenberg commented 8 years ago

Hi @vedranf can you confirm what is the exact commit you are using for the module and for redis_nginx_adapter ? With this information will be easier to check the problem.

vedranf commented 8 years ago

Hey Wandenberg,

Should be latest:

redis_nginx_adapter $ git log --format="%H" -n 1|head 78605f8d7ce6775c10748b6092c37777209019a2

nginx-selective-cache-purge-module $ git log --format="%H" -n 1|head 5eecdf50f7c44ddb35e96a83fc809dd35166dbed

git pull returns Already up-to-date. for both

Regards, Vedran

wandenberg commented 8 years ago

Hi @vedranf can you try the try_fixfor#2 branch?

vedranf commented 8 years ago

Hi Wandenberg,

I'm currently away, I'll try it out later this week when I get back. Thanks!

vedranf commented 8 years ago

Hey @wandenberg , it seems better now, there's still io_destroy() failed (22: Invalid argument), but there's no segfault anymore:

2016/03/17 13:16:57 [notice] 11156#11156: using the "epoll" event method
2016/03/17 13:16:57 [debug] 11156#11156: counter: 00002B7F94F35080, 1
2016/03/17 13:16:57 [notice] 11156#11156: nginx/1.8.1
2016/03/17 13:16:57 [notice] 11156#11156: built by gcc 4.9.3 (Debian 4.9.3-5)
2016/03/17 13:16:57 [notice] 11156#11156: OS: Linux 4.1.0-2-amd64
2016/03/17 13:16:57 [notice] 11156#11156: sysctl(KERN_RTSIGMAX): 0
2016/03/17 13:16:57 [notice] 11156#11156: getrlimit(RLIMIT_NOFILE): 65536:65536
2016/03/17 13:16:57 [debug] 11156#11156: write: 4, 00007FFCCEC022F0, 6, 0
2016/03/17 13:16:57 [debug] 11156#11156: setproctitle: "nginx: master process objs/nginx -c /tmp/nginx.conf"
2016/03/17 13:16:57 [notice] 11156#11156: start worker processes
2016/03/17 13:16:57 [debug] 11156#11156: channel 3:4
2016/03/17 13:16:57 [notice] 11156#11156: start worker process 11157
2016/03/17 13:16:57 [debug] 11156#11156: sigsuspend
2016/03/17 13:16:57 [debug] 11157#11157: notify eventfd: 6
2016/03/17 13:16:57 [debug] 11157#11157: eventfd: 7
2016/03/17 13:16:57 [debug] 11157#11157: malloc: 0000000001C3A500:6144
2016/03/17 13:16:57 [debug] 11157#11157: malloc: 0000000001C4CEB0:114688
2016/03/17 13:16:57 [debug] 11157#11157: malloc: 0000000001C68EC0:53248
2016/03/17 13:16:57 [debug] 11157#11157: malloc: 0000000001C75ED0:53248
2016/03/17 13:16:57 [debug] 11157#11157: malloc: 0000000001C30210:80
2016/03/17 13:16:57 [debug] 11157#11157: epoll add event: fd:8 op:1 ev:00002001
2016/03/17 13:16:57 [debug] 11157#11157: epoll add event: fd:4 op:1 ev:00002001
2016/03/17 13:16:57 [debug] 11157#11157: setproctitle: "nginx: worker process"
2016/03/17 13:16:57 [debug] 11157#11157: worker cycle
2016/03/17 13:16:57 [debug] 11157#11157: epoll timer: -1
2016/03/17 13:16:57 [debug] 11158#11158: setproctitle: "nginx: cache synchronizer"
2016/03/17 13:16:57 [alert] 11158#11158: io_destroy() failed (22: Invalid argument)
2016/03/17 13:16:57 [debug] 11158#11158: posix_memalign: 0000000001C354E0:16384 @16
2016/03/17 13:16:57 [debug] 11158#11158: notify eventfd: 6
2016/03/17 13:16:57 [debug] 11158#11158: eventfd: 7
2016/03/17 13:16:57 [debug] 11158#11158: malloc: 0000000001C3A500:6144
2016/03/17 13:16:57 [debug] 11158#11158: malloc: 0000000001C82EE0:114688
2016/03/17 13:16:57 [debug] 11158#11158: malloc: 0000000001C9EEF0:53248
2016/03/17 13:16:57 [debug] 11158#11158: malloc: 0000000001CABF00:53248
2016/03/17 13:16:57 [notice] 11158#11158: ngx_selective_cache_purge: sync process started
2016/03/17 13:16:57 [debug] 11158#11158: malloc: 0000000001C2FE70:80
2016/03/17 13:16:57 [debug] 11158#11158: posix_memalign: 0000000001C3BD10:4096 @16
2016/03/17 13:16:57 [debug] 11158#11158: epoll add event: fd:8 op:1 ev:80000004
2016/03/17 13:16:57 [debug] 11158#11158: epoll timer: -1
2016/03/17 13:16:57 [debug] 11158#11158: epoll: fd:8 ev:0004 d:0000000001C82EE0
2016/03/17 13:16:57 [debug] 11158#11158: epoll del event: fd:8 op:2 ev:00000000
2016/03/17 13:16:57 [debug] 11158#11158: epoll add event: fd:8 op:1 ev:80002001
2016/03/17 13:16:57 [debug] 11158#11158: timer delta: 8
2016/03/17 13:16:57 [debug] 11158#11158: epoll timer: -1
2016/03/17 13:16:57 [debug] 11158#11158: epoll: fd:8 ev:0001 d:0000000001C82EE0
2016/03/17 13:16:57 [debug] 11158#11158: timer delta: 0
2016/03/17 13:16:57 [debug] 11158#11158: epoll timer: -1
wandenberg commented 8 years ago

@vedranf great. I'm still looking for the reason why this io_destroy is failing. I will ask you to do another test when I found out.

sakshamece commented 4 years ago

hi Guys , i am stuck with this error 2019/12/19 06:37:01 [debug] 18505#0: epoll add event: fd:6 op:1 ev:00002001

can you guys tell me the cause , is it due to some module changes or nginx.conf config ?? its occurring every time, when i am trying to hit my local server

upstream www.example.com { server 192.168.56.103; server 192.168.56.102;

server web.example.com;

 #  server db.example.com;
}

server {

    server_name  _;
    listen 443 ssl default_server ;

ssl on;

    ssl_certificate      /home/vagrant/code/nginx/local/nginx/conf/cisco1/nginx.crt;
    ssl_certificate_key  /home/vagrant/code/nginx/local/nginx/conf/cisco1/nginx.key;

ssl_verify_client on;

    proxy_ssl_verify       on;
    proxy_ssl_trusted_certificate /home/vagrant/code/nginx/local/nginx/conf/cisco1/ca.crt;
    error_log /var/log/error_log  debug;
    # error_log /var/log/error.log warn;
    proxy_ssl_verify_host_name off;
    #access_log /var/log/access.log ;       
  #  ssl_session_cache    shared:SSL:1m;
  #  ssl_session_timeout  5m;
   # ssl_ciphers  HIGH:!aNULL:!MD5;
   # ssl_prefer_server_ciphers  on;
    location / {
       proxy_pass https://www.example.com;
    }
}
wandenberg commented 4 years ago

closing the issue since none of the mentioned messages could be reproduced with Nginx 1.17. Please re-open the issue if needed. @sakshamece I couldn't identify on your configuration the usage of this module. Please, open a new issue if you are really using it, describing Nginx, module, and OS versions you are using and your problem.