{5} Accepted, Active Tickets by Owner (Full Description) (52 matches)

When building with --builddir, an error is thrown during compilation.

> [...]
> Running Mkbootstrap for nginx ()
> chmod 644 "nginx.bs"
> "/foo/bar/perl5/bin/perl" -MExtUtils::Command::MM -e 'cp_nonempty' -- nginx.bs blib/arch/auto/nginx/nginx.bs 644
> gmake[2]: *** No rule to make target `../../../../../src/core/nginx.h', needed by `nginx.c'. Stop.
> gmake[2]: Leaving directory `/home/user/build/src/http/modules/perl'
> gmake[1]: *** [/home/user/build//src/http/modules/perl/blib/arch/auto/nginx/nginx.so] Error 2
> gmake[1]: Leaving directory `/home/user/nginx-1.13.8'
> gmake: *** [build] Errror 2

gmake --version GNU Make 3.81 Copyright (C) 2006 Free Software Foundation, Inc.

gcc --version gcc (GCC) 5.3.0

cpp --version cpp (GCC) 5.3.0

Hi,

nginx worker process crashes with segfault when SSI is used in a sub-request.

Config example:

    location /loc1.html {
        add_after_body /loc2.html;
    }

    location /loc2.html {
        ssi on;
    }

Seg fault happens only when I access /loc1.html location. When I access /loc2.html directly it works fine.

Error log:

==> ../log/error.log <==
2017/05/03 18:47:10 [alert] 14548#23345880: worker process 14566 exited on signal 11
2017/05/03 18:47:10 [alert] 14548#23345880: worker process 14573 exited on signal 11

Just FYI, content of loc1.html:

<p>Hi from location 1 !</p>

content of loc2.html:

<p>Hi from location 2 on <!--#echo var="host" --> !</p>

I tried to debug it and fix it, but due to the time I stopped here: file ngx_http_ssi_filter_module.c:

static ngx_str_t *
ngx_http_ssi_get_variable(ngx_http_request_t *r, ngx_str_t *name,
    ngx_uint_t key)
{
    ngx_uint_t           i;
    ngx_list_part_t     *part;
    ngx_http_ssi_var_t  *var;
    ngx_http_ssi_ctx_t  *ctx;

    ctx = ngx_http_get_module_ctx(r->main, ngx_http_ssi_filter_module);

    ...

ctx is NULL. SSI context is missing when SSI is called in a subrequest.

And then the subsequent code will cause segfault, because ctx is NULL:

    if (ctx->variables == NULL) {
        return NULL;
    }

I added some additional debug logs to the code around the ctx = ngx_http_get_module_ctx(....) line. And this is the output:

2017/05/03 18:47:10 [debug] 16787#8822579: *3 ssi ngx_http_ssi_get_variable r->main: 00007FE3FC006E50
2017/05/03 18:47:10 [debug] 16787#8822579: *3 ssi ngx_http_ssi_get_variable r->main->ctx: 00007FE3FC007770, module.ctx_index: 46
2017/05/03 18:47:10 [debug] 16787#8822579: *3 ssi ngx_http_ssi_get_variable ctx: 0000000000000000

Cheers Peter Magdina

Functions for traversing directories use ANSI versions of FindFirstFile() and FindNextFile(), so any characters in filenames besides basic latin become broken.

Proposed patch fix this issue converting WCHAR names to utf-8.

When using subrequests with try_files the following behaviour is observed.

   server {
       listen       8081;
       default_type text/html;

       location /uno {   return 200 "uno  ";   }
       location /duo {   return 200 "duo  ";   }
       location /tres {  return 200 "tres  ";  }
   }


   server {
       listen       8080;

       location / {
           root /tmp;
           try_files /tres =404;
           proxy_pass http://127.0.0.1:8081;
           add_after_body /duo;
       }
   }

Assuming /tmp/tres exists, a request to

​http://127.0.0.1:8080/uno

returns "uno tres ", not "uno duo " or "tres tres ".

I.e., main request assumes that the request URI is unmodified and passes original request URI, "/uno". But in a subrequest the URI is modified and nginx uses modified URI, "/tres".

This is believed to be a bug, and one of the following should be done:

• try_files should reset the r->valid_unparsed_uri flag if it modifies the URI;
• or try_files should not modify the URI at all.

See ​this thread (in Russian) for additional details.

I have encountered a bug in ngx_http_image_filter_module when used in conjunction with ngx_http_proxy_module ; the configuration is as following:

location /img/ {

proxy_pass ​http://mybucket.s3.amazonaws.com; image_filter resize 150 100;

}

The steps to reproduce are rather complicated as they depend on how TCP fragments the response coming from the proxy:

• If ​http://mybucket.s3.amazonaws.com returns, in the first TCP packet, a sizable amount of data (1-2k), the image is resized correctly.

• If ​http://mybucket.s3.amazonaws.com returns, in the first TCP packet, a small amount of data (HTTP header, or HTTP header + a few bytes), the content is marked as not an image and NGX_HTTP_UNSUPPORTED_MEDIA_TYPE is returned (disconnecting the client), irrespective on whether or not subsequent data would complete the response to a valid image.

Nginx appears to give up right away on waiting for data if the contents of the first TCP packet received from the proxy does not contain a valid image header- i.e. ngx_http_image_test() will return NGX_HTTP_IMAGE_SIZE, etc.

In my experience this was triggered by a subtle change in AWS S3 that introduced further fragmentation of the TCP responses.

Versions affected: 1.6.2, 1.6.3, 1.7.2, 1.8.0, etc. (all?)

Attaching a 1.8.0 patch that resolves it; the other versions can be fixed similarly.

I think a better fix would be to "return NGX_OK" if we do not have enough data in "case NGX_HTTP_IMAGE_START", and "return NGX_HTTP_UNSUPPORTED_MEDIA_TYPE" (as per the original code) if enough data has been read, but it’s really not an image- but this exceeds the scope of the fix and my use case.

nginx-devel thread: ​http://mailman.nginx.org/pipermail/nginx-devel/2015-April/006876.html

The hpack dynamic table is only initialized upon addition of the first entry (see ngx_http_v2_add_header) in http/v2/ngx_http_v2_table.c.

If a dynamic table size update is sent before the first header to be added, the size will be set appropriately. However, once the first header is added, the table size is updated with NGX_HTTP_V2_TABLE_SIZE, resulting in a different size than the client.

After a brief reading of the HTTP/2 and HPACK specification, it appears that updating the dynamic table size before adding any headers is allowed.

When using nginx as a caching reverse proxy, items may be cached for the wrong amount of time if the Expires header is inconsistent with max-age. Caching will be disabled if the Expires header value is in the past or malformed.

Per RFC 2616 section 14.9.3, max-age takes precedence over Expires. However, nginx prefers whichever header/directive occurs first in the response, which causes unexpected results when migrating to nginx from an RFC-compilant caching reverse proxy.

A minimally-reproducible config is attached. Observe that no file is cached when accessing ​http://127.0.0.2:8080/fail, but a file is cached when accessing ​http://127.0.0.2:8080/success.

при запросе URL без концевого слэша всегда происходит 301 редирект на тот же URL со слэшем в конце

пример конфига: location /dir {

alias /www/dir;

}

тоже самое происходит и в таком варианте: location /dir/ {

alias /www/dir/;

}

Однако, в документации такое поведение, вроде бы, описано только для локэйшнов с *_pass, либо я не там искал, но нашёл я только вот это:

Если location задан префиксной строкой со слэшом в конце и запросы обрабатываются при помощи proxy_pass, fastcgi_pass, uwsgi_pass, scgi_pass или memcached_pass, происходит специальная обработка. В ответ на запрос с URI равным этой строке, но без завершающего слэша, будет возвращено постоянное перенаправление с кодом 301 на URI с добавленным в конец слэшом.

пример готовой конфигурации

location /ig {

alias /www/ig_build;

}

$curl -I ​http://localhost:90/ig/infografika HTTP/1.1 301 Moved Permanently Server: nginx/1.11.3 Date: Wed, 24 Aug 2016 09:52:10 GMT Content-Type: text/html Content-Length: 185 Location: ​http://localhost:90/ig/infografika/ Connection: keep-alive

Также проверял на версии 1.4.2, всё тоже самое.

Если директории нет - то сразу возвращает 404, но если она есть, а запрос был без слэша - возникает редирект.

nginx behaves weirdly when using eventport as event engine. I tried to use eventport on Solaris when I first started using nginx, but the experience was discouraging: nginx behaved weirdly, mostly when entering indefinite timeouts during handling requests. I switched to /dev/poll and since then it worked flawlessly. Some time ago I saw a discussion stating that a work has been done on the eventport better support, so I compiled new 1.11.11 version and decided to give eventport in nginx another chance. Sadly, nothing has changed: nginx still enters idefinite loops when handling requests with eventport. This looks like the web application really waits for something, and the browser just keeps spinning the loader icon. When changed to /dev/poll and restarting nginx everything starts working back. No errors are logged in the logs.

I have this code:

map $http_incap_client_ip:$http_incap_tls_version:${http_x_forwarded_proto}:$ssl_protocol $x_forwarded_proto {

default "http"; ~^{[0-9.]*:- "http"; # incapsula http-https connection ~}[0-9.]*:TLSv1 "https"; # incapsula https-https connection ~^{-:.*:https "https"; # internal tests x-forwarded-proto ~}-:.*:TLSv1 "https"; # internal https connection

}

When i'm trying a local test connection, the log show that $http_incap_client_ip:$http_incap_tls_version:${http_x_forwarded_proto}:$ssl_protocol is:

-:-:https:TLSv1.2

Yet, the $x_forwarded_proto result is http.

Hi nginx guys,

i use a nginx in front of a varnish server. I purge my varnish via purge method.

Nginx uses the following VHost config:

server {
    listen       *:80 default_server;

    location / {
        limit_except GET POST {
            allow 127.0.0.1/32;
            deny all;
        }

        set $upstream http://127.0.0.1:8080;

        if ($http_user_agent = 'mobile') {
            set $upstream http://127.0.0.1:8080;
        }

        proxy_pass              $upstream;
        proxy_set_header        Host $host;
        proxy_set_header        X-Forwarded-For $remote_addr;
    }
}

Suggested: From not localhost i only can request GET/HEAD/POST, localhost can do everything.

From remote it works as expected:

root@test:~# curl -X PURGE -I EXTIP
HTTP/1.1 403 Forbidden
Server: nginx
Date: Mon, 18 Sep 2017 10:39:23 GMT
Content-Type: text/html
Content-Length: 162
Connection: keep-alive
Vary: Accept-Encoding

But from localhost:

root@test:~# curl -X PURGE -I http://127.0.0.1
HTTP/1.1 500 Internal Server Error
Server: nginx
Date: Mon, 18 Sep 2017 10:39:06 GMT
Content-Type: text/html
Content-Length: 186
Connection: close

Nginx error log tells me:

==> /var/log/nginx/error.log <==
2017/09/18 12:39:06 [error] 2483#2483: *2 invalid URL prefix in "", client: 127.0.0.1, server: , request: "PURGE / HTTP/1.1", host: "127.0.0.1"

Without using Variables in VHost:

server {
    listen       *:80 default_server;

    location / {
        limit_except GET POST {
            allow 127.0.0.1/32;
            deny all;
        }

        proxy_pass              http://127.0.0.1:8080;
        proxy_set_header        Host $host;
        proxy_set_header        X-Forwarded-For $remote_addr;
    }
}

Works as expected:

root@test:~# curl -X PURGE -I http://127.0.0.1
HTTP/1.1 200 OK
Server: nginx
Date: Mon, 18 Sep 2017 10:45:35 GMT
Content-Type: text/html; charset=UTF-8
Transfer-Encoding: chunked
Connection: keep-alive
Vary: Accept-Encoding

Other tests with a variable proxy_pass e.g. using the get method instead of purge also fails with same error.

Please take a look why nginx fails when combining limit_except with proxypass and variables. Thanks

I'm using Nginx as a static resource server on Windows 10. And I use php_curl to transfer file from Apache to Nginx by HTTP PUT method. When URL include Chinese in UTF8 codec like "/0/%E6%B5%B7%E6%8A%A5%E8%83%8C%E6%99%AF.jpg", the WebDAV just create a file with the UTF-8 string. But Windows use GBK to store Chinese file name. So the UTF-8 string was used as a GBK string without conversion, which lead to an incorrect name on Windows like 海报背景.jpg(correct) => 娴锋姤鑳屾櫙.jpg(incorrect). If I use GBK encode URL "/0/%BA%A3%B1%A8%B1%B3%BE%B0.jpg"(same as the UTF-8 one in Chinese), every thing works fine, the file name on Windows is correct. If I try to GET the GBK encode URL, the Nginx return 500 with error log: 1113: No mapping for the Unicode character exists in the target multi-byte code page. And if I use the UTF-8 encode URL, it works fine. So I can figure out the Nginx handle the GET method with a codec conversion, but PUT method not, maybe other WebDAV method not as well.

Hello, Nginx seems to have a bug with mirror+limit_req Configuration:

All servers could be the same for testing purposes (127.0.0.1) Frontend server

limit_req_zone $binary_remote_addr zone=one:10m rate=5r/s;
location = /url1
{
  mirror /url2;
  proxy_pass http://127.0.0.1/test;
}
location = /url2
{
  internal;
  limit_req zone=one burst=10;
  proxy_pass http://127.0.0.1/test2;
}
location = /status { stub_status on; }

Backend server

location = /test { return 200; }

Mirror server

location = /test2 { return 200; }

Now run:

# for i in {1..1000}; do curl http://127.0.0.1/url1 >/dev/null & sleep 0.05; done

Wait for completion of all requests and see writing connections:

# curl http://127.0.0.1/status
Active connections: 271 
server accepts handled requests
 2001 2001 2001 
Reading: 0 Writing: 271 Waiting: 0
# sleep 120
# netstat -atn | grep 127.0.0.1:80 | grep -v CLOSE_WAIT | wc -l
270
# service nginx reload
# pgrep -f shutting
# netstat -atn | grep 127.0.0.1:80 | grep -v CLOSE_WAIT | wc -l
0
# curl http://127.0.0.1/status
Active connections: 271 
server accepts handled requests
 2002 2002 2002 
Reading: 0 Writing: 271 Waiting: 0 

When /url1 doesn't have limit_req, but /url2 has, number of writing connections from stub status begins to grow. Watching netstat, I can also see CLOSE_WAIT connections growing. I did't find any impact on requests processing at least when the number of connections is quite low. Actually, after reloading nginx there seems to be no real connections (writing). But this breaks nginx monitoring. Restart of nginx only resets writing connections number. If both /url1 and /url2 have limit_req, or /url1 only has limit_req - all is OK.

We use amd64 debian stretch, with the nginx-extras package from debian buster (rebuilt on stretch).

Hi, The scenario is as follows:

1. Nginx is configured to work with sendfile and io-threads.
2. Client sends a request, and after receiving the entire content it sends a FIN-ACK, closing the connection.
3. Nginx occasionally considers the transaction as prematurely closed by the client even though the FIN-ACK packet acks the entire content.

The effect i've seen is that "$body_bytes_sent" holds partial data (up to the last "successful" sendfile call) and "$request_completion" is empty. I guess there are other effects though these are the one i'm using, so they popped up.

From what i've managed to understand from the code it looks like the scenario is that the read_event_handler "ngx_http_test_reading" is called before the completed task from the io-thread is handled by the main thread, effectively making Nginx think the client connection close happened earlier.

I've managed to reproduce it or latest nginx with rather simple config, but it's time sensitive so it doesn't happen on each transaction. I saw that using a bigger file with rate-limit increases the chances.

Config:

worker_processes  1;

events {
    worker_connections 1024;
}

http {
    keepalive_timeout 120s;
    keepalive_requests 1000;

    log_format main "$status\t$sent_http_content_length\t$body_bytes_sent\t$request_completion";
    access_log  logs/access.log  main;
    error_log  logs/error.log  info;

    aio threads;
    sendfile on;
    limit_rate 10m;

    server {
        listen 0.0.0.0:1234 reuseport;

        location = /test-sendfile-close {
            alias files/10mb;
        }
    }
}

• files/10mb is a file of size 10MB, created with "dd" (dd if=/dev/zero of=files/10mb bs=10M count=1)

I then tail -F the access log and the error log file, and send these requests from the same machine:

while true; do wget -q "http://10.1.1.1:1234/test-sendfile-close"; done

The output i get in error log and access log (in this order) in case of a good transaction is:

2019/12/17 14:52:34 [info] 137444#137444: *1 client 10.1.1.1 closed keepalive connection
200	10485760	10485760	OK

But every few transactions i get this output instead:

2019/12/17 14:52:38 [info] 137444#137444: *7 client prematurely closed connection while sending response to client, client: 10.1.1.1, server: , request: "GET /test-sendfile-close HTTP/1.1", host: "10.1.1.1:1234"
200	10485760	3810520	

As you can see, the reported sent bytes is lower than the actual value, and the request_completion is empty.

I understand that the closer the client is to Nginx the higher chances this could happen, but it's not just a lab issue - we've seen this in a field trial with clients in a distance of ~30ms RTT, with higher load of course.

If there is need for any other information, or anything else - i'll be glad to provide it. I appreciate the help, and in general - this great product you've built!

Thank you, Shmulik Biran

nginx logformat: log_format main escape=json '{ "http_x_forwarded_for": "[$http_x_forwarded_for]", ' '"remote_addr": "$remote_addr", ' '"remote_user": "$remote_user", ' '"time_local": "[$time_local]", ' '"request_method": "$request_method", ' '"request_host": "$scheme://$host", ' '"request_host_1": "$host", ' '"service_line": "itservice.api", ' '"request_uri": "$uri", ' '"query_string": "$query_string", ' '"server_protocol": "$server_protocol", ' '"status": "$status", ' '"body_bytes_sent": "$body_bytes_sent", ' '"http_referer": "$http_referer", ' '"http_user_agent": "$http_user_agent",' '"request_time": "$request_time", ' '"upstream_addr": "[$upstream_addr]", ' '"req_id": "$request_id", ' '"upstream_response_time": "$upstream_response_time" ' ' }';

nginx log: { "http_x_forwarded_for": "[]", "remote_addr": "192.168.11.130", "remote_user": "", "time_local": "[29/Apr/2020:01:11:33 +0800]", "request_method": "GET", "request_host": "​https://xxx.abc.com", "request_host_1": "xxx.abc.com", "service_line": "itservice.api", "request_uri": "/api/v1/sensitive-info/batch/getUserInfo", "query_string": "batchNumber=xxx&userId=xxx&dataType=1", "server_protocol": "HTTP/1.1", "status": "200", "body_bytes_sent": "113", "http_referer": "", "http_user_agent": "Apache-HttpClient/4.5.10 (Java/1.8.0_211)","request_time": "0.011", "upstream_addr": "[192.168.10.182:80]", "req_id": "6bdcc5ce837247323599d37aaceba33c", "upstream_response_time": "0.012" }

issue: upstream_response_time: 0.012 request_time: 0.011 In this log, the requset_time is less than upstream_response_time. Why does this happen?

It would be great if support for HSTS (RFC 6797) would be added to the nginx-core.

Currently HSTS is "enabled" like this (according to ​https://en.wikipedia.org/wiki/HTTP_Strict_Transport_Security):

add_header Strict-Transport-Security max-age=31536000;

However this has at least two downsides:

1. The header is only added when the HTTP status code is 200, 204, 301, 302 or 304.
   • It would be great if the header would always be added
2. The header is added on HTTPS and HTTP responses, but according to RFC 6797 (7.2.) it should not:
   • An HSTS Host MUST NOT include the STS header field in HTTP responses conveyed over non-secure transport.

RFC 6797: ​https://tools.ietf.org/html/rfc6797

Конфигурация следующая: fastcgi_cache_path /var/tmp/nginx/fastcgi_cache levels=1:2 keys_zone=fcgi_cache:16m max_size=1024m inactive=35m; fastcgi_cache_revalidate on;

fastcgi_cache fcgi_cache; fastcgi_cache_valid 200 301 302 304 10m; fastcgi_cache_valid 404 2m; fastcgi_cache_use_stale updating error timeout invalid_header http_500 http_503; fastcgi_cache_key "$request_method|$host|$uri|$args"; fastcgi_no_cache $cookie_nocache $arg_nocache $cookie_NRGNSID $cookie_NRGNTourSID $cookie_failed_login; fastcgi_cache_bypass $cookie_nocache $arg_nocache $cookie_NRGNSID $cookie_NRGNTourSID $cookie_failed_login;

Сейчас бекенд отвечает 200 с заголовками "Cache-Control: no-store, no-cache, must-revalidate" и "Pragma: no-cache". Но две недели назад некоторое время там было 302 без запрета кеширования и ответ попал в кеш по fastcgi_cache_valid 10m. После этого одинокие запросы получают upstream_cache_status EXPIRED и ответ бекенда, но если несколько приходят одновременно, то срабатывает UPDATING и редирект из кеша двухнедельной давности. Запросы приходят регулярно и удаление по inactive=35m не происходит.

Поведение полностью объяснимо механикой работы кеша, но не с точки зрения человеческих ожиданий. Хотелось бы иметь механизм инвалидации таких устаревших данных из кеша кроме удаления элементов на файловой системе внешним скриптом. Например, ещё один параметр для cache_path, который будет задавать максимальное время жизни в кеше expired элементов, даже если к ним есть обращения.

Hi, we tried nginx version 1.6.2 till version 1.12.2 and have a problem when used as proxy before artifactory. Downloads get interrupted at 1GB.

This behavior depends on the internal VLAN. On one VLAN this always happens. On an other VLAN it never happens. This is size limited, not time limited. From some network it stops after 30 seconds and from one other slow network it stops after 13 minutes.

We made a minimal proxy setup with apache and this works with all VLANs. This is why we expect it has something to do with nginx or the combination of nginx and TCP/IP stack of linux.

In wireshark we see "TCP Dup ACK" on the client side sent to the nginx server.

Wget fails with connection closed at byte 1083793011 but continues download with partial content. docker can't handle this and our customers can't download docker images with layers greater 1 GB.

The following text shows two anonymized minimal configs. The nginx config that is problematic and the apache config that works:

NGINX config:
server {
    listen *:80;
    server_name NAME;
    client_max_body_size 3G;
    access_log /var/log/nginx/NAME.access.log;
    error_log /var/log/nginx/NAME.error.log;

    if ($request_uri !~ /artifactory/) {
        rewrite ^ $scheme://NAME/artifactory/ permanent;
    }

    location /artifactory {
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header X-Real-IP $remote_addr;
        proxy_pass http://ARTIFACTORY:PORT;
        proxy_pass_header Server;
        proxy_read_timeout 90s;
    }
}

APACHE config:
<VirtualHost *:80>
    ServerName NAME
    ServerAdmin NAME

    ErrorLog ${APACHE_LOG_DIR}/error.log

    LogLevel warn

    ProxyRequests Off
    <Proxy *>
      Order allow,deny
      Allow from All
    </Proxy>

    ProxyPass / http://ARTIFACTORY:PORT/
    ProxyPassReverse / http://ARTIFACTORY:PORT/
</VirtualHost>

Hi,

We have a Flask Python application served by uWSGI through nginx using 'uwsgi-pass' via a load-balancer, hosted in AWS.

We are noticing that nginx intermittently (but frequently) seems to add a substantial delay (as much as 200 seconds, but more typically 5-10 seconds) to some requests.

I've spent a couple of weeks looking into this, with activities ranging from changes to logging and analysis of logs, configuration changes, packet traces, nginx debug logs and strace, and more, but have been unable to solve the problem.

This is a production service, so I'm limited to what I can change (particularly around uWSGI and the app), and I've been unable to replicate the issue on a test setup so far, presumably because the incoming requests and load aren't "realistic enough".

Our production servers have:

$ nginx -V
nginx version: nginx/1.4.6 (Ubuntu)
built by gcc 4.8.4 (Ubuntu 4.8.4-2ubuntu1~14.04.3)
TLS SNI support enabled
configure arguments: --with-cc-opt='-g -O2 -fstack-protector --param=ssp-buffer-size=4 -Wformat -Werror=format-security -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -Wl,-z,relro' --prefix=/usr/share/nginx --conf-path=/etc/nginx/nginx.conf --http-log-path=/var/log/nginx/access.log --error-log-path=/var/log/nginx/error.log --lock-path=/var/lock/nginx.lock --pid-path=/run/nginx.pid --http-client-body-temp-path=/var/lib/nginx/body --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-proxy-temp-path=/var/lib/nginx/proxy --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --with-debug --with-pcre-jit --with-ipv6 --with-http_ssl_module --with-http_stub_status_module --with-http_realip_module --with-http_addition_module --with-http_dav_module --with-http_geoip_module --with-http_gzip_static_module --with-http_image_filter_module --with-http_spdy_module --with-http_sub_module --with-http_xslt_module --with-mail --with-mail_ssl_module
$ uname -a
Linux webserver 3.13.0-116-generic #163-Ubuntu SMP Fri Mar 31 14:13:22 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
$ uwsgi --version
2.0.15

I did try upgrading nginx on one instance and passed some traffic through it (no improvement), it had:

$ nginx -V
nginx version: nginx/1.12.2
built with OpenSSL 1.0.1f 6 Jan 2014
TLS SNI support enabled
configure arguments: --with-cc-opt='-g -O2 -fPIE -fstack-protector --param=ssp-buffer-size=4 -Wformat -Werror=format-security -fPIC -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now -fPIC' --prefix=/usr/share/nginx --conf-path=/etc/nginx/nginx.conf --http-log-path=/var/log/nginx/access.log --error-log-path=/var/log/nginx/error.log --lock-path=/var/lock/nginx.lock --pid-path=/run/nginx.pid --modules-path=/usr/lib/nginx/modules --http-client-body-temp-path=/var/lib/nginx/body --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-proxy-temp-path=/var/lib/nginx/proxy --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --with-debug --with-pcre-jit --with-http_ssl_module --with-http_stub_status_module --with-http_realip_module --with-http_auth_request_module --with-http_v2_module --with-http_dav_module --with-http_slice_module --with-threads --with-http_addition_module --with-http_geoip_module=dynamic --with-http_gunzip_module --with-http_gzip_static_module --with-http_image_filter_module=dynamic --with-http_sub_module --with-http_xslt_module=dynamic --with-stream=dynamic --with-stream_ssl_module --with-stream_ssl_preread_module --with-mail=dynamic --with-mail_ssl_module --add-dynamic-module=/build/nginx-WaTJd7/nginx-1.12.2/debian/modules/nginx-auth-pam --add-dynamic-module=/build/nginx-WaTJd7/nginx-1.12.2/debian/modules/nginx-dav-ext-module --add-dynamic-module=/build/nginx-WaTJd7/nginx-1.12.2/debian/modules/nginx-echo --add-dynamic-module=/build/nginx-WaTJd7/nginx-1.12.2/debian/modules/nginx-upstream-fair --add-dynamic-module=/build/nginx-WaTJd7/nginx-1.12.2/debian/modules/ngx_http_substitutions_filter_module

I also tried a standalone nginx instance and pointed it at the same uWSGI across the network (still no improvement):

$ nginx -V
nginx version: nginx/1.14.0 (Ubuntu)
built with OpenSSL 1.1.0g  2 Nov 2017
TLS SNI support enabled
configure arguments: --with-cc-opt='-g -O2 -fdebug-prefix-map=/build/nginx-mcUg8N/nginx-1.14.0=. -fstack-protector-strong -Wformat -Werror=format-security -fPIC -Wdate-time -D_FORTIFY_SOURCE=2' --with-ld-opt='-Wl,-Bsymbolic-functions -Wl,-z,relro -Wl,-z,now -fPIC' --prefix=/usr/share/nginx --conf-path=/etc/nginx/nginx.conf --http-log-path=/var/log/nginx/access.log --error-log-path=/var/log/nginx/error.log --lock-path=/var/lock/nginx.lock --pid-path=/run/nginx.pid --modules-path=/usr/lib/nginx/modules --http-client-body-temp-path=/var/lib/nginx/body --http-fastcgi-temp-path=/var/lib/nginx/fastcgi --http-proxy-temp-path=/var/lib/nginx/proxy --http-scgi-temp-path=/var/lib/nginx/scgi --http-uwsgi-temp-path=/var/lib/nginx/uwsgi --with-debug --with-pcre-jit --with-http_ssl_module --with-http_stub_status_module --with-http_realip_module --with-http_auth_request_module --with-http_v2_module --with-http_dav_module --with-http_slice_module --with-threads --with-http_addition_module --with-http_geoip_module=dynamic --with-http_gunzip_module --with-http_gzip_static_module --with-http_image_filter_module=dynamic --with-http_sub_module --with-http_xslt_module=dynamic --with-stream=dynamic --with-stream_ssl_module --with-mail=dynamic --with-mail_ssl_module
$ uname -a
Linux webserver 4.15.0-1019-aws #19-Ubuntu SMP Fri Aug 10 09:34:35 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

Config is pretty standard and I've tried enabling/disabling various bits with no improvement; key statements are:

events {
    use epoll;
}
http {
    sendfile on;
    tcp_nopush on;
    tcp_nodelay on;
}

Here's log evidence of the problem (bits {LIKE_THIS} are redacted):

uWSGI:
[pid: 3923|app: -|req: -/-] {LB_IP} (-) {46 vars in 922 bytes} [Fri Oct 19 13:26:23 2018] POST {URL} => generated 82 bytes in 2474 msecs (HTTP/1.1 200) 4 headers in 253 bytes (1 switches on core 4) 1539955583.879-4615-438-18-{CLIENT_IP}

nginx:
{LB_IP} - - [19/Oct/2018:13:26:43 +0000] "POST {URL} HTTP/1.1" 200 82 "-" "-" 19.534 1539955583.879-4615-438-18-{CLIENT_IP}

The "1539955583.879-4615-438-18-{CLIENT_IP}" is an HTTP_X_TRACEID header I added with nginx and is passed to uWSGI and logged by both, so I can always tie the nginx log entry to the relevant uWSGI entry. It also contains the nginx PID and connection ID which is handy for finding related debug entries; see below.

Note the timings; uWSGI logs as 13:26:23 (which is when the request was received, not completed) and took 2474ms to generate the response, whereas nginx logs as 13:26:43 (when the response was delivered).

Before anyone assumes this is client-side delay (between browser and nginx), note that I have also included the $upstream_response_time in the nginx log, which for this request was 19534ms, 17s longer than uWSGI claims the response took.

We normally use a UNIX socket for the nginx <-> uWSGI communication, but I changed one of our servers to use TCP (port 8001); firstly to see if it made a difference - it did not - but also to then use tcpdump to capture what was happening between the two processes.

I saw this:

13:26:23.929522 IP 127.0.0.1.48880 > 127.0.0.1.8001: Flags [S], seq 2215864258, win 43690, options [mss 65495,sackOK,TS val 413969 ecr 0,nop,wscale 7], length 0
13:26:23.929528 IP 127.0.0.1.8001 > 127.0.0.1.48880: Flags [S.], seq 3951451851, ack 2215864259, win 43690, options [mss 65495,sackOK,TS val 413969 ecr 413969,nop,wscale 7], length 0
13:26:23.929537 IP 127.0.0.1.48880 > 127.0.0.1.8001: Flags [.], ack 1, win 342, options [nop,nop,TS val 413969 ecr 413969], length 0
13:26:23.931409 IP 127.0.0.1.48880 > 127.0.0.1.8001: Flags [P.], seq 1:1991, ack 1, win 342, options [nop,nop,TS val 413970 ecr 413969], length 1990
13:26:23.931424 IP 127.0.0.1.8001 > 127.0.0.1.48880: Flags [.], ack 1991, win 1365, options [nop,nop,TS val 413970 ecr 413970], length 0
13:26:26.406311 IP 127.0.0.1.8001 > 127.0.0.1.48880: Flags [P.], seq 1:336, ack 1991, win 1365, options [nop,nop,TS val 414589 ecr 413970], length 335
13:26:26.406335 IP 127.0.0.1.48880 > 127.0.0.1.8001: Flags [.], ack 336, win 350, options [nop,nop,TS val 414589 ecr 414589], length 0
13:26:43.456382 IP 127.0.0.1.8001 > 127.0.0.1.48880: Flags [F.], seq 336, ack 1991, win 1365, options [nop,nop,TS val 418851 ecr 414589], length 0
13:26:43.459119 IP 127.0.0.1.48880 > 127.0.0.1.8001: Flags [F.], seq 1991, ack 337, win 350, options [nop,nop,TS val 418852 ecr 418851], length 0
13:26:43.459135 IP 127.0.0.1.8001 > 127.0.0.1.48880: Flags [.], ack 1992, win 1365, options [nop,nop,TS val 418852 ecr 418852], length 0

So, the 335 byte response (253 bytes of headers + 82 bytes of data = 335 bytes payload) was sent (and ACK'd) at 13:26:26 (as per uWSGI's claim of 2474ms).

However, nginx doesn't appear to send the response until 13:26:43, when uWSGI closes the connection (FIN/ACK packet); this matches with nginx's $upstream_response_time of 19534ms.

By the way, the response did contain a "Content-Length: 82" header.

So, on to debug logs (sorry, bit long, and again with {REDACTED_BITS}):

2018/10/19 13:26:26 [debug] 4615#4615: *438 http upstream request: "{URL}"
2018/10/19 13:26:26 [debug] 4615#4615: *438 http upstream process header
2018/10/19 13:26:26 [debug] 4615#4615: *438 malloc: 00007F2FD2F10000:4096
2018/10/19 13:26:26 [debug] 4615#4615: *438 recv: eof:0, avail:1
2018/10/19 13:26:26 [debug] 4615#4615: *438 recv: fd:21 335 of 4096
2018/10/19 13:26:26 [debug] 4615#4615: *438 http uwsgi status 200 "200 OK"
2018/10/19 13:26:26 [debug] 4615#4615: *438 http uwsgi header: "Content-Type: application/json"
2018/10/19 13:26:26 [debug] 4615#4615: *438 http uwsgi header: "Content-Length: 82"
2018/10/19 13:26:26 [debug] 4615#4615: *438 http uwsgi header: "Cache-Control: no-cache"
2018/10/19 13:26:26 [debug] 4615#4615: *438 http uwsgi header: "Set-Cookie: session={SESSION_ID}; HttpOnly; Path=/"
2018/10/19 13:26:26 [debug] 4615#4615: *438 http uwsgi header done
2018/10/19 13:26:26 [debug] 4615#4615: *438 HTTP/1.1 200 OK
Server: nginx/1.12.2
Date: Fri, 19 Oct 2018 13:26:26 GMT
Content-Type: application/json
Content-Length: 82
Connection: keep-alive
Keep-Alive: timeout=120
Cache-Control: no-cache
Set-Cookie: session={SESSION_ID}; HttpOnly; Path=/
Accept-Ranges: bytes

2018/10/19 13:26:26 [debug] 4615#4615: *438 write new buf t:1 f:0 00007F2FD2F2F800, pos 00007F2FD2F2F800, size: 383 file: 0, size: 0
2018/10/19 13:26:26 [debug] 4615#4615: *438 http write filter: l:0 f:0 s:383
2018/10/19 13:26:26 [debug] 4615#4615: *438 http cacheable: 0
2018/10/19 13:26:26 [debug] 4615#4615: *438 http upstream process upstream
2018/10/19 13:26:26 [debug] 4615#4615: *438 pipe read upstream: 0
2018/10/19 13:26:26 [debug] 4615#4615: *438 pipe preread: 82
2018/10/19 13:26:26 [debug] 4615#4615: *438 pipe buf free s:0 t:1 f:0 00007F2FD2F10000, pos 00007F2FD2F100FD, size: 82 file: 0, size: 0
2018/10/19 13:26:26 [debug] 4615#4615: *438 pipe length: -1
2018/10/19 13:26:26 [debug] 4615#4615: *438 pipe write downstream: 1
2018/10/19 13:26:26 [debug] 4615#4615: *438 pipe write busy: 0
2018/10/19 13:26:26 [debug] 4615#4615: *438 pipe write: out:0000000000000000, f:0
2018/10/19 13:26:26 [debug] 4615#4615: *438 pipe read upstream: 0
2018/10/19 13:26:26 [debug] 4615#4615: *438 pipe buf free s:0 t:1 f:0 00007F2FD2F10000, pos 00007F2FD2F100FD, size: 82 file: 0, size: 0
2018/10/19 13:26:26 [debug] 4615#4615: *438 pipe length: -1
2018/10/19 13:26:26 [debug] 4615#4615: *438 event timer del: 21: 1539959183930
2018/10/19 13:26:26 [debug] 4615#4615: *438 event timer add: 21: 3600000:1539959186406
2018/10/19 13:26:26 [debug] 4615#4615: *438 http upstream request: "{URL}"
2018/10/19 13:26:26 [debug] 4615#4615: *438 http upstream dummy handler
[...other stuff happens here on other connections...]
2018/10/19 13:26:43 [debug] 4615#4615: *438 http upstream request: "{URL}"
2018/10/19 13:26:43 [debug] 4615#4615: *438 http upstream process upstream
2018/10/19 13:26:43 [debug] 4615#4615: *438 pipe read upstream: 1
2018/10/19 13:26:43 [debug] 4615#4615: *438 readv: eof:1, avail:1
2018/10/19 13:26:43 [debug] 4615#4615: *438 readv: 1, last:3761
2018/10/19 13:26:43 [debug] 4615#4615: *438 pipe recv chain: 0
2018/10/19 13:26:43 [debug] 4615#4615: *438 pipe buf free s:0 t:1 f:0 00007F2FD2F10000, pos 00007F2FD2F100FD, size: 82 file: 0, size: 0
2018/10/19 13:26:43 [debug] 4615#4615: *438 pipe length: -1
2018/10/19 13:26:43 [debug] 4615#4615: *438 input buf #0
2018/10/19 13:26:43 [debug] 4615#4615: *438 pipe write downstream: 1
2018/10/19 13:26:43 [debug] 4615#4615: *438 pipe write downstream flush in
2018/10/19 13:26:43 [debug] 4615#4615: *438 http output filter "{URL}"
2018/10/19 13:26:43 [debug] 4615#4615: *438 http copy filter: "{URL}"
2018/10/19 13:26:43 [debug] 4615#4615: *438 http postpone filter "{URL}" 00007F2FD2F2F4D0
2018/10/19 13:26:43 [debug] 4615#4615: *438 write old buf t:1 f:0 00007F2FD2F2F800, pos 00007F2FD2F2F800, size: 383 file: 0, size: 0
2018/10/19 13:26:43 [debug] 4615#4615: *438 write new buf t:1 f:0 00007F2FD2F10000, pos 00007F2FD2F100FD, size: 82 file: 0, size: 0
2018/10/19 13:26:43 [debug] 4615#4615: *438 http write filter: l:0 f:0 s:465
2018/10/19 13:26:43 [debug] 4615#4615: *438 http copy filter: 0 "{URL}"
2018/10/19 13:26:43 [debug] 4615#4615: *438 pipe write downstream done
2018/10/19 13:26:43 [debug] 4615#4615: *438 event timer del: 21: 1539959186406
2018/10/19 13:26:43 [debug] 4615#4615: *438 event timer add: 21: 3600000:1539959203456
2018/10/19 13:26:43 [debug] 4615#4615: *438 http upstream exit: 0000000000000000
2018/10/19 13:26:43 [debug] 4615#4615: *438 finalize http upstream request: 0
2018/10/19 13:26:43 [debug] 4615#4615: *438 finalize http uwsgi request
2018/10/19 13:26:43 [debug] 4615#4615: *438 free rr peer 1 0
2018/10/19 13:26:43 [debug] 4615#4615: *438 close http upstream connection: 21
etc.

The relevant bits of strace...

4615  13:26:26.151042 epoll_wait(72,  <unfinished ...>
4615  13:26:26.406395 <... epoll_wait resumed> {{EPOLLIN|EPOLLOUT, {u32=3521545648, u64=139843361736112}}}, 512, 97723) = 1
4615  13:26:26.406855 recvfrom(21, "HTTP/1.1 200 OK\r\nContent-Type: a"..., 4096, 0, NULL, NULL) = 335
4615  13:26:26.409079 epoll_wait(72, {{EPOLLIN|EPOLLOUT, {u32=3521545889, u64=139843361736353}}}, 512, 97467) = 1
[...lots of other unrelated activity including a lot of epoll_wait-ing...]
4615  13:26:41.180539 epoll_wait(72, {{EPOLLIN|EPOLLOUT|EPOLLRDHUP, {u32=3521545648, u64=139843361736112}}}, 512, 102058) = 1
4615  13:26:43.457042 readv(21, [{"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 3761}], 1) = 0
4615  13:26:43.459098 close(21)         = 0

At this point, I'm out of ideas; for some reason nginx appears to read all the data it needs promptly, but won't respond to the end user until uWSGI closes the connection.

Any thoughts, suggestions, and explanations welcome!

nginx should treat server_name values with and without trailing dot as identical to each other. Thus, it shall warn and continue during configuration syntax check for the below snippet due to conflicting server_name.

    server {
        server_name  localhost;
    }

    server {
        server_name  localhost.;
    }

# bug: request to "/test/x" will try "/tmp/x" (good) and
# "/tmp//test/y" (bad?)
location /test/ {
    alias /tmp/;
    try_files $uri /test/y =404;
}

# bug: request to "/test/x" will fallback to "fallback" instead of "/test/fallback"
location /test/ {
    alias /tmp/;
    try_files $uri /test/fallback?$args;
}

# bug: request to "/test/x" will try "/tmp/x/test/x" instead of "/tmp/x"
location ~ /test/(.*) {
    alias /tmp/$1;
    try_files $uri =403;
}

Or document special case for regexp locations with alias? See 3711bb1336c3.

# bug: request "/foo/test.gif" will try "/tmp//foo/test.gif"
location /foo/ {
    alias /tmp/;
    location ~ gif {
        try_files $uri =405;
    }
}

I noticed that when a %0a exists in the URL, nginx includes a literal newline in the error_log when logging a file not found:

2012/07/26 17:24:14 [error] 5478#0: *8 "/var/www/localhost/htdocs/

html/index.html" is not found (2: No such file or directory), client: 1.2.3.4, server: , request: "GET /%0a%0a%0ahtml/ HTTP/1.1", host: "test.example.com"

This wreaks havoc with my log monitoring utility 8-/.

It seems desirable to escape the newline in the log message? I tested with the latest 1.2.2. Is there any way with the existing configuration options to make this not happen, or any interest in updating the logging module to handle this situation differently?

In certain configuration scenarios the "Content-Type" HTTP response header is not of the expected type but rather falls back to the default setting.

I was able to shrink down the configuration to a bare minimum test case which gives some indication that this might happen in conjunction with regex captured in "location", "try_files" and "alias" definitions.

Verfied with Nginx 1.3.6 (with patch.spdy-52.txt applied), but was also reproducible with earlier versions, see ​http://mailman.nginx.org/pipermail/nginx/2012-August/034900.html ​http://mailman.nginx.org/pipermail/nginx/2012-August/035170.html (no response was given on those posts)

# nginx -V
nginx version: nginx/1.3.6
TLS SNI support enabled
configure arguments: --prefix=/usr/share/nginx --conf-path=/etc/nginx/nginx.conf --sbin-path=/usr/sbin/nginx --http-log-path=/var/log/nginx/access.log --error-log-path=/var/log/nginx/error.log --pid-path=/var/run/nginx.pid --user=nginx --group=nginx --with-openssl=openssl-1.0.1c --with-debug --with-http_stub_status_module --with-http_ssl_module --with-ipv6

Minimal test configuration for that specific scenario:

server {
    listen                          80;
    server_name                     t1.example.com;

    root                            /data/web/t1.example.com/htdoc;

    location                        ~ ^/quux(/.*)?$ {
        alias                       /data/web/t1.example.com/htdoc$1;
        try_files                   '' =404;
    }
}

First test request where Content-Type is being correctly set to "image/gif" as expected:

$ curl -s -o /dev/null -D - -H 'Host: t1.example.com' http://127.0.0.1/foo/bar.gif
HTTP/1.1 200 OK
Server: nginx/1.3.6
Date: Wed, 12 Sep 2012 14:20:09 GMT
Content-Type: image/gif
Content-Length: 68
Last-Modified: Thu, 02 Aug 2012 05:04:56 GMT
Connection: keep-alive
ETag: "501a0a78-44"
Accept-Ranges: bytes

Second test request where Content-Type is wrong, "application/octet-stream" instead of "image/gif" (actually matches the value of whatever "default_type" is set to):

$ curl -s -o /dev/null -D - -H 'Host: t1.example.com' http://127.0.0.1/quux/foo/bar.gif
HTTP/1.1 200 OK
Server: nginx/1.3.6
Date: Wed, 12 Sep 2012 14:20:14 GMT
Content-Type: application/octet-stream
Content-Length: 68
Last-Modified: Thu, 02 Aug 2012 05:04:56 GMT
Connection: keep-alive
ETag: "501a0a78-44"
Accept-Ranges: bytes

Debug log during the first test request:

2012/09/12 16:20:09 [debug] 15171#0: *1 delete posted event 09C2A710
2012/09/12 16:20:09 [debug] 15171#0: *1 malloc: 09BDA0C8:672
2012/09/12 16:20:09 [debug] 15171#0: *1 malloc: 09BE3210:1024
2012/09/12 16:20:09 [debug] 15171#0: *1 posix_memalign: 09C0AE10:4096 @16
2012/09/12 16:20:09 [debug] 15171#0: *1 http process request line
2012/09/12 16:20:09 [debug] 15171#0: *1 recv: fd:11 178 of 1024
2012/09/12 16:20:09 [debug] 15171#0: *1 http request line: "GET /foo/bar.gif HTTP/1.1"
2012/09/12 16:20:09 [debug] 15171#0: *1 http uri: "/foo/bar.gif"
2012/09/12 16:20:09 [debug] 15171#0: *1 http args: ""
2012/09/12 16:20:09 [debug] 15171#0: *1 http exten: "gif"
2012/09/12 16:20:09 [debug] 15171#0: *1 http process request header line
2012/09/12 16:20:09 [debug] 15171#0: *1 http header: "User-Agent: curl/7.19.7 (i386-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2"
2012/09/12 16:20:09 [debug] 15171#0: *1 http header: "Accept: */*"
2012/09/12 16:20:09 [debug] 15171#0: *1 http header: "Host: t1.example.com"
2012/09/12 16:20:09 [debug] 15171#0: *1 http header done
2012/09/12 16:20:09 [debug] 15171#0: *1 event timer del: 11: 3134905866
2012/09/12 16:20:09 [debug] 15171#0: *1 rewrite phase: 0
2012/09/12 16:20:09 [debug] 15171#0: *1 test location: ~ "^/quux(/.*)?$"
2012/09/12 16:20:09 [debug] 15171#0: *1 using configuration ""
2012/09/12 16:20:09 [debug] 15171#0: *1 http cl:-1 max:1048576
2012/09/12 16:20:09 [debug] 15171#0: *1 rewrite phase: 2
2012/09/12 16:20:09 [debug] 15171#0: *1 post rewrite phase: 3
2012/09/12 16:20:09 [debug] 15171#0: *1 generic phase: 4
2012/09/12 16:20:09 [debug] 15171#0: *1 generic phase: 5
2012/09/12 16:20:09 [debug] 15171#0: *1 access phase: 6
2012/09/12 16:20:09 [debug] 15171#0: *1 access phase: 7
2012/09/12 16:20:09 [debug] 15171#0: *1 post access phase: 8
2012/09/12 16:20:09 [debug] 15171#0: *1 try files phase: 9
2012/09/12 16:20:09 [debug] 15171#0: *1 content phase: 10
2012/09/12 16:20:09 [debug] 15171#0: *1 content phase: 11
2012/09/12 16:20:09 [debug] 15171#0: *1 content phase: 12
2012/09/12 16:20:09 [debug] 15171#0: *1 http filename: "/data/web/t1.example.com/htdoc/foo/bar.gif"
2012/09/12 16:20:09 [debug] 15171#0: *1 add cleanup: 09C0B3D8
2012/09/12 16:20:09 [debug] 15171#0: *1 http static fd: 14
2012/09/12 16:20:09 [debug] 15171#0: *1 http set discard body
2012/09/12 16:20:09 [debug] 15171#0: *1 HTTP/1.1 200 OK
Server: nginx/1.3.6
Date: Wed, 12 Sep 2012 14:20:09 GMT
Content-Type: image/gif
Content-Length: 68
Last-Modified: Thu, 02 Aug 2012 05:04:56 GMT
Connection: keep-alive
ETag: "501a0a78-44"
Accept-Ranges: bytes

2012/09/12 16:20:09 [debug] 15171#0: *1 write new buf t:1 f:0 09C0B500, pos 09C0B500, size: 235 file: 0, size: 0
2012/09/12 16:20:09 [debug] 15171#0: *1 http write filter: l:0 f:0 s:235
2012/09/12 16:20:09 [debug] 15171#0: *1 http output filter "/foo/bar.gif?"
2012/09/12 16:20:09 [debug] 15171#0: *1 http copy filter: "/foo/bar.gif?"
2012/09/12 16:20:09 [debug] 15171#0: *1 read: 14, 09C0B67C, 68, 0
2012/09/12 16:20:09 [debug] 15171#0: *1 http postpone filter "/foo/bar.gif?" 09C0B6C0
2012/09/12 16:20:09 [debug] 15171#0: *1 write old buf t:1 f:0 09C0B500, pos 09C0B500, size: 235 file: 0, size: 0
2012/09/12 16:20:09 [debug] 15171#0: *1 write new buf t:1 f:0 09C0B67C, pos 09C0B67C, size: 68 file: 0, size: 0
2012/09/12 16:20:09 [debug] 15171#0: *1 http write filter: l:1 f:0 s:303
2012/09/12 16:20:09 [debug] 15171#0: *1 http write filter limit 0
2012/09/12 16:20:09 [debug] 15171#0: *1 writev: 303
2012/09/12 16:20:09 [debug] 15171#0: *1 http write filter 00000000
2012/09/12 16:20:09 [debug] 15171#0: *1 http copy filter: 0 "/foo/bar.gif?"
2012/09/12 16:20:09 [debug] 15171#0: *1 http finalize request: 0, "/foo/bar.gif?" a:1, c:1
2012/09/12 16:20:09 [debug] 15171#0: *1 set http keepalive handler
2012/09/12 16:20:09 [debug] 15171#0: *1 http close request
2012/09/12 16:20:09 [debug] 15171#0: *1 http log handler
2012/09/12 16:20:09 [debug] 15171#0: *1 run cleanup: 09C0B3D8
2012/09/12 16:20:09 [debug] 15171#0: *1 file cleanup: fd:14
2012/09/12 16:20:09 [debug] 15171#0: *1 free: 09C0AE10, unused: 1645
2012/09/12 16:20:09 [debug] 15171#0: *1 event timer add: 11: 75000:3134920866
2012/09/12 16:20:09 [debug] 15171#0: *1 free: 09BDA0C8
2012/09/12 16:20:09 [debug] 15171#0: *1 free: 09BE3210
2012/09/12 16:20:09 [debug] 15171#0: *1 hc free: 00000000 0
2012/09/12 16:20:09 [debug] 15171#0: *1 hc busy: 00000000 0
2012/09/12 16:20:09 [debug] 15171#0: *1 tcp_nodelay
2012/09/12 16:20:09 [debug] 15171#0: *1 reusable connection: 1
2012/09/12 16:20:09 [debug] 15171#0: *1 post event 09C2A710
2012/09/12 16:20:09 [debug] 15171#0: posted event 09C2A710
2012/09/12 16:20:09 [debug] 15171#0: *1 delete posted event 09C2A710
2012/09/12 16:20:09 [debug] 15171#0: *1 http keepalive handler
2012/09/12 16:20:09 [debug] 15171#0: *1 malloc: 09BE3210:1024
2012/09/12 16:20:09 [debug] 15171#0: *1 recv: fd:11 -1 of 1024
2012/09/12 16:20:09 [debug] 15171#0: *1 recv() not ready (11: Resource temporarily unavailable)
2012/09/12 16:20:09 [debug] 15171#0: posted event 00000000
2012/09/12 16:20:09 [debug] 15171#0: worker cycle
2012/09/12 16:20:09 [debug] 15171#0: accept mutex locked
2012/09/12 16:20:09 [debug] 15171#0: epoll timer: 75000
2012/09/12 16:20:09 [debug] 15171#0: epoll: fd:11 ev:0001 d:09C117C8
2012/09/12 16:20:09 [debug] 15171#0: *1 post event 09C2A710
2012/09/12 16:20:09 [debug] 15171#0: timer delta: 2
2012/09/12 16:20:09 [debug] 15171#0: posted events 09C2A710
2012/09/12 16:20:09 [debug] 15171#0: posted event 09C2A710
2012/09/12 16:20:09 [debug] 15171#0: *1 delete posted event 09C2A710
2012/09/12 16:20:09 [debug] 15171#0: *1 http keepalive handler
2012/09/12 16:20:09 [debug] 15171#0: *1 recv: fd:11 0 of 1024
2012/09/12 16:20:09 [info] 15171#0: *1 client 127.0.0.1 closed keepalive connection
2012/09/12 16:20:09 [debug] 15171#0: *1 close http connection: 11
2012/09/12 16:20:09 [debug] 15171#0: *1 event timer del: 11: 3134920866
2012/09/12 16:20:09 [debug] 15171#0: *1 reusable connection: 0
2012/09/12 16:20:09 [debug] 15171#0: *1 free: 09BE3210
2012/09/12 16:20:09 [debug] 15171#0: *1 free: 00000000
2012/09/12 16:20:09 [debug] 15171#0: *1 free: 09BD9FC0, unused: 56

Debug log during the second test request:

2012/09/12 16:20:14 [debug] 15171#0: *2 delete posted event 09C2A710
2012/09/12 16:20:14 [debug] 15171#0: *2 malloc: 09BDA0C8:672
2012/09/12 16:20:14 [debug] 15171#0: *2 malloc: 09BE3210:1024
2012/09/12 16:20:14 [debug] 15171#0: *2 posix_memalign: 09C0AE10:4096 @16
2012/09/12 16:20:14 [debug] 15171#0: *2 http process request line
2012/09/12 16:20:14 [debug] 15171#0: *2 recv: fd:11 183 of 1024
2012/09/12 16:20:14 [debug] 15171#0: *2 http request line: "GET /quux/foo/bar.gif HTTP/1.1"
2012/09/12 16:20:14 [debug] 15171#0: *2 http uri: "/quux/foo/bar.gif"
2012/09/12 16:20:14 [debug] 15171#0: *2 http args: ""
2012/09/12 16:20:14 [debug] 15171#0: *2 http exten: "gif"
2012/09/12 16:20:14 [debug] 15171#0: *2 http process request header line
2012/09/12 16:20:14 [debug] 15171#0: *2 http header: "User-Agent: curl/7.19.7 (i386-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2"
2012/09/12 16:20:14 [debug] 15171#0: *2 http header: "Accept: */*"
2012/09/12 16:20:14 [debug] 15171#0: *2 http header: "Host: t1.example.com"
2012/09/12 16:20:14 [debug] 15171#0: *2 http header done
2012/09/12 16:20:14 [debug] 15171#0: *2 event timer del: 11: 3134910906
2012/09/12 16:20:14 [debug] 15171#0: *2 rewrite phase: 0
2012/09/12 16:20:14 [debug] 15171#0: *2 test location: ~ "^/quux(/.*)?$"
2012/09/12 16:20:14 [debug] 15171#0: *2 using configuration "^/quux(/.*)?$"
2012/09/12 16:20:14 [debug] 15171#0: *2 http cl:-1 max:1048576
2012/09/12 16:20:14 [debug] 15171#0: *2 rewrite phase: 2
2012/09/12 16:20:14 [debug] 15171#0: *2 post rewrite phase: 3
2012/09/12 16:20:14 [debug] 15171#0: *2 generic phase: 4
2012/09/12 16:20:14 [debug] 15171#0: *2 generic phase: 5
2012/09/12 16:20:14 [debug] 15171#0: *2 access phase: 6
2012/09/12 16:20:14 [debug] 15171#0: *2 access phase: 7
2012/09/12 16:20:14 [debug] 15171#0: *2 post access phase: 8
2012/09/12 16:20:14 [debug] 15171#0: *2 try files phase: 9
2012/09/12 16:20:14 [debug] 15171#0: *2 http script copy: "/data/web/t1.example.com/htdoc"
2012/09/12 16:20:14 [debug] 15171#0: *2 http script capture: "/foo/bar.gif"
2012/09/12 16:20:14 [debug] 15171#0: *2 trying to use file: "" "/data/web/t1.example.com/htdoc/foo/bar.gif"
2012/09/12 16:20:14 [debug] 15171#0: *2 try file uri: ""
2012/09/12 16:20:14 [debug] 15171#0: *2 content phase: 10
2012/09/12 16:20:14 [debug] 15171#0: *2 content phase: 11
2012/09/12 16:20:14 [debug] 15171#0: *2 content phase: 12
2012/09/12 16:20:14 [debug] 15171#0: *2 http script copy: "/data/web/t1.example.com/htdoc"
2012/09/12 16:20:14 [debug] 15171#0: *2 http script capture: "/foo/bar.gif"
2012/09/12 16:20:14 [debug] 15171#0: *2 http filename: "/data/web/t1.example.com/htdoc/foo/bar.gif"
2012/09/12 16:20:14 [debug] 15171#0: *2 add cleanup: 09C0B414
2012/09/12 16:20:14 [debug] 15171#0: *2 http static fd: 14
2012/09/12 16:20:14 [debug] 15171#0: *2 http set discard body
2012/09/12 16:20:14 [debug] 15171#0: *2 HTTP/1.1 200 OK
Server: nginx/1.3.6
Date: Wed, 12 Sep 2012 14:20:14 GMT
Content-Type: application/octet-stream
Content-Length: 68
Last-Modified: Thu, 02 Aug 2012 05:04:56 GMT
Connection: keep-alive
ETag: "501a0a78-44"
Accept-Ranges: bytes

2012/09/12 16:20:14 [debug] 15171#0: *2 write new buf t:1 f:0 09C0B53C, pos 09C0B53C, size: 250 file: 0, size: 0
2012/09/12 16:20:14 [debug] 15171#0: *2 http write filter: l:0 f:0 s:250
2012/09/12 16:20:14 [debug] 15171#0: *2 http output filter "?"
2012/09/12 16:20:14 [debug] 15171#0: *2 http copy filter: "?"
2012/09/12 16:20:14 [debug] 15171#0: *2 read: 14, 09C0B6C4, 68, 0
2012/09/12 16:20:14 [debug] 15171#0: *2 http postpone filter "?" 09C0B708
2012/09/12 16:20:14 [debug] 15171#0: *2 write old buf t:1 f:0 09C0B53C, pos 09C0B53C, size: 250 file: 0, size: 0
2012/09/12 16:20:14 [debug] 15171#0: *2 write new buf t:1 f:0 09C0B6C4, pos 09C0B6C4, size: 68 file: 0, size: 0
2012/09/12 16:20:14 [debug] 15171#0: *2 http write filter: l:1 f:0 s:318
2012/09/12 16:20:14 [debug] 15171#0: *2 http write filter limit 0
2012/09/12 16:20:14 [debug] 15171#0: *2 writev: 318
2012/09/12 16:20:14 [debug] 15171#0: *2 http write filter 00000000
2012/09/12 16:20:14 [debug] 15171#0: *2 http copy filter: 0 "?"
2012/09/12 16:20:14 [debug] 15171#0: *2 http finalize request: 0, "?" a:1, c:1
2012/09/12 16:20:14 [debug] 15171#0: *2 set http keepalive handler
2012/09/12 16:20:14 [debug] 15171#0: *2 http close request
2012/09/12 16:20:14 [debug] 15171#0: *2 http log handler
2012/09/12 16:20:14 [debug] 15171#0: *2 run cleanup: 09C0B414
2012/09/12 16:20:14 [debug] 15171#0: *2 file cleanup: fd:14
2012/09/12 16:20:14 [debug] 15171#0: *2 free: 09C0AE10, unused: 1568
2012/09/12 16:20:14 [debug] 15171#0: *2 event timer add: 11: 75000:3134925906
2012/09/12 16:20:14 [debug] 15171#0: *2 free: 09BDA0C8
2012/09/12 16:20:14 [debug] 15171#0: *2 free: 09BE3210
2012/09/12 16:20:14 [debug] 15171#0: *2 hc free: 00000000 0
2012/09/12 16:20:14 [debug] 15171#0: *2 hc busy: 00000000 0
2012/09/12 16:20:14 [debug] 15171#0: *2 tcp_nodelay
2012/09/12 16:20:14 [debug] 15171#0: *2 reusable connection: 1
2012/09/12 16:20:14 [debug] 15171#0: *2 post event 09C2A710
2012/09/12 16:20:14 [debug] 15171#0: posted event 09C2A710
2012/09/12 16:20:14 [debug] 15171#0: *2 delete posted event 09C2A710
2012/09/12 16:20:14 [debug] 15171#0: *2 http keepalive handler
2012/09/12 16:20:14 [debug] 15171#0: *2 malloc: 09BE3210:1024
2012/09/12 16:20:14 [debug] 15171#0: *2 recv: fd:11 -1 of 1024
2012/09/12 16:20:14 [debug] 15171#0: *2 recv() not ready (11: Resource temporarily unavailable)
2012/09/12 16:20:14 [debug] 15171#0: posted event 00000000
2012/09/12 16:20:14 [debug] 15171#0: worker cycle
2012/09/12 16:20:14 [debug] 15171#0: accept mutex locked
2012/09/12 16:20:14 [debug] 15171#0: epoll timer: 75000
2012/09/12 16:20:14 [debug] 15171#0: epoll: fd:11 ev:0001 d:09C117C9
2012/09/12 16:20:14 [debug] 15171#0: *2 post event 09C2A710
2012/09/12 16:20:14 [debug] 15171#0: timer delta: 2
2012/09/12 16:20:14 [debug] 15171#0: posted events 09C2A710
2012/09/12 16:20:14 [debug] 15171#0: posted event 09C2A710
2012/09/12 16:20:14 [debug] 15171#0: *2 delete posted event 09C2A710
2012/09/12 16:20:14 [debug] 15171#0: *2 http keepalive handler
2012/09/12 16:20:14 [debug] 15171#0: *2 recv: fd:11 0 of 1024
2012/09/12 16:20:14 [info] 15171#0: *2 client 127.0.0.1 closed keepalive connection
2012/09/12 16:20:14 [debug] 15171#0: *2 close http connection: 11
2012/09/12 16:20:14 [debug] 15171#0: *2 event timer del: 11: 3134925906
2012/09/12 16:20:14 [debug] 15171#0: *2 reusable connection: 0
2012/09/12 16:20:14 [debug] 15171#0: *2 free: 09BE3210
2012/09/12 16:20:14 [debug] 15171#0: *2 free: 00000000
2012/09/12 16:20:14 [debug] 15171#0: *2 free: 09BD9FC0, unused: 56

Если в $http_accept есть пробелы, то они передаются без кодирования

rewrite ^{/cgi-bin/index.pl?_requri=$uri&_accept=$http_accept break; ... proxy_pass ​http://127.0.0.1:82; # mini-httpd listening}

Instead of using the default SSL certificate, nginx should (by default or when configured) close the SSL connection as soon as it realizes that the requested domain has not been configured to be served over HTTPS.

For example,

server {
    listen 80 default_server;
    listen 443 ssl;

    server_name     aaa.example.net;

    ssl_certificate     /etc/ssl/certs/aaa.example.net.pem;
    ssl_certificate_key /etc/ssl/private/aaa.example.net.key;
}

server {
    listen 80;

    server_name     bbb.example.net;
}

If a client starts an HTTPS request for bbb.example.net, it will be greeted with a (correct) error/warning: "This certificate is untrusted, wrong domain". This is correct because nginx is serving the aaa.example.net certificate.

What nginx should do is to close the connection as soon as it discovers the domain that is being requested (after reading the SNI data, I suppose). This will communicate to the client and the user that there is HTTPS connectivity on bbb.example.net. Also, this solution will not disclose information about the fact that aaa.example.net is served by the same nginx server.

В новых версиях у браузера Opera user-agent выглядит так Opera/9.80 (Windows NT 6.1; U; MRA 5.8 (build 4661); ru) Presto/2.8.131 Version/11.11 Тоесть версию отражает Version/11.11 а не Opera/9.80 В модуле ngx_http_browser_module она определяется так:

{ "opera",

0, sizeof("Opera ") - 1, "Opera"},

Замена на

{ "opera",

sizeof("Opera ") - 1, sizeof("Version/") - 1, "Version/"},

выявляет правильно новые версии но со старыми версиями будет проблема