Runscope plugin

[mansilladev]

No description provided.

[thibaultcha]

Those ngx.ctx values slightly changed in next to be more explicit: https://github.com/Mashape/kong/blob/next/kong/plugins/log-serializers/basic.lua#L27

[thibaultcha]

s/[http-log]/[runscope]/?

It is also best to cache the ngx.log and ngx.ERR variables since it accesses the Lua globals to retrieve ngx.

local ngx_log = ngx.log
local ngx_ERR = ngx.ERR

(This is done in the handler.lua file for example)

[thibaultcha]

Very nice! I left a few comments about some details that need to be fixed.

I have two questions though:

• Wouldn't it be best to just name it runscope? The mashape-analytics plugin will be named galileo, and the Loggly plugin is named loggly, same for syslog. Granted they have "log" in their name but the consistency here is that all plugins are simply named after the plugin they are integrating Kong with.
• I remember you wanted to implement a queue mechanism and I suggested lua-resty-logger-socket. What decided you not to implement this mechanism? (Time consumption or is there any other reason that has to do with Runscope itself, would be a way to reformulate my question).

[mansilladev]

@thibaultcha Re: queuing mechanism -- pushing that out. Needed more time to grok that library, plus wasn't sure how bleeding edge that was (the README wasn't very assuring). Also, renamed to runscope.

[mansilladev]

@thibaultcha Can you look things over? I believe all optimizations you've recommended have been implemented.

[thibaultcha]

I think this part is wrong.

• ngx.ctx.KONG_ACCESS_TIME: time for Kong to run the access_by_lua directive, aka the time it took Kong before the request was sent to upstream, in ms.
• ngx.ctx.KONG_RECEIVE_TIME: time spent waiting for the upstream response headers by Kong, in ms.
• ngx.var.upstream_response_time: same as KONG_RECEIVE_TIME, except that it can contain a comma separated list of values if the request was retried by nginx_proxy (that can happen under load, see the proxy_next_* directives of nginx_proxy).
• ngx.var.request_time:time elapsed between the first bytes were read from the client and the log write after the last bytes were sent to the client`

So this value will actually be 2 to 3 times the actual processing time:

ngx.ctx.KONG_ACCESS_TIME  |  |-----------|                         |
ngx.ctx.KONG_RECEIVE_TIME |              |-------------|           |
$upstream_response_time   |              |-------------|           |
$request_time             |----------------------------------------|

The ngx.ctx.* variable were added to avoid handling the case when var variables are comma-separated strings, causing Lua to failing the +/* etc operators.

Now, I am not sure what the response_time value is supposed to represent (time it took for the client (downstream) to get a response from upstream, through Kong?) If so, the most accurate way is to mimic what the ALF serializer does: alf.lua#L110 by adding the PROXY_LATENCY (time taken for Kong to receive and proxy to upstream) + WAITING_TIME (time elapsed until Kong receives the response headers) + RECEIVE_TIME (time taken for the response body to be proxied back to downstream). Those values are also already in ms resolution.

If this is what response_time is supposed to reflect, I can make those changes myself if you want.

[mansilladev]

@thibaultcha Ignore -- there's a bug. Timings are showing up as zeros. Digging in.

[thibaultcha]

Okay, here if help needed

[mansilladev]

Reapplied Runscope plugin code to 'next' branch. Closing out this PR. #863