首页 > 系统应用 > nginx > 为什么nginx+php-fpm组合老是报错504
2015
07-31

为什么nginx+php-fpm组合老是报错504

最近碰到这个问题大为干火。

一会行,一会不行。大部分情况行,不行的情况还是比较多。

老是报错如下:

2015/04/06 19:48:02 [error] 9386#0: *1 upstream timed out (110: Connection timed out) while connecting to upstream, client: 219.134.166.25, server: www.geektcp.com, request: “GET / HTTP/1.1”, upstream: “fastcgi://127.0.0.1:9000”, host: “www.geektcp.com”

数据库可以正常访问。

网上有一种说法就是php-fpm的IO模块是阻塞的,一旦php-fpm卡住就会出现上面那报错。

到底是不是呢?

首先来看下nginx的debug日志的关键部分:

2015/04/09 21:48:19 [debug] 26490#0: *59 fastcgi param: “HTTP_ACCEPT_ENCODING: gzip, deflate, sdch”
2015/04/09 21:48:19 [debug] 26490#0: *59 fastcgi param: “HTTP_ACCEPT_LANGUAGE: zh-CN,zh;q=0.8”
2015/04/09 21:48:19 [debug] 26490#0: *59 fastcgi param: “HTTP_COOKIE: comment_author_9bc7ae7025f96b8d32f1659c9394702e=%E9%A3%9E%E9%9B%AA; comment_author_email_9bc7ae7025f96b8d32f1659c9394702e=liufei2014%40souhu.com; wordpress_test_cookie=WP+Cookie+check; wordpress_logged_in_9bc7ae7025f96b8d32f1659c9394702e=geek%7C1428758595%7CDvDFWuxfykwmBUudazEaWQqgB8ljS1h5oZPyki1lFUU%7C829fbd4a44d854f8640e7db920598ea4a92c2fa1e5423900b4a85d8ea5f73555”
2015/04/09 21:48:19 [debug] 26490#0: *59 http cleanup add: 00000000012CD630
2015/04/09 21:48:19 [debug] 26490#0: *59 get rr peer, try: 1
2015/04/09 21:48:19 [debug] 26490#0: *59 socket 31
2015/04/09 21:48:19 [debug] 26490#0: *59 epoll add connection: fd:31 ev:80002005
2015/04/09 21:48:19 [debug] 26490#0: *59 connect to 127.0.0.1:9000, fd:31 #60
2015/04/09 21:48:19 [debug] 26490#0: *59 http upstream connect: -2
2015/04/09 21:48:19 [debug] 26490#0: *59 posix_memalign: 00000000012F3F00:128 @16
2015/04/09 21:48:19 [debug] 26490#0: *59 event timer add: 31: 30000:1428587329428
2015/04/09 21:48:19 [debug] 26490#0: *59 http finalize request: -4, “/index.php?p=281” a:1, c:3
2015/04/09 21:48:19 [debug] 26490#0: *59 http request count:3 blk:0
2015/04/09 21:48:19 [debug] 26490#0: *59 http finalize request: -4, “/index.php?p=281” a:1, c:2
2015/04/09 21:48:19 [debug] 26490#0: *59 http request count:2 blk:0
2015/04/09 21:48:19 [debug] 26490#0: *59 http run request: “/index.php?p=281”
2015/04/09 21:48:19 [debug] 26490#0: *59 http upstream check client, write event:1, “/index.php”
2015/04/09 21:48:19 [debug] 26490#0: *59 http upstream recv(): -1 (11: Resource temporarily unavailable)

2015/04/09 21:48:49 [debug] 26490#0: *59 event timer del: 31: 1428587329428
2015/04/09 21:48:49 [debug] 26490#0: *59 http upstream request: “/index.php?p=281”
2015/04/09 21:48:49 [debug] 26490#0: *59 http upstream send request handler
2015/04/09 21:48:49 [debug] 26490#0: *59 http next upstream, 4
2015/04/09 21:48:49 [debug] 26490#0: *59 free rr peer 1 4
2015/04/09 21:48:49 [debug] 26490#0: *59 http upstream send request handler
2015/04/09 21:48:49 [debug] 26490#0: *59 http next upstream, 4
2015/04/09 21:48:49 [debug] 26490#0: *59 free rr peer 1 4
2015/04/09 21:48:49 [error] 26490#0: *59 upstream timed out (110: Connection timed out) while connecting to upstream, client: 183.12.199.17, server: www.geektcp.com, request: “GET /?p=281 HTTP/1.1”, upstream: “fastcgi://127.0.0.1:9000”, host: “www.geektcp.com”, referrer: “http://www.geektcp.com/?p=69”
2015/04/09 21:48:49 [debug] 26490#0: *59 finalize http upstream request: 504
2015/04/09 21:48:49 [debug] 26490#0: *59 finalize http fastcgi request
2015/04/09 21:48:49 [debug] 26490#0: *59 close http upstream connection: 31
2015/04/09 21:48:49 [debug] 26490#0: *59 finalize http fastcgi request
2015/04/09 21:48:49 [debug] 26490#0: *59 close http upstream connection: 31
2015/04/09 21:48:49 [debug] 26490#0: *59 free: 00000000012F3F00, unused: 48
2015/04/09 21:48:49 [debug] 26490#0: *59 reusable connection: 0
2015/04/09 21:48:49 [debug] 26490#0: *59 reusable connection: 0
2015/04/09 21:48:49 [debug] 26490#0: *59 http finalize request: 504, “/index.php?p=281” a:1, c:1
2015/04/09 21:48:49 [debug] 26490#0: *59 http special response: 504, “/index.php?p=281”
2015/04/09 21:48:49 [debug] 26490#0: *59 internal redirect: “/504.html?”
2015/04/09 21:48:49 [debug] 26490#0: *59 rewrite phase: 1
2015/04/09 21:48:49 [debug] 26490#0: *59 test location: “/”
2015/04/09 21:48:49 [debug] 26490#0: *59 test location: “/”

上面那部分其实用到了ngx_http_upstream_check_broken_connection这个函数,这个函数在调用recv函数时候不成功,该函数返回结果是-1,正因为recv不成功,导致后面重试调用ngx_http_upstream_next返回504错误。

首先要明确一个概念:客户端是nginx,服务端是nginx里面的upstream参数关联的php-fpm地址。

通过分析nginx源代码,发现504错误的原因有3个,分别是:

1、nginx设置的fastcgi缓存太小会导致这个问题,所以网上有一大堆的配置。

2、客户端nginx跟php-fpm建立socket连接时,数据写入失败,nginx会调用ngx_http_upstream_next抛出504错误。

3、客户端nginx读取php-fpm返回过来的数据失败,nginx会调用ngx_http_upstream_next抛出504错误。

而我的服务器为什么很容易导致504错误,直接原因是第三种,nginx通过recv读取php-fpm返回过来的数据时超时报错了。

继续深入下去,这个问题又分为两种:

1、php-fpm已经准备好数据,并发送成功。那么这种情况应该是nginx程序代码的问题。

2、php-fpm卡住了,没有发送数据给nginx,那么nginx就会抛出504错误。

显然第一种的可能性极小,我觉得这个问题要追踪到php-fpm了。

极有可能是php-fpm卡住了,没有返回数据给nginx导致。问题是php-fpm的配置已经调了很多遍了还是这个问题。

目前的解决方案是不用socket连接。如果还不行,就要看看php-fpm的代码和参数了。

###################################

经过一天的测试和观察,再也没有504错误了,即便偶尔会卡住零点几秒,之前在这个时候会报504错误,但是现在没有出现这种情况了。这个问题终于解决。very nice!

下面是这两个函数的源码:

static void
ngx_http_upstream_check_broken_connection(ngx_http_request_t *r,
    ngx_event_t *ev)
{
    int                  n;
    char                 buf[1];
    ngx_err_t            err;
    ngx_int_t            event;
    ngx_connection_t     *c;
    ngx_http_upstream_t  *u;
 
 
 
    ngx_log_debug2(NGX_LOG_DEBUG_HTTP, ev->log, 0,
                   "http upstream check client, write event:%d, \"%V\"",
                   ev->write, &r->uri);
 
    c = r->connection;
    u = r->upstream;
 
    if (c->error) {
        if ((ngx_event_flags & NGX_USE_LEVEL_EVENT) && ev->active) {
 
            event = ev->write ? NGX_WRITE_EVENT : NGX_READ_EVENT;
 
            if (ngx_del_event(ev, event, 0) != NGX_OK) {
                ngx_http_upstream_finalize_request(r, u,
                                               NGX_HTTP_INTERNAL_SERVER_ERROR);
                return;
            }
        }
 
        if (!u->cacheable) {
            ngx_http_upstream_finalize_request(r, u,
                                               NGX_HTTP_CLIENT_CLOSED_REQUEST);
        }
 
        return;
    }
 
#if (NGX_HTTP_SPDY)
    if (r->spdy_stream) {
        return;
    }
#endif
 
#if (NGX_HAVE_KQUEUE)
 
    if (ngx_event_flags & NGX_USE_KQUEUE_EVENT) {
 
        if (!ev->pending_eof) {
            return;
        }
 
        ev->eof = 1;
        c->error = 1;
 
        if (ev->kq_errno) {
            ev->error = 1;
        }
 
        if (!u->cacheable && u->peer.connection) {
            ngx_log_error(NGX_LOG_INFO, ev->log, ev->kq_errno,
                          "kevent() reported that client prematurely closed "
                          "connection, so upstream connection is closed too");
            ngx_http_upstream_finalize_request(r, u,
                                               NGX_HTTP_CLIENT_CLOSED_REQUEST);
            return;
        }
 
        ngx_log_error(NGX_LOG_INFO, ev->log, ev->kq_errno,
                      "kevent() reported that client prematurely closed "
                      "connection");
 
        if (u->peer.connection == NULL) {
            ngx_http_upstream_finalize_request(r, u,
                                               NGX_HTTP_CLIENT_CLOSED_REQUEST);
        }
 
        return;
    }
 
#endif
 
#if (NGX_HAVE_EPOLLRDHUP)
 
    if ((ngx_event_flags & NGX_USE_EPOLL_EVENT) && ev->pending_eof) {
        socklen_t  len;
 
        ev->eof = 1;
        c->error = 1;
 
        err = 0;
        len = sizeof(ngx_err_t);
 
        /*
         * BSDs and Linux return 0 and set a pending error in err
         * Solaris returns -1 and sets errno
         */
 
        if (getsockopt(c->fd, SOL_SOCKET, SO_ERROR, (void *) &err, &len)
            == -1)
        {
            err = ngx_socket_errno;
        }
 
        if (err) {
            ev->error = 1;
        }
 
        if (!u->cacheable && u->peer.connection) {
            ngx_log_error(NGX_LOG_INFO, ev->log, err,
                        "epoll_wait() reported that client prematurely closed "
                        "connection, so upstream connection is closed too");
            ngx_http_upstream_finalize_request(r, u,
                                               NGX_HTTP_CLIENT_CLOSED_REQUEST);
            return;
        }
 
        ngx_log_error(NGX_LOG_INFO, ev->log, err,
                      "epoll_wait() reported that client prematurely closed "
                      "connection");
 
        if (u->peer.connection == NULL) {
            ngx_http_upstream_finalize_request(r, u,
                                               NGX_HTTP_CLIENT_CLOSED_REQUEST);
        }
 
        return;
    }
 
#endif
 
    n = recv(c->fd, buf, 1, MSG_PEEK);
 
    err = ngx_socket_errno;
 
    ngx_log_debug1(NGX_LOG_DEBUG_HTTP, ev->log, err,
                   "http upstream recv(): %d", n);
 
    if (ev->write && (n >= 0 || err == NGX_EAGAIN)) {
        return;
    }
 
    if ((ngx_event_flags & NGX_USE_LEVEL_EVENT) && ev->active) {
 
        event = ev->write ? NGX_WRITE_EVENT : NGX_READ_EVENT;
 
        if (ngx_del_event(ev, event, 0) != NGX_OK) {
            ngx_http_upstream_finalize_request(r, u,
                                               NGX_HTTP_INTERNAL_SERVER_ERROR);
            return;
        }
    }
 
    if (n > 0) {
        return;
    }
 
    if (n == -1) {
        if (err == NGX_EAGAIN) {
            return;
        }
 
        ev->error = 1;
 
    } else { /* n == 0 */
        err = 0;
    }
 
    ev->eof = 1;
    c->error = 1;
 
    if (!u->cacheable && u->peer.connection) {
        ngx_log_error(NGX_LOG_INFO, ev->log, err,
                      "client prematurely closed connection, "
                      "so upstream connection is closed too");
        ngx_http_upstream_finalize_request(r, u,
                                           NGX_HTTP_CLIENT_CLOSED_REQUEST);
        return;
    }
 
    ngx_log_error(NGX_LOG_INFO, ev->log, err,
                  "client prematurely closed connection");
 
    if (u->peer.connection == NULL) {
        ngx_http_upstream_finalize_request(r, u,
                                           NGX_HTTP_CLIENT_CLOSED_REQUEST);
    }
}
 
#####################################################################################
 
static void
ngx_http_upstream_next(ngx_http_request_t *r, ngx_http_upstream_t *u,
    ngx_uint_t ft_type)
{
    ngx_msec_t  timeout;
    ngx_uint_t  status, state;
 
    ngx_log_debug1(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
                   "http next upstream, %xi", ft_type);
 
    if (u->peer.sockaddr) {
 
        if (ft_type == NGX_HTTP_UPSTREAM_FT_HTTP_403
            || ft_type == NGX_HTTP_UPSTREAM_FT_HTTP_404)
        {
            state = NGX_PEER_NEXT;
 
        } else {
            state = NGX_PEER_FAILED;
        }
 
        u->peer.free(&u->peer, u->peer.data, state);
        u->peer.sockaddr = NULL;
    }
 
    if (ft_type == NGX_HTTP_UPSTREAM_FT_TIMEOUT) {
        ngx_log_error(NGX_LOG_ERR, r->connection->log, NGX_ETIMEDOUT,
                      "upstream timed out");
    }
 
    if (u->peer.cached && ft_type == NGX_HTTP_UPSTREAM_FT_ERROR) {
        status = 0;
 
        /* TODO: inform balancer instead */
 
        u->peer.tries++;
 
    } else {
        switch (ft_type) {
 
        case NGX_HTTP_UPSTREAM_FT_TIMEOUT:
            status = NGX_HTTP_GATEWAY_TIME_OUT;
            break;
 
        case NGX_HTTP_UPSTREAM_FT_HTTP_500:
            status = NGX_HTTP_INTERNAL_SERVER_ERROR;
            break;
 
        case NGX_HTTP_UPSTREAM_FT_HTTP_403:
            status = NGX_HTTP_FORBIDDEN;
            break;
 
        case NGX_HTTP_UPSTREAM_FT_HTTP_404:
            status = NGX_HTTP_NOT_FOUND;
            break;
 
        /*
         * NGX_HTTP_UPSTREAM_FT_BUSY_LOCK and NGX_HTTP_UPSTREAM_FT_MAX_WAITING
         * never reach here
         */
 
        default:
            status = NGX_HTTP_BAD_GATEWAY;
        }
    }
 
    if (r->connection->error) {
        ngx_http_upstream_finalize_request(r, u,
                                           NGX_HTTP_CLIENT_CLOSED_REQUEST);
        return;
    }
 
    if (status) {
        u->state->status = status;
        timeout = u->conf->next_upstream_timeout;
 
        if (u->peer.tries == 0
            || !(u->conf->next_upstream & ft_type)
            || (timeout && ngx_current_msec - u->peer.start_time >= timeout))
        {
#if (NGX_HTTP_CACHE)
 
            if (u->cache_status == NGX_HTTP_CACHE_EXPIRED
                && (u->conf->cache_use_stale & ft_type))
            {
                ngx_int_t  rc;
 
                rc = u->reinit_request(r);
 
                if (rc == NGX_OK) {
                    u->cache_status = NGX_HTTP_CACHE_STALE;
                    rc = ngx_http_upstream_cache_send(r, u);
                }
 
                ngx_http_upstream_finalize_request(r, u, rc);
                return;
            }
#endif
 
            ngx_http_upstream_finalize_request(r, u, status);
            return;
        }
    }
 
    if (u->peer.connection) {
        ngx_log_debug1(NGX_LOG_DEBUG_HTTP, r->connection->log, 0,
                       "close http upstream connection: %d",
                       u->peer.connection->fd);
#if (NGX_HTTP_SSL)
 
        if (u->peer.connection->ssl) {
            u->peer.connection->ssl->no_wait_shutdown = 1;
            u->peer.connection->ssl->no_send_shutdown = 1;
 
            (void) ngx_ssl_shutdown(u->peer.connection);
        }
#endif
 
        if (u->peer.connection->pool) {
            ngx_destroy_pool(u->peer.connection->pool);
        }
 
        ngx_close_connection(u->peer.connection);
        u->peer.connection = NULL;
    }
 
    ngx_http_upstream_connect(r, u);
}
最后编辑:
作者:saunix
大型互联网公司linux系统运维攻城狮,专门担当消防员

留下一个回复