Problems with HTTP PUT with nginx-mogilefs-module

Hi,

I am having issues executing the http PUT to upload a file to MogileFS
via
nginx-mogilefs-module v1.0.4.

I am running nginx 1.4.1 compiled with --with-debug option on CentOS
6.3.

The nginx-mogilefs-module was forked from
GitHub - gnosek/nginx-mogilefs-module: MogileFS client for nginx where a fix for
-Werror=unused-but-set-variable warnings (with newer gcc)
was fixed. Then I manually merged changes from
GitHub - pyh/nginx-mogilefs-module: MogileFS client for nginx which implements variables
for
“mogilefs_domain” (and makes the directive mandatory).

I guess there is a sleeker way to merge changes like that but I am still
relatively new at using git. Anyway, I compiled nginx with the resulting
module and the compile was ok.

My nginx configuration is as follows:

server {

listen 192.168.0.109:80 http://192.168.0.109/;

error_log logs/node1.storage.dfs.log debug;

location ~ ^/download/(?\w.+)/(?\w.+)/(?.+)$ {

allow 192.168.0.0/24;
deny all;

mogilefs_tracker mogilefs_tracker_nodes;
mogilefs_domain $domain;
mogilefs_class $class;
mogilefs_methods GET;

mogilefs_pass $key {
proxy_pass $mogilefs_path;
proxy_hide_header Content-Type;
proxy_buffering off;
}
}

location ~ ^/upload/(?\w.+)/(?\w.+)/(?.+)$ {
allow 192.168.0.0/24;
deny all;

mogilefs_tracker mogilefs_tracker_nodes;
mogilefs_domain $domain;
mogilefs_class $class;
mogilefs_methods PUT DELETE;

mogilefs_pass $key {
proxy_pass $mogilefs_path;
proxy_hide_header Content-Type;
proxy_buffering off;
}
}

}

On start of the server I have the following in node1.storage.dfs.log:

2013/06/17 17:02:47 [debug] 12417#0: epoll add event: fd:7 op:1
ev:00000001

GET and DELETE work fine but not PUT. When I try to PUT a file via curl,
I
get the following on the console:

[email protected]:~# curl -v --upload-file ./castle.jpg
http://192.168.0.109/upload/defaultdomain/defaultclass/schwarzwald.jpg

  • About to connect() to 192.168.0.109 port 80 (#0)
  • Trying 192.168.0.109… connected
  • Connected to 192.168.0.109 (192.168.0.109) port 80 (#0)

PUT /upload/defaultdomain/defaultclass/schwarzwald.jpg HTTP/1.1
User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/
3.13.1.0 zlib/1.2.3 libidn/1.18 libssh2/1.2.2
Host: 192.168.0.109
Accept: /
Content-Length: 301027
Expect: 100-continue

< HTTP/1.1 100 Continue

and it just hangs there

And these are the debug logs for the PUT request:

2013/06/17 17:06:08 [debug] 12417#0: accept on
192.168.0.109:80http://192.168.0.109/,
ready: 0
2013/06/17 17:06:08 [debug] 12417#0: posix_memalign:
0000000002639F80:256
@16
2013/06/17 17:06:08 [debug] 12417#0: *1 accept: 192.168.0.109 fd:3
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer add: 3:
60000:1371481628599
2013/06/17 17:06:08 [debug] 12417#0: *1 reusable connection: 1
2013/06/17 17:06:08 [debug] 12417#0: *1 epoll add event: fd:3 op:1
ev:80000001
2013/06/17 17:06:08 [debug] 12417#0: *1 http wait request handler
2013/06/17 17:06:08 [debug] 12417#0: *1 posix_memalign:
000000000263A0E0:256 @16
2013/06/17 17:06:08 [debug] 12417#0: *1 malloc: 000000000266B1D0:1024
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 263 of 1024
2013/06/17 17:06:08 [debug] 12417#0: *1 reusable connection: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 posix_memalign:
0000000002646430:4096 @16
2013/06/17 17:06:08 [debug] 12417#0: *1 http process request line
2013/06/17 17:06:08 [debug] 12417#0: *1 http request line: “PUT
/upload/defaultdomain/defaultclass/schwarzwald.jpg HTTP/1.1”
2013/06/17 17:06:08 [debug] 12417#0: *1 http uri:
“/upload/defaultdomain/defaultclass/schwarzwald.jpg”
2013/06/17 17:06:08 [debug] 12417#0: *1 http args: “”
2013/06/17 17:06:08 [debug] 12417#0: *1 http exten: “jpg”
2013/06/17 17:06:08 [debug] 12417#0: *1 http process request header line
2013/06/17 17:06:08 [debug] 12417#0: *1 http header: “User-Agent:
curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.13.1.0
zlib/1.2.3
libidn/1.18 libssh2/1.2.2”
2013/06/17 17:06:08 [debug] 12417#0: *1 http header: “Host:
192.168.0.109”
2013/06/17 17:06:08 [debug] 12417#0: *1 http header: “Accept: /
2013/06/17 17:06:08 [debug] 12417#0: *1 http header: “Content-Length:
301027”
2013/06/17 17:06:08 [debug] 12417#0: *1 http header: “Expect:
100-continue”
2013/06/17 17:06:08 [debug] 12417#0: *1 http header done
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer del: 3:
1371481628599
2013/06/17 17:06:08 [debug] 12417#0: *1 rewrite phase: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 test location: “/”
2013/06/17 17:06:08 [debug] 12417#0: *1 test location:
“mogstored_spare_40237552/”
2013/06/17 17:06:08 [debug] 12417#0: *1 test location:
“mogstored_spare_40262152/”
2013/06/17 17:06:08 [debug] 12417#0: *1 test location: “robots.txt”
2013/06/17 17:06:08 [debug] 12417#0: *1 test location: ~
“^/download/(?\w.+)/(?\w.+)/(?.+)$”
2013/06/17 17:06:08 [debug] 12417#0: *1 test location: ~
“^/upload/(?\w.+)/(?\w.+)/(?.+)$”
2013/06/17 17:06:08 [debug] 12417#0: *1 http regex set $class to
“defaultclass”
2013/06/17 17:06:08 [debug] 12417#0: *1 http regex set $domain to
“defaultdomain”
2013/06/17 17:06:08 [debug] 12417#0: *1 http regex set $key to
“schwarzwald.jpg”
2013/06/17 17:06:08 [debug] 12417#0: *1 using configuration
“^/upload/(?\w.+)/(?\w.+)/(?.+)$”
2013/06/17 17:06:08 [debug] 12417#0: *1 http cl:301027 max:10485760
2013/06/17 17:06:08 [debug] 12417#0: *1 rewrite phase: 2
2013/06/17 17:06:08 [debug] 12417#0: *1 post rewrite phase: 3
2013/06/17 17:06:08 [debug] 12417#0: *1 generic phase: 4
2013/06/17 17:06:08 [debug] 12417#0: *1 generic phase: 5
2013/06/17 17:06:08 [debug] 12417#0: *1 access phase: 6
2013/06/17 17:06:08 [debug] 12417#0: *1 access: 6D00A8C0 00FFFFFF
0000A8C0
2013/06/17 17:06:08 [debug] 12417#0: *1 access phase: 7
2013/06/17 17:06:08 [debug] 12417#0: *1 post access phase: 8
2013/06/17 17:06:08 [debug] 12417#0: *1 http finalize request: -5,
“/upload/defaultdomain/defaultclass/schwarzwald.jpg?” a:1, c:1
2013/06/17 17:06:08 [debug] 12417#0: *1 content phase: 9
2013/06/17 17:06:08 [debug] 12417#0: *1 mogilefs put handler
2013/06/17 17:06:08 [debug] 12417#0: *1 posix_memalign:
000000000263E530:4096 @16
2013/06/17 17:06:08 [debug] 12417#0: *1 http script var:
“schwarzwald.jpg”
2013/06/17 17:06:08 [debug] 12417#0: *1 send 100 Continue
2013/06/17 17:06:08 [debug] 12417#0: *1 send: fd:3 25 of 25
2013/06/17 17:06:08 [debug] 12417#0: *1 http request body content length
filter
2013/06/17 17:06:08 [debug] 12417#0: *1 malloc: 000000000263F540:8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http read client request body
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 -1 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 recv() not ready (11: Resource
temporarily unavailable)
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv -2
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body rest
301027
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer add: 3:
60000:1371481628603
2013/06/17 17:06:08 [debug] 12417#0: *1 http finalize request: -4,
“/upload/defaultdomain/defaultclass/schwarzwald.jpg?” a:1, c:2
2013/06/17 17:06:08 [debug] 12417#0: *1 http request count:2 blk:0
2013/06/17 17:06:08 [debug] 12417#0: *1 http run request:
“/upload/defaultdomain/defaultclass/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http read client request body
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E698
2013/06/17 17:06:08 [debug] 12417#0: *1 add cleanup: 000000000263E7D0
2013/06/17 17:06:08 [debug] 12417#0: *1 hashed path:
/usr/local/nginx/client_body_temp/0000000001
2013/06/17 17:06:08 [debug] 12417#0: *1 temp fd:10
2013/06/17 17:06:08 [warn] 12417#0: *1 a client request body is buffered
to
a temporary file /usr/local/nginx/client_body_temp/0000000001, client:
192.168.0.109, server: , request: “PUT
/upload/defaultdomain/defaultclass/schwarzwald.jpg HTTP/1.1”, host:
“192.168.0.109”
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192, 0
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E800
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E810
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
16384
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E820
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
24576
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E830
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
32768
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E840
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
40960
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E850
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
49152
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E860
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
57344
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E870
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
65536
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E880
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
73728
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E890
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
81920
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E8A0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
90112
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E8B0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
98304
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E8C0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
106496
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E8D0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
114688
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E8E0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
122880
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E8F0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
131072
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E900
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
139264
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 -1 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 recv() not ready (11: Resource
temporarily unavailable)
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv -2
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body rest
153571
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer: 3, old:
1371481628603,
new: 1371481628627
2013/06/17 17:06:08 [debug] 12417#0: *1 http run request:
“/upload/defaultdomain/defaultclass/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http read client request body
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E910
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
147456
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E920
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
155648
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E930
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
163840
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E940
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
172032
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E950
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
180224
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E960
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
188416
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E970
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
196608
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E980
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
204800
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E990
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
212992
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E9A0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
221184
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 -1 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 recv() not ready (11: Resource
temporarily unavailable)
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv -2
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body rest
71651
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer: 3, old:
1371481628603,
new: 1371481628646
2013/06/17 17:06:08 [debug] 12417#0: *1 http run request:
“/upload/defaultdomain/defaultclass/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http read client request body
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E9B0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
229376
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E9C0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
237568
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E9D0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
245760
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E9E0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
253952
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263E9F0
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
262144
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263EA00
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
270336
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263EA10
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
278528
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 8192 of 8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
8192
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 8192 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263EA20
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
8192,
286720
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:3 6115 of 6115
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body recv
6115
2013/06/17 17:06:08 [debug] 12417#0: *1 http body new buf t:1 f:0
000000000263F540, pos 000000000263F540, size: 6115 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http client request body rest 0
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer del: 3:
1371481628603
2013/06/17 17:06:08 [debug] 12417#0: *1 http write client request body,
bufs 000000000263EA30
2013/06/17 17:06:08 [debug] 12417#0: *1 write: 10, 000000000263F540,
6115,
294912
2013/06/17 17:06:08 [debug] 12417#0: *1 mogilefs body handler
2013/06/17 17:06:08 [debug] 12417#0: *1 mogilefs put handler
2013/06/17 17:06:08 [debug] 12417#0: *1 mogilefs put handler state: 0,
status: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http subrequest
“/mogstored_spare_40251304/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http posted request:
“/mogstored_spare_40251304/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 rewrite phase: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 test location: “/”
2013/06/17 17:06:08 [debug] 12417#0: *1 test location:
“mogstored_spare_40237552/”
2013/06/17 17:06:08 [debug] 12417#0: *1 test location:
“mogstored_spare_40262152/”
2013/06/17 17:06:08 [debug] 12417#0: *1 test location:
“mogstored_spare_40256728/”
2013/06/17 17:06:08 [debug] 12417#0: *1 test location:
“mogstored_spare_40251304/”
2013/06/17 17:06:08 [debug] 12417#0: *1 using configuration
“/mogstored_spare_40251304/”
2013/06/17 17:06:08 [debug] 12417#0: *1 http cl:301027 max:10485760
2013/06/17 17:06:08 [debug] 12417#0: *1 rewrite phase: 2
2013/06/17 17:06:08 [debug] 12417#0: *1 post rewrite phase: 3
2013/06/17 17:06:08 [debug] 12417#0: *1 generic phase: 4
2013/06/17 17:06:08 [debug] 12417#0: *1 generic phase: 5
2013/06/17 17:06:08 [debug] 12417#0: *1 posix_memalign:
0000000002641550:4096 @16
2013/06/17 17:06:08 [debug] 12417#0: *1 http init upstream, client
timer: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 epoll add event: fd:3 op:3
ev:80000005
2013/06/17 17:06:08 [debug] 12417#0: *1 http script var: “defaultdomain”
2013/06/17 17:06:08 [debug] 12417#0: *1 http script var: “defaultclass”
2013/06/17 17:06:08 [debug] 12417#0: *1 mogilefs request: “create_open
key=schwarzwald.jpg&domain=defaultdomain&class=defaultclass”
2013/06/17 17:06:08 [debug] 12417#0: *1 http cleanup add:
0000000002641B40
2013/06/17 17:06:08 [debug] 12417#0: *1 get rr peer, try: 1
2013/06/17 17:06:08 [debug] 12417#0: *1 socket 11
2013/06/17 17:06:08 [debug] 12417#0: *1 epoll add connection: fd:11
ev:80000005
2013/06/17 17:06:08 [debug] 12417#0: *1 connect to 192.168.0.109:6001,
fd:11 #2
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream connect: -2
2013/06/17 17:06:08 [debug] 12417#0: *1 posix_memalign:
000000000263A1F0:128 @16
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer add: 11:
60000:1371481628674
2013/06/17 17:06:08 [debug] 12417#0: *1 http finalize request: -4,
“/mogstored_spare_40251304/schwarzwald.jpg?” a:1, c:3
2013/06/17 17:06:08 [debug] 12417#0: *1 http request count:3 blk:0
2013/06/17 17:06:08 [debug] 12417#0: *1 http run request:
“/mogstored_spare_40251304/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream check client,
write
event:1, “/mogstored_spare_40251304/schwarzwald.jpg”
2013/06/17 17:06:08 [debug] 12417#0: *1 epoll add connection: fd:11
ev:80000005
2013/06/17 17:06:08 [debug] 12417#0: *1 connect to 192.168.0.109:6001,
fd:11 #2
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream connect: -2
2013/06/17 17:06:08 [debug] 12417#0: *1 posix_memalign:
000000000263A1F0:128 @16
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer add: 11:
60000:1371481628674
2013/06/17 17:06:08 [debug] 12417#0: *1 http finalize request: -4,
“/mogstored_spare_40251304/schwarzwald.jpg?” a:1, c:3
2013/06/17 17:06:08 [debug] 12417#0: *1 http request count:3 blk:0
2013/06/17 17:06:08 [debug] 12417#0: *1 http run request:
“/mogstored_spare_40251304/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream check client,
write
event:1, “/mogstored_spare_40251304/schwarzwald.jpg”
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream recv(): -1 (11:
Resource temporarily unavailable)
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream request:
“/mogstored_spare_40251304/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream send request
handler
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream send request
2013/06/17 17:06:08 [debug] 12417#0: *1 chain writer buf fl:0 s:73
2013/06/17 17:06:08 [debug] 12417#0: *1 chain writer in:
0000000002641B78
2013/06/17 17:06:08 [debug] 12417#0: *1 writev: 73
2013/06/17 17:06:08 [debug] 12417#0: *1 chain writer out:
0000000000000000
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer del: 11:
1371481628674
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer add: 11:
60000:1371481628676
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream request:
“/mogstored_spare_40251304/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream process header
2013/06/17 17:06:08 [debug] 12417#0: *1 malloc: 00000000026A59F0:4096
2013/06/17 17:06:08 [debug] 12417#0: *1 recv: fd:11 80 of 4096
“013/06/17 17:06:08 [debug] 12417#0: *1 mogilefs: “OK
devid=2&fid=50&path=
http://192.168.0.108:7500/dev2/0/000/000/0000000050.fid
2013/06/17 17:06:08 [debug] 12417#0: *1 mogilefs param: “devid”=“2”
2013/06/17 17:06:08 [debug] 12417#0: *1 mogilefs param: “fid”=“50”
2013/06/17 17:06:08 [debug] 12417#0: *1 mogilefs param: “path”=”
http://192.168.0.108:7500/dev2/0/000/000/0000000050.fid
2013/06/17 17:06:08 [debug] 12417#0: *1 tcp_nodelay
2013/06/17 17:06:08 [debug] 12417#0: *1 http upstream process non
buffered
downstream
2013/06/17 17:06:08 [debug] 12417#0: *1 finalize http upstream request:
0
2013/06/17 17:06:08 [debug] 12417#0: *1 finalize mogilefs request
2013/06/17 17:06:08 [debug] 12417#0: *1 free rr peer 1 0
2013/06/17 17:06:08 [debug] 12417#0: *1 close http upstream connection:
11
2013/06/17 17:06:08 [debug] 12417#0: *1 free: 000000000263A1F0, unused:
48
2013/06/17 17:06:08 [debug] 12417#0: *1 event timer del: 11:
1371481628676
2013/06/17 17:06:08 [debug] 12417#0: *1 reusable connection: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http output filter
“/mogstored_spare_40251304/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http copy filter:
“/mogstored_spare_40251304/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http postpone filter
“/mogstored_spare_40251304/schwarzwald.jpg?” 00007FFFC19595A0
2013/06/17 17:06:08 [debug] 12417#0: *1 write new buf t:0 f:0
0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2013/06/17 17:06:08 [debug] 12417#0: *1 http write filter: l:0 f:0 s:0
2013/06/17 17:06:08 [debug] 12417#0: *1 http copy filter: 0
“/mogstored_spare_40251304/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http finalize request: 0,
“/mogstored_spare_40251304/schwarzwald.jpg?” a:1, c:2
2013/06/17 17:06:08 [debug] 12417#0: *1 mogilefs finish phase handler:
state=1, status=0
2013/06/17 17:06:08 [debug] 12417#0: *1 http wake parent request:
“/upload/defaultdomain/defaultclass/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http posted request:
“/upload/defaultdomain/defaultclass/schwarzwald.jpg?”
2013/06/17 17:06:08 [debug] 12417#0: *1 http request empty handler
2013/06/17 17:06:28 [debug] 12417#0: *1 http run request:
“/upload/defaultdomain/defaultclass/schwarzwald.jpg?”
2013/06/17 17:06:28 [debug] 12417#0: *1 http reading blocked
2013/06/17 17:06:28 [debug] 12417#0: *1 http run request:
“/upload/defaultdomain/defaultclass/schwarzwald.jpg?”
2013/06/17 17:06:28 [debug] 12417#0: *1 http request empty handler