From 32c85d487ddbbf61189d819497f8cea2a73563ad Mon Sep 17 00:00:00 2001 From: Thijs Schreijer Date: Thu, 6 Apr 2017 14:42:34 +0200 Subject: [PATCH] fix(file-log) add timeout to reopen files automatically If files got rotated, the plugin would keep writing to the existing filedescriptor, instead of recreating a new file. The new `valid` property (in seconds) will automatically reopen the file after the specified number of seconds. --- CHANGELOG.md | 3 ++ kong/plugins/file-log/handler.lua | 25 +++++++-- kong/plugins/file-log/schema.lua | 11 +++- spec/03-plugins/04-file-log/01-log_spec.lua | 59 ++++++++++++++++++++- 4 files changed, 92 insertions(+), 6 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index bb4e3ccfb42b..9a2378b5426d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -33,6 +33,9 @@ which contains the properties of the authenticated Consumer (`id`, `custom_id`, and `username`), if any. [#2367](https://github.com/Mashape/kong/pull/2367) + - File-log plugin now has a new `valid` setting (in seconds) to close and + reopen the logfiles automatically which enables rotating the logs. + [#2348](https://github.com/Mashape/kong/pull/2348) ### Fixed diff --git a/kong/plugins/file-log/handler.lua b/kong/plugins/file-log/handler.lua index 48e86b4b2f53..796f304e4e01 100644 --- a/kong/plugins/file-log/handler.lua +++ b/kong/plugins/file-log/handler.lua @@ -17,9 +17,12 @@ local S_IROTH = system_constants.S_IROTH() local oflags = bit.bor(O_WRONLY, O_CREAT, O_APPEND) local mode = bit.bor(S_IRUSR, S_IWUSR, S_IRGRP, S_IROTH) +local now = ngx.now + ffi.cdef[[ int open(char * filename, int flags, int mode); int write(int fd, void * ptr, int numbytes); +int close(int fd); char *strerror(int errnum); ]] @@ -27,11 +30,25 @@ char *strerror(int errnum); local file_descriptors = {} local function get_fd(conf_path) - return file_descriptors[conf_path] + local fd = file_descriptors[conf_path] + if not fd then + return nil + elseif fd.timeout > now() then + return fd.descriptor + end + -- resetting fd, clear cache + ngx.log(ngx.DEBUG, "[file-log] closing file :", conf_path) + ffi.C.close(fd.descriptor) + file_descriptors[conf_path] = nil + return nil end -local function set_fd(conf_path, file_descriptor) - file_descriptors[conf_path] = file_descriptor +local function set_fd(conf_path, file_descriptor, valid) + local fd = { + descriptor = file_descriptor, + timeout = now() + (valid or 60), -- TODO: remove default, replace it by a migration setting that default + } + file_descriptors[conf_path] = fd end local function string_to_char(str) @@ -54,7 +71,7 @@ local function log(premature, conf, message) local errno = ffi.errno() ngx.log(ngx.ERR, "[file-log] failed to open the file: ", ffi.string(ffi.C.strerror(errno))) else - set_fd(conf.path, fd) + set_fd(conf.path, fd, conf.valid) end end diff --git a/kong/plugins/file-log/schema.lua b/kong/plugins/file-log/schema.lua index b3ad2cf08aa8..efe36dca1485 100644 --- a/kong/plugins/file-log/schema.lua +++ b/kong/plugins/file-log/schema.lua @@ -11,8 +11,17 @@ local function validate_file(value) return true end +local function validate_valid(value) + if value < 0 then + return false, "Value for 'valid' cannot be less than 0" + end + + return true +end + return { fields = { - path = { required = true, type = "string", func = validate_file } + path = { required = true, type = "string", func = validate_file }, + valid = { type = "number", default = 60, func = validate_valid }, } } diff --git a/spec/03-plugins/04-file-log/01-log_spec.lua b/spec/03-plugins/04-file-log/01-log_spec.lua index 88393a941c27..def09a40ac44 100644 --- a/spec/03-plugins/04-file-log/01-log_spec.lua +++ b/spec/03-plugins/04-file-log/01-log_spec.lua @@ -20,7 +20,8 @@ describe("Plugin: file-log (log)", function() api_id = api1.id, name = "file-log", config = { - path = FILE_LOG_PATH + path = FILE_LOG_PATH, + valid = 0.2, } }) @@ -32,9 +33,11 @@ describe("Plugin: file-log (log)", function() before_each(function() client = helpers.proxy_client() + os.remove(FILE_LOG_PATH) end) after_each(function() if client then client:close() end + os.remove(FILE_LOG_PATH) end) it("logs to file", function() @@ -59,7 +62,61 @@ describe("Plugin: file-log (log)", function() local log_message = cjson.decode(pl_stringx.strip(file_log)) assert.same("127.0.0.1", log_message.client_ip) assert.same(uuid, log_message.request.headers["file-log-uuid"]) + end) + + it("reopens file after 'valid' period expires", function() + local uuid1 = utils.random_string() + + -- Making the request + local res = assert(client:send({ + method = "GET", + path = "/status/200", + headers = { + ["file-log-uuid"] = uuid1, + ["Host"] = "file_logging.com" + } + })) + assert.res_status(200, res) + + helpers.wait_until(function() + return pl_path.exists(FILE_LOG_PATH) and pl_path.getsize(FILE_LOG_PATH) > 0 + end, 10) + -- remove the file to see whether it gets recreated os.remove(FILE_LOG_PATH) + ngx.sleep(0.3) -- wait for file to expire + + -- Making the next request + local uuid2 = utils.random_string() + local res = assert(client:send({ + method = "GET", + path = "/status/200", + headers = { + ["file-log-uuid"] = uuid2, + ["Host"] = "file_logging.com" + } + })) + assert.res_status(200, res) + + local uuid3 = utils.random_string() + local res = assert(client:send({ + method = "GET", + path = "/status/200", + headers = { + ["file-log-uuid"] = uuid3, + ["Host"] = "file_logging.com" + } + })) + assert.res_status(200, res) + + helpers.wait_until(function() + return pl_path.exists(FILE_LOG_PATH) and pl_path.getsize(FILE_LOG_PATH) > 0 + end, 10) + + local file_log, err = pl_file.read(FILE_LOG_PATH) + assert.is_nil(err) + assert(not file_log:find(uuid1, nil, true), "did not expected 1st request in logfile") + assert(file_log:find(uuid2, nil, true), "expected 2nd request in logfile") + assert(file_log:find(uuid3, nil, true), "expected 3rd request in logfile") end) end)