$msec variable in proxy_set_header

[Donatas Abraitis]

Already found the problem. There was timer_resolution set to 100ms, which
distorted these latencies.

On Sat, Nov 14, 2015 at 12:09 PM, Donatas Abraitis <
donatas.abraitis at gmail.com> wrote:

> Hi there!
>
> I want to know when $msec is used in proxy_set_header directive? I set:
>
> location / {
>   proxy_set_header X-Queue-Start $msec;
> }
>
> But it's set with the same value as $r->start_sec + $r->start_msec. Is it
> true, that $msec == ("%d.%d", $r->start_sec, $r->start_msec)? Or it's
> really generated separately on demand?
>
> As I see in backtrace (hooked on ngx_http_variable_msec()), it should be
> generated normally, but it isn't (I'm getting $msec == $r...):
>
> ~$ stap -e 'probe
> process("/usr/sbin/nginx").function("ngx_http_variable_msec") {
> print_ubacktrace(); }'
>  0x446c74 : ngx_http_variable_msec+0x4/0x80 [/usr/sbin/nginx]
>  0x4464f8 : ngx_http_get_indexed_variable+0x78/0x100 [/usr/sbin/nginx]
>  0x449381 : ngx_http_script_copy_var_len_code+0x21/0x60 [/usr/sbin/nginx]
>  0x47a005 : ngx_http_proxy_create_request+0x1b5/0xa60 [/usr/sbin/nginx]
>
> The problem is, that we are getting very high latency when using
> proxy_pass for example:
> X-Queue-Start: 1447494119.609 (Nginx X-Queue-Start header $msec value)
> X-Queue-Start: 1447494119.678595 (Ruby Time.now.to_f)
> X-Queue-Start: 1447494121.709 (The same as above)
> X-Queue-Start: 1447494121.7741442 (The same as above)
>
> An this information distort real situation calculating request queuing
> (NewRelic).
>
> Thank you very much!
>
> --
> Donatas
>



-- 
Donatas
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx-devel/attachments/20151115/c45c65f7/attachment.html>