srcache + mogilefs module

haad nginx-forum at nginx.us
Fri Apr 20 20:16:46 UTC 2012


Hi,

I'm currently in a process of setting mogilefs + memcached + nginx
environment. My idea is to have nginx as a frontend server which will be
used to access files stored on a mogile filesystem. This is working
perfectly. To add some caching I would like to add support for memcached
to nginx itself. That way it will be able to cache some images for
itself and do not ask mogilefs for them.

My problem is that it seems that even if I put files to memcache
manually and it srcache will find it (see log below), my file is still
served from mogilefs and not from memcached.

    upstream mogilefs_trackers {
        server 192.168.206.3:6001;
        #server 192.168.206.2:6001;
    }

    upstream memcached_servers {
	server 192.168.206.3:11211;
    }

    server {
        listen       80;
        server_name  ws01x.test.reality.sk;

	root /var/www/html;

	#
	# Check if we can find anything on a memcache server if not fetch it
from a mogilefs.
	#
	location = /memc {
 	   internal;
	   memc_connect_timeout 100ms;
	   memc_send_timeout 100ms;
	   memc_read_timeout 100ms;

	   set $memc_key $query_string;
	   set $memc_exptime 300;

	   memc_pass memcached_servers;
	}

	location /share/ {
	    set $key $uri;

	    srcache_fetch GET /memc $key;
	    srcache_store PUT /memc $key;
    	    srcache_store_statuses 200 301 302;
	    srcache_response_cache_control off;

            mogilefs_tracker mogilefs_trackers;
            mogilefs_domain test;
            #mogilefs_class testclass;
	    mogilefs_methods GET;
            mogilefs_noverify on;

            mogilefs_pass {
                proxy_pass $mogilefs_path;
                proxy_hide_header Content-Type;
                proxy_buffering off;
            }
            
	    if ($request_uri ~* \.(ico|css|js)$) {
                expires 72h;
                break;
            }
	}
}



------ LOG

2012/04/20 21:28:21 [debug] 7385#0: *501 http request line: "GET
/share/file.html HTTP/1.0"
2012/04/20 21:28:21 [debug] 7385#0: *501 http uri: "/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http args: ""
2012/04/20 21:28:21 [debug] 7385#0: *501 http exten: "html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http process request header
line
2012/04/20 21:28:21 [debug] 7385#0: *501 http header: "User-Agent:
Wget/1.11.4 Red Hat modified"
2012/04/20 21:28:21 [debug] 7385#0: *501 http header: "Accept: */*"
2012/04/20 21:28:21 [debug] 7385#0: *501 http header: "Host:
192.168.200.64"
2012/04/20 21:28:21 [debug] 7385#0: *501 http header: "Connection:
Keep-Alive"
2012/04/20 21:28:21 [debug] 7385#0: *501 http header done
2012/04/20 21:28:21 [debug] 7385#0: *501 event timer del: 3:
1334950161661
2012/04/20 21:28:21 [debug] 7385#0: *501 rewrite phase: 0
2012/04/20 21:28:21 [debug] 7385#0: *501 test location: "/memc"
2012/04/20 21:28:21 [debug] 7385#0: *501 test location: "/prehliadac"
2012/04/20 21:28:21 [debug] 7385#0: *501 test location: "/share/"
2012/04/20 21:28:21 [debug] 7385#0: *501 using configuration "/share/"
2012/04/20 21:28:21 [debug] 7385#0: *501 http cl:-1 max:1048576
2012/04/20 21:28:21 [debug] 7385#0: *501 rewrite phase: 2
2012/04/20 21:28:21 [debug] 7385#0: *501 http script complex value
2012/04/20 21:28:21 [debug] 7385#0: *501 http script var:
"/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http script set $key
2012/04/20 21:28:21 [debug] 7385#0: *501 http script var
2012/04/20 21:28:21 [debug] 7385#0: *501 http script var:
"/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http script regex:
"\.(ico|css|js)$"
2012/04/20 21:28:21 [notice] 7385#0: *501 "\.(ico|css|js)$" does not
match "/share/file.html", client: 192.168.200.64, server:
ws01x.test.reality.sk, request: "GET /share/file.html HTTP/1.0", host:
"192.168.200.64"
2012/04/20 21:28:21 [debug] 7385#0: *501 http script if
2012/04/20 21:28:21 [debug] 7385#0: *501 http script if: false
2012/04/20 21:28:21 [debug] 7385#0: *501 post rewrite phase: 3
2012/04/20 21:28:21 [debug] 7385#0: *501 generic phase: 4
2012/04/20 21:28:21 [debug] 7385#0: *501 generic phase: 5
2012/04/20 21:28:21 [debug] 7385#0: *501 access phase: 6
2012/04/20 21:28:21 [debug] 7385#0: *501 access phase: 7
2012/04/20 21:28:21 [debug] 7385#0: *501 access phase: 8
2012/04/20 21:28:21 [debug] 7385#0: *501 access phase: 9
2012/04/20 21:28:21 [debug] 7385#0: *501 http script var:
"/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 posix_memalign:
0000000000EA31C0:4096 @16
2012/04/20 21:28:21 [debug] 7385#0: *501 http subrequest
"/memc?/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http posted request:
"/memc?/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 rewrite phase: 0
2012/04/20 21:28:21 [debug] 7385#0: *501 test location: "/memc"
2012/04/20 21:28:21 [debug] 7385#0: *501 using configuration "=/memc"
2012/04/20 21:28:21 [debug] 7385#0: *501 http cl:-1 max:1048576
2012/04/20 21:28:21 [debug] 7385#0: *501 rewrite phase: 2
2012/04/20 21:28:21 [debug] 7385#0: *501 http script complex value
2012/04/20 21:28:21 [debug] 7385#0: *501 http script var:
"/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http script set $memc_key
2012/04/20 21:28:21 [debug] 7385#0: *501 http script value: "300"
2012/04/20 21:28:21 [debug] 7385#0: *501 http script set $memc_exptime
2012/04/20 21:28:21 [debug] 7385#0: *501 post rewrite phase: 3
2012/04/20 21:28:21 [debug] 7385#0: *501 generic phase: 4
2012/04/20 21:28:21 [debug] 7385#0: *501 generic phase: 5
2012/04/20 21:28:21 [debug] 7385#0: *501 http init upstream, client
timer: 0
2012/04/20 21:28:21 [debug] 7385#0: *501 epoll add event: fd:3 op:3
ev:80000005
2012/04/20 21:28:21 [debug] 7385#0: *501 http memcached request:
"/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http cleanup add:
0000000000EA4110
2012/04/20 21:28:21 [debug] 7385#0: *501 get rr peer, try: 1
2012/04/20 21:28:21 [debug] 7385#0: *501 socket 4
2012/04/20 21:28:21 [debug] 7385#0: *501 epoll add connection: fd:4
ev:80000005
2012/04/20 21:28:21 [debug] 7385#0: *501 connect to 192.168.206.3:11211,
fd:4 #502
2012/04/20 21:28:21 [debug] 7385#0: *501 http upstream connect: -2
2012/04/20 21:28:21 [debug] 7385#0: *501 event timer add: 4:
100:1334950101761
2012/04/20 21:28:21 [debug] 7385#0: *501 http finalize request: -4,
"/memc?/share/file.html" a:1, c:3
2012/04/20 21:28:21 [debug] 7385#0: *501 http request count:3 blk:0
2012/04/20 21:28:21 [debug] 7385#0: *501 http run request:
"/memc?/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http upstream check client,
write event:1, "/memc"
2012/04/20 21:28:21 [debug] 7385#0: *501 http upstream recv(): -1 (11:
Resource temporarily unavailable)
2012/04/20 21:28:21 [debug] 7385#0: *501 http upstream request:
"/memc?/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http upstream send request
handler
2012/04/20 21:28:21 [debug] 7385#0: *501 http upstream send request
2012/04/20 21:28:21 [debug] 7385#0: *501 chain writer buf fl:0 s:22
2012/04/20 21:28:21 [debug] 7385#0: *501 chain writer in:
0000000000EA4148
2012/04/20 21:28:21 [debug] 7385#0: *501 writev: 22
2012/04/20 21:28:21 [debug] 7385#0: *501 chain writer out:
0000000000000000
2012/04/20 21:28:21 [debug] 7385#0: *501 event timer del: 4:
1334950101761
2012/04/20 21:28:21 [debug] 7385#0: *501 event timer add: 4:
100:1334950101763
2012/04/20 21:28:21 [debug] 7385#0: *501 http upstream request:
"/memc?/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http upstream process header
2012/04/20 21:28:21 [debug] 7385#0: *501 malloc: 0000000000E989F0:4096
2012/04/20 21:28:21 [debug] 7385#0: *501 posix_memalign:
0000000000E99A00:4096 @16
2012/04/20 21:28:21 [debug] 7385#0: *501 recv: fd:4 46 of 4096
2012/04/20 21:28:21 [debug] 7385#0: *501 memcached: "VALUE
/share/file.html 0 10" <---- WE got it 
2012/04/20 21:28:21 [debug] 7385#0: *501 srcache_fetch: subrequest
returned status 200
2012/04/20 21:28:21 [debug] 7385#0: *501 srcache_fetch decides to send
the response in cache
2012/04/20 21:28:21 [debug] 7385#0: *501 tcp_nodelay
2012/04/20 21:28:21 [debug] 7385#0: *501 memcached filter bytes:17
size:17 length:17 rest:7
2012/04/20 21:28:21 [debug] 7385#0: *501 http upstream process non
buffered downstream
2012/04/20 21:28:21 [debug] 7385#0: *501 http output filter
"/memc?/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http copy filter:
"/memc?/share/file.html"
2012/04/20 21:28:21 [error] 7385#0: *501 srcache_fetch: cache sent
invalid status line while sending to client, client: 192.168.200.64,
server: ws01x.test.reality.sk, request: "GET /share/file.html HTTP/1.0",
subrequest: "/memc", upstream: "memcached://192.168.206.3:11211", host:
"192.168.200.64"
2012/04/20 21:28:21 [debug] 7385#0: *501 http copy filter: 0
"/memc?/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 finalize http upstream request:
0
2012/04/20 21:28:21 [debug] 7385#0: *501 finalize http memcached
request
2012/04/20 21:28:21 [debug] 7385#0: *501 free rr peer 1 0
2012/04/20 21:28:21 [debug] 7385#0: *501 close http upstream connection:
4
2012/04/20 21:28:21 [debug] 7385#0: *501 event timer del: 4:
1334950101763
2012/04/20 21:28:21 [debug] 7385#0: *501 reusable connection: 0
2012/04/20 21:28:21 [debug] 7385#0: *501 http output filter
"/memc?/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http copy filter:
"/memc?/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http copy filter: 0
"/memc?/share/file.html"
2012/04/20 21:28:21 [debug] 7385#0: *501 http finalize request: 0,
"/memc?/share/file.html" a:1, c:2
2012/04/20 21:28:21 [debug] 7385#0: *501 http wake parent request:
"/share/file.html?"
2012/04/20 21:28:21 [debug] 7385#0: *501 http posted request:
"/share/file.html?"
2012/04/20 21:28:21 [debug] 7385#0: *501 access phase: 9
2012/04/20 21:28:21 [debug] 7385#0: *501 post access phase: 10
2012/04/20 21:28:21 [debug] 7385#0: *501 http set discard body
2012/04/20 21:28:21 [debug] 7385#0: *501 http init upstream, client
timer: 0
2012/04/20 21:28:21 [debug] 7385#0: *501 mogilefs request: "get_paths
key=file.html&domain=test&noverify=1"

>From this log I can see why is file can't serverd from memcached, server
status 200. Are srcache and mogilefs module somehow incompatible ?

Posted at Nginx Forum: http://forum.nginx.org/read.php?2,225568,225568#msg-225568



More information about the nginx mailing list