Finding how much time nginx spent in every step of a request processing

Question

We are using Nginx as a reverse proxy to an IIS back-end server serving .NET WCF application.

Recently I had noticed a degradation of the overhead response time. What I mean by that is I used to see 6ms difference between $request_time and $upstream_response_time, now I'm at 22ms.

The number of active connections had not augmented, neither the requests count, size, response size. CPU and disk IO are very low. Network traffic seem to be fine too.

I've tried :

• Disabling SSL, no change.
• Changing back the config of nginx back to default values, no change.
• The machine was rebuild from scratch, no change.
• A much slower VM with the original config and the overhead is very low, +/-6ms.

How can I investigate this problem... ?

Is there a way to see how much time nginx spent in every step of a request processing ? Can't find this answer by looking in error.log in debug mode.

Thanks

Answer 1

there is no easy way (i know of) to do it:

• nginx + lua
• hack ngx_log - module
• create your own,. custom ngx_module

depending on how deep you need to go inside nginx, the luad-solution might be ok or just not enough; using lua you are able to access / modify (and thus meter) different phases of a request

• access
• rewrite
• content-generation

from what you wrote, i wouldnt want to be the one who has to debug your problem :)

Answer 2

Adding an answer because I can't comment.

The reasons for a slowdown could be completely unrelated to nginx.

I think you should try to benchmark your disk read latency, since going back to the default configuration didn't change things.