Help! log phase is not executed due to r->count being non-zero

[Maxim Dounin]

Hello!

On Sat, Oct 11, 2014 at 12:28:08AM -0400, wangweixun wrote:

> Hey all,
> 
> I'm writing an authentication module that is structurally very similar to
> ngx_http_auth_request_module
> (https://github.com/PiotrSikora/ngx_http_auth_request_module/blob/master/ngx_http_auth_request_module.c).
> It basically sends a subrequest to a service for auth. For testing, I put a
> hello_world module module
> (https://github.com/perusio/nginx-hello-world-module/blob/master/ngx_http_hello_world_module.c)
> behind it like:
> 
> location /hello_world {
>      auth_request /auth;
>      hello_world;
>      hello_world_string "Hello World!";
> }
> 
> Everything works fine EXCEPT I found today that the log phase is not
> excuted. I traced it down to ngx_http_close_request function in
> ngx_http_request.c (as it calls ngx_http_free_request(r, rc); to excute log
> handlers) where I found r->count = 2 so after r->count--; it's still
> non-zero thus ngx_http_close_request simply returns. I did not touch request
> count in my code.
> 
> Are we supposed to handle r->acount (either directly or through
> ngx_http_finalize_request) when using subrequest? I didn't see the original
> ngx_http_auth_request_module does so. If not, then why the request count is
> incorrect?

My best quess is that in your module you are calling 
ngx_http_read_client_request_body(), which will increment r->count.

-- 
Maxim Dounin
http://nginx.org/