fix(logging) include 'balancer_by_lua' latency in Kong latency

[subnetmarco]

• fix(logging) include balancer_by_lua latency in Kong latency

[thibaultcha]

Sadly this won't do it. The balancer_by_lua directive can be invoked multiple times during a single request, and the current implementation in this patch will only consider the last invocation of the balancer handler.

You will need to distinguish the first invocation of the balancer handler (via the addr.try_count variable), and set the KONG_BALANCER_START variable only once. The same way, KONG_BALANCER_TIME can only be computed when we are sure that the current balancer invocation will be the last one.

It might be worth considering making this a list of entries, and have a different time for each try. After all, try 1 can, for various reasons (like DNS resolution, or load-balancing algorithm variations), be significantly slower of faster than another try. This would give useful debug information to a user if they were include in the serialized data sent by the logging plugins, for example.

[p0pr0ck5]

@thefosk do we still need this, or can we close this PR since we have a few debug/latency patches floating around?

[thibaultcha]

We still need this, as this is missing from the current logging serializers, but as mentioned, a better version of it.

[subnetmarco]

I will give this another look soon

[Tieske]

you can use the tries field as it will contain info for each try (will be logged by serializers). See https://github.com/Mashape/kong/blob/master/kong/core/handler.lua#L108

As a side note: on its own the latency here will pretty much always be near 0ms, as the actual dns resolution is done in the access phase.

[thibaultcha]

(cc @thefosk)

[Tieske]

@thibaultcha @thefosk I updated this pr to properly track time spent per try. Please have a look.

[thibaultcha]

This one will do. Updated the commit author + moved the balancer callbacks to the right place in core.handler (after access). Thanks!