Nginx Proxy Cache and Tomcat

Server NGINX
1

Hello,

We need a little bit of help to understand what’s wrong with our
config.
We try to setup a reverse proxy cache using Nginx but somthing seems to
be wrong with our configuration.
Behind the Nginx there is a tomcat server.

The problem is that Nginx doesn’t cache at all.
Logs shows that the content isen’t cacheable, but we diden’t understand
why !!

The config is:

nginx -V
nginx version: nginx/0.8.53
built by gcc 4.4.3 20100127 (Red Hat 4.4.3-4) (GCC)
configure arguments: --with-debug

nginx.conf
worker_processes 2;
error_log logs/error.log debug_core debug_http debug_alloc debug_mutex
debug_event ;
worker_rlimit_nofile 8192;
events {
worker_connections 1024;
use epoll;
}

http {
include mime.types;
default_type application/octet-stream;
sendfile on;
client_body_buffer_size 1m;
proxy_buffering on;
proxy_buffer_size 4k;
proxy_buffers 8 32k;
tcp_nopush on;

#keepalive_timeout  0;
keepalive_timeout  65;

#gzip  on;

proxy_cache_path /tmp/cache levels=1:2 keys_zone=tmpcache:15m;

server {
    listen       8080;
    server_name  myservername;

    #charset koi8-r;

    #access_log  logs/host.access.log  main;

    location / {
        proxy_pass        http://localhost:8085;
        proxy_set_header  Host $host;
        proxy_set_header  X-Real-IP  $remote_addr;
        proxy_set_header  X-Forwarded-For

$proxy_add_x_forwarded_for;
}

    location /test/v1/ {
        proxy_pass        http://localhost:8085;
        proxy_set_header  Host $http_host;
        proxy_set_header  X-Real-IP  $remote_addr;
        proxy_set_header  X-Forwarded-For

$proxy_add_x_forwarded_for;
proxy_cache_valid 200 301 302 120m;
expires 864000;
proxy_cache tmpcache;
}
}
}

logs:
2010/11/09 17:08:35 [debug] 3900#0: *1 http request line: “GET
/test/v1/lookup/?method=listConnectedCountries HTTP/1.1”
2010/11/09 17:08:35 [debug] 3900#0: *1 http uri: “/test/v1/lookup/”
2010/11/09 17:08:35 [debug] 3900#0: *1 http args:
“method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 http exten: “”
2010/11/09 17:08:35 [debug] 3900#0: *1 http process request header line
2010/11/09 17:08:35 [debug] 3900#0: *1 http header: “Host:
myhostname:8080”
2010/11/09 17:08:35 [debug] 3900#0: 1 http header: “User-Agent:
Mozilla/5.0 (Windows; U; Windows NT 6.0; fr; rv:1.9.2.12) Gecko/20101026
AskTbUT2V5/3.9.1.14019 Firefox/3.6.12 ( .NET CLR 3.5.30729)”
2010/11/09 17:08:35 [debug] 3900#0: 1 http header: "Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,/;q=0.8"
2010/11/09 17:08:35 [debug] 3900#0: *1 http header: “Accept-Language:
fr,fr-fr;q=0.8,en-us;q=0.5,en;q=0.3”
2010/11/09 17:08:35 [debug] 3900#0: *1 http header: “Accept-Encoding:
gzip,deflate”
2010/11/09 17:08:35 [debug] 3900#0: 1 http header: "Accept-Charset:
ISO-8859-1,utf-8;q=0.7,;q=0.7"
2010/11/09 17:08:35 [debug] 3900#0: *1 http header: “Keep-Alive: 115”
2010/11/09 17:08:35 [debug] 3900#0: *1 http header: “Connection:
keep-alive”
2010/11/09 17:08:35 [debug] 3900#0: *1 http header: “Cookie:
__utma=38270632.803570674.1278490999.1288117398.1288363663.11;
__utmz=38270632.1278490999.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none)”
2010/11/09 17:08:35 [debug] 3900#0: *1 http header: “Pragma: no-cache”
2010/11/09 17:08:35 [debug] 3900#0: *1 http header: “Cache-Control:
no-cache”
2010/11/09 17:08:35 [debug] 3900#0: *1 http header done
2010/11/09 17:08:35 [debug] 3900#0: *1 event timer del: 11: 832387028
2010/11/09 17:08:35 [debug] 3900#0: *1 rewrite phase: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 test location: “/”
2010/11/09 17:08:35 [debug] 3900#0: *1 test location: “test/v1/”
2010/11/09 17:08:35 [debug] 3900#0: *1 using configuration “/test/v1/”
2010/11/09 17:08:35 [debug] 3900#0: *1 http cl:-1 max:1048576
2010/11/09 17:08:35 [debug] 3900#0: *1 rewrite phase: 2
2010/11/09 17:08:35 [debug] 3900#0: *1 post rewrite phase: 3
2010/11/09 17:08:35 [debug] 3900#0: *1 generic phase: 4
2010/11/09 17:08:35 [debug] 3900#0: *1 generic phase: 5
2010/11/09 17:08:35 [debug] 3900#0: *1 access phase: 6
2010/11/09 17:08:35 [debug] 3900#0: *1 access phase: 7
2010/11/09 17:08:35 [debug] 3900#0: *1 post access phase: 8
2010/11/09 17:08:35 [debug] 3900#0: *1 http init upstream, client timer:
0
2010/11/09 17:08:35 [debug] 3900#0: *1 epoll add event: fd:11 op:3
ev:80000005
2010/11/09 17:08:35 [debug] 3900#0: *1 http cache key:
“http://localhost:8085”
2010/11/09 17:08:35 [debug] 3900#0: *1 http cache key:
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 add cleanup: 08CF0DD0
2010/11/09 17:08:35 [debug] 3900#0: slab alloc: 76 slot: 4
2010/11/09 17:08:35 [debug] 3900#0: slab alloc: B5A8C000
2010/11/09 17:08:35 [debug] 3900#0: *1 http file cache exists: -5 e:0
2010/11/09 17:08:35 [debug] 3900#0: *1 cache file:
“/tmp/cache/9/3f/e20791cdfc84e7878b482605b9bdd3f9”
2010/11/09 17:08:35 [debug] 3900#0: *1 add cleanup: 08CF0E10
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream cache: -5
2010/11/09 17:08:35 [debug] 3900#0: *1 http script copy: "Host: "
2010/11/09 17:08:35 [debug] 3900#0: *1 http script var:
“myhostname:8080”
2010/11/09 17:08:35 [debug] 3900#0: *1 http script copy: "
"
2010/11/09 17:08:35 [debug] 3900#0: *1 http script copy: "X-Real-IP: "
2010/11/09 17:08:35 [debug] 3900#0: *1 http script var: “myhostipaddr”
2010/11/09 17:08:35 [debug] 3900#0: *1 http script copy: "
"
2010/11/09 17:08:35 [debug] 3900#0: *1 http script copy:
“X-Forwarded-For: "
2010/11/09 17:08:35 [debug] 3900#0: *1 http script var: “myhostipaddr”
2010/11/09 17:08:35 [debug] 3900#0: *1 http script copy: "
"
2010/11/09 17:08:35 [debug] 3900#0: *1 http script copy: “Connection:
close
"
2010/11/09 17:08:35 [debug] 3900#0: 1 http proxy header: “User-Agent:
Mozilla/5.0 (Windows; U; Windows NT 6.0; fr; rv:1.9.2.12) Gecko/20101026
AskTbUT2V5/3.9.1.14019 Firefox/3.6.12 ( .NET CLR 3.5.30729)”
2010/11/09 17:08:35 [debug] 3900#0: 1 http proxy header: "Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,/;q=0.8”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header:
“Accept-Language: fr,fr-fr;q=0.8,en-us;q=0.5,en;q=0.3”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header:
“Accept-Encoding: gzip,deflate”
2010/11/09 17:08:35 [debug] 3900#0: 1 http proxy header:
"Accept-Charset: ISO-8859-1,utf-8;q=0.7,;q=0.7”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header: “Cookie:
__utma=38270632.803570674.1278490999.1288117398.1288363663.11;
__utmz=38270632.1278490999.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none)”
2010/11/09 17:08:35 [debug] 3900#0: 1 http proxy header: “Pragma:
no-cache”
2010/11/09 17:08:35 [debug] 3900#0: 1 http proxy header:
“Cache-Control: no-cache”
2010/11/09 17:08:35 [debug] 3900#0: 1 http proxy header:
"GET /test/v1/lookup/?method=listConnectedCountries HTTP/1.0
Host: myhostname:8080
X-Real-IP: myhostipaddr
X-Forwarded-For: myhostipaddr
Connection: close
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 6.0; fr; rv:1.9.2.12)
Gecko/20101026 AskTbUT2V5/3.9.1.14019 Firefox/3.6.12 ( .NET CLR
3.5.30729)
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,/;q=0.8
Accept-Language: fr,fr-fr;q=0.8,en-us;q=0.5,en;q=0.3
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,;q=0.7
Cookie: __utma=38270632.803570674.1278490999.1288117398.1288363663.11;
__utmz=38270632.1278490999.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none)
Pragma: no-cache
Cache-Control: no-cache

"
2010/11/09 17:08:35 [debug] 3900#0: *1 http cleanup add: 08CF1164
2010/11/09 17:08:35 [debug] 3900#0: *1 get rr peer, try: 2
2010/11/09 17:08:35 [debug] 3900#0: *1 get rr peer, current: 1 1
2010/11/09 17:08:35 [debug] 3900#0: *1 socket 12
2010/11/09 17:08:35 [debug] 3900#0: *1 epoll add connection: fd:12
ev:80000005
2010/11/09 17:08:35 [debug] 3900#0: *1 connect to 127.0.0.1:8085, fd:12
#2
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream connect: -2
2010/11/09 17:08:35 [debug] 3900#0: *1 event timer add: 12:
60000:832387049
2010/11/09 17:08:35 [debug] 3900#0: *1 http finalize request: -4,
“/test/v1/lookup/?method=listConnectedCountries” a:1, c:2
2010/11/09 17:08:35 [debug] 3900#0: *1 http request count:2 blk:0
2010/11/09 17:08:35 [debug] 3900#0: posted event 00000000
2010/11/09 17:08:35 [debug] 3900#0: worker cycle
2010/11/09 17:08:35 [debug] 3900#0: accept mutex locked
2010/11/09 17:08:35 [debug] 3900#0: epoll timer: 60000
2010/11/09 17:08:35 [debug] 3900#0: epoll: fd:11 ev:0004 d:08D00B78
2010/11/09 17:08:35 [debug] 3900#0: *1 post event 08D23B40
2010/11/09 17:08:35 [debug] 3900#0: epoll: fd:12 ev:0004 d:08D00BD0
2010/11/09 17:08:35 [debug] 3900#0: *1 post event 08D23B74
2010/11/09 17:08:35 [debug] 3900#0: timer delta: 1
2010/11/09 17:08:35 [debug] 3900#0: posted events 08D23B74
2010/11/09 17:08:35 [debug] 3900#0: posted event 08D23B74
2010/11/09 17:08:35 [debug] 3900#0: *1 delete posted event 08D23B74
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream request:
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream send request
handler
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream send request
2010/11/09 17:08:35 [debug] 3900#0: *1 chain writer buf fl:1 s:713
2010/11/09 17:08:35 [debug] 3900#0: *1 chain writer in: 08CF1180
2010/11/09 17:08:35 [debug] 3900#0: *1 writev: 713
2010/11/09 17:08:35 [debug] 3900#0: *1 chain writer out: 00000000
2010/11/09 17:08:35 [debug] 3900#0: *1 event timer del: 12: 832387049
2010/11/09 17:08:35 [debug] 3900#0: *1 event timer add: 12:
60000:832387050
2010/11/09 17:08:35 [debug] 3900#0: posted event 08D23B40
2010/11/09 17:08:35 [debug] 3900#0: *1 delete posted event 08D23B40
2010/11/09 17:08:35 [debug] 3900#0: *1 http run request:
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream check client, write
event:1, “/test/v1/lookup/”
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream recv(): -1 (11:
Resource temporarily unavailable)
2010/11/09 17:08:35 [debug] 3900#0: posted event 00000000
2010/11/09 17:08:35 [debug] 3900#0: worker cycle
2010/11/09 17:08:35 [debug] 3900#0: accept mutex locked
2010/11/09 17:08:35 [debug] 3900#0: epoll timer: 60000
2010/11/09 17:08:35 [debug] 3900#0: epoll: fd:12 ev:0005 d:08D00BD0
2010/11/09 17:08:35 [debug] 3900#0: *1 post event 08D16B6C
2010/11/09 17:08:35 [debug] 3900#0: *1 post event 08D23B74
2010/11/09 17:08:35 [debug] 3900#0: timer delta: 7
2010/11/09 17:08:35 [debug] 3900#0: posted events 08D23B74
2010/11/09 17:08:35 [debug] 3900#0: posted event 08D23B74
2010/11/09 17:08:35 [debug] 3900#0: *1 delete posted event 08D23B74
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream request:
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream dummy handler
2010/11/09 17:08:35 [debug] 3900#0: posted event 08D16B6C
2010/11/09 17:08:35 [debug] 3900#0: *1 delete posted event 08D16B6C
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream request:
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream process header
2010/11/09 17:08:35 [debug] 3900#0: *1 malloc: 08CF1508:4096
2010/11/09 17:08:35 [debug] 3900#0: *1 recv: fd:12 354 of 3998
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy status 200 “200 OK”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header: “Server:
Apache-Coyote/1.1”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header: “Pragma:
no-cache”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header: “Expires: Thu,
01 Jan 1970 00:00:00 GMT”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header:
“Cache-Control: no-cache”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header:
“Cache-Control: no-store”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header: “Date: Tue, 09
Nov 2010 17:08:35 GMT”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header: “Connection:
close”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header done
2010/11/09 17:08:35 [debug] 3900#0: *1 HTTP/1.1 200 OK
Server: nginx/0.8.53
Date: Tue, 09 Nov 2010 17:08:35 GMT
Transfer-Encoding: chunked
Connection: keep-alive
Expires: Fri, 19 Nov 2010 17:08:35 GMT
Cache-Control: max-age=864000

2010/11/09 17:08:35 [debug] 3900#0: *1 write new buf t:1 f:0 08CF13B8,
pos 08CF13B8, size: 201 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 http write filter: l:0 f:0 s:201
2010/11/09 17:08:35 [debug] 3900#0: *1 http cacheable: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 http file cache free, fd: -1
2010/11/09 17:08:35 [debug] 3900#0: slab free: B5A8C000
2010/11/09 17:08:35 [debug] 3900#0: *1 posix_memalign: 08D30AE0:4096
@16
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream process upstream
2010/11/09 17:08:35 [debug] 3900#0: *1 pipe read upstream: 1
2010/11/09 17:08:35 [debug] 3900#0: *1 pipe preread: 144
2010/11/09 17:08:35 [debug] 3900#0: *1 readv: 1:3644
2010/11/09 17:08:35 [debug] 3900#0: *1 pipe recv chain: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 pipe buf free s:0 t:1 f:0
08CF1508, pos 08CF163C, size: 144 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 input buf #0
2010/11/09 17:08:35 [debug] 3900#0: *1 pipe write downstream: 1
2010/11/09 17:08:35 [debug] 3900#0: *1 pipe write downstream flush in
2010/11/09 17:08:35 [debug] 3900#0: *1 http output filter
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 http copy filter:
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 http postpone filter
“/test/v1/lookup/?method=listConnectedCountries” 08CF14C8
2010/11/09 17:08:35 [debug] 3900#0: *1 http chunk: 144
2010/11/09 17:08:35 [debug] 3900#0: *1 write old buf t:1 f:0 08CF13B8,
pos 08CF13B8, size: 201 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 write new buf t:1 f:0 00000000,
pos 08CF14D8, size: 4 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 write new buf t:1 f:0 08CF1508,
pos 08CF163C, size: 144 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 write new buf t:0 f:0 00000000,
pos 080AE7E1, size: 2 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 http write filter: l:0 f:0 s:351
2010/11/09 17:08:35 [debug] 3900#0: *1 http copy filter: 0
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 pipe write downstream done
2010/11/09 17:08:35 [debug] 3900#0: *1 event timer: 12, old: 832387050,
new: 832387057
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream exit: 00000000
2010/11/09 17:08:35 [debug] 3900#0: *1 finalize http upstream request:
0
2010/11/09 17:08:35 [debug] 3900#0: *1 finalize http proxy request
2010/11/09 17:08:35 [debug] 3900#0: *1 free rr peer 2 0
2010/11/09 17:08:35 [debug] 3900#0: *1 close http upstream connection:
12
2010/11/09 17:08:35 [debug] 3900#0: *1 event timer del: 12: 832387050
2010/11/09 17:08:35 [debug] 3900#0: *1 http upstream temp fd: -1
2010/11/09 17:08:35 [debug] 3900#0: *1 http output filter
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 http copy filter:
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 http postpone filter
“/test/v1/lookup/?method=listConnectedCountries” BF969EE8
2010/11/09 17:08:35 [debug] 3900#0: *1 http chunk: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 write old buf t:1 f:0 08CF13B8,
pos 08CF13B8, size: 201 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 write old buf t:1 f:0 00000000,
pos 08CF14D8, size: 4 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 write old buf t:1 f:0 08CF1508,
pos 08CF163C, size: 144 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 write old buf t:0 f:0 00000000,
pos 080AE7E1, size: 2 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 write new buf t:0 f:0 00000000,
pos 080AE7DE, size: 5 file: 0, size: 0
2010/11/09 17:08:35 [debug] 3900#0: *1 http write filter: l:1 f:0 s:356
2010/11/09 17:08:35 [debug] 3900#0: *1 http write filter limit 0
2010/11/09 17:08:35 [debug] 3900#0: *1 writev: 356
2010/11/09 17:08:35 [debug] 3900#0: *1 http write filter 00000000
2010/11/09 17:08:35 [debug] 3900#0: *1 http copy filter: 0
“/test/v1/lookup/?method=listConnectedCountries”
2010/11/09 17:08:35 [debug] 3900#0: *1 http finalize request: 0,
“/test/v1/lookup/?method=listConnectedCountries” a:1, c:1
2010/11/09 17:08:35 [debug] 3900#0: *1 set http keepalive handler
2010/11/09 17:08:35 [debug] 3900#0: *1 http close request

Thank you in advance for your help.

Posted at Nginx Forum:

2

not sure if this would help but worth a try, also give
“Module ngx_http_proxy_module” a read

proxy_cache_key
syntax: proxy_cache_key line;

default: $scheme$proxy_host$request_uri;

context: http, server, location

The directive specifies what information is included in the key for
caching, for example
proxy_cache_key “$host$request_uri$cookie_user”;
Note that by default, the hostname of the server is not included in the
cache key. If you are using subdomains for different locations on your
website, you need to include it, e.g. by changing the cache key to
something like
proxy_cache_key “$scheme$host$request_uri”;

-Payam

3

Hello!

On Tue, Nov 09, 2010 at 12:50:14PM -0500, nams wrote:

why !!
[…]

2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header: “Expires: Thu, 01 Jan
1970 00:00:00 GMT”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header: “Cache-Control:
no-cache”
2010/11/09 17:08:35 [debug] 3900#0: *1 http proxy header: “Cache-Control:
no-store”

See Module ngx_http_proxy_module
if you want to instruct nginx to ignore these headers.

Maxim D.

4

Hello,

Thank you for your help.

Now it works fine.

As suggested by Maxim, i used the proxy_ignore_headers directive to
igonre Expires Cache-Control headers.

Thanks again.

Posted at Nginx Forum: