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

@@ -6,6 +6,8 @@
   status and message. Thanks to [Paul Austin](https://github.com/pauldaustin)
   for the contribution.
   [#2051](https://github.com/Mashape/kong/pull/2051)
+- File-log plugin now has a new `valid` setting (in seconds) to close and 
+  reopen the logfiles automatically which enables rotating the logs.
 
 ## [0.10.1] - 2017/03/27
 

kong/plugins/file-log/handler.lua

@@ -17,21 +17,38 @@ 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);
 ]]
 
 -- fd tracking utility functions
 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
 

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 },
   }
 }

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(uuid2, nil, true), "expected 3rd request in logfile")
   end)
 end)