upload module parameters issue

Andrew Hammond andrew.george.hammond at gmail.com
Mon Oct 3 19:04:22 UTC 2011


Hello all,

I am trying to implement resumable uploads using the nginx upload module to
a django script. I am running a deb-src build of the nginx 1.0.6 PPA with
the following config, which includes version 2.2.0 of the upload module
(renamed to nginx-upload-resume for consistency).

ahammond at ws-trans02:~$ nginx -V
nginx: nginx version: nginx/1.0.6
nginx: TLS SNI support enabled
nginx: configure arguments:
  --prefix=/etc/nginx
  --conf-path=/etc/nginx/nginx.conf
  --error-log-path=/var/log/nginx/error.log
  --http-client-body-temp-path=/var/lib/nginx/body
  --http-fastcgi-temp-path=/var/lib/nginx/fastcgi
  --http-log-path=/var/log/nginx/access.log
  --http-proxy-temp-path=/var/lib/nginx/proxy
  --http-scgi-temp-path=/var/lib/nginx/scgi
  --http-uwsgi-temp-path=/var/lib/nginx/uwsgi
  --lock-path=/var/lock/nginx.lock
  --pid-path=/var/run/nginx.pid
  --with-debug
  --with-http_addition_module
  --with-http_dav_module
  --with-http_geoip_module
  --with-http_gzip_static_module
  --with-http_image_filter_module
  --with-http_realip_module
  --with-http_stub_status_module
  --with-http_ssl_module
  --with-http_sub_module
  --with-http_xslt_module
  --with-ipv6
  --with-sha1=/usr/include/openssl
  --with-md5=/usr/include/openssl
  --with-mail
  --with-mail_ssl_module
  --add-module=/home/ahammond/nginx/nginx-1.0.6/debian/modules/nginx-echo

--add-module=/home/ahammond/nginx/nginx-1.0.6/debian/modules/nginx-upstream-fair

--add-module=/home/ahammond/nginx/nginx-1.0.6/debian/modules/nginx-upload-resume


My config is pretty simple. Uploads connect to the rspool location via a
proxy for resumable uploading, and then upload pass sends them to a fastcgi
that goes to a django script. Details follow.

ahammond at ws-trans02:/etc/nginx$ cat sites-enabled/rspool.conf
upstream transactions {
    server localhost:10000;
}

server
{
    listen 80;

    include common.conf;

    root /nutricate/static;

    client_max_body_size 50m;

    location /rspool/ {
        gzip off;

        upload_resumable on;
        upload_pass @rspool_upload;
        upload_pass_args on;
upload_pass_form_field "^unique_id$|^entity_id$|.*";

        include upload_resume_params;
    }

    location @rspool_upload {
        gzip off;

        fastcgi_pass transactions;
        include fastcgi_params;
        fastcgi_intercept_errors off;
        break;
    }
}


ahammond at ws-trans02:/etc/nginx$ cat common.conf
error_page 500 /500.html;
error_page 502 /502.html;
error_page 503 /503.html;
error_page 504 /504.html;

location = /50x.html {
    root   html;
}


ahammond at ws-trans02:/etc/nginx$ cat fastcgi_params
fastcgi_param QUERY_STRING $query_string;
fastcgi_param REQUEST_METHOD $request_method;
fastcgi_param CONTENT_TYPE $content_type;
fastcgi_param CONTENT_LENGTH $content_length;

#fastcgi_param SCRIPT_FILENAME $request_filename;
fastcgi_param SCRIPT_FILENAME $fastcgi_script_name;
#fastcgi_param   SCRIPT_NAME $fastcgi_script_name;
fastcgi_param SCRIPT_NAME '';
fastcgi_param REQUEST_URI $request_uri;
fastcgi_param DOCUMENT_URI $document_uri;
fastcgi_param DOCUMENT_ROOT $document_root;
fastcgi_param SERVER_PROTOCOL $server_protocol;

fastcgi_param GATEWAY_INTERFACE CGI/1.1;
fastcgi_param SERVER_SOFTWARE nginx/$nginx_version;

fastcgi_param REMOTE_ADDR $remote_addr;
fastcgi_param REMOTE_PORT $remote_port;
fastcgi_param SERVER_ADDR $server_addr;
fastcgi_param SERVER_PORT $server_port;
fastcgi_param SERVER_NAME $server_name;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param REDIRECT_STATUS 200;

# weird django requirements
fastcgi_param FCGI $server_name;
fastcgi_param PATH_INFO $fastcgi_script_name;


ahammond at ws-trans02:/etc/nginx$ cat upload_resume_params
upload_store /var/lib/nginx/resumable_download 1;
upload_store_access user:r group:r;

upload_set_form_field "${upload_field_name}_name" $upload_file_name;
upload_set_form_field "${upload_field_name}_content_type"
$upload_content_type;
upload_set_form_field "${upload_field_name}_path" $upload_tmp_path;
upload_aggregate_form_field "${upload_field_name}_sha1" $upload_file_sha1;
upload_aggregate_form_field "${upload_field_name}_size" $upload_file_size;

upload_cleanup 400 404 499 500-505;


I upload to the system using the following (see
https://github.com/SmartReceipt/py_lightweight_uploader):

ahammond at lappy386:~/src/py_lightweight_uploader (master)$
./py_lightweight_uploader.py -vv http://testsrv/rspool/?a=b\&c=d ric.log
2011-10-03 11:24:41,805 root DEBUG py_lightweight_uploader.py:278: Starting
theLightweightUploader thread
2011-10-03 11:24:41,806 root DEBUG py_lightweight_uploader.py:117: Upload
queue is empty.
2011-10-03 11:24:41,806 root INFO py_lightweight_uploader.py:71: Queueing
ric.log for upload to http://209.114.46.109/rspool/?a=b&c=d, id:
60890468-1330-4748-866e-e4426584e83f
2011-10-03 11:24:41,917 root DEBUG py_lightweight_uploader.py:179: guessing
file type: text/plain
2011-10-03 11:24:41,917 root DEBUG py_lightweight_uploader.py:222: Sending
ric.log bytes 0-51199/210000
2011-10-03 11:24:42,303 root DEBUG py_lightweight_uploader.py:225: Got
response: 0-51199/210000
2011-10-03 11:24:42,303 root DEBUG py_lightweight_uploader.py:127: Uploaded
a chunk, continuing to upload ric.log
2011-10-03 11:24:42,303 root DEBUG py_lightweight_uploader.py:222: Sending
ric.log bytes 51199-102398/210000
2011-10-03 11:24:42,496 root DEBUG py_lightweight_uploader.py:225: Got
response: 0-102398/210000
2011-10-03 11:24:42,497 root DEBUG py_lightweight_uploader.py:127: Uploaded
a chunk, continuing to upload ric.log
2011-10-03 11:24:42,497 root DEBUG py_lightweight_uploader.py:222: Sending
ric.log bytes 102398-153597/210000
2011-10-03 11:24:42,720 root DEBUG py_lightweight_uploader.py:225: Got
response: 0-153597/210000
2011-10-03 11:24:42,720 root DEBUG py_lightweight_uploader.py:127: Uploaded
a chunk, continuing to upload ric.log
2011-10-03 11:24:42,720 root DEBUG py_lightweight_uploader.py:222: Sending
ric.log bytes 153597-204796/210000
2011-10-03 11:24:42,900 root DEBUG py_lightweight_uploader.py:225: Got
response: 0-204796/210000
2011-10-03 11:24:42,901 root DEBUG py_lightweight_uploader.py:127: Uploaded
a chunk, continuing to upload ric.log
2011-10-03 11:24:42,901 root DEBUG py_lightweight_uploader.py:222: Sending
ric.log bytes 204796-210000/210000
2011-10-03 11:24:43,034 root DEBUG py_lightweight_uploader.py:225: Got
response: k-thanks
2011-10-03 11:24:43,034 root INFO py_lightweight_uploader.py:124: Completed
uploading ric.log
2011-10-03 11:24:43,034 root DEBUG py_lightweight_uploader.py:117: Upload
queue is empty.


Which produces the following nginx access log,

ahammond at ws-trans02:/var/log/nginx$ cat access.log
10.178.51.115 - - [03/Oct/2011:10:58:45 -0700] "POST /rspool/?a=b&c=d
HTTP/1.0" 201 158 "-" "-" "-"
10.178.51.115 - - [03/Oct/2011:10:58:46 -0700] "POST /rspool/?a=b&c=d
HTTP/1.0" 201 160 "-" "-" "-"
10.178.51.115 - - [03/Oct/2011:10:58:46 -0700] "POST /rspool/?a=b&c=d
HTTP/1.0" 201 160 "-" "-" "-"
10.178.51.115 - - [03/Oct/2011:10:58:46 -0700] "POST /rspool/?a=b&c=d
HTTP/1.0" 201 160 "-" "-" "-"
10.178.51.115 - - [03/Oct/2011:10:58:46 -0700] "POST /rspool/?a=b&c=d
HTTP/1.0" 200 144 "-" "-" "-"


and the following debug logfile (sorry for the length, I'm an nginx newbie
and don't want to cut out important stuff).

ahammond at ws-trans02:/var/log/nginx$ cat -n error.log
     1 2011/10/03 11:24:40 [debug] 8111#0: post event 00007F2538837010
     2 2011/10/03 11:24:40 [debug] 8111#0: delete posted event
00007F2538837010
     3 2011/10/03 11:24:40 [debug] 8111#0: accept on 0.0.0.0:80, ready: 0
     4 2011/10/03 11:24:40 [debug] 8111#0: posix_memalign:
0000000000F2F8A0:256 @16
     5 2011/10/03 11:24:40 [debug] 8111#0: *43 accept: 10.178.51.115 fd:7
     6 2011/10/03 11:24:40 [debug] 8111#0: *43 event timer add: 7:
60000:1317666340718
     7 2011/10/03 11:24:40 [debug] 8111#0: *43 epoll add event: fd:7 op:1
ev:80000001
     8 2011/10/03 11:24:40 [debug] 8111#0: *43 post event 00007F25388370E0
     9 2011/10/03 11:24:40 [debug] 8111#0: *43 delete posted event
00007F25388370E0
    10 2011/10/03 11:24:40 [debug] 8111#0: *43 malloc: 0000000000F3D730:1296
    11 2011/10/03 11:24:40 [debug] 8111#0: *43 posix_memalign:
0000000000F5CCC0:256 @16
    12 2011/10/03 11:24:40 [debug] 8111#0: *43 malloc: 0000000000F3DC50:1024
    13 2011/10/03 11:24:40 [debug] 8111#0: *43 posix_memalign:
0000000000F3E060:4096 @16
    14 2011/10/03 11:24:40 [debug] 8111#0: *43 http process request line
    15 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 1024 of 1024
    16 2011/10/03 11:24:40 [debug] 8111#0: *43 http request line: "POST
/rspool/?a=b&c=d HTTP/1.0"
    17 2011/10/03 11:24:40 [debug] 8111#0: *43 http uri: "/rspool/"
    18 2011/10/03 11:24:40 [debug] 8111#0: *43 http args: "a=b&c=d"
    19 2011/10/03 11:24:40 [debug] 8111#0: *43 http exten: ""
    20 2011/10/03 11:24:40 [debug] 8111#0: *43 http process request header
line
    21 2011/10/03 11:24:40 [debug] 8111#0: *43 http header: "Host:
209.114.46.109"
    22 2011/10/03 11:24:40 [debug] 8111#0: *43 http header: "X-Real-IP:
98.173.193.68"
    23 2011/10/03 11:24:40 [debug] 8111#0: *43 http header:
"X-Forwarded-For: 98.173.193.68"
    24 2011/10/03 11:24:40 [debug] 8111#0: *43 http header: "Connection:
close"
    25 2011/10/03 11:24:40 [debug] 8111#0: *43 http header:
"Accept-Encoding: identity"
    26 2011/10/03 11:24:40 [debug] 8111#0: *43 http header: "Content-Length:
51200"
    27 2011/10/03 11:24:40 [debug] 8111#0: *43 http header: "Session-ID:
14367198"
    28 2011/10/03 11:24:40 [debug] 8111#0: *43 http header:
"X-Content-Range: bytes 0-51199/210000"
    29 2011/10/03 11:24:40 [debug] 8111#0: *43 http header: "Content-Type:
text/plain"
    30 2011/10/03 11:24:40 [debug] 8111#0: *43 http header:
"Content-Disposition: attachment; filename="ric.log""
    31 2011/10/03 11:24:40 [debug] 8111#0: *43 http header done
    32 2011/10/03 11:24:40 [debug] 8111#0: *43 event timer del: 7:
1317666340718
    33 2011/10/03 11:24:40 [debug] 8111#0: *43 generic phase: 0
    34 2011/10/03 11:24:40 [debug] 8111#0: *43 rewrite phase: 1
    35 2011/10/03 11:24:40 [debug] 8111#0: *43 test location: "/rspool/"
    36 2011/10/03 11:24:40 [debug] 8111#0: *43 using configuration
"/rspool/"
    37 2011/10/03 11:24:40 [debug] 8111#0: *43 http cl:51200 max:52428800
    38 2011/10/03 11:24:40 [debug] 8111#0: *43 rewrite phase: 3
    39 2011/10/03 11:24:40 [debug] 8111#0: *43 post rewrite phase: 4
    40 2011/10/03 11:24:40 [debug] 8111#0: *43 generic phase: 5
    41 2011/10/03 11:24:40 [debug] 8111#0: *43 generic phase: 6
    42 2011/10/03 11:24:40 [debug] 8111#0: *43 generic phase: 7
    43 2011/10/03 11:24:40 [debug] 8111#0: *43 access phase: 8
    44 2011/10/03 11:24:40 [debug] 8111#0: *43 access phase: 9
    45 2011/10/03 11:24:40 [debug] 8111#0: *43 post access phase: 10
    46 2011/10/03 11:24:40 [debug] 8111#0: *43 session id 14367198
    47 2011/10/03 11:24:40 [debug] 8111#0: *43 partial content, range
0-51199/210000
    48 2011/10/03 11:24:40 [debug] 8111#0: *43 posix_memalign:
0000000000F34400:4096 @16
    49 2011/10/03 11:24:40 [debug] 8111#0: *43 malloc: 0000000000F35410:4096
    50 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body
preread 701
    51 2011/10/03 11:24:40 [debug] 8111#0: *43 malloc: 0000000000F36420:8192
    52 2011/10/03 11:24:40 [debug] 8111#0: *43 http read client request body
    53 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 8192 of 8192
    54 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body recv
8192
    55 2011/10/03 11:24:40 [debug] 8111#0: *43 add cleanup: 0000000000F347D8
    56 2011/10/03 11:24:40 [debug] 8111#0: *43 hashed path:
/var/lib/nginx/resumable_download/8/14367198
    57 2011/10/03 11:24:40 [debug] 8111#0: *43 hashed path of state file:
/var/lib/nginx/resumable_download/8/14367198.state
    58 2011/10/03 11:24:40 [debug] 8111#0: *43 http script var: ""
    59 2011/10/03 11:24:40 [debug] 8111#0: *43 http script copy: "_name"
    60 2011/10/03 11:24:40 [debug] 8111#0: *43 http script var: "ric.log"
    61 2011/10/03 11:24:40 [debug] 8111#0: *43 http script var: ""
    62 2011/10/03 11:24:40 [debug] 8111#0: *43 http script copy:
"_content_type"
    63 2011/10/03 11:24:40 [debug] 8111#0: *43 http script var: "text/plain"
    64 2011/10/03 11:24:40 [debug] 8111#0: *43 posix_memalign:
0000000000F62730:4096 @16
    65 2011/10/03 11:24:40 [debug] 8111#0: *43 http script var: ""
    66 2011/10/03 11:24:40 [debug] 8111#0: *43 http script copy: "_path"
    67 2011/10/03 11:24:40 [debug] 8111#0: *43 http script var:
"/var/lib/nginx/resumable_download/8/14367198"
    68 2011/10/03 11:24:40 [info] 8111#0: *43 started uploading part
0-51199/210000 of file "ric.log" to
"/var/lib/nginx/resumable_download/8/14367198" (field "", content type
"text/plain"), client: 10.178.51.115, server: account.nutricateonline.com,
request: "POST /rspool/?a=b&c=d HTTP/1.0", host: "209.114.46.109"
    69 2011/10/03 11:24:40 [debug] 8111#0: *43 write: 14, 0000000000F3DD93,
701, 0
    70 2011/10/03 11:24:40 [debug] 8111#0: *43 write: 14, 0000000000F36420,
8192, 701
    71 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 8192 of 8192
    72 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body recv
8192
    73 2011/10/03 11:24:40 [debug] 8111#0: *43 write: 14, 0000000000F36420,
8192, 8893
    74 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 8192 of 8192
    75 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body recv
8192
    76 2011/10/03 11:24:40 [debug] 8111#0: *43 write: 14, 0000000000F36420,
8192, 17085
    77 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 8192 of 8192
    78 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body recv
8192
    79 2011/10/03 11:24:40 [debug] 8111#0: *43 write: 14, 0000000000F36420,
8192, 25277
    80 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 8192 of 8192
    81 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body recv
8192
    82 2011/10/03 11:24:40 [debug] 8111#0: *43 write: 14, 0000000000F36420,
8192, 33469
    83 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 2904 of 8192
    84 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body recv
2904
    85 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body rest
6635
    86 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 5288 of 5288
    87 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body recv
5288
    88 2011/10/03 11:24:40 [debug] 8111#0: *43 write: 14, 0000000000F36420,
8192, 41661
    89 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 1347 of 1347
    90 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body recv
1347
    91 2011/10/03 11:24:40 [debug] 8111#0: *43 http client request body rest
0
    92 2011/10/03 11:24:40 [debug] 8111#0: *43 write: 14, 0000000000F36420,
1347, 49853
    93 2011/10/03 11:24:40 [debug] 8111#0: *43 a 0-51199/210000
    94 2011/10/03 11:24:40 [debug] 8111#0: *43 write: 14, 0000000000F34850,
15, 0
    95 2011/10/03 11:24:40 [info] 8111#0: *43 finished uploading part
0-51199/210000 of a file "ric.log" to
"/var/lib/nginx/resumable_download/8/14367198", client: 10.178.51.115,
server: account.nutricateonline.com, request: "POST /rspool/?a=b&c=d
HTTP/1.0", host: "209.114.46.109"
    96 2011/10/03 11:24:40 [debug] 8111#0: *43 xslt filter header
    97 2011/10/03 11:24:40 [debug] 8111#0: *43 HTTP/1.1 201 Created
    98 Server: nginx/1.0.6
    99 Date: Mon, 03 Oct 2011 18:24:40 GMT
   100 Content-Length: 14
   101 Connection: close
   102 Range: 0-51199/210000
   103
   104 2011/10/03 11:24:40 [debug] 8111#0: *43 write new buf t:1 f:0
0000000000F62A70, pos 0000000000F62A70, size: 144 file: 0, size: 0
   105 2011/10/03 11:24:40 [debug] 8111#0: *43 http write filter: l:0 f:0
s:144
   106 2011/10/03 11:24:40 [debug] 8111#0: *43 http output filter
"/rspool/?a=b&c=d"
   107 2011/10/03 11:24:40 [debug] 8111#0: *43 http copy filter:
"/rspool/?a=b&c=d"
   108 2011/10/03 11:24:40 [debug] 8111#0: *43 image filter
   109 2011/10/03 11:24:40 [debug] 8111#0: *43 xslt filter body
   110 2011/10/03 11:24:40 [debug] 8111#0: *43 http postpone filter
"/rspool/?a=b&c=d" 00007FFF96ECBAE0
   111 2011/10/03 11:24:40 [debug] 8111#0: *43 write old buf t:1 f:0
0000000000F62A70, pos 0000000000F62A70, size: 144 file: 0, size: 0
   112 2011/10/03 11:24:40 [debug] 8111#0: *43 write new buf t:0 f:0
0000000000F34628, pos 0000000000F34628, size: 14 file: 0, size: 0
   113 2011/10/03 11:24:40 [debug] 8111#0: *43 http write filter: l:1 f:1
s:158
   114 2011/10/03 11:24:40 [debug] 8111#0: *43 http write filter limit 0
   115 2011/10/03 11:24:40 [debug] 8111#0: *43 writev: 158
   116 2011/10/03 11:24:40 [debug] 8111#0: *43 http write filter
0000000000000000
   117 2011/10/03 11:24:40 [debug] 8111#0: *43 http copy filter: 0
"/rspool/?a=b&c=d"
   118 2011/10/03 11:24:40 [debug] 8111#0: *43 http finalize request: 0,
"/rspool/?a=b&c=d" a:1, c:2
   119 2011/10/03 11:24:40 [debug] 8111#0: *43 http request count:2 blk:0
   120 2011/10/03 11:24:40 [debug] 8111#0: *43 http finalize request: -4,
"/rspool/?a=b&c=d" a:1, c:1
   121 2011/10/03 11:24:40 [debug] 8111#0: *43 event timer add: 7:
5000:1317666285719
   122 2011/10/03 11:24:40 [debug] 8111#0: *43 http lingering close handler
   123 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 -1 of 4096
   124 2011/10/03 11:24:40 [debug] 8111#0: *43 recv() not ready (11:
Resource temporarily unavailable)
   125 2011/10/03 11:24:40 [debug] 8111#0: *43 lingering read: -2
   126 2011/10/03 11:24:40 [debug] 8111#0: *43 event timer: 7, old:
1317666285719, new: 1317666285719
   127 2011/10/03 11:24:40 [debug] 8111#0: *43 post event 00007F25388370E0
   128 2011/10/03 11:24:40 [debug] 8111#0: *43 delete posted event
00007F25388370E0
   129 2011/10/03 11:24:40 [debug] 8111#0: *43 http lingering close handler
   130 2011/10/03 11:24:40 [debug] 8111#0: *43 recv: fd:7 0 of 4096
   131 2011/10/03 11:24:40 [debug] 8111#0: *43 lingering read: 0
   132 2011/10/03 11:24:40 [debug] 8111#0: *43 http request count:1 blk:0
   133 2011/10/03 11:24:40 [debug] 8111#0: *43 http close request
   134 2011/10/03 11:24:40 [debug] 8111#0: *43 http log handler
   135 2011/10/03 11:24:40 [debug] 8111#0: *43 run cleanup: 0000000000F347D8
   136 2011/10/03 11:24:40 [debug] 8111#0: *43 free: 0000000000F36420
   137 2011/10/03 11:24:40 [debug] 8111#0: *43 free: 0000000000F35410
   138 2011/10/03 11:24:40 [debug] 8111#0: *43 free: 0000000000F3E060,
unused: 0
   139 2011/10/03 11:24:40 [debug] 8111#0: *43 free: 0000000000F34400,
unused: 0
   140 2011/10/03 11:24:40 [debug] 8111#0: *43 free: 0000000000F62730,
unused: 2843
   141 2011/10/03 11:24:40 [debug] 8111#0: *43 close http connection: 7
   142 2011/10/03 11:24:40 [debug] 8111#0: *43 event timer del: 7:
1317666285719
   143 2011/10/03 11:24:40 [debug] 8111#0: *43 reusable connection: 0
   144 2011/10/03 11:24:40 [debug] 8111#0: *43 free: 0000000000F3DC50
   145 2011/10/03 11:24:40 [debug] 8111#0: *43 free: 0000000000F3D730
   146 2011/10/03 11:24:40 [debug] 8111#0: *43 free: 0000000000F2F8A0,
unused: 8
   147 2011/10/03 11:24:40 [debug] 8111#0: *43 free: 0000000000F5CCC0,
unused: 128
   148 2011/10/03 11:24:40 [debug] 8111#0: post event 00007F2538837010
   149 2011/10/03 11:24:40 [debug] 8111#0: delete posted event
00007F2538837010
   150 2011/10/03 11:24:40 [debug] 8111#0: accept on 0.0.0.0:80, ready: 0
   151 2011/10/03 11:24:40 [debug] 8111#0: posix_memalign:
0000000000F2F8A0:256 @16
   152 2011/10/03 11:24:40 [debug] 8111#0: *44 accept: 10.178.51.115 fd:7
   153 2011/10/03 11:24:40 [debug] 8111#0: *44 event timer add: 7:
60000:1317666340906
   154 2011/10/03 11:24:40 [debug] 8111#0: *44 epoll add event: fd:7 op:1
ev:80000001
   155 2011/10/03 11:24:40 [debug] 8111#0: *44 post event 00007F25388370E0
   156 2011/10/03 11:24:40 [debug] 8111#0: *44 delete posted event
00007F25388370E0
   157 2011/10/03 11:24:40 [debug] 8111#0: *44 malloc: 0000000000F3D730:1296
   158 2011/10/03 11:24:40 [debug] 8111#0: *44 posix_memalign:
0000000000F5CCC0:256 @16
   159 2011/10/03 11:24:40 [debug] 8111#0: *44 malloc: 0000000000F3DC50:1024
   160 2011/10/03 11:24:40 [debug] 8111#0: *44 posix_memalign:
0000000000F3E060:4096 @16
   161 2011/10/03 11:24:40 [debug] 8111#0: *44 http process request line
   162 2011/10/03 11:24:40 [debug] 8111#0: *44 recv: fd:7 1024 of 1024
   163 2011/10/03 11:24:40 [debug] 8111#0: *44 http request line: "POST
/rspool/?a=b&c=d HTTP/1.0"
   164 2011/10/03 11:24:40 [debug] 8111#0: *44 http uri: "/rspool/"
   165 2011/10/03 11:24:40 [debug] 8111#0: *44 http args: "a=b&c=d"
   166 2011/10/03 11:24:40 [debug] 8111#0: *44 http exten: ""
   167 2011/10/03 11:24:40 [debug] 8111#0: *44 http process request header
line
   168 2011/10/03 11:24:40 [debug] 8111#0: *44 http header: "Host:
209.114.46.109"
   169 2011/10/03 11:24:40 [debug] 8111#0: *44 http header: "X-Real-IP:
98.173.193.68"
   170 2011/10/03 11:24:40 [debug] 8111#0: *44 http header:
"X-Forwarded-For: 98.173.193.68"
   171 2011/10/03 11:24:40 [debug] 8111#0: *44 http header: "Connection:
close"
   172 2011/10/03 11:24:40 [debug] 8111#0: *44 http header:
"Accept-Encoding: identity"
   173 2011/10/03 11:24:40 [debug] 8111#0: *44 http header: "Content-Length:
51200"
   174 2011/10/03 11:24:40 [debug] 8111#0: *44 http header: "Session-ID:
14367198"
   175 2011/10/03 11:24:40 [debug] 8111#0: *44 http header:
"X-Content-Range: bytes 51199-102398/210000"
   176 2011/10/03 11:24:40 [debug] 8111#0: *44 http header: "Content-Type:
text/plain"
   177 2011/10/03 11:24:40 [debug] 8111#0: *44 http header:
"Content-Disposition: attachment; filename="ric.log""
   178 2011/10/03 11:24:40 [debug] 8111#0: *44 http header done
   179 2011/10/03 11:24:40 [debug] 8111#0: *44 event timer del: 7:
1317666340906
   180 2011/10/03 11:24:40 [debug] 8111#0: *44 generic phase: 0
   181 2011/10/03 11:24:40 [debug] 8111#0: *44 rewrite phase: 1
   182 2011/10/03 11:24:40 [debug] 8111#0: *44 test location: "/rspool/"
   183 2011/10/03 11:24:40 [debug] 8111#0: *44 using configuration
"/rspool/"
   184 2011/10/03 11:24:40 [debug] 8111#0: *44 http cl:51200 max:52428800
   185 2011/10/03 11:24:40 [debug] 8111#0: *44 rewrite phase: 3
   186 2011/10/03 11:24:40 [debug] 8111#0: *44 post rewrite phase: 4
   187 2011/10/03 11:24:40 [debug] 8111#0: *44 generic phase: 5
   188 2011/10/03 11:24:40 [debug] 8111#0: *44 generic phase: 6
   189 2011/10/03 11:24:40 [debug] 8111#0: *44 generic phase: 7
   190 2011/10/03 11:24:40 [debug] 8111#0: *44 access phase: 8
   191 2011/10/03 11:24:40 [debug] 8111#0: *44 access phase: 9
   192 2011/10/03 11:24:40 [debug] 8111#0: *44 post access phase: 10
   193 2011/10/03 11:24:40 [debug] 8111#0: *44 session id 14367198
   194 2011/10/03 11:24:40 [debug] 8111#0: *44 partial content, range
51199-102398/210000
   195 2011/10/03 11:24:40 [debug] 8111#0: *44 posix_memalign:
0000000000F34400:4096 @16
   196 2011/10/03 11:24:40 [debug] 8111#0: *44 malloc: 0000000000F35410:4096
   197 2011/10/03 11:24:40 [debug] 8111#0: *44 http client request body
preread 696
   198 2011/10/03 11:24:40 [debug] 8111#0: *44 malloc: 0000000000F36420:8192
   199 2011/10/03 11:24:40 [debug] 8111#0: *44 http read client request body
   200 2011/10/03 11:24:40 [debug] 8111#0: *44 recv: fd:7 8192 of 8192
   201 2011/10/03 11:24:40 [debug] 8111#0: *44 http client request body recv
8192
   202 2011/10/03 11:24:40 [debug] 8111#0: *44 add cleanup: 0000000000F347D8
   203 2011/10/03 11:24:40 [debug] 8111#0: *44 hashed path:
/var/lib/nginx/resumable_download/8/14367198
   204 2011/10/03 11:24:40 [debug] 8111#0: *44 hashed path of state file:
/var/lib/nginx/resumable_download/8/14367198.state
   205 2011/10/03 11:24:40 [debug] 8111#0: *44 http script var: ""
   206 2011/10/03 11:24:40 [debug] 8111#0: *44 http script copy: "_name"
   207 2011/10/03 11:24:40 [debug] 8111#0: *44 http script var: "ric.log"
   208 2011/10/03 11:24:40 [debug] 8111#0: *44 http script var: ""
   209 2011/10/03 11:24:40 [debug] 8111#0: *44 http script copy:
"_content_type"
   210 2011/10/03 11:24:40 [debug] 8111#0: *44 http script var: "text/plain"
   211 2011/10/03 11:24:40 [debug] 8111#0: *44 posix_memalign:
0000000000F62730:4096 @16
   212 2011/10/03 11:24:40 [debug] 8111#0: *44 http script var: ""
   213 2011/10/03 11:24:40 [debug] 8111#0: *44 http script copy: "_path"
   214 2011/10/03 11:24:40 [debug] 8111#0: *44 http script var:
"/var/lib/nginx/resumable_download/8/14367198"
   215 2011/10/03 11:24:40 [info] 8111#0: *44 started uploading part
51199-102398/210000 of file "ric.log" to
"/var/lib/nginx/resumable_download/8/14367198" (field "", content type
"text/plain"), client: 10.178.51.115, server: account.nutricateonline.com,
request: "POST /rspool/?a=b&c=d HTTP/1.0", host: "209.114.46.109"
   216 2011/10/03 11:24:40 [debug] 8111#0: *44 write: 14, 0000000000F3DD98,
696, 51199
   217 2011/10/03 11:24:40 [debug] 8111#0: *44 write: 14, 0000000000F36420,
8192, 51895
   218 2011/10/03 11:24:40 [debug] 8111#0: *44 recv: fd:7 8192 of 8192
   219 2011/10/03 11:24:40 [debug] 8111#0: *44 http client request body recv
8192
   220 2011/10/03 11:24:40 [debug] 8111#0: *44 write: 14, 0000000000F36420,
8192, 60087
   221 2011/10/03 11:24:40 [debug] 8111#0: *44 recv: fd:7 8192 of 8192
   222 2011/10/03 11:24:40 [debug] 8111#0: *44 http client request body recv
8192
   223 2011/10/03 11:24:40 [debug] 8111#0: *44 write: 14, 0000000000F36420,
8192, 68279
   224 2011/10/03 11:24:40 [debug] 8111#0: *44 recv: fd:7 8192 of 8192
   225 2011/10/03 11:24:40 [debug] 8111#0: *44 http client request body recv
8192
   226 2011/10/03 11:24:40 [debug] 8111#0: *44 write: 14, 0000000000F36420,
8192, 76471
   227 2011/10/03 11:24:40 [debug] 8111#0: *44 recv: fd:7 8192 of 8192
   228 2011/10/03 11:24:40 [debug] 8111#0: *44 http client request body recv
8192
   229 2011/10/03 11:24:40 [debug] 8111#0: *44 write: 14, 0000000000F36420,
8192, 84663
   230 2011/10/03 11:24:40 [debug] 8111#0: *44 recv: fd:7 8192 of 8192
   231 2011/10/03 11:24:40 [debug] 8111#0: *44 http client request body recv
8192
   232 2011/10/03 11:24:40 [debug] 8111#0: *44 write: 14, 0000000000F36420,
8192, 92855
   233 2011/10/03 11:24:40 [debug] 8111#0: *44 recv: fd:7 1352 of 1352
   234 2011/10/03 11:24:40 [debug] 8111#0: *44 http client request body recv
1352
   235 2011/10/03 11:24:40 [debug] 8111#0: *44 http client request body rest
0
   236 2011/10/03 11:24:40 [debug] 8111#0: *44 write: 14, 0000000000F36420,
1352, 101047
   237 2011/10/03 11:24:40 [debug] 8111#0: *44 read: 14, 0000000000F34C8F,
15, 0
   238 2011/10/03 11:24:40 [debug] 8111#0: *44 a 0-102398/210000
   239 2011/10/03 11:24:40 [debug] 8111#0: *44 write: 14, 0000000000F34850,
16, 0
   240 2011/10/03 11:24:40 [info] 8111#0: *44 finished uploading part
51199-102398/210000 of a file "ric.log" to
"/var/lib/nginx/resumable_download/8/14367198", client: 10.178.51.115,
server: account.nutricateonline.com, request: "POST /rspool/?a=b&c=d
HTTP/1.0", host: "209.114.46.109"
   241 2011/10/03 11:24:40 [debug] 8111#0: *44 xslt filter header
   242 2011/10/03 11:24:40 [debug] 8111#0: *44 HTTP/1.1 201 Created
   243 Server: nginx/1.0.6
   244 Date: Mon, 03 Oct 2011 18:24:40 GMT
   245 Content-Length: 15
   246 Connection: close
   247 Range: 0-102398/210000
   248
   249 2011/10/03 11:24:40 [debug] 8111#0: *44 write new buf t:1 f:0
0000000000F62A70, pos 0000000000F62A70, size: 145 file: 0, size: 0
   250 2011/10/03 11:24:40 [debug] 8111#0: *44 http write filter: l:0 f:0
s:145
   251 2011/10/03 11:24:40 [debug] 8111#0: *44 http output filter
"/rspool/?a=b&c=d"
   252 2011/10/03 11:24:40 [debug] 8111#0: *44 http copy filter:
"/rspool/?a=b&c=d"
   253 2011/10/03 11:24:40 [debug] 8111#0: *44 image filter
   254 2011/10/03 11:24:40 [debug] 8111#0: *44 xslt filter body
   255 2011/10/03 11:24:40 [debug] 8111#0: *44 http postpone filter
"/rspool/?a=b&c=d" 00007FFF96ECBAE0
   256 2011/10/03 11:24:40 [debug] 8111#0: *44 write old buf t:1 f:0
0000000000F62A70, pos 0000000000F62A70, size: 145 file: 0, size: 0
   257 2011/10/03 11:24:40 [debug] 8111#0: *44 write new buf t:0 f:0
0000000000F34628, pos 0000000000F34628, size: 15 file: 0, size: 0
   258 2011/10/03 11:24:40 [debug] 8111#0: *44 http write filter: l:1 f:1
s:160
   259 2011/10/03 11:24:40 [debug] 8111#0: *44 http write filter limit 0
   260 2011/10/03 11:24:40 [debug] 8111#0: *44 writev: 160
   261 2011/10/03 11:24:40 [debug] 8111#0: *44 http write filter
0000000000000000
   262 2011/10/03 11:24:40 [debug] 8111#0: *44 http copy filter: 0
"/rspool/?a=b&c=d"
   263 2011/10/03 11:24:40 [debug] 8111#0: *44 http finalize request: 0,
"/rspool/?a=b&c=d" a:1, c:2
   264 2011/10/03 11:24:40 [debug] 8111#0: *44 http request count:2 blk:0
   265 2011/10/03 11:24:40 [debug] 8111#0: *44 http finalize request: -4,
"/rspool/?a=b&c=d" a:1, c:1
   266 2011/10/03 11:24:40 [debug] 8111#0: *44 event timer add: 7:
5000:1317666285906
   267 2011/10/03 11:24:40 [debug] 8111#0: *44 http lingering close handler
   268 2011/10/03 11:24:40 [debug] 8111#0: *44 recv: fd:7 -1 of 4096
   269 2011/10/03 11:24:40 [debug] 8111#0: *44 recv() not ready (11:
Resource temporarily unavailable)
   270 2011/10/03 11:24:40 [debug] 8111#0: *44 lingering read: -2
   271 2011/10/03 11:24:40 [debug] 8111#0: *44 event timer: 7, old:
1317666285906, new: 1317666285906
   272 2011/10/03 11:24:40 [debug] 8111#0: *44 post event 00007F25388370E0
   273 2011/10/03 11:24:40 [debug] 8111#0: *44 delete posted event
00007F25388370E0
   274 2011/10/03 11:24:40 [debug] 8111#0: *44 http lingering close handler
   275 2011/10/03 11:24:40 [debug] 8111#0: *44 recv: fd:7 0 of 4096
   276 2011/10/03 11:24:40 [debug] 8111#0: *44 lingering read: 0
   277 2011/10/03 11:24:40 [debug] 8111#0: *44 http request count:1 blk:0
   278 2011/10/03 11:24:40 [debug] 8111#0: *44 http close request
   279 2011/10/03 11:24:40 [debug] 8111#0: *44 http log handler
   280 2011/10/03 11:24:40 [debug] 8111#0: *44 run cleanup: 0000000000F347D8
   281 2011/10/03 11:24:40 [debug] 8111#0: *44 free: 0000000000F36420
   282 2011/10/03 11:24:40 [debug] 8111#0: *44 free: 0000000000F35410
   283 2011/10/03 11:24:40 [debug] 8111#0: *44 free: 0000000000F3E060,
unused: 0
   284 2011/10/03 11:24:40 [debug] 8111#0: *44 free: 0000000000F34400,
unused: 0
   285 2011/10/03 11:24:40 [debug] 8111#0: *44 free: 0000000000F62730,
unused: 2843
   286 2011/10/03 11:24:40 [debug] 8111#0: *44 close http connection: 7
   287 2011/10/03 11:24:40 [debug] 8111#0: *44 event timer del: 7:
1317666285906
   288 2011/10/03 11:24:40 [debug] 8111#0: *44 reusable connection: 0
   289 2011/10/03 11:24:40 [debug] 8111#0: *44 free: 0000000000F3DC50
   290 2011/10/03 11:24:40 [debug] 8111#0: *44 free: 0000000000F3D730
   291 2011/10/03 11:24:40 [debug] 8111#0: *44 free: 0000000000F2F8A0,
unused: 8
   292 2011/10/03 11:24:40 [debug] 8111#0: *44 free: 0000000000F5CCC0,
unused: 128
   293 2011/10/03 11:24:41 [debug] 8111#0: post event 00007F2538837010
   294 2011/10/03 11:24:41 [debug] 8111#0: delete posted event
00007F2538837010
   295 2011/10/03 11:24:41 [debug] 8111#0: accept on 0.0.0.0:80, ready: 0
   296 2011/10/03 11:24:41 [debug] 8111#0: posix_memalign:
0000000000F2F8A0:256 @16
   297 2011/10/03 11:24:41 [debug] 8111#0: *45 accept: 10.178.51.115 fd:7
   298 2011/10/03 11:24:41 [debug] 8111#0: *45 event timer add: 7:
60000:1317666341135
   299 2011/10/03 11:24:41 [debug] 8111#0: *45 epoll add event: fd:7 op:1
ev:80000001
   300 2011/10/03 11:24:41 [debug] 8111#0: *45 post event 00007F25388370E0
   301 2011/10/03 11:24:41 [debug] 8111#0: *45 delete posted event
00007F25388370E0
   302 2011/10/03 11:24:41 [debug] 8111#0: *45 malloc: 0000000000F3D730:1296
   303 2011/10/03 11:24:41 [debug] 8111#0: *45 posix_memalign:
0000000000F5CCC0:256 @16
   304 2011/10/03 11:24:41 [debug] 8111#0: *45 malloc: 0000000000F3DC50:1024
   305 2011/10/03 11:24:41 [debug] 8111#0: *45 posix_memalign:
0000000000F3E060:4096 @16
   306 2011/10/03 11:24:41 [debug] 8111#0: *45 http process request line
   307 2011/10/03 11:24:41 [debug] 8111#0: *45 recv: fd:7 1024 of 1024
   308 2011/10/03 11:24:41 [debug] 8111#0: *45 http request line: "POST
/rspool/?a=b&c=d HTTP/1.0"
   309 2011/10/03 11:24:41 [debug] 8111#0: *45 http uri: "/rspool/"
   310 2011/10/03 11:24:41 [debug] 8111#0: *45 http args: "a=b&c=d"
   311 2011/10/03 11:24:41 [debug] 8111#0: *45 http exten: ""
   312 2011/10/03 11:24:41 [debug] 8111#0: *45 http process request header
line
   313 2011/10/03 11:24:41 [debug] 8111#0: *45 http header: "Host:
209.114.46.109"
   314 2011/10/03 11:24:41 [debug] 8111#0: *45 http header: "X-Real-IP:
98.173.193.68"
   315 2011/10/03 11:24:41 [debug] 8111#0: *45 http header:
"X-Forwarded-For: 98.173.193.68"
   316 2011/10/03 11:24:41 [debug] 8111#0: *45 http header: "Connection:
close"
   317 2011/10/03 11:24:41 [debug] 8111#0: *45 http header:
"Accept-Encoding: identity"
   318 2011/10/03 11:24:41 [debug] 8111#0: *45 http header: "Content-Length:
51200"
   319 2011/10/03 11:24:41 [debug] 8111#0: *45 http header: "Session-ID:
14367198"
   320 2011/10/03 11:24:41 [debug] 8111#0: *45 http header:
"X-Content-Range: bytes 102398-153597/210000"
   321 2011/10/03 11:24:41 [debug] 8111#0: *45 http header: "Content-Type:
text/plain"
   322 2011/10/03 11:24:41 [debug] 8111#0: *45 http header:
"Content-Disposition: attachment; filename="ric.log""
   323 2011/10/03 11:24:41 [debug] 8111#0: *45 http header done
   324 2011/10/03 11:24:41 [debug] 8111#0: *45 event timer del: 7:
1317666341135
   325 2011/10/03 11:24:41 [debug] 8111#0: *45 generic phase: 0
   326 2011/10/03 11:24:41 [debug] 8111#0: *45 rewrite phase: 1
   327 2011/10/03 11:24:41 [debug] 8111#0: *45 test location: "/rspool/"
   328 2011/10/03 11:24:41 [debug] 8111#0: *45 using configuration
"/rspool/"
   329 2011/10/03 11:24:41 [debug] 8111#0: *45 http cl:51200 max:52428800
   330 2011/10/03 11:24:41 [debug] 8111#0: *45 rewrite phase: 3
   331 2011/10/03 11:24:41 [debug] 8111#0: *45 post rewrite phase: 4
   332 2011/10/03 11:24:41 [debug] 8111#0: *45 generic phase: 5
   333 2011/10/03 11:24:41 [debug] 8111#0: *45 generic phase: 6
   334 2011/10/03 11:24:41 [debug] 8111#0: *45 generic phase: 7
   335 2011/10/03 11:24:41 [debug] 8111#0: *45 access phase: 8
   336 2011/10/03 11:24:41 [debug] 8111#0: *45 access phase: 9
   337 2011/10/03 11:24:41 [debug] 8111#0: *45 post access phase: 10
   338 2011/10/03 11:24:41 [debug] 8111#0: *45 session id 14367198
   339 2011/10/03 11:24:41 [debug] 8111#0: *45 partial content, range
102398-153597/210000
   340 2011/10/03 11:24:41 [debug] 8111#0: *45 posix_memalign:
0000000000F34400:4096 @16
   341 2011/10/03 11:24:41 [debug] 8111#0: *45 malloc: 0000000000F35410:4096
   342 2011/10/03 11:24:41 [debug] 8111#0: *45 http client request body
preread 695
   343 2011/10/03 11:24:41 [debug] 8111#0: *45 malloc: 0000000000F36420:8192
   344 2011/10/03 11:24:41 [debug] 8111#0: *45 http read client request body
   345 2011/10/03 11:24:41 [debug] 8111#0: *45 recv: fd:7 8192 of 8192
   346 2011/10/03 11:24:41 [debug] 8111#0: *45 http client request body recv
8192
   347 2011/10/03 11:24:41 [debug] 8111#0: *45 add cleanup: 0000000000F347D8
   348 2011/10/03 11:24:41 [debug] 8111#0: *45 hashed path:
/var/lib/nginx/resumable_download/8/14367198
   349 2011/10/03 11:24:41 [debug] 8111#0: *45 hashed path of state file:
/var/lib/nginx/resumable_download/8/14367198.state
   350 2011/10/03 11:24:41 [debug] 8111#0: *45 http script var: ""
   351 2011/10/03 11:24:41 [debug] 8111#0: *45 http script copy: "_name"
   352 2011/10/03 11:24:41 [debug] 8111#0: *45 http script var: "ric.log"
   353 2011/10/03 11:24:41 [debug] 8111#0: *45 http script var: ""
   354 2011/10/03 11:24:41 [debug] 8111#0: *45 http script copy:
"_content_type"
   355 2011/10/03 11:24:41 [debug] 8111#0: *45 http script var: "text/plain"
   356 2011/10/03 11:24:41 [debug] 8111#0: *45 posix_memalign:
0000000000F62730:4096 @16
   357 2011/10/03 11:24:41 [debug] 8111#0: *45 http script var: ""
   358 2011/10/03 11:24:41 [debug] 8111#0: *45 http script copy: "_path"
   359 2011/10/03 11:24:41 [debug] 8111#0: *45 http script var:
"/var/lib/nginx/resumable_download/8/14367198"
   360 2011/10/03 11:24:41 [info] 8111#0: *45 started uploading part
102398-153597/210000 of file "ric.log" to
"/var/lib/nginx/resumable_download/8/14367198" (field "", content type
"text/plain"), client: 10.178.51.115, server: account.nutricateonline.com,
request: "POST /rspool/?a=b&c=d HTTP/1.0", host: "209.114.46.109"
   361 2011/10/03 11:24:41 [debug] 8111#0: *45 write: 14, 0000000000F3DD99,
695, 102398
   362 2011/10/03 11:24:41 [debug] 8111#0: *45 write: 14, 0000000000F36420,
8192, 103093
   363 2011/10/03 11:24:41 [debug] 8111#0: *45 recv: fd:7 8192 of 8192
   364 2011/10/03 11:24:41 [debug] 8111#0: *45 http client request body recv
8192
   365 2011/10/03 11:24:41 [debug] 8111#0: *45 write: 14, 0000000000F36420,
8192, 111285
   366 2011/10/03 11:24:41 [debug] 8111#0: *45 recv: fd:7 8192 of 8192
   367 2011/10/03 11:24:41 [debug] 8111#0: *45 http client request body recv
8192
   368 2011/10/03 11:24:41 [debug] 8111#0: *45 write: 14, 0000000000F36420,
8192, 119477
   369 2011/10/03 11:24:41 [debug] 8111#0: *45 recv: fd:7 8192 of 8192
   370 2011/10/03 11:24:41 [debug] 8111#0: *45 http client request body recv
8192
   371 2011/10/03 11:24:41 [debug] 8111#0: *45 write: 14, 0000000000F36420,
8192, 127669
   372 2011/10/03 11:24:41 [debug] 8111#0: *45 recv: fd:7 8192 of 8192
   373 2011/10/03 11:24:41 [debug] 8111#0: *45 http client request body recv
8192
   374 2011/10/03 11:24:41 [debug] 8111#0: *45 write: 14, 0000000000F36420,
8192, 135861
   375 2011/10/03 11:24:41 [debug] 8111#0: *45 recv: fd:7 8192 of 8192
   376 2011/10/03 11:24:41 [debug] 8111#0: *45 http client request body recv
8192
   377 2011/10/03 11:24:41 [debug] 8111#0: *45 write: 14, 0000000000F36420,
8192, 144053
   378 2011/10/03 11:24:41 [debug] 8111#0: *45 recv: fd:7 1353 of 1353
   379 2011/10/03 11:24:41 [debug] 8111#0: *45 http client request body recv
1353
   380 2011/10/03 11:24:41 [debug] 8111#0: *45 http client request body rest
0
   381 2011/10/03 11:24:41 [debug] 8111#0: *45 write: 14, 0000000000F36420,
1353, 152245
   382 2011/10/03 11:24:41 [debug] 8111#0: *45 read: 14, 0000000000F34C8F,
16, 0
   383 2011/10/03 11:24:41 [debug] 8111#0: *45 a 0-153597/210000
   384 2011/10/03 11:24:41 [debug] 8111#0: *45 write: 14, 0000000000F34850,
16, 0
   385 2011/10/03 11:24:41 [info] 8111#0: *45 finished uploading part
102398-153597/210000 of a file "ric.log" to
"/var/lib/nginx/resumable_download/8/14367198", client: 10.178.51.115,
server: account.nutricateonline.com, request: "POST /rspool/?a=b&c=d
HTTP/1.0", host: "209.114.46.109"
   386 2011/10/03 11:24:41 [debug] 8111#0: *45 xslt filter header
   387 2011/10/03 11:24:41 [debug] 8111#0: *45 HTTP/1.1 201 Created
   388 Server: nginx/1.0.6
   389 Date: Mon, 03 Oct 2011 18:24:41 GMT
   390 Content-Length: 15
   391 Connection: close
   392 Range: 0-153597/210000
   393
   394 2011/10/03 11:24:41 [debug] 8111#0: *45 write new buf t:1 f:0
0000000000F62A70, pos 0000000000F62A70, size: 145 file: 0, size: 0
   395 2011/10/03 11:24:41 [debug] 8111#0: *45 http write filter: l:0 f:0
s:145
   396 2011/10/03 11:24:41 [debug] 8111#0: *45 http output filter
"/rspool/?a=b&c=d"
   397 2011/10/03 11:24:41 [debug] 8111#0: *45 http copy filter:
"/rspool/?a=b&c=d"
   398 2011/10/03 11:24:41 [debug] 8111#0: *45 image filter
   399 2011/10/03 11:24:41 [debug] 8111#0: *45 xslt filter body
   400 2011/10/03 11:24:41 [debug] 8111#0: *45 http postpone filter
"/rspool/?a=b&c=d" 00007FFF96ECBAE0
   401 2011/10/03 11:24:41 [debug] 8111#0: *45 write old buf t:1 f:0
0000000000F62A70, pos 0000000000F62A70, size: 145 file: 0, size: 0
   402 2011/10/03 11:24:41 [debug] 8111#0: *45 write new buf t:0 f:0
0000000000F34628, pos 0000000000F34628, size: 15 file: 0, size: 0
   403 2011/10/03 11:24:41 [debug] 8111#0: *45 http write filter: l:1 f:1
s:160
   404 2011/10/03 11:24:41 [debug] 8111#0: *45 http write filter limit 0
   405 2011/10/03 11:24:41 [debug] 8111#0: *45 writev: 160
   406 2011/10/03 11:24:41 [debug] 8111#0: *45 http write filter
0000000000000000
   407 2011/10/03 11:24:41 [debug] 8111#0: *45 http copy filter: 0
"/rspool/?a=b&c=d"
   408 2011/10/03 11:24:41 [debug] 8111#0: *45 http finalize request: 0,
"/rspool/?a=b&c=d" a:1, c:2
   409 2011/10/03 11:24:41 [debug] 8111#0: *45 http request count:2 blk:0
   410 2011/10/03 11:24:41 [debug] 8111#0: *45 http finalize request: -4,
"/rspool/?a=b&c=d" a:1, c:1
   411 2011/10/03 11:24:41 [debug] 8111#0: *45 event timer add: 7:
5000:1317666286135
   412 2011/10/03 11:24:41 [debug] 8111#0: *45 http lingering close handler
   413 2011/10/03 11:24:41 [debug] 8111#0: *45 recv: fd:7 -1 of 4096
   414 2011/10/03 11:24:41 [debug] 8111#0: *45 recv() not ready (11:
Resource temporarily unavailable)
   415 2011/10/03 11:24:41 [debug] 8111#0: *45 lingering read: -2
   416 2011/10/03 11:24:41 [debug] 8111#0: *45 event timer: 7, old:
1317666286135, new: 1317666286135
   417 2011/10/03 11:24:41 [debug] 8111#0: *45 post event 00007F25388370E0
   418 2011/10/03 11:24:41 [debug] 8111#0: *45 delete posted event
00007F25388370E0
   419 2011/10/03 11:24:41 [debug] 8111#0: *45 http lingering close handler
   420 2011/10/03 11:24:41 [debug] 8111#0: *45 recv: fd:7 0 of 4096
   421 2011/10/03 11:24:41 [debug] 8111#0: *45 lingering read: 0
   422 2011/10/03 11:24:41 [debug] 8111#0: *45 http request count:1 blk:0
   423 2011/10/03 11:24:41 [debug] 8111#0: *45 http close request
   424 2011/10/03 11:24:41 [debug] 8111#0: *45 http log handler
   425 2011/10/03 11:24:41 [debug] 8111#0: *45 run cleanup: 0000000000F347D8
   426 2011/10/03 11:24:41 [debug] 8111#0: *45 free: 0000000000F36420
   427 2011/10/03 11:24:41 [debug] 8111#0: *45 free: 0000000000F35410
   428 2011/10/03 11:24:41 [debug] 8111#0: *45 free: 0000000000F3E060,
unused: 0
   429 2011/10/03 11:24:41 [debug] 8111#0: *45 free: 0000000000F34400,
unused: 0
   430 2011/10/03 11:24:41 [debug] 8111#0: *45 free: 0000000000F62730,
unused: 2843
   431 2011/10/03 11:24:41 [debug] 8111#0: *45 close http connection: 7
   432 2011/10/03 11:24:41 [debug] 8111#0: *45 event timer del: 7:
1317666286135
   433 2011/10/03 11:24:41 [debug] 8111#0: *45 reusable connection: 0
   434 2011/10/03 11:24:41 [debug] 8111#0: *45 free: 0000000000F3DC50
   435 2011/10/03 11:24:41 [debug] 8111#0: *45 free: 0000000000F3D730
   436 2011/10/03 11:24:41 [debug] 8111#0: *45 free: 0000000000F2F8A0,
unused: 8
   437 2011/10/03 11:24:41 [debug] 8111#0: *45 free: 0000000000F5CCC0,
unused: 128
   438 2011/10/03 11:24:41 [debug] 8111#0: post event 00007F2538837010
   439 2011/10/03 11:24:41 [debug] 8111#0: delete posted event
00007F2538837010
   440 2011/10/03 11:24:41 [debug] 8111#0: accept on 0.0.0.0:80, ready: 0
   441 2011/10/03 11:24:41 [debug] 8111#0: posix_memalign:
0000000000F2F8A0:256 @16
   442 2011/10/03 11:24:41 [debug] 8111#0: *46 accept: 10.178.51.115 fd:7
   443 2011/10/03 11:24:41 [debug] 8111#0: *46 event timer add: 7:
60000:1317666341316
   444 2011/10/03 11:24:41 [debug] 8111#0: *46 epoll add event: fd:7 op:1
ev:80000001
   445 2011/10/03 11:24:41 [debug] 8111#0: *46 post event 00007F25388370E0
   446 2011/10/03 11:24:41 [debug] 8111#0: *46 delete posted event
00007F25388370E0
   447 2011/10/03 11:24:41 [debug] 8111#0: *46 malloc: 0000000000F3D730:1296
   448 2011/10/03 11:24:41 [debug] 8111#0: *46 posix_memalign:
0000000000F5CCC0:256 @16
   449 2011/10/03 11:24:41 [debug] 8111#0: *46 malloc: 0000000000F3DC50:1024
   450 2011/10/03 11:24:41 [debug] 8111#0: *46 posix_memalign:
0000000000F3E060:4096 @16
   451 2011/10/03 11:24:41 [debug] 8111#0: *46 http process request line
   452 2011/10/03 11:24:41 [debug] 8111#0: *46 recv: fd:7 1024 of 1024
   453 2011/10/03 11:24:41 [debug] 8111#0: *46 http request line: "POST
/rspool/?a=b&c=d HTTP/1.0"
   454 2011/10/03 11:24:41 [debug] 8111#0: *46 http uri: "/rspool/"
   455 2011/10/03 11:24:41 [debug] 8111#0: *46 http args: "a=b&c=d"
   456 2011/10/03 11:24:41 [debug] 8111#0: *46 http exten: ""
   457 2011/10/03 11:24:41 [debug] 8111#0: *46 http process request header
line
   458 2011/10/03 11:24:41 [debug] 8111#0: *46 http header: "Host:
209.114.46.109"
   459 2011/10/03 11:24:41 [debug] 8111#0: *46 http header: "X-Real-IP:
98.173.193.68"
   460 2011/10/03 11:24:41 [debug] 8111#0: *46 http header:
"X-Forwarded-For: 98.173.193.68"
   461 2011/10/03 11:24:41 [debug] 8111#0: *46 http header: "Connection:
close"
   462 2011/10/03 11:24:41 [debug] 8111#0: *46 http header:
"Accept-Encoding: identity"
   463 2011/10/03 11:24:41 [debug] 8111#0: *46 http header: "Content-Length:
51200"
   464 2011/10/03 11:24:41 [debug] 8111#0: *46 http header: "Session-ID:
14367198"
   465 2011/10/03 11:24:41 [debug] 8111#0: *46 http header:
"X-Content-Range: bytes 153597-204796/210000"
   466 2011/10/03 11:24:41 [debug] 8111#0: *46 http header: "Content-Type:
text/plain"
   467 2011/10/03 11:24:41 [debug] 8111#0: *46 http header:
"Content-Disposition: attachment; filename="ric.log""
   468 2011/10/03 11:24:41 [debug] 8111#0: *46 http header done
   469 2011/10/03 11:24:41 [debug] 8111#0: *46 event timer del: 7:
1317666341316
   470 2011/10/03 11:24:41 [debug] 8111#0: *46 generic phase: 0
   471 2011/10/03 11:24:41 [debug] 8111#0: *46 rewrite phase: 1
   472 2011/10/03 11:24:41 [debug] 8111#0: *46 test location: "/rspool/"
   473 2011/10/03 11:24:41 [debug] 8111#0: *46 using configuration
"/rspool/"
   474 2011/10/03 11:24:41 [debug] 8111#0: *46 http cl:51200 max:52428800
   475 2011/10/03 11:24:41 [debug] 8111#0: *46 rewrite phase: 3
   476 2011/10/03 11:24:41 [debug] 8111#0: *46 post rewrite phase: 4
   477 2011/10/03 11:24:41 [debug] 8111#0: *46 generic phase: 5
   478 2011/10/03 11:24:41 [debug] 8111#0: *46 generic phase: 6
   479 2011/10/03 11:24:41 [debug] 8111#0: *46 generic phase: 7
   480 2011/10/03 11:24:41 [debug] 8111#0: *46 access phase: 8
   481 2011/10/03 11:24:41 [debug] 8111#0: *46 access phase: 9
   482 2011/10/03 11:24:41 [debug] 8111#0: *46 post access phase: 10
   483 2011/10/03 11:24:41 [debug] 8111#0: *46 session id 14367198
   484 2011/10/03 11:24:41 [debug] 8111#0: *46 partial content, range
153597-204796/210000
   485 2011/10/03 11:24:41 [debug] 8111#0: *46 posix_memalign:
0000000000F34400:4096 @16
   486 2011/10/03 11:24:41 [debug] 8111#0: *46 malloc: 0000000000F35410:4096
   487 2011/10/03 11:24:41 [debug] 8111#0: *46 http client request body
preread 695
   488 2011/10/03 11:24:41 [debug] 8111#0: *46 malloc: 0000000000F36420:8192
   489 2011/10/03 11:24:41 [debug] 8111#0: *46 http read client request body
   490 2011/10/03 11:24:41 [debug] 8111#0: *46 recv: fd:7 8192 of 8192
   491 2011/10/03 11:24:41 [debug] 8111#0: *46 http client request body recv
8192
   492 2011/10/03 11:24:41 [debug] 8111#0: *46 add cleanup: 0000000000F347D8
   493 2011/10/03 11:24:41 [debug] 8111#0: *46 hashed path:
/var/lib/nginx/resumable_download/8/14367198
   494 2011/10/03 11:24:41 [debug] 8111#0: *46 hashed path of state file:
/var/lib/nginx/resumable_download/8/14367198.state
   495 2011/10/03 11:24:41 [debug] 8111#0: *46 http script var: ""
   496 2011/10/03 11:24:41 [debug] 8111#0: *46 http script copy: "_name"
   497 2011/10/03 11:24:41 [debug] 8111#0: *46 http script var: "ric.log"
   498 2011/10/03 11:24:41 [debug] 8111#0: *46 http script var: ""
   499 2011/10/03 11:24:41 [debug] 8111#0: *46 http script copy:
"_content_type"
   500 2011/10/03 11:24:41 [debug] 8111#0: *46 http script var: "text/plain"
   501 2011/10/03 11:24:41 [debug] 8111#0: *46 posix_memalign:
0000000000F62730:4096 @16
   502 2011/10/03 11:24:41 [debug] 8111#0: *46 http script var: ""
   503 2011/10/03 11:24:41 [debug] 8111#0: *46 http script copy: "_path"
   504 2011/10/03 11:24:41 [debug] 8111#0: *46 http script var:
"/var/lib/nginx/resumable_download/8/14367198"
   505 2011/10/03 11:24:41 [info] 8111#0: *46 started uploading part
153597-204796/210000 of file "ric.log" to
"/var/lib/nginx/resumable_download/8/14367198" (field "", content type
"text/plain"), client: 10.178.51.115, server: account.nutricateonline.com,
request: "POST /rspool/?a=b&c=d HTTP/1.0", host: "209.114.46.109"
   506 2011/10/03 11:24:41 [debug] 8111#0: *46 write: 14, 0000000000F3DD99,
695, 153597
   507 2011/10/03 11:24:41 [debug] 8111#0: *46 write: 14, 0000000000F36420,
8192, 154292
   508 2011/10/03 11:24:41 [debug] 8111#0: *46 recv: fd:7 8192 of 8192
   509 2011/10/03 11:24:41 [debug] 8111#0: *46 http client request body recv
8192
   510 2011/10/03 11:24:41 [debug] 8111#0: *46 write: 14, 0000000000F36420,
8192, 162484
   511 2011/10/03 11:24:41 [debug] 8111#0: *46 recv: fd:7 8192 of 8192
   512 2011/10/03 11:24:41 [debug] 8111#0: *46 http client request body recv
8192
   513 2011/10/03 11:24:41 [debug] 8111#0: *46 write: 14, 0000000000F36420,
8192, 170676
   514 2011/10/03 11:24:41 [debug] 8111#0: *46 recv: fd:7 8192 of 8192
   515 2011/10/03 11:24:41 [debug] 8111#0: *46 http client request body recv
8192
   516 2011/10/03 11:24:41 [debug] 8111#0: *46 write: 14, 0000000000F36420,
8192, 178868
   517 2011/10/03 11:24:41 [debug] 8111#0: *46 recv: fd:7 8192 of 8192
   518 2011/10/03 11:24:41 [debug] 8111#0: *46 http client request body recv
8192
   519 2011/10/03 11:24:41 [debug] 8111#0: *46 write: 14, 0000000000F36420,
8192, 187060
   520 2011/10/03 11:24:41 [debug] 8111#0: *46 recv: fd:7 8192 of 8192
   521 2011/10/03 11:24:41 [debug] 8111#0: *46 http client request body recv
8192
   522 2011/10/03 11:24:41 [debug] 8111#0: *46 write: 14, 0000000000F36420,
8192, 195252
   523 2011/10/03 11:24:41 [debug] 8111#0: *46 recv: fd:7 1353 of 1353
   524 2011/10/03 11:24:41 [debug] 8111#0: *46 http client request body recv
1353
   525 2011/10/03 11:24:41 [debug] 8111#0: *46 http client request body rest
0
   526 2011/10/03 11:24:41 [debug] 8111#0: *46 write: 14, 0000000000F36420,
1353, 203444
   527 2011/10/03 11:24:41 [debug] 8111#0: *46 read: 14, 0000000000F34C8F,
16, 0
   528 2011/10/03 11:24:41 [debug] 8111#0: *46 a 0-204796/210000
   529 2011/10/03 11:24:41 [debug] 8111#0: *46 write: 14, 0000000000F34850,
16, 0
   530 2011/10/03 11:24:41 [info] 8111#0: *46 finished uploading part
153597-204796/210000 of a file "ric.log" to
"/var/lib/nginx/resumable_download/8/14367198", client: 10.178.51.115,
server: account.nutricateonline.com, request: "POST /rspool/?a=b&c=d
HTTP/1.0", host: "209.114.46.109"
   531 2011/10/03 11:24:41 [debug] 8111#0: *46 xslt filter header
   532 2011/10/03 11:24:41 [debug] 8111#0: *46 HTTP/1.1 201 Created
   533 Server: nginx/1.0.6
   534 Date: Mon, 03 Oct 2011 18:24:41 GMT
   535 Content-Length: 15
   536 Connection: close
   537 Range: 0-204796/210000
   538
   539 2011/10/03 11:24:41 [debug] 8111#0: *46 write new buf t:1 f:0
0000000000F62A70, pos 0000000000F62A70, size: 145 file: 0, size: 0
   540 2011/10/03 11:24:41 [debug] 8111#0: *46 http write filter: l:0 f:0
s:145
   541 2011/10/03 11:24:41 [debug] 8111#0: *46 http output filter
"/rspool/?a=b&c=d"
   542 2011/10/03 11:24:41 [debug] 8111#0: *46 http copy filter:
"/rspool/?a=b&c=d"
   543 2011/10/03 11:24:41 [debug] 8111#0: *46 image filter
   544 2011/10/03 11:24:41 [debug] 8111#0: *46 xslt filter body
   545 2011/10/03 11:24:41 [debug] 8111#0: *46 http postpone filter
"/rspool/?a=b&c=d" 00007FFF96ECBAE0
   546 2011/10/03 11:24:41 [debug] 8111#0: *46 write old buf t:1 f:0
0000000000F62A70, pos 0000000000F62A70, size: 145 file: 0, size: 0
   547 2011/10/03 11:24:41 [debug] 8111#0: *46 write new buf t:0 f:0
0000000000F34628, pos 0000000000F34628, size: 15 file: 0, size: 0
   548 2011/10/03 11:24:41 [debug] 8111#0: *46 http write filter: l:1 f:1
s:160
   549 2011/10/03 11:24:41 [debug] 8111#0: *46 http write filter limit 0
   550 2011/10/03 11:24:41 [debug] 8111#0: *46 writev: 160
   551 2011/10/03 11:24:41 [debug] 8111#0: *46 http write filter
0000000000000000
   552 2011/10/03 11:24:41 [debug] 8111#0: *46 http copy filter: 0
"/rspool/?a=b&c=d"
   553 2011/10/03 11:24:41 [debug] 8111#0: *46 http finalize request: 0,
"/rspool/?a=b&c=d" a:1, c:2
   554 2011/10/03 11:24:41 [debug] 8111#0: *46 http request count:2 blk:0
   555 2011/10/03 11:24:41 [debug] 8111#0: *46 http finalize request: -4,
"/rspool/?a=b&c=d" a:1, c:1
   556 2011/10/03 11:24:41 [debug] 8111#0: *46 event timer add: 7:
5000:1317666286316
   557 2011/10/03 11:24:41 [debug] 8111#0: *46 http lingering close handler
   558 2011/10/03 11:24:41 [debug] 8111#0: *46 recv: fd:7 -1 of 4096
   559 2011/10/03 11:24:41 [debug] 8111#0: *46 recv() not ready (11:
Resource temporarily unavailable)
   560 2011/10/03 11:24:41 [debug] 8111#0: *46 lingering read: -2
   561 2011/10/03 11:24:41 [debug] 8111#0: *46 event timer: 7, old:
1317666286316, new: 1317666286316
   562 2011/10/03 11:24:41 [debug] 8111#0: *46 post event 00007F25388370E0
   563 2011/10/03 11:24:41 [debug] 8111#0: *46 delete posted event
00007F25388370E0
   564 2011/10/03 11:24:41 [debug] 8111#0: *46 http lingering close handler
   565 2011/10/03 11:24:41 [debug] 8111#0: *46 recv: fd:7 0 of 4096
   566 2011/10/03 11:24:41 [debug] 8111#0: *46 lingering read: 0
   567 2011/10/03 11:24:41 [debug] 8111#0: *46 http request count:1 blk:0
   568 2011/10/03 11:24:41 [debug] 8111#0: *46 http close request
   569 2011/10/03 11:24:41 [debug] 8111#0: *46 http log handler
   570 2011/10/03 11:24:41 [debug] 8111#0: *46 run cleanup: 0000000000F347D8
   571 2011/10/03 11:24:41 [debug] 8111#0: *46 free: 0000000000F36420
   572 2011/10/03 11:24:41 [debug] 8111#0: *46 free: 0000000000F35410
   573 2011/10/03 11:24:41 [debug] 8111#0: *46 free: 0000000000F3E060,
unused: 0
   574 2011/10/03 11:24:41 [debug] 8111#0: *46 free: 0000000000F34400,
unused: 0
   575 2011/10/03 11:24:41 [debug] 8111#0: *46 free: 0000000000F62730,
unused: 2843
   576 2011/10/03 11:24:41 [debug] 8111#0: *46 close http connection: 7
   577 2011/10/03 11:24:41 [debug] 8111#0: *46 event timer del: 7:
1317666286316
   578 2011/10/03 11:24:41 [debug] 8111#0: *46 reusable connection: 0
   579 2011/10/03 11:24:41 [debug] 8111#0: *46 free: 0000000000F3DC50
   580 2011/10/03 11:24:41 [debug] 8111#0: *46 free: 0000000000F3D730
   581 2011/10/03 11:24:41 [debug] 8111#0: *46 free: 0000000000F2F8A0,
unused: 8
   582 2011/10/03 11:24:41 [debug] 8111#0: *46 free: 0000000000F5CCC0,
unused: 128
   583 2011/10/03 11:24:41 [debug] 8111#0: post event 00007F2538837010
   584 2011/10/03 11:24:41 [debug] 8111#0: delete posted event
00007F2538837010
   585 2011/10/03 11:24:41 [debug] 8111#0: accept on 0.0.0.0:80, ready: 0
   586 2011/10/03 11:24:41 [debug] 8111#0: posix_memalign:
0000000000F2F8A0:256 @16
   587 2011/10/03 11:24:41 [debug] 8111#0: *47 accept: 10.178.51.115 fd:7
   588 2011/10/03 11:24:41 [debug] 8111#0: *47 event timer add: 7:
60000:1317666341381
   589 2011/10/03 11:24:41 [debug] 8111#0: *47 epoll add event: fd:7 op:1
ev:80000001
   590 2011/10/03 11:24:41 [debug] 8111#0: *47 post event 00007F25388370E0
   591 2011/10/03 11:24:41 [debug] 8111#0: *47 delete posted event
00007F25388370E0
   592 2011/10/03 11:24:41 [debug] 8111#0: *47 malloc: 0000000000F3D730:1296
   593 2011/10/03 11:24:41 [debug] 8111#0: *47 posix_memalign:
0000000000F5CCC0:256 @16
   594 2011/10/03 11:24:41 [debug] 8111#0: *47 malloc: 0000000000F3DC50:1024
   595 2011/10/03 11:24:41 [debug] 8111#0: *47 posix_memalign:
0000000000F3E060:4096 @16
   596 2011/10/03 11:24:41 [debug] 8111#0: *47 http process request line
   597 2011/10/03 11:24:41 [debug] 8111#0: *47 recv: fd:7 1024 of 1024
   598 2011/10/03 11:24:41 [debug] 8111#0: *47 http request line: "POST
/rspool/?a=b&c=d HTTP/1.0"
   599 2011/10/03 11:24:41 [debug] 8111#0: *47 http uri: "/rspool/"
   600 2011/10/03 11:24:41 [debug] 8111#0: *47 http args: "a=b&c=d"
   601 2011/10/03 11:24:41 [debug] 8111#0: *47 http exten: ""
   602 2011/10/03 11:24:41 [debug] 8111#0: *47 http process request header
line
   603 2011/10/03 11:24:41 [debug] 8111#0: *47 http header: "Host:
209.114.46.109"
   604 2011/10/03 11:24:41 [debug] 8111#0: *47 http header: "X-Real-IP:
98.173.193.68"
   605 2011/10/03 11:24:41 [debug] 8111#0: *47 http header:
"X-Forwarded-For: 98.173.193.68"
   606 2011/10/03 11:24:41 [debug] 8111#0: *47 http header: "Connection:
close"
   607 2011/10/03 11:24:41 [debug] 8111#0: *47 http header:
"Accept-Encoding: identity"
   608 2011/10/03 11:24:41 [debug] 8111#0: *47 http header: "Content-Length:
5204"
   609 2011/10/03 11:24:41 [debug] 8111#0: *47 http header: "Session-ID:
14367198"
   610 2011/10/03 11:24:41 [debug] 8111#0: *47 http header:
"X-Content-Range: bytes 204796-210000/210000"
   611 2011/10/03 11:24:41 [debug] 8111#0: *47 http header: "Content-Type:
text/plain"
   612 2011/10/03 11:24:41 [debug] 8111#0: *47 http header:
"Content-Disposition: attachment; filename="ric.log""
   613 2011/10/03 11:24:41 [debug] 8111#0: *47 http header done
   614 2011/10/03 11:24:41 [debug] 8111#0: *47 event timer del: 7:
1317666341381
   615 2011/10/03 11:24:41 [debug] 8111#0: *47 generic phase: 0
   616 2011/10/03 11:24:41 [debug] 8111#0: *47 rewrite phase: 1
   617 2011/10/03 11:24:41 [debug] 8111#0: *47 test location: "/rspool/"
   618 2011/10/03 11:24:41 [debug] 8111#0: *47 using configuration
"/rspool/"
   619 2011/10/03 11:24:41 [debug] 8111#0: *47 http cl:5204 max:52428800
   620 2011/10/03 11:24:41 [debug] 8111#0: *47 rewrite phase: 3
   621 2011/10/03 11:24:41 [debug] 8111#0: *47 post rewrite phase: 4
   622 2011/10/03 11:24:41 [debug] 8111#0: *47 generic phase: 5
   623 2011/10/03 11:24:41 [debug] 8111#0: *47 generic phase: 6
   624 2011/10/03 11:24:41 [debug] 8111#0: *47 generic phase: 7
   625 2011/10/03 11:24:41 [debug] 8111#0: *47 access phase: 8
   626 2011/10/03 11:24:41 [debug] 8111#0: *47 access phase: 9
   627 2011/10/03 11:24:41 [debug] 8111#0: *47 post access phase: 10
   628 2011/10/03 11:24:41 [debug] 8111#0: *47 session id 14367198
   629 2011/10/03 11:24:41 [debug] 8111#0: *47 partial content, range
204796-210000/210000
   630 2011/10/03 11:24:41 [debug] 8111#0: *47 posix_memalign:
0000000000F34400:4096 @16
   631 2011/10/03 11:24:41 [debug] 8111#0: *47 malloc: 0000000000F35410:4096
   632 2011/10/03 11:24:41 [debug] 8111#0: *47 http client request body
preread 696
   633 2011/10/03 11:24:41 [debug] 8111#0: *47 malloc: 0000000000F36420:4508
   634 2011/10/03 11:24:41 [debug] 8111#0: *47 http read client request body
   635 2011/10/03 11:24:41 [debug] 8111#0: *47 recv: fd:7 4508 of 4508
   636 2011/10/03 11:24:41 [debug] 8111#0: *47 http client request body recv
4508
   637 2011/10/03 11:24:41 [debug] 8111#0: *47 http client request body rest
0
   638 2011/10/03 11:24:41 [debug] 8111#0: *47 add cleanup: 0000000000F347D8
   639 2011/10/03 11:24:41 [debug] 8111#0: *47 hashed path:
/var/lib/nginx/resumable_download/8/14367198
   640 2011/10/03 11:24:41 [debug] 8111#0: *47 hashed path of state file:
/var/lib/nginx/resumable_download/8/14367198.state
   641 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: ""
   642 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy: "_name"
   643 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "ric.log"
   644 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: ""
   645 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"_content_type"
   646 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "text/plain"
   647 2011/10/03 11:24:41 [debug] 8111#0: *47 posix_memalign:
0000000000F375D0:4096 @16
   648 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: ""
   649 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy: "_path"
   650 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var:
"/var/lib/nginx/resumable_download/8/14367198"
   651 2011/10/03 11:24:41 [info] 8111#0: *47 started uploading part
204796-210000/210000 of file "ric.log" to
"/var/lib/nginx/resumable_download/8/14367198" (field "", content type
"text/plain"), client: 10.178.51.115, server: account.nutricateonline.com,
request: "POST /rspool/?a=b&c=d HTTP/1.0", host: "209.114.46.109"
   652 2011/10/03 11:24:41 [debug] 8111#0: *47 write: 14, 0000000000F3DD98,
696, 204796
   653 2011/10/03 11:24:41 [debug] 8111#0: *47 write: 14, 0000000000F36420,
4508, 205492
   654 2011/10/03 11:24:41 [error] 8111#0: *47 file offset at the end of a
part 210000 does not match the end specified range 204796-210000/210000,
client: 10.178.51.115, server: account.nutricateonline.com, request: "POST
/rspool/?a=b&c=d HTTP/1.0", host: "209.114.46.109"
   655 2011/10/03 11:24:41 [debug] 8111#0: *47 test location:
"@rspool_upload"
   656 2011/10/03 11:24:41 [debug] 8111#0: *47 using location:
@rspool_upload "/rspool/?a=b&c=d"
   657 2011/10/03 11:24:41 [debug] 8111#0: *47 rewrite phase: 3
   658 2011/10/03 11:24:41 [debug] 8111#0: *47 post rewrite phase: 4
   659 2011/10/03 11:24:41 [debug] 8111#0: *47 generic phase: 5
   660 2011/10/03 11:24:41 [debug] 8111#0: *47 generic phase: 6
   661 2011/10/03 11:24:41 [debug] 8111#0: *47 generic phase: 7
   662 2011/10/03 11:24:41 [debug] 8111#0: *47 access phase: 8
   663 2011/10/03 11:24:41 [debug] 8111#0: *47 access phase: 9
   664 2011/10/03 11:24:41 [debug] 8111#0: *47 post access phase: 10
   665 2011/10/03 11:24:41 [debug] 8111#0: *47 http init upstream, client
timer: 0
   666 2011/10/03 11:24:41 [debug] 8111#0: *47 epoll add event: fd:7 op:3
ev:80000005
   667 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"QUERY_STRING"
   668 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "a=b&c=d"
   669 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "QUERY_STRING:
a=b&c=d"
   670 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"REQUEST_METHOD"
   671 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "POST"
   672 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"REQUEST_METHOD: POST"
   673 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"CONTENT_TYPE"
   674 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var:
"multipart/form-data; boundary=00000000000000000040"
   675 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "CONTENT_TYPE:
multipart/form-data; boundary=00000000000000000040"
   676 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"CONTENT_LENGTH"
   677 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "28"
   678 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"CONTENT_LENGTH: 28"
   679 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"SCRIPT_FILENAME"
   680 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "/rspool/"
   681 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"SCRIPT_FILENAME: /rspool/"
   682 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"SCRIPT_NAME"
   683 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "SCRIPT_NAME:
"
   684 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"REQUEST_URI"
   685 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var:
"/rspool/?a=b&c=d"
   686 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "REQUEST_URI:
/rspool/?a=b&c=d"
   687 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"DOCUMENT_URI"
   688 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "/rspool/"
   689 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "DOCUMENT_URI:
/rspool/"
   690 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"DOCUMENT_ROOT"
   691 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var:
"/nutricate/static"
   692 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"DOCUMENT_ROOT: /nutricate/static"
   693 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"SERVER_PROTOCOL"
   694 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "HTTP/1.0"
   695 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"SERVER_PROTOCOL: HTTP/1.0"
   696 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"GATEWAY_INTERFACE"
   697 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy: "CGI/1.1"
   698 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"GATEWAY_INTERFACE: CGI/1.1"
   699 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"SERVER_SOFTWARE"
   700 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy: "nginx/"
   701 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "1.0.6"
   702 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"SERVER_SOFTWARE: nginx/1.0.6"
   703 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"REMOTE_ADDR"
   704 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var:
"10.178.51.115"
   705 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "REMOTE_ADDR:
10.178.51.115"
   706 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"REMOTE_PORT"
   707 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "60461"
   708 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "REMOTE_PORT:
60461"
   709 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"SERVER_ADDR"
   710 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var:
"10.178.34.181"
   711 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "SERVER_ADDR:
10.178.34.181"
   712 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"SERVER_PORT"
   713 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "80"
   714 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "SERVER_PORT:
80"
   715 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"SERVER_NAME"
   716 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "
account.nutricateonline.com"
   717 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "SERVER_NAME:
account.nutricateonline.com"
   718 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy:
"REDIRECT_STATUS"
   719 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy: "200"
   720 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"REDIRECT_STATUS: 200"
   721 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy: "FCGI"
   722 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "
account.nutricateonline.com"
   723 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "FCGI:
account.nutricateonline.com"
   724 2011/10/03 11:24:41 [debug] 8111#0: *47 http script copy: "PATH_INFO"
   725 2011/10/03 11:24:41 [debug] 8111#0: *47 http script var: "/rspool/"
   726 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "PATH_INFO:
/rspool/"
   727 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param: "HTTP_HOST:
209.114.46.109"
   728 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"HTTP_X_REAL_IP: 98.173.193.68"
   729 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"HTTP_X_FORWARDED_FOR: 98.173.193.68"
   730 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"HTTP_CONNECTION: close"
   731 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"HTTP_ACCEPT_ENCODING: identity"
   732 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"HTTP_CONTENT_LENGTH: 28"
   733 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"HTTP_SESSION_ID: 14367198"
   734 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"HTTP_X_CONTENT_RANGE: bytes 204796-210000/210000"
   735 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"HTTP_CONTENT_TYPE: multipart/form-data; boundary=00000000000000000040"
   736 2011/10/03 11:24:41 [debug] 8111#0: *47 fastcgi param:
"HTTP_CONTENT_DISPOSITION: attachment; filename="ric.log""
   737 2011/10/03 11:24:41 [debug] 8111#0: *47 http cleanup add:
0000000000F38418
   738 2011/10/03 11:24:41 [debug] 8111#0: *47 get rr peer, try: 1
   739 2011/10/03 11:24:41 [debug] 8111#0: *47 socket 14
   740 2011/10/03 11:24:41 [debug] 8111#0: *47 epoll add connection: fd:14
ev:80000005
   741 2011/10/03 11:24:41 [debug] 8111#0: *47 connect to 127.0.0.1:10000,
fd:14 #48
   742 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream connect: -2
   743 2011/10/03 11:24:41 [debug] 8111#0: *47 event timer add: 14:
60000:1317666341381
   744 2011/10/03 11:24:41 [debug] 8111#0: *47 http finalize request: -4,
"/rspool/?a=b&c=d" a:1, c:3
   745 2011/10/03 11:24:41 [debug] 8111#0: *47 http request count:3 blk:0
   746 2011/10/03 11:24:41 [debug] 8111#0: *47 http finalize request: -4,
"/rspool/?a=b&c=d" a:1, c:2
   747 2011/10/03 11:24:41 [debug] 8111#0: *47 http request count:2 blk:0
   748 2011/10/03 11:24:41 [debug] 8111#0: *47 post event 00007F25388020E0
   749 2011/10/03 11:24:41 [debug] 8111#0: *47 post event 00007F2538802148
   750 2011/10/03 11:24:41 [debug] 8111#0: *47 delete posted event
00007F2538802148
   751 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream request:
"/rspool/?a=b&c=d"
   752 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream send request
handler
   753 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream send request
   754 2011/10/03 11:24:41 [debug] 8111#0: *47 chain writer buf fl:0 s:928
   755 2011/10/03 11:24:41 [debug] 8111#0: *47 chain writer buf fl:0 s:28
   756 2011/10/03 11:24:41 [debug] 8111#0: *47 chain writer buf fl:0 s:12
   757 2011/10/03 11:24:41 [debug] 8111#0: *47 chain writer in:
0000000000F38480
   758 2011/10/03 11:24:41 [debug] 8111#0: *47 writev: 968
   759 2011/10/03 11:24:41 [debug] 8111#0: *47 chain writer out:
0000000000000000
   760 2011/10/03 11:24:41 [debug] 8111#0: *47 event timer del: 14:
1317666341381
   761 2011/10/03 11:24:41 [debug] 8111#0: *47 event timer add: 14:
60000:1317666341383
   762 2011/10/03 11:24:41 [debug] 8111#0: *47 delete posted event
00007F25388020E0
   763 2011/10/03 11:24:41 [debug] 8111#0: *47 http run request:
"/rspool/?a=b&c=d"
   764 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream check client,
write event:1, "/rspool/"
   765 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream recv(): -1 (11:
Resource temporarily unavailable)
   766 2011/10/03 11:24:41 [debug] 8111#0: *47 post event 00007F2538837148
   767 2011/10/03 11:24:41 [debug] 8111#0: *47 post event 00007F2538802148
   768 2011/10/03 11:24:41 [debug] 8111#0: *47 delete posted event
00007F2538802148
   769 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream request:
"/rspool/?a=b&c=d"
   770 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream dummy handler
   771 2011/10/03 11:24:41 [debug] 8111#0: *47 delete posted event
00007F2538837148
   772 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream request:
"/rspool/?a=b&c=d"
   773 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream process header
   774 2011/10/03 11:24:41 [debug] 8111#0: *47 malloc: 0000000000F62730:4096
   775 2011/10/03 11:24:41 [debug] 8111#0: *47 posix_memalign:
0000000000F63740:4096 @16
   776 2011/10/03 11:24:41 [debug] 8111#0: *47 recv: fd:14 96 of 4096
   777 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 01
   778 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 06
   779 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   780 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 01
   781 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   782 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 3A
   783 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 06
   784 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   785 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record length:
58
   786 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi parser: 0
   787 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi header: "Status:
200 OK"
   788 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi parser: 0
   789 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi header:
"Content-Type: text/html; charset=utf-8"
   790 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi parser: 1
   791 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi header done
   792 2011/10/03 11:24:41 [debug] 8111#0: *47 xslt filter header
   793 2011/10/03 11:24:41 [debug] 8111#0: *47 HTTP/1.1 200 OK
   794 Server: nginx/1.0.6
   795 Date: Mon, 03 Oct 2011 18:24:41 GMT
   796 Content-Type: text/html; charset=utf-8
   797 Connection: close
   798
   799 2011/10/03 11:24:41 [debug] 8111#0: *47 write new buf t:1 f:0
0000000000F638E0, pos 0000000000F638E0, size: 136 file: 0, size: 0
   800 2011/10/03 11:24:41 [debug] 8111#0: *47 http write filter: l:0 f:0
s:136
   801 2011/10/03 11:24:41 [debug] 8111#0: *47 http cacheable: 0
   802 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream process
upstream
   803 2011/10/03 11:24:41 [debug] 8111#0: *47 pipe read upstream: 1
   804 2011/10/03 11:24:41 [debug] 8111#0: *47 pipe preread: 30
   805 2011/10/03 11:24:41 [debug] 8111#0: *47 readv: 1:4000
   806 2011/10/03 11:24:41 [debug] 8111#0: *47 pipe recv chain: 16
   807 2011/10/03 11:24:41 [debug] 8111#0: *47 readv: 1:3984
   808 2011/10/03 11:24:41 [debug] 8111#0: *47 pipe recv chain: 0
   809 2011/10/03 11:24:41 [debug] 8111#0: *47 pipe buf free s:0 t:1 f:0
0000000000F62730, pos 0000000000F62772, size: 46 file: 0, size: 0
   810 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 01
   811 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 06
   812 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   813 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 01
   814 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   815 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 08
   816 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   817 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   818 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record length: 8
   819 2011/10/03 11:24:41 [debug] 8111#0: *47 input buf #0 0000000000F62780
   820 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 01
   821 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 06
   822 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   823 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 01
   824 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   825 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   826 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   827 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   828 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record length: 0
   829 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi closed stdout
   830 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 01
   831 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 03
   832 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   833 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 01
   834 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   835 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 08
   836 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   837 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record byte: 00
   838 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi record length: 8
   839 2011/10/03 11:24:41 [debug] 8111#0: *47 http fastcgi sent end request
   840 2011/10/03 11:24:41 [debug] 8111#0: *47 input buf 0000000000F62780 8
   841 2011/10/03 11:24:41 [debug] 8111#0: *47 pipe write downstream: 1
   842 2011/10/03 11:24:41 [debug] 8111#0: *47 pipe write downstream flush
in
   843 2011/10/03 11:24:41 [debug] 8111#0: *47 http output filter
"/rspool/?a=b&c=d"
   844 2011/10/03 11:24:41 [debug] 8111#0: *47 http copy filter:
"/rspool/?a=b&c=d"
   845 2011/10/03 11:24:41 [debug] 8111#0: *47 image filter
   846 2011/10/03 11:24:41 [debug] 8111#0: *47 xslt filter body
   847 2011/10/03 11:24:41 [debug] 8111#0: *47 http postpone filter
"/rspool/?a=b&c=d" 0000000000F63A68
   848 2011/10/03 11:24:41 [debug] 8111#0: *47 write old buf t:1 f:0
0000000000F638E0, pos 0000000000F638E0, size: 136 file: 0, size: 0
   849 2011/10/03 11:24:41 [debug] 8111#0: *47 write new buf t:1 f:0
0000000000F62730, pos 0000000000F62780, size: 8 file: 0, size: 0
   850 2011/10/03 11:24:41 [debug] 8111#0: *47 http write filter: l:0 f:0
s:144
   851 2011/10/03 11:24:41 [debug] 8111#0: *47 http copy filter: 0
"/rspool/?a=b&c=d"
   852 2011/10/03 11:24:41 [debug] 8111#0: *47 pipe write downstream done
   853 2011/10/03 11:24:41 [debug] 8111#0: *47 event timer: 14, old:
1317666341383, new: 1317666341450
   854 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream exit:
0000000000000000
   855 2011/10/03 11:24:41 [debug] 8111#0: *47 finalize http upstream
request: 0
   856 2011/10/03 11:24:41 [debug] 8111#0: *47 finalize http fastcgi request
   857 2011/10/03 11:24:41 [debug] 8111#0: *47 free rr peer 1 0
   858 2011/10/03 11:24:41 [debug] 8111#0: *47 close http upstream
connection: 14
   859 2011/10/03 11:24:41 [debug] 8111#0: *47 event timer del: 14:
1317666341383
   860 2011/10/03 11:24:41 [debug] 8111#0: *47 reusable connection: 0
   861 2011/10/03 11:24:41 [debug] 8111#0: *47 http upstream temp fd: -1
   862 2011/10/03 11:24:41 [debug] 8111#0: *47 http output filter
"/rspool/?a=b&c=d"
   863 2011/10/03 11:24:41 [debug] 8111#0: *47 http copy filter:
"/rspool/?a=b&c=d"
   864 2011/10/03 11:24:41 [debug] 8111#0: *47 image filter
   865 2011/10/03 11:24:41 [debug] 8111#0: *47 xslt filter body
   866 2011/10/03 11:24:41 [debug] 8111#0: *47 http postpone filter
"/rspool/?a=b&c=d" 00007FFF96ECBB50
   867 2011/10/03 11:24:41 [debug] 8111#0: *47 write old buf t:1 f:0
0000000000F638E0, pos 0000000000F638E0, size: 136 file: 0, size: 0
   868 2011/10/03 11:24:41 [debug] 8111#0: *47 write old buf t:1 f:0
0000000000F62730, pos 0000000000F62780, size: 8 file: 0, size: 0
   869 2011/10/03 11:24:41 [debug] 8111#0: *47 write new buf t:0 f:0
0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
   870 2011/10/03 11:24:41 [debug] 8111#0: *47 http write filter: l:1 f:0
s:144
   871 2011/10/03 11:24:41 [debug] 8111#0: *47 http write filter limit 0
   872 2011/10/03 11:24:41 [debug] 8111#0: *47 writev: 144
   873 2011/10/03 11:24:41 [debug] 8111#0: *47 http write filter
0000000000000000
   874 2011/10/03 11:24:41 [debug] 8111#0: *47 http copy filter: 0
"/rspool/?a=b&c=d"
   875 2011/10/03 11:24:41 [debug] 8111#0: *47 http finalize request: 0,
"/rspool/?a=b&c=d" a:1, c:1
   876 2011/10/03 11:24:41 [debug] 8111#0: *47 event timer add: 7:
5000:1317666286450
   877 2011/10/03 11:24:41 [debug] 8111#0: *47 http lingering close handler
   878 2011/10/03 11:24:41 [debug] 8111#0: *47 recv: fd:7 -1 of 4096
   879 2011/10/03 11:24:41 [debug] 8111#0: *47 recv() not ready (11:
Resource temporarily unavailable)
   880 2011/10/03 11:24:41 [debug] 8111#0: *47 lingering read: -2
   881 2011/10/03 11:24:41 [debug] 8111#0: *47 event timer: 7, old:
1317666286450, new: 1317666286450
   882 2011/10/03 11:24:41 [debug] 8111#0: *47 post event 00007F25388370E0
   883 2011/10/03 11:24:41 [debug] 8111#0: *47 delete posted event
00007F25388370E0
   884 2011/10/03 11:24:41 [debug] 8111#0: *47 http lingering close handler
   885 2011/10/03 11:24:41 [debug] 8111#0: *47 recv: fd:7 0 of 4096
   886 2011/10/03 11:24:41 [debug] 8111#0: *47 lingering read: 0
   887 2011/10/03 11:24:41 [debug] 8111#0: *47 http request count:1 blk:0
   888 2011/10/03 11:24:41 [debug] 8111#0: *47 http close request
   889 2011/10/03 11:24:41 [debug] 8111#0: *47 http log handler
   890 2011/10/03 11:24:41 [debug] 8111#0: *47 run cleanup: 0000000000F347D8
   891 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F62730
   892 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F36420
   893 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F35410
   894 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F3E060,
unused: 0
   895 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F34400,
unused: 4
   896 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F375D0,
unused: 8
   897 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F63740,
unused: 2939
   898 2011/10/03 11:24:41 [debug] 8111#0: *47 close http connection: 7
   899 2011/10/03 11:24:41 [debug] 8111#0: *47 event timer del: 7:
1317666286450
   900 2011/10/03 11:24:41 [debug] 8111#0: *47 reusable connection: 0
   901 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F3DC50
   902 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F3D730
   903 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F2F8A0,
unused: 8
   904 2011/10/03 11:24:41 [debug] 8111#0: *47 free: 0000000000F5CCC0,
unused: 112


Please note that despite the error message on line 680, the uploaded file is
byte-for-byte identical to the source file. Error message follows:

2011/10/03 10:58:46 [error] 8111#0: *35 file offset at the end of a part
210000 does not match the end specified range 204796-210000/210000, client:
10.178.51.115, server: account.nutricateonline.com, request: "POST
/rspool/?a=b&c=d HTTP/1.0", host: "209.114.46.109"


I am uploading to the following django script. All it currently does is log
it's calling parameters.

def index(request, **kwargs):
    obj = ResumableSpoolerUpload()
    return obj.run(request, **kwargs)

class ResumableSpoolerUpload(View):

    def __init__(self):
        pass

    def run(self, request, **kwargs):
        self.request = request
        print "--------------------------------------------"
        print datetime.now().isoformat()
        print "request.path %r" % request.path
print "kwargs %r" % kwargs
        print "request.GET %r" % request.GET
        print "request.POST %r" % request.POST
        print "request.FILES %r" % request.FILES
        print "request.META %r" % request.META

        return HttpResponse('k-thanks')

When I check the output of the django script (which, right now simply logs
everything it was called with), I do not see any of the upload variables:

2011-10-03T09:48:49.150461
request.path u'/rspool/'
kwargs {'full_url': u'rspool/'}
request.GET <QueryDict: {u'a': [u'b'], u'c': [u'd']}>
request.POST <QueryDict: {}>
request.FILES <MultiValueDict: {}>
request.META {'wsgi.multiprocess': True, 'REDIRECT_STATUS': '200',
'SERVER_SOFTWARE': 'nginx/1.0.6', 'SCRIPT_NAME': u'', 'REQUEST_METHOD':
'POST', 'PATH_INFO': u'/rspool/', 'SERVER_PROTOCOL': 'HTTP/1.0',
'QUERY_STRING': 'a=b&c=d', 'HTTP_X_REAL_IP': '98.173.193.68',
'CONTENT_LENGTH': '28', 'HTTP_CONNECTION': 'close', 'SERVER_NAME': '
account.nutricateonline.com', 'REMOTE_PORT': '36801', 'wsgi.url_scheme':
'http', 'SERVER_PORT': '80', 'SERVER_ADDR': '10.178.34.181',
'DOCUMENT_ROOT': '/nutricate/static', 'HTTP_SESSION_ID': '60833313',
'HTTP_CONTENT_LENGTH': '28', 'SCRIPT_FILENAME': '/rspool/', 'DOCUMENT_URI':
'/rspool/', 'FCGI': 'account.nutricateonline.com', 'wsgi.input':
<flup.server.fcgi_base.InputStream object at 0x33d5690>, 'HTTP_HOST':
'209.114.46.109', 'wsgi.multithread': False, 'HTTP_CONTENT_DISPOSITION':
'attachment; filename="ric.log"', 'HTTP_CONTENT_TYPE': 'multipart/form-data;
boundary=00000000000000000020', 'REQUEST_URI': '/rspool/?a=b&c=d',
'wsgi.version': (1, 0), 'GATEWAY_INTERFACE': 'CGI/1.1',
'HTTP_X_FORWARDED_FOR': '98.173.193.68', 'wsgi.errors':
<flup.server.fcgi_base.TeeOutputStream object at 0x34da290>, 'REMOTE_ADDR':
'10.178.51.115', 'HTTP_X_CONTENT_RANGE': 'bytes 204796-210000/210000',
'wsgi.run_once': False, 'CONTENT_TYPE': 'multipart/form-data;
boundary=00000000000000000020', 'HTTP_ACCEPT_ENCODING': 'identity'}


I think that having request.FILES empty is correct. The two parameters in
the GET dictionary are from the command line (also correct). However I think
the upload parameters should be represented somewhere. Can anyone suggest
next steps?

Andrew
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20111003/2646a259/attachment-0001.html>


More information about the nginx mailing list