не читает тело запроса целиком (recv not ready)

ak nginx-forum на nginx.us
Ср Мар 24 16:57:33 MSK 2010


Задача:
написать простейший модуль, который перехватывает сообщение из тела POST запроса и отправляет в другую систему.

NGINX версии 0.7.65
Модуль:


static void ngx_http_qpidapi_body_handler(ngx_http_request_t *r);

static char *ngx_http_qpidapi(ngx_conf_t *cf, ngx_command_t *cmd, void *conf);

static ngx_command_t ngx_http_qpidapi_commands[] = { { ngx_string("send_message"),
		NGX_HTTP_LOC_CONF | NGX_CONF_NOARGS, ngx_http_qpidapi, 0, 0, NULL },
		ngx_null_command };

static ngx_http_module_t ngx_http_qpidapi_module_ctx = { 
//все НУЛЛ
};

ngx_module_t ngx_http_qpidapi_module = { NGX_MODULE_V1,
&ngx_http_qpidapi_module_ctx, /* module context */
ngx_http_qpidapi_commands, /* module directives */
NGX_HTTP_MODULE, /* module type */
NULL, /* init master */
NULL, /* init module */
NULL, /* init process */
NULL, /* init thread */
NULL, /* exit thread */
NULL, /* exit process */
NULL, /* exit master */
NGX_MODULE_V1_PADDING};

static void ngx_http_qpidapi_body_handler(ngx_http_request_t *r) {
	ngx_log_error(NGX_LOG_ERR,r->connection->log,NGX_EISDIR,"body handler!!!");
	return;
}

static ngx_int_t ngx_http_qpidapi_handler(ngx_http_request_t *r) {
...//переменные

	ngx_log_error(NGX_LOG_ERR,r->connection->log,NGX_EISDIR,"run handler!!!");
	rc = ngx_http_read_client_request_body(r, ngx_http_qpidapi_body_handler);
	if(rc==NGX_AGAIN) {
		ngx_log_error(NGX_LOG_ERR,r->connection->log,NGX_EISDIR,"NGX_AGAIN!!!");
		return NGX_AGAIN;
	}
	ngx_log_error(NGX_LOG_ERR,r->connection->log,NGX_EISDIR,"after handler!!!");

	if (rc >= NGX_HTTP_SPECIAL_RESPONSE) {
		return rc;
	}
	
	//set status SUCCESS
...
}

//-------------------------------------------------------------------------------------------------
static char *
ngx_http_qpidapi(ngx_conf_t *cf, ngx_command_t *cmd, void *conf) {
	ngx_http_core_loc_conf_t *clcf;

	clcf = ngx_http_conf_get_module_loc_conf(cf, ngx_http_core_module);
	clcf->handler = ngx_http_qpidapi_handler;

	return NGX_CONF_OK;
}


Единичный запрос, которым проверяю:

POST /svc/broker/message/1 HTTP/1.1
Host:
Content-Length: 180000

....//180тысяч буква а


Конфиг(остальные настройки все дефолтны):
 
server {
	listen 82;
	server_name localhost;
	client_max_body_size       1024k;
	client_body_buffer_size 1024k;
	client_body_in_single_buffer on;
	location /svc/broker/message/ {
	    send_message;
	}



Иногда данный тело данного запроса успешно считывается, иногда возникают ошибки. Объясните что неправильно сделал, или что может так влиять на работу модуля?
Знаю, что запрос неправилен с точки зрения ХТТП - нехотелось возиться с boundary. может ли это повлиять на работу?

Лог:

2010/03/24 19:37:03  15776#0: epoll: fd:11 ev:0001 d:094E7254
2010/03/24 19:37:03  15776#0: accept on 0.0.0.0:82, ready: 0
2010/03/24 19:37:03  15776#0: malloc: 094D5230:256
2010/03/24 19:37:03  15776#0: *1 accept: 192.168.10.109 fd:6
2010/03/24 19:37:03  15776#0: *1 event timer add: 6: 60000:2422531034
2010/03/24 19:37:03  15776#0: *1 epoll add event: fd:6 op:1 ev:80000001
2010/03/24 19:37:03  15776#0: timer delta: 6347
2010/03/24 19:37:03  15776#0: posted events 00000000
2010/03/24 19:37:03  15776#0: worker cycle
2010/03/24 19:37:03  15776#0: epoll timer: 60000
2010/03/24 19:37:03  15776#0: epoll: fd:6 ev:0001 d:094E730C
2010/03/24 19:37:03  15776#0: *1 malloc: 094DE998:656
2010/03/24 19:37:03  15776#0: *1 malloc: 094DB5D8:1024
2010/03/24 19:37:03  15776#0: *1 malloc: 094DB9E0:4096
2010/03/24 19:37:03  15776#0: *1 http process request line
2010/03/24 19:37:03  15776#0: *1 recv: fd:6 1024 of 1024
2010/03/24 19:37:03  15776#0: *1 http request line: "POST /svc/broker/message/1 HTTP/1.1"
2010/03/24 19:37:03  15776#0: *1 http uri: "/svc/broker/message/1"
2010/03/24 19:37:03  15776#0: *1 http args: ""
2010/03/24 19:37:03  15776#0: *1 http exten: ""
2010/03/24 19:37:03  15776#0: *1 http process request header line
2010/03/24 19:37:03  15776#0: *1 http header: "Host: 192.168.10.109"
2010/03/24 19:37:03  15776#0: *1 http header: "Content-Length: 180000"
2010/03/24 19:37:03  15776#0: *1 http header done
2010/03/24 19:37:03  15776#0: *1 event timer del: 6: 2422531034
2010/03/24 19:37:03  15776#0: *1 generic phase: 0
2010/03/24 19:37:03  15776#0: *1 test location: "/svc/broker/message/"
2010/03/24 19:37:03  15776#0: *1 using configuration "/svc/broker/message/"
2010/03/24 19:37:03  15776#0: *1 http cl:180000 max:1048576
2010/03/24 19:37:03  15776#0: *1 generic phase: 2
2010/03/24 19:37:03  15776#0: *1 post rewrite phase: 3
2010/03/24 19:37:03  15776#0: *1 generic phase: 4
2010/03/24 19:37:03  15776#0: *1 generic phase: 5
2010/03/24 19:37:03  15776#0: *1 access phase: 6
2010/03/24 19:37:03  15776#0: *1 access phase: 7
2010/03/24 19:37:03  15776#0: *1 post access phase: 8
2010/03/24 19:37:03  15776#0: *1 run handler!!! (21: Is a directory), client: 192.168.10.109, server: localhost, request: "POST /svc/broker/message/1 HTTP/1.1", host: "192.168.10.109"
2010/03/24 19:37:03  15776#0: *1 http client request body preread 940
2010/03/24 19:37:03  15776#0: *1 malloc: B7FA1008:180000
2010/03/24 19:37:03  15776#0: *1 http read client request body
2010/03/24 19:37:03  15776#0: *1 recv: fd:6 64512 of 179060
2010/03/24 19:37:03  15776#0: *1 http client request body recv 64512
2010/03/24 19:37:03  15776#0: *1 http client request body rest 114548
2010/03/24 19:37:03  15776#0: *1 recv: fd:6 49152 of 114548
2010/03/24 19:37:03  15776#0: *1 http client request body recv 49152
2010/03/24 19:37:03  15776#0: *1 http client request body rest 65396
2010/03/24 19:37:03  15776#0: *1 recv: fd:6 32768 of 65396
2010/03/24 19:37:03  15776#0: *1 http client request body recv 32768
2010/03/24 19:37:03  15776#0: *1 http client request body rest 32628
2010/03/24 19:37:03  15776#0: *1 recv: fd:6 -1 of 32628
2010/03/24 19:37:03  15776#0: *1 recv() not ready (11: Resource temporarily unavailable)
2010/03/24 19:37:03  15776#0: *1 http client request body recv -2
2010/03/24 19:37:03  15776#0: *1 http client request body rest 32628
2010/03/24 19:37:03  15776#0: *1 event timer add: 6: 60000:2422531035
2010/03/24 19:37:03  15776#0: *1 NGX_AGAIN!!! (21: Is a directory), client: 192.168.10.109, server: localhost, request: "POST /svc/broker/message/1 HTTP/1.1", host: "192.168.10.109"
2010/03/24 19:37:03  15776#0: *1 http finalize request: -2, "/svc/broker/message/1?" 1
2010/03/24 19:37:03  15776#0: *1 event timer del: 6: 2422531035
2010/03/24 19:37:03  15776#0: *1 set http keepalive handler
2010/03/24 19:37:03  15776#0: *1 http close request
2010/03/24 19:37:03  15776#0: *1 http log handler
2010/03/24 19:37:03  15776#0: *1 free: B7FA1008
2010/03/24 19:37:03  15776#0: *1 free: 094DB9E0, unused: 2597
2010/03/24 19:37:03  15776#0: *1 event timer add: 6: 65000:2422536035
2010/03/24 19:37:03  15776#0: *1 free: 094DE998
2010/03/24 19:37:03  15776#0: *1 free: 094DB5D8
2010/03/24 19:37:03  15776#0: *1 hc free: 00000000 0
2010/03/24 19:37:03  15776#0: *1 hc busy: 00000000 0
2010/03/24 19:37:03  15776#0: *1 tcp_nodelay
2010/03/24 19:37:03  15776#0: timer delta: 1
2010/03/24 19:37:03  15776#0: posted events 00000000
2010/03/24 19:37:03  15776#0: worker cycle
2010/03/24 19:37:03  15776#0: epoll timer: 65000
2010/03/24 19:37:03  15776#0: epoll: fd:6 ev:0001 d:094E730C
2010/03/24 19:37:03  15776#0: *1 http keepalive handler
2010/03/24 19:37:03  15776#0: *1 malloc: 094DE998:1024
2010/03/24 19:37:03  15776#0: *1 recv: fd:6 1024 of 1024
2010/03/24 19:37:03  15776#0: *1 malloc: 094DB5D8:656
2010/03/24 19:37:03  15776#0: *1 malloc: 094DB870:4096
2010/03/24 19:37:03  15776#0: *1 http process request line
2010/03/24 19:37:03  15776#0: *1 client sent invalid method while reading client request line, client: 192.168.10.109, server: localhost, request: "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"
2010/03/24 19:37:03  15776#0: *1 http finalize request: 400, "?" 1
2010/03/24 19:37:03  15776#0: *1 event timer del: 6: 2422536035
2010/03/24 19:37:03  15776#0: *1 http special response: 400, "?"
2010/03/24 19:37:03  15776#0: *1 http set discard body
2010/03/24 19:37:03  15776#0: *1 http output filter "?"
2010/03/24 19:37:03  15776#0: *1 copy filter: "?"
2010/03/24 19:37:03  15776#0: *1 http postpone filter "?" 094DBBC8
2010/03/24 19:37:03  15776#0: *1 write new buf t:0 f:0 00000000, pos 080DE560, size: 120 file: 0, size: 0
2010/03/24 19:37:03  15776#0: *1 write new buf t:0 f:0 00000000, pos 080DE1E0, size: 53 file: 0, size: 0
2010/03/24 19:37:03  15776#0: *1 http write filter: l:1 f:0 s:173
2010/03/24 19:37:03  15776#0: *1 http write filter limit 0
2010/03/24 19:37:03  15776#0: *1 writev: 173
2010/03/24 19:37:03  15776#0: *1 http write filter 00000000
2010/03/24 19:37:03  15776#0: *1 copy filter: 0 "?"
2010/03/24 19:37:03  15776#0: *1 http finalize request: 0, "?" 1
2010/03/24 19:37:03  15776#0: *1 http close request
2010/03/24 19:37:03  15776#0: *1 http log handler
2010/03/24 19:37:03  15776#0: *1 free: 094DB870, unused: 2100
2010/03/24 19:37:03  15776#0: *1 close http connection: 6
2010/03/24 19:37:03  15776#0: *1 free: 094DE998
2010/03/24 19:37:03  15776#0: *1 free: 094DB5D8
2010/03/24 19:37:03  15776#0: *1 free: 094D5230, unused: 56
2010/03/24 19:37:03  15776#0: timer delta: 18
2010/03/24 19:37:03  15776#0: posted events 00000000
2010/03/24 19:37:03  15776#0: worker cycle
2010/03/24 19:37:03  15776#0: epoll timer: -1


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




Подробная информация о списке рассылки nginx-ru