From 64fcb9fd72d0cd68c9f0edaddbab9be48e6743a6 Mon Sep 17 00:00:00 2001 From: Nirojan Selvanathan Date: Sat, 9 May 2020 10:19:41 +0200 Subject: [PATCH] plugin: add HTTP logger for APISIX (#1396) --- .travis/linux_openresty_runner.sh | 1 + .travis/linux_tengine_runner.sh | 1 + apisix/plugins/http-logger.lua | 175 +++++++++ conf/config.yaml | 1 + doc/plugins/http-logger.md | 100 +++++ t/admin/plugins.t | 2 +- t/debug/debug-mode.t | 1 + t/plugin/http-logger.t | 597 ++++++++++++++++++++++++++++++ 8 files changed, 877 insertions(+), 1 deletion(-) create mode 100644 apisix/plugins/http-logger.lua create mode 100644 doc/plugins/http-logger.md create mode 100644 t/plugin/http-logger.t diff --git a/.travis/linux_openresty_runner.sh b/.travis/linux_openresty_runner.sh index 384d10ec4a82..117ee3617831 100755 --- a/.travis/linux_openresty_runner.sh +++ b/.travis/linux_openresty_runner.sh @@ -37,6 +37,7 @@ before_install() { sudo cpanm --notest Test::Nginx >build.log 2>&1 || (cat build.log && exit 1) docker pull redis:3.0-alpine docker run --rm -itd -p 6379:6379 --name apisix_redis redis:3.0-alpine + docker run --rm -itd -e HTTP_PORT=8888 -e HTTPS_PORT=9999 -p 8888:8888 -p 9999:9999 mendhak/http-https-echo # spin up kafka cluster for tests (1 zookeper and 1 kafka instance) docker pull bitnami/zookeeper:3.6.0 docker pull bitnami/kafka:latest diff --git a/.travis/linux_tengine_runner.sh b/.travis/linux_tengine_runner.sh index 45a9ec448e29..e246c7a69964 100755 --- a/.travis/linux_tengine_runner.sh +++ b/.travis/linux_tengine_runner.sh @@ -38,6 +38,7 @@ before_install() { sudo cpanm --notest Test::Nginx >build.log 2>&1 || (cat build.log && exit 1) docker pull redis:3.0-alpine docker run --rm -itd -p 6379:6379 --name apisix_redis redis:3.0-alpine + docker run --rm -itd -e HTTP_PORT=8888 -e HTTPS_PORT=9999 -p 8888:8888 -p 9999:9999 mendhak/http-https-echo # spin up kafka cluster for tests (1 zookeper and 1 kafka instance) docker pull bitnami/zookeeper:3.6.0 docker pull bitnami/kafka:latest diff --git a/apisix/plugins/http-logger.lua b/apisix/plugins/http-logger.lua new file mode 100644 index 000000000000..523d02d09796 --- /dev/null +++ b/apisix/plugins/http-logger.lua @@ -0,0 +1,175 @@ +-- +-- Licensed to the Apache Software Foundation (ASF) under one or more +-- contributor license agreements. See the NOTICE file distributed with +-- this work for additional information regarding copyright ownership. +-- The ASF licenses this file to You under the Apache License, Version 2.0 +-- (the "License"); you may not use this file except in compliance with +-- the License. You may obtain a copy of the License at +-- +-- http://www.apache.org/licenses/LICENSE-2.0 +-- +-- Unless required by applicable law or agreed to in writing, software +-- distributed under the License is distributed on an "AS IS" BASIS, +-- WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +-- See the License for the specific language governing permissions and +-- limitations under the License. +-- +local core = require("apisix.core") +local log_util = require("apisix.utils.log-util") +local batch_processor = require("apisix.utils.batch-processor") +local plugin_name = "http-logger" +local ngx = ngx +local tostring = tostring +local http = require "resty.http" +local url = require "net.url" +local buffers = {} + +local schema = { + type = "object", + properties = { + uri = {type = "string"}, + auth_header = {type = "string", default = ""}, + timeout = {type = "integer", minimum = 1, default = 3}, + name = {type = "string", default = "http logger"}, + max_retry_count = {type = "integer", minimum = 0, default = 0}, + retry_delay = {type = "integer", minimum = 0, default = 1}, + buffer_duration = {type = "integer", minimum = 1, default = 60}, + inactive_timeout = {type = "integer", minimum = 1, default = 5}, + batch_max_size = {type = "integer", minimum = 1, default = 1000}, + }, + required = {"uri"} +} + + +local _M = { + version = 0.1, + priority = 410, + name = plugin_name, + schema = schema, +} + + +function _M.check_schema(conf) + return core.schema.check(schema, conf) +end + + +local function send_http_data(conf, log_message) + local err_msg + local res = true + local url_decoded = url.parse(conf.uri) + local host = url_decoded.host + local port = url_decoded.port + + if ((not port) and url_decoded.scheme == "https") then + port = 443 + elseif not port then + port = 80 + end + + local httpc = http.new() + httpc:set_timeout(conf.timeout * 1000) + local ok, err = httpc:connect(host, port) + + if not ok then + return false, "failed to connect to host[" .. host .. "] port[" + .. tostring(port) .. "] " .. err + end + + if url_decoded.scheme == "https" then + ok, err = httpc:ssl_handshake(true, host, false) + if not ok then + return nil, "failed to perform SSL with host[" .. host .. "] " + .. "port[" .. tostring(port) .. "] " .. err + end + end + + local httpc_res, httpc_err = httpc:request({ + method = "POST", + path = url_decoded.path, + query = url_decoded.query, + body = log_message, + headers = { + ["Host"] = url_decoded.host, + ["Content-Type"] = "application/json", + ["Authorization"] = conf.auth_header + } + }) + + if not httpc_res then + return false, "error while sending data to [" .. host .. "] port[" + .. tostring(port) .. "] " .. httpc_err + end + + -- some error occurred in the server + if httpc_res.status >= 400 then + res = false + err_msg = "server returned status code[" .. httpc_res.status .. "] host[" + .. host .. "] port[" .. tostring(port) .. "] " + .. "body[" .. httpc_res:read_body() .. "]" + end + + -- keep the connection alive + ok, err = httpc:set_keepalive(conf.keepalive) + + if not ok then + core.log.debug("failed to keep the connection alive", err) + end + + return res, err_msg +end + + +function _M.log(conf) + local entry = log_util.get_full_log(ngx) + + if not entry.route_id then + core.log.error("failed to obtain the route id for http logger") + return + end + + local log_buffer = buffers[entry.route_id] + + if log_buffer then + log_buffer:push(entry) + return + end + + -- Generate a function to be executed by the batch processor + local func = function(entries, batch_max_size) + local data, err + if batch_max_size == 1 then + data, err = core.json.encode(entries[1]) -- encode as single {} + else + data, err = core.json.encode(entries) -- encode as array [{}] + end + + if not data then + return false, 'error occurred while encoding the data: ' .. err + end + + return send_http_data(conf, data) + end + + local config = { + name = conf.name, + retry_delay = conf.retry_delay, + batch_max_size = conf.batch_max_size, + max_retry_count = conf.max_retry_count, + buffer_duration = conf.buffer_duration, + inactive_timeout = conf.inactive_timeout, + } + + local err + log_buffer, err = batch_processor:new(func, config) + + if not log_buffer then + core.log.error("error when creating the batch processor: ", err) + return + end + + buffers[entry.route_id] = log_buffer + log_buffer:push(entry) +end + +return _M diff --git a/conf/config.yaml b/conf/config.yaml index 8de3fe1945d0..ef3a7f89ad55 100644 --- a/conf/config.yaml +++ b/conf/config.yaml @@ -147,5 +147,6 @@ plugins: # plugin list - cors - syslog - batch-requests + - http-logger stream_plugins: - mqtt-proxy diff --git a/doc/plugins/http-logger.md b/doc/plugins/http-logger.md new file mode 100644 index 000000000000..55d0bc4eb9e7 --- /dev/null +++ b/doc/plugins/http-logger.md @@ -0,0 +1,100 @@ + + +# Summary +- [**Name**](#name) +- [**Attributes**](#attributes) +- [**How To Enable**](#how-to-enable) +- [**Test Plugin**](#test-plugin) +- [**Disable Plugin**](#disable-plugin) + + +## Name + +`http-logger` is a plugin which push Log data requests to HTTP/HTTPS servers. + +This will provide the ability to send Log data requests as JSON objects to Monitoring tools and other HTTP servers. + +## Attributes + +|Name |Requirement |Description| +|--------- |-------- |-----------| +|uri |required |URI of the server| +|authorization |optional |Any authorization headers| +|keepalive |optional |Time to keep the connection alive after sending a request| +|name |optional |A unique identifier to identity the logger| +|batch_max_size |optional |Max size of each batch, default is 1000| +|inactive_timeout|optional |maximum age in seconds when the buffer will be flushed if inactive, default is 5s| +|buffer_duration|optional |Maximum age in seconds of the oldest entry in a batch before the batch must be processed, default is 5| +|max_retry_count|optional |Maximum number of retries before removing from the processing pipe line; default is zero| +|retry_delay |optional |Number of seconds the process execution should be delayed if the execution fails; default is 1| + + +## How To Enable + +The following is an example on how to enable the http-logger for a specific route. + +```shell +curl http://127.0.0.1:9080/apisix/admin/routes/5 -H 'X-API-KEY: edd1c9f034335f136f87ad84b625c8f1' -X PUT -d ' +{ + "plugins": { + "http-logger": { + "uri": "127.0.0.1:80/postendpoint?param=1", + } + }, + "upstream": { + "type": "roundrobin", + "nodes": { + "127.0.0.1:1980": 1 + } + }, + "uri": "/hello" +}' +``` + +## Test Plugin + +* success: + +```shell +$ curl -i http://127.0.0.1:9080/hello +HTTP/1.1 200 OK +... +hello, world +``` + +## Disable Plugin + +Remove the corresponding json configuration in the plugin configuration to disable the `http-logger`. +APISIX plugins are hot-reloaded, therefore no need to restart APISIX. + +```shell +$ curl http://127.0.0.1:2379/apisix/admin/routes/1 -X PUT -d value=' +{ + "methods": ["GET"], + "uri": "/hello", + "plugins": {}, + "upstream": { + "type": "roundrobin", + "nodes": { + "127.0.0.1:1980": 1 + } + } +}' +``` diff --git a/t/admin/plugins.t b/t/admin/plugins.t index 344ffe80a212..0c838e6c6173 100644 --- a/t/admin/plugins.t +++ b/t/admin/plugins.t @@ -30,7 +30,7 @@ __DATA__ --- request GET /apisix/admin/plugins/list --- response_body_like eval -qr/\["limit-req","limit-count","limit-conn","key-auth","basic-auth","prometheus","node-status","jwt-auth","zipkin","ip-restriction","grpc-transcode","serverless-pre-function","serverless-post-function","openid-connect","proxy-rewrite","redirect","response-rewrite","fault-injection","udp-logger","wolf-rbac","proxy-cache","tcp-logger","proxy-mirror","kafka-logger","cors","syslog","batch-requests"\]/ +qr/\["limit-req","limit-count","limit-conn","key-auth","basic-auth","prometheus","node-status","jwt-auth","zipkin","ip-restriction","grpc-transcode","serverless-pre-function","serverless-post-function","openid-connect","proxy-rewrite","redirect","response-rewrite","fault-injection","udp-logger","wolf-rbac","proxy-cache","tcp-logger","proxy-mirror","kafka-logger","cors","syslog","batch-requests","http-logger"\]/ --- no_error_log [error] diff --git a/t/debug/debug-mode.t b/t/debug/debug-mode.t index de97e00f8e83..1799f509bc95 100644 --- a/t/debug/debug-mode.t +++ b/t/debug/debug-mode.t @@ -76,6 +76,7 @@ loaded plugin and sort by priority: 900 name: redirect loaded plugin and sort by priority: 899 name: response-rewrite loaded plugin and sort by priority: 506 name: grpc-transcode loaded plugin and sort by priority: 500 name: prometheus +loaded plugin and sort by priority: 410 name: http-logger loaded plugin and sort by priority: 405 name: tcp-logger loaded plugin and sort by priority: 403 name: kafka-logger loaded plugin and sort by priority: 401 name: syslog diff --git a/t/plugin/http-logger.t b/t/plugin/http-logger.t new file mode 100644 index 000000000000..029a85e17413 --- /dev/null +++ b/t/plugin/http-logger.t @@ -0,0 +1,597 @@ +# +# Licensed to the Apache Software Foundation (ASF) under one or more +# contributor license agreements. See the NOTICE file distributed with +# this work for additional information regarding copyright ownership. +# The ASF licenses this file to You under the Apache License, Version 2.0 +# (the "License"); you may not use this file except in compliance with +# the License. You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# +use t::APISIX 'no_plan'; + +log_level('debug'); +repeat_each(1); +no_long_string(); +no_root_location(); +run_tests; + +__DATA__ + +=== TEST 1: sanity +--- config + location /t { + content_by_lua_block { + local plugin = require("apisix.plugins.http-logger") + local ok, err = plugin.check_schema({uri = "127.0.0.1"}) + if not ok then + ngx.say(err) + end + + ngx.say("done") + } + } +--- request +GET /t +--- response_body +done +--- no_error_log +[error] + + + +=== TEST 2: full schema check +--- config + location /t { + content_by_lua_block { + local plugin = require("apisix.plugins.http-logger") + local ok, err = plugin.check_schema({uri = "127.0.0.1", + auth_header = "Basic 123", + timeout = 3, + name = "http-logger", + max_retry_count = 2, + retry_delay = 2, + buffer_duration = 2, + inactive_timeout = 2, + batch_max_size = 500, + }) + if not ok then + ngx.say(err) + end + + ngx.say("done") + } + } +--- request +GET /t +--- response_body +done +--- no_error_log +[error] + + + +=== TEST 3: uri is missing +--- config + location /t { + content_by_lua_block { + local plugin = require("apisix.plugins.http-logger") + local ok, err = plugin.check_schema({auth_header = "Basic 123", + timeout = 3, + name = "http-logger", + max_retry_count = 2, + retry_delay = 2, + buffer_duration = 2, + inactive_timeout = 2, + batch_max_size = 500, + }) + if not ok then + ngx.say(err) + end + + ngx.say("done") + } + } +--- request +GET /t +--- response_body +property "uri" is required +done +--- no_error_log +[error] + + + +=== TEST 4: add plugin +--- config + location /t { + content_by_lua_block { + local t = require("lib.test_admin").test + local code, body = t('/apisix/admin/routes/1', + ngx.HTTP_PUT, + [[{ + "plugins": { + "http-logger": { + "uri": "http://127.0.0.1:1982/hello", + "batch_max_size": 1, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/opentracing" + }]], + [[{ + "node": { + "value": { + "plugins": { + "http-logger": { + "uri": "http://127.0.0.1:1982/hello", + "batch_max_size": 1, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/opentracing" + }, + "key": "/apisix/routes/1" + }, + "action": "set" + }]] + ) + + if code >= 300 then + ngx.status = code + end + ngx.say(body) + } + } +--- request +GET /t +--- response_body +passed +--- no_error_log +[error] + + + +=== TEST 5: access local server +--- request +GET /opentracing +--- response_body +opentracing +--- error_log +Batch Processor[http logger] successfully processed the entries +--- wait: 0.5 + + + +=== TEST 6: set to the http external endpoint +--- config + location /t { + content_by_lua_block { + local t = require("lib.test_admin").test + local code, body = t('/apisix/admin/routes/1', + ngx.HTTP_PUT, + [[{ + "plugins": { + "http-logger": { + "uri": "http://127.0.0.1:8888/hello-world-http", + "batch_max_size": 1, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/hello" + }]], + [[{ + "node": { + "value": { + "plugins": { + "http-logger": { + "uri": "http://127.0.0.1:8888/hello-world-http", + "batch_max_size": 1, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/hello" + }, + "key": "/apisix/routes/1" + }, + "action": "set" + }]] + ) + + if code >= 300 then + ngx.status = code + end + ngx.say(body) + } + } +--- request +GET /t +--- response_body +passed +--- no_error_log +[error] + + + +=== TEST 7: access external endpoint +--- request +GET /hello +--- response_body +hello world +--- error_log +Batch Processor[http logger] successfully processed the entries +--- wait: 1.5 + + + +=== TEST 8: set wrong https endpoint +--- config + location /t { + content_by_lua_block { + local t = require("lib.test_admin").test + local code, body = t('/apisix/admin/routes/1', + ngx.HTTP_PUT, + [[{ + "plugins": { + "http-logger": { + "uri": "https://127.0.0.1:8888/hello-world-http", + "batch_max_size": 1, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/hello1" + }]], + [[{ + "node": { + "value": { + "plugins": { + "http-logger": { + "uri": "https://127.0.0.1:8888/hello-world-http", + "batch_max_size": 1, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/hello1" + }, + "key": "/apisix/routes/1" + }, + "action": "set" + }]] + ) + + if code >= 300 then + ngx.status = code + end + ngx.say(body) + } + } +--- request +GET /t +--- response_body +passed +--- no_error_log +[error] + + + +=== TEST 9: access wrong https endpoint +--- request +GET /hello1 +--- response_body +hello1 world +--- error_log +failed to perform SSL with host[127.0.0.1] port[8888] handshake failed +--- wait: 1.5 + + + +=== TEST 10: set correct https endpoint +--- config + location /t { + content_by_lua_block { + local t = require("lib.test_admin").test + local code, body = t('/apisix/admin/routes/1', + ngx.HTTP_PUT, + [[{ + "plugins": { + "http-logger": { + "uri": "https://127.0.0.1:9999/hello-world-http", + "batch_max_size": 1, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/hello1" + }]], + [[{ + "node": { + "value": { + "plugins": { + "http-logger": { + "uri": "https://127.0.0.1:9999/hello-world-http", + "batch_max_size": 1, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/hello1" + }, + "key": "/apisix/routes/1" + }, + "action": "set" + }]] + ) + + if code >= 300 then + ngx.status = code + end + ngx.say(body) + } + } +--- request +GET /t +--- response_body +passed +--- no_error_log +[error] + + + +=== TEST 11: access correct https endpoint +--- request +GET /hello1 +--- response_body +hello1 world +--- error_log +Batch Processor[http logger] successfully processed the entries +--- wait: 1.5 + + + +=== TEST 12: set batch max size to two +--- config + location /t { + content_by_lua_block { + local t = require("lib.test_admin").test + local code, body = t('/apisix/admin/routes/1', + ngx.HTTP_PUT, + [[{ + "plugins": { + "http-logger": { + "uri": "https://127.0.0.1:9999/hello-world-http", + "batch_max_size": 2, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/hello1" + }]], + [[{ + "node": { + "value": { + "plugins": { + "http-logger": { + "uri": "https://127.0.0.1:9999/hello-world-http", + "batch_max_size": 2, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/hello1" + }, + "key": "/apisix/routes/1" + }, + "action": "set" + }]] + ) + + if code >= 300 then + ngx.status = code + end + ngx.say(body) + } + } +--- request +GET /t +--- response_body +passed +--- no_error_log +[error] + + + +=== TEST 13: access route with batch max size twice +--- config + location /t { + content_by_lua_block { + local http = require "resty.http" + local httpc = http.new() + local uri = "http://127.0.0.1:" .. ngx.var.server_port .. "/hello1" + local res, err = httpc:request_uri(uri, { method = "GET"}) + res, err = httpc:request_uri(uri, { method = "GET"}) + ngx.status = res.status + if res.status == 200 then + ngx.say("hello1 world") + end + } + } +--- request +GET /t +--- response_body +hello1 world +--- error_log +Batch Processor[http logger] batch max size has exceeded +tranferring buffer entries to processing pipe line, buffercount[2] +Batch Processor[http logger] successfully processed the entries +--- wait: 1.5 + + + +=== TEST 14: set wrong port +--- config + location /t { + content_by_lua_block { + local t = require("lib.test_admin").test + local code, body = t('/apisix/admin/routes/1', + ngx.HTTP_PUT, + [[{ + "plugins": { + "http-logger": { + "uri": "http://127.0.0.1:9991/hello-world-http", + "batch_max_size": 1, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/hello1" + }]], + [[{ + "node": { + "value": { + "plugins": { + "http-logger": { + "uri": "http://127.0.0.1:9991/hello-world-http", + "batch_max_size": 1, + "max_retry_count": 1, + "retry_delay": 2, + "buffer_duration": 2, + "inactive_timeout": 2 + } + }, + "upstream": { + "nodes": { + "127.0.0.1:1982": 1 + }, + "type": "roundrobin" + }, + "uri": "/hello1" + }, + "key": "/apisix/routes/1" + }, + "action": "set" + }]] + ) + + if code >= 300 then + ngx.status = code + end + ngx.say(body) + } + } +--- request +GET /t +--- response_body +passed +--- no_error_log +[error] + + + +=== TEST 15: access wrong port +--- request +GET /hello1 +--- response_body +hello1 world +--- error_log +Batch Processor[http logger] failed to process entries: failed to connect to host[127.0.0.1] port[9991] connection refused +--- wait: 1.5