Proxy_store takes long time fetching from the upstream


#1

Hi list,
this is my config


user nginx nginx;
worker_processes 8;

error_log /var/log/nginx/error_log info;

events {
worker_connections 8192;
use epoll;
}

http {
include /etc/nginx/mime.types;
default_type application/octet-stream;

log_format main
'$remote_addr - $remote_user [$time_local] ’
'"$request" $status $bytes_sent ’
'"$http_referer" “$http_user_agent” ’
‘"$gzip_ratio"’;

  client_max_body_size    10m;
   client_body_buffer_size 256k;
   proxy_connect_timeout  90;
   proxy_send_timeout      90;
   proxy_read_timeout      90;
   proxy_buffer_size      4k;
   proxy_buffers          10 32k;
   proxy_busy_buffers_size 64k;
   proxy_temp_file_write_size 64k;

upstream backend{
server 192.168.172.254:3128;
}

server {
listen 127.0.0.1:8888;
server_name localhost;

  access_log  /var/log/nginx/localhost.access_log main;
  error_log   /var/log/nginx/localhost.error_log debug;
  proxy_temp_path   /cache/temp;
  root  /cache/$host;

  location / {
     index index.shtml;
     error_page 404 = /fetch$uri;
  }
  location /fetch{
     internal;
     proxy_pass http://backend;
     proxy_store on;
     proxy_store_access user:rw group:rw all:rw;
     proxy_set_header Host $host;
     proxy_set_header X-Real_IP $remote_addr;
     proxy_set_header Via "pahud/nginx";
     #proxy_buffering off;
     alias /cache/$host;
  }

}

}


so nginx is listening on localhost:8888 and when trying to fetch a
missing
jpg it goes to upstream proxy to fetch it. So I made a try here:

pahud@gentoo-9 ~ $[15:24:07] time curl -L -v
http://farm4.static.flickr.com/3081/3144192428_7dcf9da972.jpg -x
127.0.0.1:8888 -o /dev/null

  • About to connect() to proxy 127.0.0.1 port 8888 (#0)
  • Trying 127.0.0.1… connected
  • Connected to 127.0.0.1 (127.0.0.1) port 8888 (#0)

GET http://farm4.static.flickr.com/3081/3144192428_7dcf9da972.jpg HTTP/1.1
User-Agent: curl/7.18.2 (i686-pc-linux-gnu) libcurl/7.18.2 OpenSSL/0.9.8g
zlib/1.2.3
Host: farm4.static.flickr.com
Pragma: no-cache
Accept: /
Proxy-Connection: Keep-Alive

< HTTP/1.1 200 OK
< Server: nginx/0.7.30
< Date: Mon, 29 Dec 2008 07:24:10 GMT
< Content-Type: image/jpeg
< Connection: keep-alive
< Last-Modified: Sun, 28 Dec 2008 13:32:53 GMT
< Accept-Ranges: bytes
< Content-Length: 165659
< Expires: Mon, 28 Jul 2014 23:30:00 GMT
< Cache-Control: max-age=315360000
< X-Cache: HIT from photocache416.flickr.gq1.yahoo.com
< X-Cache-Lookup: HIT from photocache416.flickr.gq1.yahoo.com:80
< X-Cache: MISS from gateway.office
< Via: 1.1 photocache416.flickr.gq1.yahoo.com:80 (squid/2.7.STABLE2),
1.0
gateway.office:3128 (squid/2.6.STABLE12)
<
{ [data not shown]
% Total % Received % Xferd Average Speed Time Time Time
Current
Dload Upload Total Spent Left
Speed
100 161k 100 161k 0 0 2695 0 0:01:01 0:01:01 --:–:--
3893* Connection #0 to host 127.0.0.1 left intact

  • Closing connection #0

real 1m1.462s
user 0m0.000s
sys 0m0.004s

Well, it took 1m 1.462s to complete. But if I directly fetch from my
upstream server:

pahud@gentoo-9 ~ $[15:26:26] time curl -L -v
http://farm4.static.flickr.com/3081/3144192428_7dcf9da972.jpg -x
192.168.172.254:3128 -o /dev/null

  • About to connect() to proxy 192.168.172.254 port 3128 (#0)
  • Trying 192.168.172.254… connected
  • Connected to 192.168.172.254 (192.168.172.254) port 3128 (#0)

GET http://farm4.static.flickr.com/3081/3144192428_7dcf9da972.jpg HTTP/1.1
User-Agent: curl/7.18.2 (i686-pc-linux-gnu) libcurl/7.18.2 OpenSSL/0.9.8g
zlib/1.2.3
Host: farm4.static.flickr.com
Pragma: no-cache
Accept: /
Proxy-Connection: Keep-Alive

  • HTTP 1.0, assume close after body
    < HTTP/1.0 200 OK
    < Last-Modified: Sun, 28 Dec 2008 13:32:53 GMT
    < Accept-Ranges: bytes
    < Content-Length: 165659
    < Content-Type: image/jpeg
    < Date: Mon, 29 Dec 2008 07:26:42 GMT
    < Server: Apache/2.0.52 (Red Hat)
    < Expires: Mon, 28 Jul 2014 23:30:00 GMT
    < Cache-Control: max-age=315360000
    < X-Cache: HIT from photocache416.flickr.gq1.yahoo.com
    < X-Cache-Lookup: HIT from photocache416.flickr.gq1.yahoo.com:80
    < X-Cache: MISS from gateway.office
    < Via: 1.1 photocache416.flickr.gq1.yahoo.com:80 (squid/2.7.STABLE2),
    1.0
    gateway.office:3128 (squid/2.6.STABLE12)

  • HTTP/1.0 proxy connection set to keep alive!
    < Proxy-Connection: keep-alive
    <
    { [data not shown]
    % Total % Received % Xferd Average Speed Time Time Time
    Current
    Dload Upload Total Spent Left
    Speed
    100 161k 100 161k 0 0 25465 0 0:00:06 0:00:06 --:–:--
    34140* Connection #0 to host 192.168.172.254 left intact

  • Closing connection #0

real 0m6.514s
user 0m0.000s
sys 0m0.000s

Only 6 seconds!!

Can someone tell me how can I find the bottleneck?

pahud