modsecurity "failing open" with a large number of requests

[mac-chaffee]

Looks like if an SPOP request to modsecurity exceeds the timeout processing, the request will be allowed to proceed. Is there some way of configuring HAProxy to "fail closed" when it encounters a timeout?

Here's an example of the behavior. I sent 300 requests, 100 at a time to an haproxy server. This server is using spoa-modsecurity with timeout processing 1s set:

$ hey -n 300 -c 100 -T "text/html" 'https://<myhost>?p=/etc/passwd'

Summary:
  Total:	1.2475 secs
  Slowest:	1.0317 secs
  Fastest:	0.0204 secs
  Average:	0.1325 secs
  Requests/sec:	240.4834

  Total data:	26319 bytes
  Size/request:	87 bytes

Response time histogram:
  0.020 [1]	|
  0.122 [212]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.223 [70]	|■■■■■■■■■■■■■
  0.324 [0]	|
  0.425 [0]	|
  0.526 [0]	|
  0.627 [0]	|
  0.728 [0]	|
  0.829 [0]	|
  0.931 [0]	|
  1.032 [17]	|■■■               <---------- NOTE


Latency distribution:
  10% in 0.0310 secs
  25% in 0.0442 secs
  50% in 0.0670 secs
  75% in 0.1245 secs
  90% in 0.1611 secs
  95% in 1.0182 secs
  99% in 1.0309 secs

Details (average, fastest, slowest):
  DNS+dialup:	0.0245 secs, 0.0204 secs, 1.0317 secs
  DNS-lookup:	0.0012 secs, 0.0000 secs, 0.0046 secs
  req write:	0.0000 secs, 0.0000 secs, 0.0007 secs
  resp wait:	0.1061 secs, 0.0203 secs, 1.0315 secs
  resp read:	0.0000 secs, 0.0000 secs, 0.0002 secs

Status code distribution:
  [200]	17 responses               <---------- NOTE
  [403]	283 responses

Note how 17 requests took slightly longer than 1 second to process, but instead of being denied (403) by modsecurity for trying to access /etc/passwd, the requests went through (200).

This might be a separate issue, but the request distribution also looks suspicious. I'd expect to have a long tail of requests between 0.2 and 1.0 seconds, but instead it's a sharp cliff. Maybe there's some other limit being hit here which causes modsecurity to lock up? I'm running modsecurity with "-n 16" worker threads on a VM with 4 CPUs, for context.

[mac-chaffee]

The issue appears to be the conditional which is mentioned in the readme:

spoa-modsecurity/README

Line 97 in 3c895f3

http-request deny if { var(txn.modsec.code) -m int gt 0 }

When a timeout is hit, txn.modsec.code stays uninitialized as -1, which mean the request is NOT denied.

It's debatable whether the readme should be changed to change the "fail open" to "fail closed", but if you do want to do that, use this conditional instead:

http-request deny unless { var(txn.modsec.code) -m int eq 0 }

EDIT: See comment below, don't use the above workaround since it doesn't work

[mac-chaffee]

It seems that the return code from modsecurity is a signed integer:

spoa-modsecurity/spoa.c

Line 93 in 3c895f3

int modsec_code; /* modsecurity return code. -1 if unset, 0 if none, other it returns http code. */

But when encoded via SPOP, it's treated as a uint64_t:

spoa-modsecurity/include/haproxy/intops.h

Line 399 in 3c895f3

static inline int encode_varint(uint64_t i, char **buf, char *end)

This seems to be related to this issue because I'm not sure what the value of txn.modsec.code should be on success. In my testing it appears that txn.modsec.code is 403 when modsec denies the request and on success, it's -1, but does -1 always imply success? Seems there are some code paths where -1 also implies an error with spoa-modsecurity like here.

So I'm having trouble constructing a conditional that fails-closed for all error states, but allows the request for all other cases.