debug设置:
删除epoll地方做个debug
static ngx_int_t
ngx_epoll_del_event(ngx_event_t *ev, ngx_int_t event, ngx_uint_t flags)
{
int op;
uint32_t prev;
ngx_event_t *e;
ngx_connection_t *c;
struct epoll_event ee;
/*
* when the file descriptor is closed, the epoll automatically deletes
* it from its queue, so we do not need to delete explicitly the event
* before the closing the file descriptor
*/
if (flags & NGX_CLOSE_EVENT) {
ev->active = 0;
return NGX_OK;
}
c = ev->data;
if (event == NGX_READ_EVENT) {
e = c->write;
prev = EPOLLOUT;
} else {
e = c->read;
prev = EPOLLIN;
}
if (e->active) {
//我的debug
ngx_log_debug2(NGX_LOG_DEBUG_HTTP, ev->log, 0,"del mod pollevent: \"%d=id=%d\"", getpid(),c->fd);
op = EPOLL_CTL_ADD;
op = EPOLL_CTL_MOD;
ee.events = prev | (uint32_t) flags;
ee.data.ptr = (void *) ((uintptr_t) c | ev->instance);
} else {
//我的debug
ngx_log_debug2(NGX_LOG_DEBUG_HTTP, ev->log, 0,"del del pollevent: \"%d=id=%d\"", getpid(),c->fd);
op = EPOLL_CTL_DEL;
ee.events = 0;
ee.data.ptr = NULL;
}
添加epoll地方:
static ngx_int_t
ngx_epoll_add_event(ngx_event_t *ev, ngx_int_t event, ngx_uint_t flags)
{
int op;
uint32_t events, prev;
ngx_event_t *e;
ngx_connection_t *c;
struct epoll_event ee;
c = ev->data;
events = (uint32_t) event;
if (event == NGX_READ_EVENT) {
e = c->write;
prev = EPOLLOUT;
#if (NGX_READ_EVENT != EPOLLIN)
events = EPOLLIN;
#endif
} else {
e = c->read;
prev = EPOLLIN;
#if (NGX_WRITE_EVENT != EPOLLOUT)
events = EPOLLOUT;
#endif
}
if (e->active) {
ngx_log_debug2(NGX_LOG_DEBUG_HTTP, ev->log, 0,"modepollevent: \"%d=id=%d\"", getpid(),c->fd);
op = EPOLL_CTL_MOD;
events |= prev;
} else {
ngx_log_debug2(NGX_LOG_DEBUG_HTTP, ev->log, 0,"addpollevent: \"%d=id=%d\"", getpid(),c->fd);
op = EPOLL_CTL_ADD;
}
接收的地方:
static ngx_int_t
ngx_enable_accept_events(ngx_cycle_t *cycle)
{
ngx_uint_t i;
ngx_listening_t *ls;
ngx_connection_t *c;
ls = cycle->listening.elts;
for (i = 0; i < cycle->listening.nelts; i++) {
c = ls[i].connection;
if (c->read->active) {
continue;
}
if (ngx_event_flags & NGX_USE_RTSIG_EVENT) {
//我的debug
ngx_log_debug2(NGX_LOG_DEBUG_HTTP, cycle->log, 0,"enable-addconnaccept: \"%d=id=%d\"", getpid(),c->fd);
if (ngx_add_conn(c) == NGX_ERROR) {
return NGX_ERROR;
}
} else {
//我的debug
ngx_log_debug2(NGX_LOG_DEBUG_HTTP, cycle->log, 0,"enable-addeventaccept: \"%d=id=%d\"", getpid(),c->fd);
if (ngx_add_event(c->read, NGX_READ_EVENT, 0) == NGX_ERROR) {
return NGX_ERROR;
}
}
}
锁的地方添加:
ngx_process_events_and_timers(ngx_cycle_t *cycle) 的
if (ngx_accept_mutex_held) {
ngx_shmtx_unlock(&ngx_accept_mutex);
//我的debug
ngx_log_debug1(NGX_LOG_DEBUG_HTTP, cycle->log, 0,"----begin sleep---: %M", delta) ;
sleep(5);
ngx_log_debug1(NGX_LOG_DEBUG_HTTP, cycle->log, 0,"----end sleep---: %M", delta);
}
运行多进程的结果是:
非全部debug_http
2013/01/29 15:06:53 [notice] 15001#0: start worker process 15009
2013/01/29 15:06:53 [debug] 15006#0: addpollevent: "15006=id=15"
2013/01/29 15:06:53 [debug] 15006#0: enable-addeventaccept: "15006=id=6"
2013/01/29 15:06:53 [debug] 15006#0: addpollevent: "15006=id=6"
2013/01/29 15:06:53 [debug] 15006#0: ----begin sleep---: 4
2013/01/29 15:06:53 [debug] 15004#0: addpollevent: "15004=id=11"
2013/01/29 15:06:53 [debug] 15004#0: enable-addeventaccept: "15004=id=6"
2013/01/29 15:06:53 [debug] 15004#0: addpollevent: "15004=id=6"
2013/01/29 15:06:53 [debug] 15004#0: ----begin sleep---: 4
2013/01/29 15:06:53 [debug] 15008#0: addpollevent: "15008=id=19"
2013/01/29 15:06:53 [debug] 15008#0: enable-addeventaccept: "15008=id=6"
2013/01/29 15:06:53 [debug] 15008#0: addpollevent: "15008=id=6"
2013/01/29 15:06:53 [debug] 15008#0: ----begin sleep---: 5
2013/01/29 15:06:53 [debug] 15003#0: addpollevent: "15003=id=9"
2013/01/29 15:06:53 [debug] 15003#0: enable-addeventaccept: "15003=id=6"
2013/01/29 15:06:53 [debug] 15003#0: addpollevent: "15003=id=6"
2013/01/29 15:06:53 [debug] 15003#0: ----begin sleep---: 5
2013/01/29 15:06:53 [debug] 15002#0: addpollevent: "15002=id=7"
2013/01/29 15:06:53 [debug] 15002#0: enable-addeventaccept: "15002=id=6"
2013/01/29 15:06:53 [debug] 15002#0: addpollevent: "15002=id=6"
2013/01/29 15:06:53 [debug] 15002#0: ----begin sleep---: 6
2013/01/29 15:06:53 [debug] 15007#0: addpollevent: "15007=id=17"
2013/01/29 15:06:53 [debug] 15007#0: enable-addeventaccept: "15007=id=6"
2013/01/29 15:06:53 [debug] 15007#0: addpollevent: "15007=id=6"
2013/01/29 15:06:53 [debug] 15007#0: ----begin sleep---: 6
2013/01/29 15:06:53 [debug] 15009#0: addpollevent: "15009=id=21"
2013/01/29 15:06:53 [debug] 15009#0: enable-addeventaccept: "15009=id=6"
2013/01/29 15:06:53 [debug] 15009#0: addpollevent: "15009=id=6"
2013/01/29 15:06:53 [debug] 15005#0: addpollevent: "15005=id=13"
2013/01/29 15:06:58 [debug] 15009#0: *1 addpollevent: "15009=id=7"
2013/01/29 15:06:58 [debug] 15009#0: ----begin sleep---: 4860
2013/01/29 15:06:53 [debug] 15006#0: ----end sleep---: 4
2013/01/29 15:06:53 [debug] 15004#0: ----end sleep---: 4
2013/01/29 15:06:53 [debug] 15004#0: del del pollevent: "15004=id=6"
2013/01/29 15:06:53 [debug] 15008#0: ----end sleep---: 5
2013/01/29 15:06:53 [debug] 15008#0: del del pollevent: "15008=id=6"
2013/01/29 15:06:53 [debug] 15003#0: ----end sleep---: 5
2013/01/29 15:06:53 [debug] 15003#0: del del pollevent: "15003=id=6"
2013/01/29 15:06:53 [debug] 15002#0: ----end sleep---: 6
2013/01/29 15:06:53 [debug] 15002#0: del del pollevent: "15002=id=6"
2013/01/29 15:06:53 [debug] 15007#0: ----end sleep---: 6
2013/01/29 15:06:53 [debug] 15007#0: del del pollevent: "15007=id=6"
2013/01/29 15:06:58 [debug] 15009#0: ----end sleep---: 4860
2013/01/29 15:06:58 [debug] 15009#0: del del pollevent: "15009=id=6"
2013/01/29 15:07:03 [debug] 15009#0: *1 http process request line
2013/01/29 15:07:03 [debug] 15009#0: *1 http request line: "GET / HTTP/1.1"
2013/01/29 15:07:03 [debug] 15009#0: *1 http uri: "/"
2013/01/29 15:07:03 [debug] 15009#0: *1 http keepalive handler
2013/01/29 15:08:08 [debug] 15009#0: *1 http keepalive handler
2013/01/29 15:08:08 [debug] 15009#0: *1 close http connection: 7
2013/01/29 15:24:03 [debug] 15006#0: *2 addpollevent: "15006=id=13"
2013/01/29 15:24:03 [debug] 15006#0: ----begin sleep---: 1030043
2013/01/29 15:24:03 [debug] 15009#0: enable-addeventaccept: "15009=id=6"
2013/01/29 15:24:03 [debug] 15009#0: addpollevent: "15009=id=6"
2013/01/29 15:24:03 [debug] 15006#0: ----end sleep---: 1030043
2013/01/29 15:24:03 [debug] 15006#0: del del pollevent: "15006=id=6"
2013/01/29 15:24:08 [debug] 15006#0: *2 http process request line
2013/01/29 15:25:13 [debug] 15006#0: *2 close http connection: 13
2013/01/29 15:25:52 [debug] 15009#0: *3 addpollevent: "15009=id=7"
2013/01/29 15:25:52 [debug] 15009#0: ----begin sleep---: 108250
2013/01/29 15:25:52 [debug] 15005#0: enable-addeventaccept: "15005=id=6"
2013/01/29 15:25:52 [debug] 15005#0: addpollevent: "15005=id=6"
2013/01/29 15:25:52 [debug] 15009#0: ----end sleep---: 108250
2013/01/29 15:25:52 [debug] 15009#0: del del pollevent: "15009=id=6"
2013/01/29 15:25:57 [debug] 15009#0: *3 http process request line
2013/01/29 15:27:02 [debug] 15009#0: *3 close http connection: 7
全部debug的一部分信息:
2013/01/29 15:35:48 [debug] 15391#0: ----end sleep---: 107386
2013/01/29 15:35:48 [debug] 15391#0: posted events 0000000000000000
2013/01/29 15:35:48 [debug] 15391#0: worker cycle
2013/01/29 15:35:48 [debug] 15391#0: accept mutex lock failed: 1
2013/01/29 15:35:48 [debug] 15391#0: del del pollevent: "15391=id=6"
2013/01/29 15:35:48 [debug] 15391#0: epoll del event: fd:6 op:2 ev:00000000
2013/01/29 15:35:48 [debug] 15391#0: epoll timer: 500
2013/01/29 15:35:53 [debug] 15391#0: epoll: fd:7 ev:0001 d:00007FBBC025F190
2013/01/29 15:35:53 [debug] 15391#0: *1 malloc: 0000000001295610:1256
2013/01/29 15:35:53 [debug] 15391#0: *1 posix_memalign: 0000000001280160:256 @16
2013/01/29 15:35:53 [debug] 15391#0: *1 malloc: 0000000001295B00:1024
2013/01/29 15:35:53 [debug] 15391#0: *1 posix_memalign: 00000000012867B0:4096 @16
2013/01/29 15:35:53 [debug] 15391#0: *1 http process request line
2013/01/29 15:35:53 [debug] 15391#0: *1 recv: fd:7 460 of 1024
2013/01/29 15:35:53 [debug] 15391#0: *1 http request line: "GET / HTTP/1.1"
2013/01/29 15:35:53 [debug] 15391#0: *1 http header done
2013/01/29 15:35:53 [debug] 15391#0: *1 event timer del: 7: 1359445008260
2013/01/29 15:35:53 [debug] 15391#0: posted event 0000000000000000
2013/01/29 15:35:53 [debug] 15391#0: worker cycle
2013/01/29 15:35:53 [debug] 15391#0: accept mutex lock failed: 0
2013/01/29 15:35:53 [debug] 15391#0: epoll timer: 500
结论:
1、当某个进程获得锁,并且accept后,sleep放弃锁。
2、让其他进程获得锁后,标识该锁被占用了(ngx_accept_mutex_held 1代表已经被占用),并且其他进程accept。
3、sleep(和1/8放弃锁一个原理)返回后,发现锁已经被占用,然后(del del pollevent:) 删除自己在epoll里面等待的锁。
4、处理客户端的请求,完成后关闭。
5、循环判断,如果能抢到锁,那么把linsten添加到epollevent里面去。进行下一步处理。
销毁epoll里面的锁是在这里销毁的:
ngx_int_t
ngx_trylock_accept_mutex(ngx_cycle_t *cycle)
if (ngx_accept_mutex_held) {
if (ngx_disable_accept_events(cycle) == NGX_ERROR) {
return NGX_ERROR;
}
ngx_accept_mutex_held = 0;
}