Re: [openresty] Re: 奇怪的问题，子请求连接超时，访问日志显示200，浏览器显示nginx错误日志。

agentzh

Hello!

2012/10/26 朱茂海
>
> 子请求的响应状态码是200，响应体却是错误页面。
>

你具体是如何确认这一点的？你是否排除了 ngx.exec("/proxy") 那条代码路径被执行的可能性？

另外，在 nginx 这个支持 C10K 的服务器之前放置不支持 C10K 的 Varnish 服务器，其实并不是一个好主意 ;)

Best regards,
-agentzh

z329224946

子请求的响应码不是通过看这一条日志吗：

192.168.2.208 - - [25/Oct/2012:19:13:40 +0000] "GET /static/images/iphone_switch.png?e9c3fed6aab8 HTTP/1.1" 200 2722 "http://my.xxx.com/my-websites/cloud-

config/yyy.com/" "Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 6.1; Trident/4.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media

Center PC 6.0; .NET4.0C)"

另外，我已经在server区域增加log_subrequest on;; 但似乎日志并没有变化。

On Saturday, October 27, 2012 11:13:30 AM UTC+8, agentzh wrote:

Hello!
2012/10/26 朱茂海
>
> 子请求的响应状态码是200，响应体却是错误页面。
>
你具体是如何确认这一点的？你是否排除了 ngx.exec("/proxy") 那条代码路径被执行的可能性？
另外，在 nginx 这个支持 C10K 的服务器之前放置不支持 C10K 的 Varnish 服务器，其实并不是一个好主意 ;)
Best regards,
-agentzh

z329224946

我是这样添加开启子请求日志的，不知道对不对：

location /proxy {

internal;

log_subrequest on;

proxy_pass $scheme://$http_host$request_uri;

proxy_set_header Accept-Encoding '';

proxy_redirect off;

}

On Saturday, October 27, 2012 11:27:01 AM UTC+8, 朱茂海 wrote:

子请求的响应码不是通过看这一条日志吗：
192.168.2.208 - - [25/Oct/2012:19:13:40 +0000] "GET /static/images/iphone_switch.png?e9c3fed6aab8 HTTP/1.1" 200 2722 "http://my.xxx.com/my-websites/cloud-
config/yyy.com/" "Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 6.1; Trident/4.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media
Center PC 6.0; .NET4.0C)"
另外，我已经在server区域增加log_subrequest on;; 但似乎日志并没有变化。

On Saturday, October 27, 2012 11:13:30 AM UTC+8, agentzh wrote:
Hello!
2012/10/26 朱茂海
>
> 子请求的响应状态码是200，响应体却是错误页面。
>
你具体是如何确认这一点的？你是否排除了 ngx.exec("/proxy") 那条代码路径被执行的可能性？
另外，在 nginx 这个支持 C10K 的服务器之前放置不支持 C10K 的 Varnish 服务器，其实并不是一个好主意 ;)
Best regards,
-agentzh

agentzh

Hello!

2012/10/26 朱茂海:
> 子请求的响应码不是通过看这一条日志吗：
> 192.168.2.208 - - [25/Oct/2012:19:13:40 +0000] "GET
> /static/images/iphone_switch.png?e9c3fed6aab8 HTTP/1.1" 200 2722
> "http://my.xxx.com/my-websites/cloud-
> config/yyy.com/" "Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 6.1;
> Trident/4.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR
> 3.0.30729; Media
> Center PC 6.0; .NET4.0C)"

这样是看不出这条记录究竟是主请求的还是子请求的。

如果你的主请求和子请求的 URI 有明显区别，则可以在你的 log_format 定义的日志模版中加入 "$uri?$args" 这一段。而
$request 变量的值永远是主请求的请求行。

> 另外，我已经在server区域增加log_subrequest on; 但似乎日志并没有变化。
>

建议你在开发环境启动一个最小化的例子进行测试，同时把 "$uri?$args" 加入到 log_format
定义的日志模版中去（可以直接取代 $request 变量的位置）。

下面是一个最小化的示例：

    log_format test '$remote_addr - $remote_user [$time_local]
"$echo_request_method $uri?$args" $status $bytes_sent "$http_referer"
"$http_user_agent"';
    access_log logs/access.log test;

    server {
        ...
        location /main {
            content_by_lua '
                local res = ngx.location.capture("/sub?a=3")
                ngx.say("status = ", res.status)
            ';
        }

        location /sub {
            log_subrequest on;

            proxy_connect_timeout 100ms;
            proxy_pass http://www.google.com:1234;
        }
    }

此时请求 /main 可以在 logs/access.log 中产生下面这两行日志：

    127.0.0.1 - - [26/Oct/2012:20:47:31 -0700] "GET /sub?a=3" 504 0 "-" "-"
    127.0.0.1 - - [26/Oct/2012:20:47:31 -0700] "GET /main?-" 200 183 "-" "-"

我们可以看到，第一条是子请求 /sub 的，是 504 状态码，第二条是主请求 /main 的，是 200 状态码。

建议遇到问题时，总是首先尝试使用最小化的例子进行测试。这样经常可以节约很多时间 :)

当然，最直接的做法还是在 Lua 代码里使用 ngx.log() 函数在出错时记录错误日志：

    http://wiki.nginx.org/HttpLuaModule#ngx.log

Best regards,
-agentzh