You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@apisix.apache.org by mo...@apache.org on 2023/05/18 03:42:23 UTC

[apisix] branch master updated: fix: syslog plugin doesn't work (#9425)

This is an automated email from the ASF dual-hosted git repository.

monkeydluffy pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/apisix.git


The following commit(s) were added to refs/heads/master by this push:
     new 35ea74ee8 fix: syslog plugin doesn't work (#9425)
35ea74ee8 is described below

commit 35ea74ee8b7af5c4e3040914d5d535c20d7f7b8b
Author: Tristan <ji...@foxmail.com>
AuthorDate: Thu May 18 11:42:13 2023 +0800

    fix: syslog plugin doesn't work (#9425)
---
 Makefile                                     |   3 -
 apisix/plugins/sls-logger.lua                |  13 ++--
 apisix/plugins/syslog/init.lua               |  37 ++++++----
 apisix/{plugins/slslog => utils}/rfc5424.lua |  24 +++++--
 ci/pod/docker-compose.plugin.yml             |   2 +
 ci/pod/vector/vector.toml                    |  24 ++++++-
 t/plugin/sls-logger.t                        |  28 ++++----
 t/plugin/syslog.t                            | 104 +++++++++++++++++++++++----
 t/utils/rfc5424.t                            |  83 +++++++++++++++++++++
 t/xrpc/pingpong2.t                           |   4 +-
 t/xrpc/pingpong3.t                           |   2 +-
 t/xrpc/redis2.t                              |   8 +--
 12 files changed, 269 insertions(+), 63 deletions(-)

diff --git a/Makefile b/Makefile
index 3a55a85ae..0e2238f2a 100644
--- a/Makefile
+++ b/Makefile
@@ -349,9 +349,6 @@ install: runtime
 	$(ENV_INSTALL) -d $(ENV_INST_LUADIR)/apisix/plugins/serverless
 	$(ENV_INSTALL) apisix/plugins/serverless/*.lua $(ENV_INST_LUADIR)/apisix/plugins/serverless/
 
-	$(ENV_INSTALL) -d $(ENV_INST_LUADIR)/apisix/plugins/slslog
-	$(ENV_INSTALL) apisix/plugins/slslog/*.lua $(ENV_INST_LUADIR)/apisix/plugins/slslog/
-
 	$(ENV_INSTALL) -d $(ENV_INST_LUADIR)/apisix/plugins/syslog
 	$(ENV_INSTALL) apisix/plugins/syslog/*.lua $(ENV_INST_LUADIR)/apisix/plugins/syslog/
 
diff --git a/apisix/plugins/sls-logger.lua b/apisix/plugins/sls-logger.lua
index 6c2415ac6..de2fbae67 100644
--- a/apisix/plugins/sls-logger.lua
+++ b/apisix/plugins/sls-logger.lua
@@ -21,7 +21,7 @@ local bp_manager_mod = require("apisix.utils.batch-processor-manager")
 
 local plugin_name = "sls-logger"
 local ngx = ngx
-local rf5424 = require("apisix.plugins.slslog.rfc5424")
+local rf5424 = require("apisix.utils.rfc5424")
 local tcp = ngx.socket.tcp
 local tostring = tostring
 local ipairs = ipairs
@@ -138,9 +138,14 @@ function _M.log(conf, ctx)
         return
     end
 
-    local rf5424_data = rf5424.encode("SYSLOG", "INFO", ctx.var.host,"apisix",
-                                      ctx.var.pid, conf.project, conf.logstore,
-                                      conf.access_key_id, conf.access_key_secret, json_str)
+    local structured_data = {
+        {name = "project", value = conf.project},
+        {name = "logstore", value = conf.logstore},
+        {name = "access-key-id", value = conf.access_key_id},
+        {name = "access-key-secret", value = conf.access_key_secret},
+    }
+    local rf5424_data = rf5424.encode("SYSLOG", "INFO", ctx.var.host, "apisix",
+                                      ctx.var.pid, json_str, structured_data)
 
     local process_context = {
         data = rf5424_data,
diff --git a/apisix/plugins/syslog/init.lua b/apisix/plugins/syslog/init.lua
index 24f2f62ab..0ab34f805 100644
--- a/apisix/plugins/syslog/init.lua
+++ b/apisix/plugins/syslog/init.lua
@@ -18,6 +18,10 @@
 local core = require("apisix.core")
 local bp_manager_mod = require("apisix.utils.batch-processor-manager")
 local logger_socket = require("resty.logger.socket")
+local rfc5424 = require("apisix.utils.rfc5424")
+local ipairs = ipairs
+local table_insert = core.table.insert
+local table_concat = core.table.concat
 
 local batch_processor_manager = bp_manager_mod.new("sys logger")
 
@@ -63,7 +67,8 @@ local function send_syslog_data(conf, log_message, api_ctx)
     end
 
     -- reuse the logger object
-    local ok, err = logger:log(core.json.encode(log_message))
+    local ok, err = logger:log(log_message)
+
     if not ok then
         res = false
         err_msg = "failed to log message" .. err
@@ -75,28 +80,32 @@ end
 
 -- called in log phase of APISIX
 function _M.push_entry(conf, ctx, entry)
-    if batch_processor_manager:add_entry(conf, entry) then
+    local json_str, err = core.json.encode(entry)
+    if not json_str then
+        core.log.error('error occurred while encoding the data: ', err)
+        return
+    end
+
+    local rfc5424_data = rfc5424.encode("SYSLOG", "INFO", ctx.var.host,
+                                "apisix", ctx.var.pid, json_str)
+
+    if batch_processor_manager:add_entry(conf, rfc5424_data) then
         return
     end
 
     -- Generate a function to be executed by the batch processor
     local cp_ctx = core.table.clone(ctx)
-    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
+    local func = function(entries)
+        local items = {}
+        for _, e in ipairs(entries) do
+            table_insert(items, e)
+            core.log.debug("buffered logs:", e)
         end
 
-        return send_syslog_data(conf, data, cp_ctx)
+        return send_syslog_data(conf, table_concat(items), cp_ctx)
     end
 
-    batch_processor_manager:add_entry_to_new_processor(conf, entry, ctx, func)
+    batch_processor_manager:add_entry_to_new_processor(conf, rfc5424_data, ctx, func)
 end
 
 
diff --git a/apisix/plugins/slslog/rfc5424.lua b/apisix/utils/rfc5424.lua
similarity index 83%
rename from apisix/plugins/slslog/rfc5424.lua
rename to apisix/utils/rfc5424.lua
index 5d09a58a5..e046194bf 100644
--- a/apisix/plugins/slslog/rfc5424.lua
+++ b/apisix/utils/rfc5424.lua
@@ -79,12 +79,13 @@ local Severity = {
 }
 
 local log_util = require("apisix.utils.log-util")
-
+local ipairs = ipairs
+local str_format = string.format
 
 local _M = { version = 0.1 }
 
-function _M.encode(facility, severity, hostname, appname, pid, project,
-                   logstore, access_key_id, access_key_secret, msg)
+
+function _M.encode(facility, severity, hostname, appname, pid, msg, structured_data)
     local pri = (Facility[facility] * 8 + Severity[severity])
     local t = log_util.get_rfc3339_zulu_timestamp()
     if not hostname then
@@ -95,10 +96,19 @@ function _M.encode(facility, severity, hostname, appname, pid, project,
         appname = "-"
     end
 
-    return "<" .. pri .. ">1 " .. t .. " " .. hostname .. " " .. appname .. " " .. pid
-           .. " - [logservice project=\"" .. project .. "\" logstore=\"" .. logstore
-           .. "\" access-key-id=\"" .. access_key_id .. "\" access-key-secret=\""
-           .. access_key_secret .. "\"] " .. msg .. "\n"
+    local structured_data_str = "-"
+
+    if structured_data then
+        structured_data_str = "[logservice"
+        for _, sd_param in ipairs(structured_data) do
+            structured_data_str = structured_data_str .. " " .. sd_param.name
+                                  .. "=\"" .. sd_param.value .. "\""
+        end
+        structured_data_str = structured_data_str .. "]"
+    end
+
+    return str_format("<%d>1 %s %s %s %d - %s %s\n", pri, t, hostname,
+                    appname, pid, structured_data_str, msg)
 end
 
 return _M
diff --git a/ci/pod/docker-compose.plugin.yml b/ci/pod/docker-compose.plugin.yml
index f4e391698..0979e1e61 100644
--- a/ci/pod/docker-compose.plugin.yml
+++ b/ci/pod/docker-compose.plugin.yml
@@ -321,6 +321,8 @@ services:
     ports:
       - '3000:3000'
       - '43000:43000'
+      - '5140:5140'
+      - '5150:5150/udp'
     networks:
       vector_net:
 
diff --git a/ci/pod/vector/vector.toml b/ci/pod/vector/vector.toml
index 0e02e0fd2..953f30746 100644
--- a/ci/pod/vector/vector.toml
+++ b/ci/pod/vector/vector.toml
@@ -35,8 +35,18 @@ tls.ca_file = "/certs/vector_logs_ca.crt"
 tls.crt_file = "/certs/vector_logs_server.crt"
 tls.key_file = "/certs/vector_logs_server.key"
 
+[sources.log-from-syslog-tcp]
+type = "syslog"
+address = "0.0.0.0:5140"
+mode = "tcp"
+
+[sources.log-from-syslog-udp]
+type = "syslog"
+address = "0.0.0.0:5150"
+mode = "udp"
+
 [sinks.log-2-console]
-inputs = [ "log-from-tcp",  "log-from-tls" ]
+inputs = [ "log-from-tcp",  "log-from-tls", "log-from-syslog-tcp", "log-from-syslog-udp" ]
 type = "console"
 encoding.codec = "json"
 
@@ -51,3 +61,15 @@ inputs = [ "log-from-tls" ]
 type = "file"
 encoding.codec = "json"
 path = "/etc/vector/tls-datas.log"
+
+[sinks.log-2-syslog-tcp-file]
+inputs = [ "log-from-syslog-tcp" ]
+type = "file"
+encoding.codec = "text"
+path = "/etc/vector/syslog-tcp.log"
+
+[sinks.log-2-syslog-udp-file]
+inputs = [ "log-from-syslog-udp" ]
+type = "file"
+encoding.codec = "text"
+path = "/etc/vector/syslog-udp.log"
diff --git a/t/plugin/sls-logger.t b/t/plugin/sls-logger.t
index a56d6121f..9e668e1bf 100644
--- a/t/plugin/sls-logger.t
+++ b/t/plugin/sls-logger.t
@@ -173,16 +173,20 @@ hello world
             end
 
             math.randomseed(os.time())
-            local rfc5424 = require("apisix.plugins.slslog.rfc5424")
+            local rfc5424 = require("apisix.utils.rfc5424")
             local m = 0
             -- because the millisecond value obtained by `ngx.now` may be `0`
             -- it is executed multiple times to ensure the accuracy of the test
             for i = 1, 5 do
                 ngx.sleep(string.format("%0.3f", math.random()))
+                local structured_data = {
+                    {name = "project", value = "apisix.apache.org"},
+                    {name = "logstore", value = "apisix.apache.org"},
+                    {name = "access-key-id", value = "apisix.sls.logger"},
+                    {name = "access-key-secret", value = "BD274822-96AA-4DA6-90EC-15940FB24444"}
+                }
                 local log_entry = rfc5424.encode("SYSLOG", "INFO", "localhost", "apisix",
-                                                 123456, "apisix.apache.org", "apisix.apache.log",
-                                                 "apisix.sls.logger", "BD274822-96AA-4DA6-90EC-15940FB24444",
-                                                 "hello world")
+                                                 123456, "hello world", structured_data)
                 m = get_syslog_timestamp_millisecond(log_entry) + m
             end
 
@@ -226,15 +230,13 @@ passed
 === TEST 9: access
 --- extra_init_by_lua
     local json = require("toolkit.json")
-    local rfc5424 = require("apisix.plugins.slslog.rfc5424")
+    local rfc5424 = require("apisix.utils.rfc5424")
     local old_f = rfc5424.encode
-    rfc5424.encode = function(facility, severity, hostname, appname, pid, project,
-                   logstore, access_key_id, access_key_secret, msg)
+    rfc5424.encode = function(facility, severity, hostname, appname, pid, msg, structured_data)
         local r = json.decode(msg)
         assert(r.client_ip == "127.0.0.1", r.client_ip)
         assert(r.host == "localhost", r.host)
-        return old_f(facility, severity, hostname, appname, pid, project,
-                     logstore, access_key_id, access_key_secret, msg)
+        return old_f(facility, severity, hostname, appname, pid, msg, structured_data)
     end
 --- request
 GET /hello
@@ -372,14 +374,12 @@ passed
 === TEST 13: access
 --- extra_init_by_lua
     local json = require("toolkit.json")
-    local rfc5424 = require("apisix.plugins.slslog.rfc5424")
+    local rfc5424 = require("apisix.utils.rfc5424")
     local old_f = rfc5424.encode
-    rfc5424.encode = function(facility, severity, hostname, appname, pid, project,
-                   logstore, access_key_id, access_key_secret, msg)
+    rfc5424.encode = function(facility, severity, hostname, appname, pid, msg, structured_data)
         local r = json.decode(msg)
         assert(r.vip == "127.0.0.1", r.vip)
-        return old_f(facility, severity, hostname, appname, pid, project,
-                     logstore, access_key_id, access_key_secret, msg)
+        return old_f(facility, severity, hostname, appname, pid, msg, structured_data)
     end
 --- request
 GET /hello
diff --git a/t/plugin/syslog.t b/t/plugin/syslog.t
index a8795bc24..5e13aa301 100644
--- a/t/plugin/syslog.t
+++ b/t/plugin/syslog.t
@@ -31,7 +31,7 @@ __DATA__
             local plugin = require("apisix.plugins.syslog")
             local ok, err = plugin.check_schema({
                  host = "127.0.0.1",
-                 port = 3000,
+                 port = 5140,
             })
             if not ok then
                 ngx.say(err)
@@ -73,7 +73,7 @@ done
             local plugin = require("apisix.plugins.syslog")
             local ok, err = plugin.check_schema({
                  host = "127.0.0.1",
-                 port = "3000",
+                 port = "5140",
             })
             if not ok then
                 ngx.say(err)
@@ -100,7 +100,7 @@ done
                         "plugins": {
                             "syslog": {
                                 "host" : "127.0.0.1",
-                                "port" : 5044
+                                "port" : 5140
                             }
                         },
                         "upstream": {
@@ -142,7 +142,7 @@ hello world
             local logger_socket = require("resty.logger.socket")
             local logger, err = logger_socket:new({
                     host = "127.0.0.1",
-                    port = 5044,
+                    port = 5140,
                     flush_limit = 100,
             })
 
@@ -183,7 +183,7 @@ done
                     "plugins": {
                         "syslog": {
                                 "host" : "127.0.0.1",
-                                "port" : 5044,
+                                "port" : 5140,
                                 "flush_limit" : 1,
                                 "inactive_timeout": 1
                             }
@@ -236,7 +236,15 @@ unlock with key route#1
 
 
 
-=== TEST 8: check plugin configuration updating
+=== TEST 8: check log
+--- exec
+tail -n 1 ci/pod/vector/syslog-tcp.log
+--- response_body eval
+qr/.*apisix_latency.*/
+
+
+
+=== TEST 9: check plugin configuration updating
 --- config
     location /t {
         content_by_lua_block {
@@ -327,7 +335,7 @@ sending a batch logs to 127.0.0.1:5045
 
 
 
-=== TEST 9: add log format
+=== TEST 10: add log format
 --- config
     location /t {
         content_by_lua_block {
@@ -355,7 +363,7 @@ passed
 
 
 
-=== TEST 10: Add route and Enable Syslog Plugin, batch_max_size=1
+=== TEST 11: Add route and Enable Syslog Plugin, batch_max_size=1
 --- config
     location /t {
         content_by_lua_block {
@@ -369,7 +377,7 @@ passed
                                 "disable": false,
                                 "flush_limit": 1,
                                 "host" : "127.0.0.1",
-                                "port" : 5050
+                                "port" : 5140
                             }
                         },
                         "upstream": {
@@ -394,7 +402,7 @@ passed
 
 
 
-=== TEST 11: hit route and report sys logger
+=== TEST 12: hit route and report sys logger
 --- extra_init_by_lua
     local syslog = require("apisix.plugins.syslog.init")
     local json = require("apisix.core.json")
@@ -416,7 +424,15 @@ qr/syslog-log-format.*\{.*"upstream":"127.0.0.1:\d+"/
 
 
 
-=== TEST 12: log format in plugin
+=== TEST 13: check log
+--- exec
+tail -n 1 ci/pod/vector/syslog-tcp.log
+--- response_body eval
+qr/.*\"host\":\"localhost\".*/
+
+
+
+=== TEST 14: log format in plugin
 --- config
     location /t {
         content_by_lua_block {
@@ -432,7 +448,7 @@ qr/syslog-log-format.*\{.*"upstream":"127.0.0.1:\d+"/
                                     "vip": "$remote_addr"
                                 },
                                 "host" : "127.0.0.1",
-                                "port" : 5050
+                                "port" : 5140
                             }
                         },
                         "upstream": {
@@ -461,7 +477,7 @@ passed
 
 
 
-=== TEST 13: access
+=== TEST 15: access
 --- extra_init_by_lua
     local syslog = require("apisix.plugins.syslog.init")
     local json = require("apisix.core.json")
@@ -481,3 +497,65 @@ hello world
 [error]
 --- error_log
 push_entry is called with data
+
+
+
+=== TEST 16: check log
+--- exec
+tail -n 1 ci/pod/vector/syslog-tcp.log
+--- response_body eval
+qr/.*vip.*/
+
+
+
+=== TEST 17: test udp mode
+--- 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": {
+                            "syslog": {
+                                "batch_max_size": 1,
+                                "disable": false,
+                                "flush_limit": 1,
+                                "host" : "127.0.0.1",
+                                "port" : 5150,
+                                "sock_type": "udp"
+                            }
+                        },
+                        "upstream": {
+                            "nodes": {
+                                "127.0.0.1:1980": 1
+                            },
+                            "type": "roundrobin"
+                        },
+                        "uri": "/hello"
+                }]]
+                )
+            if code >= 300 then
+                ngx.status = code
+            end
+            ngx.say(body)
+        }
+    }
+--- request
+GET /t
+--- response_body
+passed
+
+
+
+=== TEST 18: hit
+--- request
+GET /hello
+
+
+
+=== TEST 19: check log
+--- exec
+tail -n 1 ci/pod/vector/syslog-udp.log
+--- response_body eval
+qr/.*upstream.*/
diff --git a/t/utils/rfc5424.t b/t/utils/rfc5424.t
new file mode 100644
index 000000000..06051e627
--- /dev/null
+++ b/t/utils/rfc5424.t
@@ -0,0 +1,83 @@
+#
+# 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';
+
+repeat_each(1);
+no_long_string();
+no_root_location();
+
+add_block_preprocessor(sub {
+    my ($block) = @_;
+
+    if (!defined $block->request) {
+        $block->set_value("request", "GET /t");
+    }
+
+});
+
+run_tests();
+
+__DATA__
+
+=== TEST 1: Compatibility testing
+--- config
+    location /t {
+        content_by_lua_block {
+            local rfc5424 = require("apisix.utils.rfc5424")
+            local structured_data = {
+                {name = "project", value = "apisix.apache.org"},
+                {name = "logstore", value = "apisix.apache.org"},
+                {name = "access-key-id", value = "apisix.sls.logger"},
+                {name = "access-key-secret", value = "BD274822-96AA-4DA6-90EC-15940FB24444"}
+            }
+            local data = rfc5424.encode("SYSLOG", "INFO", "localhost", "apisix",
+                                                123456, "hello world", structured_data)
+            ngx.say(data)
+        }
+    }
+--- response_body eval
+qr/<46>1.*localhost apisix 123456 - \[logservice project=\"apisix\.apache\.org\" logstore=\"apisix\.apache\.org\" access-key-id=\"apisix\.sls\.logger\" access-key-secret=\"BD274822-96AA-4DA6-90EC-15940FB24444\"\] hello world/
+
+
+
+=== TEST 2: No structured data test
+--- config
+    location /t {
+        content_by_lua_block {
+            local rfc5424 = require("apisix.utils.rfc5424")
+            local data = rfc5424.encode("SYSLOG", "INFO", "localhost", "apisix",
+                                                123456, "hello world")
+            ngx.say(data)
+        }
+    }
+--- response_body eval
+qr/<46>1.*localhost apisix 123456 - - hello world/
+
+
+
+=== TEST 3: No host and appname test
+--- config
+    location /t {
+        content_by_lua_block {
+            local rfc5424 = require("apisix.utils.rfc5424")
+            local data = rfc5424.encode("SYSLOG", "INFO", nil, nil,
+                                                123456, "hello world")
+            ngx.say(data)
+        }
+    }
+--- response_body eval
+qr/<46>1.*- - 123456 - - hello world/
diff --git a/t/xrpc/pingpong2.t b/t/xrpc/pingpong2.t
index fc77fa148..7365929ac 100644
--- a/t/xrpc/pingpong2.t
+++ b/t/xrpc/pingpong2.t
@@ -497,7 +497,7 @@ passed
 --- stream_conf_enable
 --- wait: 0.5
 --- error_log eval
-qr/message received:.*\"client_ip\\"\:\\"127.0.0.1\\"/
+qr/message received:.*\"client_ip\"\:\"127.0.0.1\"/
 
 
 
@@ -556,7 +556,7 @@ passed
 --- stream_conf_enable
 --- wait: 0.5
 --- error_log eval
-qr/message received:.*\"client_ip\\"\:\\"127.0.0.1\\"/
+qr/message received:.*\"client_ip\"\:\"127.0.0.1\"/
 
 
 
diff --git a/t/xrpc/pingpong3.t b/t/xrpc/pingpong3.t
index c6d98810d..da16e626b 100644
--- a/t/xrpc/pingpong3.t
+++ b/t/xrpc/pingpong3.t
@@ -190,4 +190,4 @@ passed
 --- stream_conf_enable
 --- wait: 0.5
 --- error_log eval
-qr/message received:.*\"rpc_time\\"\:(0.\d+|0)\}\"/
+qr/message received:.*\"rpc_time\"\:(0.\d+|0)\}/
diff --git a/t/xrpc/redis2.t b/t/xrpc/redis2.t
index 65ca9829c..7e378f836 100644
--- a/t/xrpc/redis2.t
+++ b/t/xrpc/redis2.t
@@ -193,8 +193,8 @@ ping: pong
 --- stream_conf_enable
 --- wait: 1
 --- grep_error_log eval
-qr/message received:.*\"redis_cmd_line\\"\:[^,]+/
+qr/message received:.*\"redis_cmd_line\":[^,]+/
 --- grep_error_log_out eval
-[qr/message received:.*\"redis_cmd_line\\"\:\\\"hmset animals dog bark cat meow\\\"/,
-qr/message received:.*\"redis_cmd_line\\"\:\\\"hmget animals dog cat\\\"/,
-qr/message received:.*\"redis_cmd_line\\"\:\\\"ping\\\"/]
+[qr/message received:.*\"redis_cmd_line\":\"hmset animals dog bark cat meow\"/,
+qr/message received:.*\"redis_cmd_line\":\"hmget animals dog cat\"/,
+qr/message received:.*\"redis_cmd_line\":\"ping\"/]