fix(file-log) add option to reopen files on every request (Kong#2437)

If files got rotated, the plugin would keep writing to the existing
filedescriptor, instead of recreating a new file.
The new `reopen` flag property will automatically close/reopen the file
on every request if set.

CHANGELOG.md

@@ -44,6 +44,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 `reopen` setting to close and 
+    reopen the logfiles on every request which enables rotating the logs.
+    [#2348](https://github.com/Mashape/kong/pull/2348)
 
 ### Fixed
 

kong/plugins/file-log/handler.lua

@@ -20,24 +20,17 @@ local mode = bit.bor(S_IRUSR, S_IWUSR, S_IRGRP, S_IROTH)
 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);
 ]]
 
--- fd tracking utility functions
-local file_descriptors = {}
-
-local function get_fd(conf_path)
-  return file_descriptors[conf_path]
-end
-
-local function set_fd(conf_path, file_descriptor)
-  file_descriptors[conf_path] = file_descriptor
-end
-
 local function string_to_char(str)
   return ffi.cast("uint8_t*", str)
 end
 
+-- fd tracking utility functions
+local file_descriptors = {}
+
 -- Log to a file. Function used as callback from an nginx timer.
 -- @param `premature` see OpenResty `ngx.timer.at()`
 -- @param `conf`     Configuration table, holds http endpoint details
@@ -47,14 +40,23 @@ local function log(premature, conf, message)
 
   local msg = cjson.encode(message).."\n"
 
-  local fd = get_fd(conf.path)
+  local fd = file_descriptors[conf.path]
+
+  if fd and conf.reopen then
+    -- close fd, we do this here, to make sure a previously cached fd also
+    -- gets closed upon dynamic changes of the configuration
+    ffi.C.close(fd)
+    file_descriptors[conf.path] = nil
+    fd = nil
+  end
+
   if not fd then
     fd = ffi.C.open(string_to_char(conf.path), oflags, mode)
     if fd < 0 then
       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)
+      file_descriptors[conf.path] = fd
     end
   end
 

kong/plugins/file-log/schema.lua

@@ -13,6 +13,7 @@ end
 
 return {
   fields = {
-    path = { required = true, type = "string", func = validate_file }
+    path = { required = true, type = "string", func = validate_file },
+    reopen = { type = "boolean", default = false },
   }
 }

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,
+        reopen = true,
       }
     })
 
@@ -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,60 @@ 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 on each request", 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)
+
+    -- 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)