Nginx Proxy Cache and Tomcat

nams nginx-forum at nginx.us
Tue Nov 9 20:50:14 MSK 2010


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: http://forum.nginx.org/read.php?2,149206,149206#msg-149206




More information about the nginx mailing list