Improve Captcha Post Error Handling

README.md

@@ -118,7 +118,7 @@ NETACEA_PROTECTOR_API_URL=https://your-protector-api-url
 | --------------------------------------------- | ------------------------ |
 | `NETACEA_API_KEY`                             | none                     |
 | `NETACEA_BLOCKED_RESPONSE_BODY`               | unset                    |
-| `NETACEA_BLOCKED_RESPONSE_CONTENT_TYPE`       | `text/plain`                    |
+| `NETACEA_BLOCKED_RESPONSE_CONTENT_TYPE`       | `text/plain`             |
 | `NETACEA_BLOCKED_RESPONSE_STATUS`             | `403`                    |
 | `NETACEA_CAPTCHA_COOKIE_ATTRIBUTES`           | `Max-Age=86400; Path=/;` |
 | `NETACEA_CAPTCHA_COOKIE_NAME`                 | `_mitatacaptcha`         |

lua_resty_netacea-1.6.4-0.rockspec → lua_resty_netacea-1.7.0-0.rockspec

@@ -1,5 +1,5 @@
 package = "lua_resty_netacea"
-version = "1.6.4-0"
+version = "1.7.0-0"
 source = {
   url = "git://github.com/Netacea/lua_resty_netacea",
   branch = "master"

src/lua_resty_netacea.lua

@@ -8,7 +8,7 @@ local Constants = require("lua_resty_netacea_constants")
 local mitigation = require("lua_resty_netacea_mitigation")
 
 local _N = {}
-_N._VERSION = '1.6.4'
+_N._VERSION = '1.7.0'
 _N._TYPE = 'nginx'
 
 local ngx = require 'ngx'
@@ -60,6 +60,11 @@ local function serveCaptchaFailOpen(body, options)
   return true
 end
 
+local function isPassThroughStatus(status)
+  if type(status) ~= 'number' then return false end
+  return (status >= 200 and status < 300) or (status >= 400 and status < 500)
+end
+
 local function readRequestBody()
   ngx.req.read_body()
 
@@ -301,21 +306,38 @@ function _N:handleCaptcha()
 
   local captcha_data = readRequestBody()
   local protector_result = self.protectorClient:validateCaptcha(captcha_data)
+  if not protector_result then
+    return ngx.exit(ngx.HTTP_BAD_GATEWAY)
+  end
   ngx.ctx.NetaceaState.protector_result = protector_result
   ngx.ctx.NetaceaState.grace_period = -1000
   ngx.log(ngx.DEBUG, "NETACEA CAPTCHA - protector result: ", cjson.encode(ngx.ctx.NetaceaState))
 
   -- Refresh session only when the captcha verification succeeded and this wasn't a checkpoint post
-  local isCheckpointPost = protector_result.captcha ~= Constants['checkpointStates'].POST
-  if protector_result.exit_status == 200 and isCheckpointPost then
+  local isCheckpointPost = protector_result.captcha == Constants['checkpointStates'].POST
+  if protector_result.exit_status == 200 and not isCheckpointPost then
     self:refreshSession(Constants['issueReasons'].CAPTCHA_POST)
   end
 
-  if protector_result.response and protector_result.response.body then
-    ngx.print(protector_result.response.body)
+  -- Only pass 2xx/4xx protector responses through; anything else becomes a generic 502
+  local status = protector_result.exit_status
+  if not isPassThroughStatus(status) then
+    return ngx.exit(ngx.HTTP_BAD_GATEWAY)
+  end
+
+  local response = protector_result.response or {}
+  local headers = response.headers or {}
+  if headers['Content-Type'] then
+    ngx.header['Content-Type'] = headers['Content-Type']
+  end
+
+  -- Status must be set before printing, as the first print sends the response headers
+  ngx.status = status
+  if response.body then
+    ngx.print(response.body)
   end
 
-  ngx.exit(protector_result.exit_status)
+  ngx.exit(status)
 end
 
 function _N:refreshIngestSession()

src/lua_resty_netacea_ingest.lua

@@ -244,8 +244,10 @@ function Ingest:ingest()
     RequestHost = vars.http_host or vars.host or "",
     RequestId = vars.request_id or "",
     ProtectionMode = self._N.mitigationType or "ERROR",
-    -- TODO
-    BytesReceived = vars.bytes_received or 0, -- Doesn't seem to work
+    ProtectorStatus = NetaceaState.protector_status,
+    ProtectorLatencyMs = NetaceaState.protector_latency_ms,
+    -- $bytes_received only exists in the stream module; $request_length is the http equivalent
+    BytesReceived = tonumber(vars.request_length) or 0,
     NetaceaUserIdCookieStatus = 1,
     Optional = {}
   }

src/lua_resty_netacea_protector_client.lua

@@ -17,6 +17,24 @@ local function createHttpConnection()
   return hc
 end
 
+-- Makes the protector request, recording its status and latency for ingest.
+-- ngx.now() is cached per event loop tick, so refresh it around the request.
+local function timedRequest(hc, url, params)
+  ngx.update_time()
+  local start = ngx.now()
+  local res, err = hc:request_uri(url, params)
+  ngx.update_time()
+
+  local NetaceaState = ngx.ctx.NetaceaState
+  if NetaceaState then
+    -- 0 means no response was received, e.g. a timeout or refused connection
+    NetaceaState.protector_status = res and res.status or 0
+    NetaceaState.protector_latency_ms = math.floor((ngx.now() - start) * 1000 + 0.5)
+  end
+
+  return res, err
+end
+
 local function appendTrackingId(url, trackingId)
     if not trackingId then return url end
     local separator = url:find('?', 1, true) and '&' or '?'
@@ -77,7 +95,8 @@ function ProtectorClient:checkReputation()
     ngx.log(ngx.DEBUG, 'Netacea mitigation headers: ' .. require('cjson').encode(headers))
     self.endpointIndex = (self.endpointIndex + 1) % table.getn(self.mitigationEndpoint)
 
-    local res, err = hc:request_uri(
+    local res, err = timedRequest(
+        hc,
         self.mitigationEndpoint[self.endpointIndex + 1],
         {
         method = 'GET',
@@ -107,7 +126,8 @@ function ProtectorClient:validateCaptcha(captcha_data)
 
   self.endpointIndex = (self.endpointIndex + 1) % table.getn(self.mitigationEndpoint)
 
-  local res, err = hc:request_uri(
+  local res, err = timedRequest(
+    hc,
     self.mitigationEndpoint[self.endpointIndex + 1] .. '/AtaVerifyCaptcha',
     {
       method = 'POST',
@@ -145,7 +165,8 @@ function ProtectorClient:getCaptchaPage(trackingId)
   local headers = self:getMitigationRequestHeaders()
   self.endpointIndex = (self.endpointIndex + 1) % table.getn(self.mitigationEndpoint)
 
-  local res, err = hc:request_uri(
+  local res, err = timedRequest(
+    hc,
     appendTrackingId(self.mitigationEndpoint[self.endpointIndex + 1] .. '/captcha', trackingId),
     {
       method = 'GET',

test/lua_resty_netacea_ingest_spec.lua

@@ -37,7 +37,7 @@ describe("lua_resty_netacea_ingest", function()
                 query_string = "param=value",
                 host = "test.example.com",
                 request_id = "req-12345",
-                bytes_received = "512",
+                request_length = "512",
                 cookie__mitata = "fallback_mitata"
             },
             log = spy.new(function() end),
@@ -409,6 +409,26 @@ describe("lua_resty_netacea_ingest", function()
             assert.is.equal("test.example.com", queued_item.RequestHost)
             assert.is.equal("req-12345", queued_item.RequestId)
             assert.is.equal("monitor", queued_item.ProtectionMode)
+            assert.is.equal(512, queued_item.BytesReceived)
+        end)
+
+        it("should include protector status and latency when a protector call was made", function()
+            ngx_mock.ctx.NetaceaState.protector_status = 502
+            ngx_mock.ctx.NetaceaState.protector_latency_ms = 37
+
+            ingest:ingest()
+
+            local queued_item = ingest.data_queue:pop()
+            assert.is.equal(502, queued_item.ProtectorStatus)
+            assert.is.equal(37, queued_item.ProtectorLatencyMs)
+        end)
+
+        it("should omit protector status and latency when no protector call was made", function()
+            ingest:ingest()
+
+            local queued_item = ingest.data_queue:pop()
+            assert.is_nil(queued_item.ProtectorStatus)
+            assert.is_nil(queued_item.ProtectorLatencyMs)
         end)
 
         it("should use the raw http_host header, including port, when present", function()
@@ -464,7 +484,7 @@ describe("lua_resty_netacea_ingest", function()
             ngx_mock.var.query_string = nil
             ngx_mock.var.host = nil
             ngx_mock.var.request_id = nil
-            ngx_mock.var.bytes_received = nil
+            ngx_mock.var.request_length = nil
 
             ingest:ingest()
 

test/lua_resty_netacea_protector_client_spec.lua

@@ -9,9 +9,11 @@ describe("lua_resty_netacea_protector_client", function()
     local http_mock_instance
     local http_mock
     local constants
+    local clock
 
     before_each(function()
         constants = require('lua_resty_netacea_constants')
+        clock = 1700000000.000
 
         ngx_mock = {
             ctx = {
@@ -26,6 +28,9 @@ describe("lua_resty_netacea_protector_client", function()
                 http_content_type = "application/json"
             },
             log = spy.new(function() end),
+            -- Each update_time advances the clock by 42ms, so every request takes 42ms
+            update_time = spy.new(function() clock = clock + 0.042 end),
+            now = spy.new(function() return clock end),
             ERR = 3,
             HTTP_FORBIDDEN = 403,
             HTTP_OK = 200
@@ -471,4 +476,49 @@ describe("lua_resty_netacea_protector_client", function()
             assert.are.equal("https://endpoint1.example.com/captcha", call_args.vals[2])
         end)
     end)
+    describe("protector status and latency", function()
+        local function new_client()
+            return ProtectorClient:new({
+                apiKey = "test-api-key",
+                mitigationEndpoint = { "https://endpoint1.example.com" }
+            })
+        end
+
+        it("should record status and latency for checkReputation", function()
+            new_client():checkReputation()
+            assert.are.equal(200, ngx_mock.ctx.NetaceaState.protector_status)
+            assert.are.equal(42, ngx_mock.ctx.NetaceaState.protector_latency_ms)
+        end)
+
+        it("should record status and latency for validateCaptcha", function()
+            http_mock_instance.request_uri = spy.new(function()
+                return { status = 502, body = "Bad Gateway", headers = {} }, nil
+            end)
+            new_client():validateCaptcha("captcha_data")
+            assert.are.equal(502, ngx_mock.ctx.NetaceaState.protector_status)
+            assert.are.equal(42, ngx_mock.ctx.NetaceaState.protector_latency_ms)
+        end)
+
+        it("should record status and latency for getCaptchaPage", function()
+            new_client():getCaptchaPage(nil)
+            assert.are.equal(200, ngx_mock.ctx.NetaceaState.protector_status)
+            assert.are.equal(42, ngx_mock.ctx.NetaceaState.protector_latency_ms)
+        end)
+
+        for _, request_error in ipairs({ "timeout", "connection refused" }) do
+            it("should record status 0 and latency when the request fails with " .. request_error, function()
+                http_mock_instance.request_uri = spy.new(function()
+                    return nil, request_error
+                end)
+                new_client():checkReputation()
+                assert.are.equal(0, ngx_mock.ctx.NetaceaState.protector_status)
+                assert.are.equal(42, ngx_mock.ctx.NetaceaState.protector_latency_ms)
+            end)
+        end
+
+        it("should refresh the cached time before and after the request", function()
+            new_client():checkReputation()
+            assert.spy(ngx_mock.update_time).was.called(2)
+        end)
+    end)
 end)