Skip to content

Commit

Permalink
Browse files Browse the repository at this point in the history
feat(http-log) adds log buffering to http-log plugin
Adds three new properties to the configuration of http-log:

* `retry_count` - default 10
* `queue_size` - default 1
* `flush_timeout` - default 2

Their behaviors are the same as the identically-named options
in the `galileo` plugin.

The default of `queue_size` is set to 1 so that the default behavior
of the plugin remains backwards-compatible.

When `queue_size` is 1, it makes one HTTP request per logged
entry, containing a single JSON object in each.

When `queue_size` is greater than 1, the HTTP connection will send
a JSON array containing one or more JSON objects in it, up to
the configured queue size.

The new fields are not required, and when absent their defaults
mean that they behave the same as the http-log plugin always did,
meaning this requires no migrations.

Includes a test case using the mock log server.
  • Loading branch information
hishamhm committed Jul 18, 2018
1 parent 72f2093 commit de4a002
Show file tree
Hide file tree
Showing 7 changed files with 341 additions and 99 deletions.
3 changes: 3 additions & 0 deletions kong-0.14.0-0.rockspec
Expand Up @@ -195,6 +195,8 @@ build = {
["kong.plugins.oauth2.daos"] = "kong/plugins/oauth2/daos.lua",
["kong.plugins.oauth2.api"] = "kong/plugins/oauth2/api.lua",

["kong.plugins.log-buffering.json_producer"] = "kong/plugins/log-buffering/json_producer.lua",
["kong.plugins.log-buffering.lua_producer"] = "kong/plugins/log-buffering/lua_producer.lua",
["kong.plugins.log-buffering.buffer"] = "kong/plugins/log-buffering/buffer.lua",

["kong.plugins.log-serializers.basic"] = "kong/plugins/log-serializers/basic.lua",
Expand All @@ -209,6 +211,7 @@ build = {

["kong.plugins.http-log.handler"] = "kong/plugins/http-log/handler.lua",
["kong.plugins.http-log.schema"] = "kong/plugins/http-log/schema.lua",
["kong.plugins.http-log.sender"] = "kong/plugins/http-log/sender.lua",

["kong.plugins.file-log.handler"] = "kong/plugins/file-log/handler.lua",
["kong.plugins.file-log.schema"] = "kong/plugins/file-log/schema.lua",
Expand Down
147 changes: 51 additions & 96 deletions kong/plugins/http-log/handler.lua
@@ -1,114 +1,39 @@
local basic_serializer = require "kong.plugins.log-serializers.basic"
local BasePlugin = require "kong.plugins.base_plugin"
local LuaProducer = require "kong.plugins.log-buffering.lua_producer"
local JSONProducer = require "kong.plugins.log-buffering.json_producer"
local Sender = require "kong.plugins.http-log.sender"
local Buffer = require "kong.plugins.log-buffering.buffer"
local cjson = require "cjson"
local url = require "socket.url"

local string_format = string.format

local cjson_encode = cjson.encode
local ERR = ngx.ERR


local HttpLogHandler = BasePlugin:extend()


HttpLogHandler.PRIORITY = 12
HttpLogHandler.VERSION = "0.1.0"

local HTTP = "http"
local HTTPS = "https"

-- Generates the raw http message.
-- @param `method` http method to be used to send data
-- @param `content_type` the type to set in the header
-- @param `parsed_url` contains the host details
-- @param `body` Body of the message as a string (must be encoded according to the `content_type` parameter)
-- @return raw http message
local function generate_post_payload(method, content_type, parsed_url, body)
local url
if parsed_url.query then
url = parsed_url.path .. "?" .. parsed_url.query
else
url = parsed_url.path
end
local headers = string_format(
"%s %s HTTP/1.1\r\nHost: %s\r\nConnection: Keep-Alive\r\nContent-Type: %s\r\nContent-Length: %s\r\n",
method:upper(), url, parsed_url.host, content_type, #body)

if parsed_url.userinfo then
local auth_header = string_format(
"Authorization: Basic %s\r\n",
ngx.encode_base64(parsed_url.userinfo)
)
headers = headers .. auth_header
end

return string_format("%s\r\n%s", headers, body)
end
local buffers = {} -- buffers per-route / -api

-- Parse host url.
-- @param `url` host url
-- @return `parsed_url` a table with host details like domain name, port, path etc
local function parse_url(host_url)
local parsed_url = url.parse(host_url)
if not parsed_url.port then
if parsed_url.scheme == HTTP then
parsed_url.port = 80
elseif parsed_url.scheme == HTTPS then
parsed_url.port = 443
end
end
if not parsed_url.path then
parsed_url.path = "/"
end
return parsed_url
end

-- Log to a Http end point.
-- This basically is structured as a timer callback.
-- @param `premature` see openresty ngx.timer.at function
-- @param `conf` plugin configuration table, holds http endpoint details
-- @param `body` raw http body to be logged
-- @param `name` the plugin name (used for logging purposes in case of errors etc.)
local function log(premature, conf, body, name)
if premature then
return
end
name = "[" .. name .. "] "

local ok, err
local parsed_url = parse_url(conf.http_endpoint)
local host = parsed_url.host
local port = tonumber(parsed_url.port)

local sock = ngx.socket.tcp()
sock:settimeout(conf.timeout)

ok, err = sock:connect(host, port)
if not ok then
ngx.log(ngx.ERR, name .. "failed to connect to " .. host .. ":" .. tostring(port) .. ": ", err)
return
end

if parsed_url.scheme == HTTPS then
local _, err = sock:sslhandshake(true, host, false)
if err then
ngx.log(ngx.ERR, name .. "failed to do SSL handshake with " .. host .. ":" .. tostring(port) .. ": ", err)
end
end
-- Only provide `name` when deriving from this class. Not when initializing an instance.
function HttpLogHandler:new(name)
name = name or "http-log"
HttpLogHandler.super.new(self, name)

ok, err = sock:send(generate_post_payload(conf.method, conf.content_type, parsed_url, body))
if not ok then
ngx.log(ngx.ERR, name .. "failed to send data to " .. host .. ":" .. tostring(port) .. ": ", err)
end
self.ngx_log = ngx.log
-- self.ngx_log = function(lvl, ...)
-- ngx_log(lvl, "[", name, "] ", ...)
-- end

ok, err = sock:setkeepalive(conf.keepalive)
if not ok then
ngx.log(ngx.ERR, name .. "failed to keepalive to " .. host .. ":" .. tostring(port) .. ": ", err)
return
end
self.name = name
end

-- Only provide `name` when deriving from this class. Not when initializing an instance.
function HttpLogHandler:new(name)
HttpLogHandler.super.new(self, name or "http-log")
end

-- serializes context data into an html message body.
-- @param `ngx` The context table for the request being logged
Expand All @@ -118,13 +43,43 @@ function HttpLogHandler:serialize(ngx, conf)
return cjson_encode(basic_serializer.serialize(ngx))
end


function HttpLogHandler:log(conf)
HttpLogHandler.super.log(self)

local ok, err = ngx.timer.at(0, log, conf, self:serialize(ngx, conf), self._name)
if not ok then
ngx.log(ngx.ERR, "[" .. self._name .. "] failed to create timer: ", err)
local route_id = conf.route_id or conf.api_id
local buf = buffers[route_id]
if not buf then

if conf.queue_size == nil then
conf.queue_size = 1
end

-- base delay between batched sends
conf.send_delay = 0

local buffer_producer
-- If using a queue, produce messages into a JSON array,
-- otherwise keep it as a 1-entry Lua array which will
-- result in a backward-compatible single-object HTTP request.
if conf.queue_size > 1 then
buffer_producer = JSONProducer.new(true)
else
buffer_producer = LuaProducer.new()
end

local err
buf, err = Buffer.new(self.name, conf, buffer_producer, Sender.new(conf, self.ngx_log), self.ngx_log)
if not buf then
self.ngx_log(ERR, "could not create buffer: ", err)
return
end
buffers[route_id] = buf
end

-- This can be simplified if we don't expect third-party plugins to
-- "subclass" this plugin.
buf:add_entry(self:serialize(ngx, conf))
end

return HttpLogHandler
6 changes: 5 additions & 1 deletion kong/plugins/http-log/schema.lua
Expand Up @@ -4,6 +4,10 @@ return {
method = { default = "POST", enum = { "POST", "PUT", "PATCH" } },
content_type = { default = "application/json", enum = { "application/json" } },
timeout = { default = 10000, type = "number" },
keepalive = { default = 60000, type = "number" }
keepalive = { default = 60000, type = "number" },

retry_count = {type = "number", default = 10},
queue_size = {type = "number", default = 1},
flush_timeout = {type = "number", default = 2},
}
}
114 changes: 114 additions & 0 deletions kong/plugins/http-log/sender.lua
@@ -0,0 +1,114 @@
local url = require "socket.url"
local http = require "resty.http"


local sender = {}


local ngx_encode_base64 = ngx.encode_base64
local ERR = ngx.ERR


-- Parse host url.
-- @param `url` host url
-- @return `parsed_url` a table with host details like domain name, port, path etc
local function parse_url(host_url)
local parsed_url = url.parse(host_url)
if not parsed_url.port then
if parsed_url.scheme == "http" then
parsed_url.port = 80
elseif parsed_url.scheme == "https" then
parsed_url.port = 443
end
end
if not parsed_url.path then
parsed_url.path = "/"
end
return parsed_url
end


-- Log to a Http end point.
-- @param `bodies` raw http bodies to be logged
local function send(self, bodies)
local log = self.log

local ok, err
local parsed_url = parse_url(self.http_endpoint)
local host = parsed_url.host
local port = tonumber(parsed_url.port)

if type(bodies) == "string" then
bodies = { bodies }
end
for _, body in ipairs(bodies) do
local httpc = http.new()
httpc:set_timeout(self.timeout)
ok, err = httpc:connect(host, port)
if not ok then
log(ERR, "failed to connect to ", host, ":", tostring(port), ": ", err)
return false
end

if parsed_url.scheme == "https" then
local _, err = httpc:ssl_handshake(true, host, false)
if err then
log(ERR, "failed to do SSL handshake with ",
host, ":", tostring(port), ": ", err)
return false
end
end

local res, err = httpc:request({
method = self.method,
path = parsed_url.path,
query = parsed_url.query,
headers = {
["Host"] = parsed_url.host,
["Content-Type"] = self.content_type,
["Content-Length"] = #body,
["Authorization"] = parsed_url.userinfo and (
"Basic " .. ngx_encode_base64(parsed_url.userinfo)
),
},
body = body,
})
if not res then
log(ERR, "failed request to ", host, ":", tostring(port), ": ", err)
end

-- read and discard body
-- TODO should we fail if response status was >= 500 ?
res:read_body()

ok, err = httpc:set_keepalive(self.keepalive)
if not ok then
log(ERR, "failed keepalive for ", host, ":", tostring(port), ": ", err)
end
end

return true
end


function sender.new(conf, log)
if type(log) ~= "function" then
error("arg #2 (log) must be a function")
end

local self = {
http_endpoint = conf.http_endpoint,
content_type = conf.content_type,
keepalive = conf.keepalive,
timeout = conf.timeout,
method = conf.method,

send = send,
log = log,
}

return self
end


return sender
66 changes: 66 additions & 0 deletions kong/plugins/log-buffering/json_producer.lua
@@ -0,0 +1,66 @@
-- JSON array producer object for using the Generic Logging Buffer.
local cjson = require("cjson")


local json_producer = {}


local cjson_encode = cjson.encode


local function add_entry(self, data)
if not self.encoded then
data = cjson_encode(data)
end
local n = #self.output
if n == 0 then
self.output[1] = "["
else
self.output[n+1] = ","
end
self.output[n+2] = data
self.bytes = self.bytes + #data + 1
return true, (n + 2) / 2
end


local function produce(self)
local count = #self.output / 2
self.output[#self.output + 1] = "]"
local data = table.concat(self.output)
return data, count, #data
end


local function reset(self)
self.output = {}
self.bytes = 1
end


-- Produces the given entries into a JSON array.
-- @param raw_tree (boolean)
-- If `encoded` is `true`, entries are assumed to be strings
-- that already represent JSON-encoded data.
-- If `encoded` is `false`, entries are assumed to be Lua objects
-- that need to be encoded during serialization.
function json_producer.new(encoded)
if encoded ~= nil and type(encoded) ~= "boolean" then
error("arg 2 (encoded) must be boolean")
end

local self = {
output = {},
bytes = 1,
encoded = encoded,

add_entry = add_entry,
produce = produce,
reset = reset,
}

return self
end


return json_producer

1 comment on commit de4a002

@jeremyjpj0916
Copy link
Contributor

@jeremyjpj0916 jeremyjpj0916 commented on de4a002 Oct 16, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@hishamhm I decided to test some of this logic on one of our own branches with tweaks for 0.14.1. I found that a change between the IMPL as it stands vs older logic is the reliance on a route.id or api.id(for deprecated entities). I think the appropriate behavior would be if route or api id is nil to use a static buffer key and let that batch for all proxy calls that are not necessarily associated with a route/api, because even 404 not founds to the gateway should get logged. Plugin will throw a nil pointer exception in current state because buffer[nil] on gateway paths that don't exist.

https://github.com/Kong/kong/blob/next/kong/plugins/http-log/handler.lua#L51

I made mine something like

local route_id = conf.route_id or conf.api_id or "notfound"

But I also want to thank you for this revised logic, the batching plus leveraging the rest client lib seems to have resolved problems we had with the older plugin(lots of ssl and tcp connection problems) 👍 .

Please sign in to comment.