shm_add_upstream

[romankoblov]

Hi,
there is some issues with nginx 1.7.10

1. 2015/04/08 10:26:17 [error] 1073#0: *118 shm_add_upstream failed while logging request, client: 127.0.0.1, server: , request: "GET /favicon.ico HTTP/1.1", upstream: "http://127.0.0.1:8000/favicon.ico", host: "example.com"
2. on 'Server zones' there is something looks like part of nginx process memory dump in 'Zone' field.
3. This happens if server_name is empty or there is multiple names in it.

[vozlt]

Thanks for the report.
But I could not reproduce the problem.
I wondering, is that a log is every time written while requested?
And can I get a your nginx configuraton?

[romankoblov]

Hi, there is minimal config on which I reproduced this issue:

user www-data;
worker_processes 4;
pid /run/nginx.pid;

events {
    worker_connections 768;
}

http {
    sendfile on;
    tcp_nopush on;
    tcp_nodelay on;
    keepalive_timeout 65;
    types_hash_max_size 2048;
    include /etc/nginx/mime.types;
    default_type application/octet-stream;
    access_log /var/log/nginx/access.log;
    error_log /var/log/nginx/error.log;
    vhost_traffic_status_zone;
    server
    {
        listen 80;
        location /status {
            vhost_traffic_status_display;
        vhost_traffic_status_display_format json;
        }
    }
}

And here is curl to json:

curl localhost/status
{"nginxVersion":"1.7.10","loadMsec":1428505244822,"nowMsec":1428505417996,"connections":{"active":1,"reading":0,"writing":1,"waiting":0,"accepted":13,"handled":13,"requests":13},"serverZones":{"8Ly":{"requestCounter":12,"inBytes":948,"outBytes":6689,"responses":{"1xx":0,"2xx":12,"3xx":0,"4xx":0,"5xx":0}},"*":{"requestCounter":12,"inBytes":948,"outBytes":6689,"responses":{"1xx":0,"2xx":12,"3xx":0,"4xx":0,"5xx":0}}}}

Notice '8Ly' as zone name, it changes, sometimes here is some binary data.
If i'm adding 'server_name test;' to this config it works fine (zone name: 'test')

[vozlt]

I added default server_name "_" in ngx_http_vhost_traffic_status_shm_add_server(), if the server_name directive is not defined.
Give it a fly, please give me the result.

Last Commit: bd63446

[romankoblov]

Hi, thank you for fix, now it works correctly.
Another problem, I've just noticed that upstream metrics counts incorrectly:

user www-data;
worker_processes 4;
pid /run/nginx.pid;

events {
    worker_connections 768;
}

http {
    sendfile on;
    tcp_nopush on;
    tcp_nodelay on;
    keepalive_timeout 65;
    types_hash_max_size 2048;
    include /etc/nginx/mime.types;
    default_type application/octet-stream;
    access_log /var/log/nginx/access.log;
    error_log /var/log/nginx/error.log;
    vhost_traffic_status_zone;
    upstream site
    {
        ip_hash;
            server localhost:3000;
            keepalive 256;
        }
    server {
        listen 80;
        server_name example.com test.example.com;
        location /{
            proxy_pass http://site$request_uri;
        }
    }
        server {
            listen 80;
        }
    server
    {
        listen 8011;
        server_name stats;
        location /status {
            vhost_traffic_status_display;
        vhost_traffic_status_display_format json;
        }
    }
}

after request to example.com, it counts in 'example.com' zone, but there is nothing in upsteam zone:
{"nginxVersion":"1.7.10","loadMsec":1428607075816,"nowMsec":1428607145151,"connections":{"active":1,"reading":0,"writing":1,"waiting":0,"accepted":8,"handled":8,"requests":8},"serverZones":{"stats":{"requestCounter":3,"inBytes":252,"outBytes":2403,"responses":{"1xx":0,"2xx":3,"3xx":0,"4xx":0,"5xx":0}},"_":{"requestCounter":1,"inBytes":86,"outBytes":324,"responses":{"1xx":0,"2xx":0,"3xx":0,"4xx":1,"5xx":0}},"example.com":{"requestCounter":3,"inBytes":235,"outBytes":2540,"responses":{"1xx":0,"2xx":2,"3xx":0,"4xx":0,"5xx":1}},"*":{"requestCounter":7,"inBytes":573,"outBytes":5267,"responses":{"1xx":0,"2xx":5,"3xx":0,"4xx":1,"5xx":1}}},"upstreamZones":{"site":[{"server":"127.0.0.1:3000","requestCounter":0,"inBytes":0,"outBytes":0,"responses":{"1xx":0,"2xx":0,"3xx":0,"4xx":0,"5xx":0},"responeMsec":0,"weight":1,"maxFails":1,"failTimeout":10,"backup":false,"down":false}]}}

[vozlt]

Thank you for looking into this.
I fixed it.
Give it a fly, please give me the result.

Last commit: 5548b2d

[romankoblov]

Hi, now it works fine, thank you!

[stankevich]

This is still an issue if there are multiple entries in server_name. To reproduce: use @penpen's snippet above and add server_name example.com *.example.com; in server block.

Throws handler::shm_add_upstream() failed while logging request error.

Nginx 1.9.10, latest master branch of this module.

[vozlt]

Thanks.
I failed to occur the message by using above configuration.
Does it frequently appears?
Can I get the your configuration to reproduce?

[vs801]

Thanks for great nginx module.
Same problem: in error log handler::shm_add_upstream() failed while logging request. Nginx 1.8.0, latest zip-archive with master branch of this module, error generated for all requests. In conf files using two type of server_name:
server_name: _
and
server_name: s1.example.com s2.example.com s3.example.com s4.example.com s5.example.com
Maybe problem in my my nginx-conf files - I'm don't have static upstream sections and using internal redirect and generate proxy_pass links for many different upstreams.
In function ngx_http_vhost_traffic_status_shm_add_upstream check's configured upstream in conf-files or not?

[vozlt]

Does it appears on all requests?(one log per a request)
If so, can I get a nginx configuration to be reproduced?

[seven-wjx]

nginx version: nginx/1.11.1

Error info:

2016/07/20 18:25:40 [error] 30780#30780: *549 handler::shm_add_upstream() failed while logging request, client: 172.16.189.197, server: xxxxxxx.com, request: "GET /phpinfo_172.30.2.87.php?apc_clear_cache=sys HTTP/1.1", upstream: "fastcgi://172.30.2.87:9000", host: “xxxxxxx.com”

It happened when nginx fastcgi_pass use variables:

server {
    listen 80 ;
    server_name xxxxxxx;
    access_log logs/access.log main;
    error_log logs/error.log debug;
    location ~ "^/phpinfo_(.*)\.php$" {
    fastcgi_pass   $1:9000;                   ##### it not happened error when fastcgi_pass  use not variables:   fastcgi_pass 172.30.2.87:9000
    fastcgi_index  index.php;
    fastcgi_param  SCRIPT_FILENAME     /home/deploy/liveapi/phpinfo.php;
    include fastcgi_params;
    }
    location /status {
        vhost_traffic_status_display;
        vhost_traffic_status_display_format html;
    }
}

[vozlt]

Hi, Thanks for reporting.
The latest code has now patched. (389f350)
Please test...