Repository: corazawaf/coraza
Pull request #680 (2023-02-27 17:20:43)

chore: adds phases check before processing body
This PR proposes to add a check about the latest phase executed before running process body. It would permit to avoid some corner cases where the server/proxy denies the connection detecting a malformed http request, but still triggers ResponseBody(). In that case, the latter would be executed as the only phase, without any header in memory nor initialized CRS variables.
It can be reproduced running tests 920430-3 and 920280-3 against coraza-proxy-wasm.

An alternative, if the proposed solution does not sound right, is to rely on a flag connector side, avoiding triggering the process body if a certain point (e.g. process headers has not been called).

codecov[bot]: # [Codecov](https://codecov.io/gh/corazawaf/coraza/pull/680?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf) Report
Base: **80.46**% // Head: **80.37**% // Decreases project coverage by **`-0.10%`** :warning:
> Coverage data is based on head [(`5221851`)](https://codecov.io/gh/corazawaf/coraza/pull/680?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf) compared to base [(`f050500`)](https://codecov.io/gh/corazawaf/coraza/commit/f050500615669fa6f57e2cd293600029668da1bf?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf).
> Patch coverage: 85.71% of modified lines in pull request are covered.

<details><summary>Additional details and impacted files</summary>


```diff
@@            Coverage Diff             @@
##           v3/dev     #680      +/-   ##
==========================================
- Coverage   80.46%   80.37%   -0.10%     
==========================================
  Files         145      145              
  Lines        7757     7779      +22     
==========================================
+ Hits         6242     6252      +10     
- Misses       1284     1294      +10     
- Partials      231      233       +2     
```

| Flag | Coverage Δ | |
|---|---|---|
| default | `76.38% <85.71%> (-0.09%)` | :arrow_down: |
| examples | `26.97% <0.00%> (-0.08%)` | :arrow_down: |
| ftw | `51.33% <0.00%> (-0.16%)` | :arrow_down: |
| ftw-multiphase | `51.42% <0.00%> (-0.16%)` | :arrow_down: |
| tinygo | `75.35% <85.71%> (-0.10%)` | :arrow_down: |

Flags with carried forward coverage won't be shown. [Click here](https://docs.codecov.io/docs/carryforward-flags?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf#carryforward-flags-in-the-pull-request-comment) to find out more.

| [Impacted Files](https://codecov.io/gh/corazawaf/coraza/pull/680?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf) | Coverage Δ | |
|---|---|---|
| [internal/corazawaf/transaction.go](https://codecov.io/gh/corazawaf/coraza/pull/680?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf#diff-aW50ZXJuYWwvY29yYXphd2FmL3RyYW5zYWN0aW9uLmdv) | `77.91% <76.19%> (-0.69%)` | :arrow_down: |
| [internal/collections/map.go](https://codecov.io/gh/corazawaf/coraza/pull/680?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf#diff-aW50ZXJuYWwvY29sbGVjdGlvbnMvbWFwLmdv) | `95.37% <100.00%> (+0.08%)` | :arrow_up: |
| [internal/collections/named.go](https://codecov.io/gh/corazawaf/coraza/pull/680?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf#diff-aW50ZXJuYWwvY29sbGVjdGlvbnMvbmFtZWQuZ28=) | `93.84% <100.00%> (+0.19%)` | :arrow_up: |
| [internal/collections/single.go](https://codecov.io/gh/corazawaf/coraza/pull/680?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf#diff-aW50ZXJuYWwvY29sbGVjdGlvbnMvc2luZ2xlLmdv) | `100.00% <100.00%> (ø)` | |
| [internal/collections/sized.go](https://codecov.io/gh/corazawaf/coraza/pull/680?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf#diff-aW50ZXJuYWwvY29sbGVjdGlvbnMvc2l6ZWQuZ28=) | `81.81% <100.00%> (+2.50%)` | :arrow_up: |

Help us with your feedback. Take ten seconds to tell us [how you rate us](https://about.codecov.io/nps?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf). Have a feature suggestion? [Share it here.](https://app.codecov.io/gh/feedback/?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf)

</details>

[:umbrella: View full report at Codecov](https://codecov.io/gh/corazawaf/coraza/pull/680?src=pr&el=continue&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf).   
:loudspeaker: Do you have feedback about the report comment? [Let us know in this issue](https://about.codecov.io/codecov-pr-comment-feedback/?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=corazawaf).


Patch:
diff --git a/internal/corazawaf/transaction.go b/internal/corazawaf/transaction.go
index bfef2f7..95b4caa 100644
--- a/internal/corazawaf/transaction.go
+++ b/internal/corazawaf/transaction.go
@@ -911,17 +911,21 @@ func (tx *Transaction) ProcessRequestBody() (*types.Interruption, error) {
 		return nil, nil
 	}
 
-	if tx.LastPhase >= types.PhaseRequestBody {
-		// Phase already evaluated
-		tx.debugLogger.Warn().Msg("ProcessRequestBody has already been called")
-		return tx.interruption, nil
-	}
-
 	if tx.interruption != nil {
 		tx.debugLogger.Error().Msg("Calling ProcessRequestBody but there is a preexisting interruption")
 		return tx.interruption, nil
 	}
 
+	if tx.LastPhase != types.PhaseRequestHeaders {
+		if tx.LastPhase >= types.PhaseRequestBody {
+			// Phase already evaluated or skipped
+			tx.debugLogger.Warn().Msg("ProcessRequestBody should have already been called")
+		} else {
+			tx.debugLogger.Debug().Msg("Skipping request body processing, anomalous call before request headers evaluation")
+		}
+		return nil, nil
+	}
+
 	// we won't process empty request bodies or disabled RequestBodyAccess
 	if !tx.RequestBodyAccess || tx.requestBodyBuffer.length == 0 {
 		tx.WAF.Rules.Eval(types.PhaseRequestBody, tx)
@@ -1145,17 +1149,24 @@ func (tx *Transaction) ProcessResponseBody() (*types.Interruption, error) {
 		return nil, nil
 	}
 
-	if tx.LastPhase >= types.PhaseResponseBody {
-		// Phase already evaluated
-		tx.debugLogger.Warn().Msg("ProcessResponseBody has already been called")
-		return tx.interruption, nil
-	}
-
 	if tx.interruption != nil {
 		tx.debugLogger.Error().Msg("Calling ProcessResponseBody but there is a preexisting interruption")
 		return tx.interruption, nil
 	}
 
+	if tx.LastPhase != types.PhaseResponseHeaders {
+		if tx.LastPhase >= types.PhaseResponseBody {
+			// Phase already evaluated or skipped
+			tx.debugLogger.Warn().Msg("ProcessResponseBody should have already been called")
+		} else {
+			// Prevents evaluating response body rules if last phase has not been response headers. It may happen
+			// when a server returns an error prior to evaluating WAF rules, but ResponseBody is still called at
+			// the end of http stream
+			tx.debugLogger.Debug().Msg("Skipping response body processing, anomalous call before response headers evaluation")
+		}
+		return nil, nil
+	}
+
 	if !tx.ResponseBodyAccess || !tx.IsResponseBodyProcessable() {
 		tx.debugLogger.Debug().
 			Bool("response_body_access", tx.ResponseBodyAccess).


Test patch:
diff --git a/internal/corazawaf/transaction_test.go b/internal/corazawaf/transaction_test.go
index bc58f0f..66f0e24 100644
--- a/internal/corazawaf/transaction_test.go
+++ b/internal/corazawaf/transaction_test.go
@@ -762,6 +762,7 @@ func TestRequestBodyProcessingAlgorithm(t *testing.T) {
 	tx.ForceRequestBodyVariable = true
 	tx.AddRequestHeader("content-type", "text/plain")
 	tx.AddRequestHeader("content-length", "7")
+	tx.LastPhase = types.PhaseRequestHeaders
 	if _, err := tx.requestBodyBuffer.Write([]byte("test123")); err != nil {
 		t.Error("Failed to write request body buffer")
 	}
@@ -776,6 +777,47 @@ func TestRequestBodyProcessingAlgorithm(t *testing.T) {
 	}
 }
 
+func TestProcessBodiesSkippedIfHeadersPhasesNotReached(t *testing.T) {
+	l := &inspectableLogger{}
+	waf := NewWAF()
+	waf.SetDebugLogOutput(l)
+	_ = waf.SetDebugLogLevel(debuglog.LogLevelDebug)
+	tx := waf.NewTransaction()
+	tx.RuleEngine = types.RuleEngineOn
+	tx.RequestBodyAccess = true
+	// Current phase is PhaseUnknown (ProcessRequestHeaders has not been called)
+	it, err := tx.ProcessRequestBody()
+	if err != nil {
+		t.Fatal(err)
+	}
+	if it != nil {
+		t.Fatal("Unexpected interruption")
+	}
+	it, err = tx.ProcessResponseBody()
+	if err != nil {
+		t.Fatal(err)
+	}
+	if it != nil {
+		t.Fatal("Unexpected interruption")
+	}
+	// At this point we are expecting three log entries:
+	// [0] New transaction log
+	// [1] Anomalous call before request headers evaluation
+	// [2] Anomalous call before response headers evaluation
+	if want, have := 3, len(l.entries); want != have {
+		t.Fatalf("unexpected number of log entries, want %d, have %d", want, have)
+	}
+	if want, have := "anomalous call before request headers evaluation", l.entries[1]; !strings.Contains(have, want) {
+		t.Fatalf("unexpected message, want %q, have %q", want, have)
+	}
+	if want, have := "anomalous call before response headers evaluation", l.entries[2]; !strings.Contains(have, want) {
+		t.Fatalf("unexpected message, want %q, have %q", want, have)
+	}
+	if err := tx.Close(); err != nil {
+		t.Error(err)
+	}
+}
+
 func TestTxVariables(t *testing.T) {
 	tx := makeTransaction(t)
 	rv := ruleVariableParams{
@@ -875,6 +917,7 @@ func TestTxPhase4Magic(t *testing.T) {
 	waf.ResponseBodyMimeTypes = []string{"text/html"}
 	tx := waf.NewTransaction()
 	tx.AddResponseHeader("content-type", "text/html")
+	tx.LastPhase = types.PhaseResponseHeaders
 	if it, _, err := tx.WriteResponseBody([]byte("more bytes")); it != nil || err != nil {
 		t.Error(err)
 	}
@@ -916,6 +959,7 @@ func TestVariablesMatch(t *testing.T) {
 func TestTxReqBodyForce(t *testing.T) {
 	waf := NewWAF()
 	tx := waf.NewTransaction()
+	tx.LastPhase = types.PhaseRequestHeaders
 	tx.RequestBodyAccess = true
 	tx.ForceRequestBodyVariable = true
 	if _, err := tx.requestBodyBuffer.Write([]byte("test")); err != nil {
@@ -1183,7 +1227,7 @@ func (l *inspectableLogger) Close() error {
 	return nil
 }
 
-func TestProcessorsIdempotency(t *testing.T) {
+func TestProcessorsIdempotencyWithAlreadyRaisedInterruption(t *testing.T) {
 	l := &inspectableLogger{}
 
 	waf := NewWAF()
diff --git a/internal/seclang/rules_test.go b/internal/seclang/rules_test.go
index cd9af61..2f2648d 100644
--- a/internal/seclang/rules_test.go
+++ b/internal/seclang/rules_test.go
@@ -316,6 +316,7 @@ func TestTxIssue147(t *testing.T) {
 	tx.ResponseBodyAccess = true
 	tx.WAF.ResponseBodyMimeTypes = []string{"text/html"}
 	tx.AddResponseHeader("Content-Type", "text/html")
+	tx.LastPhase = types.PhaseResponseHeaders
 
 	if tx.IsResponseBodyProcessable() {
 		if it, _, err := tx.WriteResponseBody([]byte("#!/usr/bin/python")); it != nil || err != nil {
@@ -451,6 +452,7 @@ func TestUnicode(t *testing.T) {
 	}
 
 	tx := waf.NewTransaction()
+	tx.LastPhase = types.PhaseRequestHeaders
 	tx.AddPostRequestArgument("var", `ハローワールド`)
 	it, err := tx.ProcessRequestBody()
 	if err != nil {
@@ -568,6 +570,7 @@ func TestArgumentsCaseSensitive(t *testing.T) {
 	}
 
 	tx := waf.NewTransaction()
+	tx.LastPhase = types.PhaseRequestHeaders
 	tx.AddPostRequestArgument("Test1", "Xyz")
 	it, err := tx.ProcessRequestBody()
 	if err != nil {
@@ -578,6 +581,7 @@ func TestArgumentsCaseSensitive(t *testing.T) {
 	}
 
 	tx = waf.NewTransaction()
+	tx.LastPhase = types.PhaseRequestHeaders
 	tx.AddPostRequestArgument("TEST1", "Xyz")
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
@@ -588,6 +592,7 @@ func TestArgumentsCaseSensitive(t *testing.T) {
 	}
 
 	tx = waf.NewTransaction()
+	tx.LastPhase = types.PhaseRequestHeaders
 	tx.AddPostRequestArgument("test1", "Xyz")
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
@@ -598,6 +603,7 @@ func TestArgumentsCaseSensitive(t *testing.T) {
 	}
 
 	tx = waf.NewTransaction()
+	tx.LastPhase = types.PhaseRequestHeaders
 	tx.AddPostRequestArgument("test1", "xyz")
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
@@ -608,6 +614,7 @@ func TestArgumentsCaseSensitive(t *testing.T) {
 	}
 
 	tx = waf.NewTransaction()
+	tx.LastPhase = types.PhaseRequestHeaders
 	tx.AddPostRequestArgument("test1", "XYZ")
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
@@ -631,6 +638,7 @@ func TestCookiesCaseSensitive(t *testing.T) {
 
 	tx := waf.NewTransaction()
 	tx.AddRequestHeader("cookie", "Test1=Xyz")
+	tx.LastPhase = types.PhaseRequestHeaders
 	it, err := tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -641,6 +649,7 @@ func TestCookiesCaseSensitive(t *testing.T) {
 
 	tx = waf.NewTransaction()
 	tx.AddRequestHeader("cookie", "TEST1=Xyz")
+	tx.LastPhase = types.PhaseRequestHeaders
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -651,6 +660,7 @@ func TestCookiesCaseSensitive(t *testing.T) {
 
 	tx = waf.NewTransaction()
 	tx.AddRequestHeader("cookie", "test1=Xyz")
+	tx.LastPhase = types.PhaseRequestHeaders
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -661,6 +671,7 @@ func TestCookiesCaseSensitive(t *testing.T) {
 
 	tx = waf.NewTransaction()
 	tx.AddRequestHeader("cookie", "test1=xyz")
+	tx.LastPhase = types.PhaseRequestHeaders
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -671,6 +682,7 @@ func TestCookiesCaseSensitive(t *testing.T) {
 
 	tx = waf.NewTransaction()
 	tx.AddRequestHeader("cookie", "test1=XYZ")
+	tx.LastPhase = types.PhaseRequestHeaders
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -693,6 +705,7 @@ func TestHeadersCaseSensitive(t *testing.T) {
 
 	tx := waf.NewTransaction()
 	tx.AddRequestHeader("Test1", "Xyz")
+	tx.LastPhase = types.PhaseRequestHeaders
 	it, err := tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -703,6 +716,7 @@ func TestHeadersCaseSensitive(t *testing.T) {
 
 	tx = waf.NewTransaction()
 	tx.AddRequestHeader("TEST1", "Xyz")
+	tx.LastPhase = types.PhaseRequestHeaders
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -713,6 +727,7 @@ func TestHeadersCaseSensitive(t *testing.T) {
 
 	tx = waf.NewTransaction()
 	tx.AddRequestHeader("test1", "Xyz")
+	tx.LastPhase = types.PhaseRequestHeaders
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -723,6 +738,7 @@ func TestHeadersCaseSensitive(t *testing.T) {
 
 	tx = waf.NewTransaction()
 	tx.AddRequestHeader("test1", "xyz")
+	tx.LastPhase = types.PhaseRequestHeaders
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -733,6 +749,7 @@ func TestHeadersCaseSensitive(t *testing.T) {
 
 	tx = waf.NewTransaction()
 	tx.AddRequestHeader("test1", "XYZ")
+	tx.LastPhase = types.PhaseRequestHeaders
 	it, err = tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -754,6 +771,7 @@ func TestParameterPollution(t *testing.T) {
 	}
 
 	tx := waf.NewTransaction()
+	tx.LastPhase = types.PhaseRequestHeaders
 	tx.AddPostRequestArgument("test1", "xyz")
 	tx.AddPostRequestArgument("Test1", "Xyz")
 	tx.AddPostRequestArgument("TEST1", "XYZ")
@@ -773,6 +791,7 @@ func TestParameterPollution(t *testing.T) {
 	}
 
 	tx = waf.NewTransaction()
+	tx.LastPhase = types.PhaseRequestHeaders
 	tx.AddPostRequestArgument("test1", "xyz")
 	tx.AddPostRequestArgument("Test1", "Xyz")
 	tx.AddPostRequestArgument("tesT1", "Xyz")
@@ -806,6 +825,7 @@ func TestURIQueryParamCaseSensitive(t *testing.T) {
 
 	tx := waf.NewTransaction()
 	tx.ProcessURI("/url?Test1='SQLI", "POST", "HTTP/1.1")
+	tx.LastPhase = types.PhaseRequestHeaders
 	_, err = tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -826,6 +846,7 @@ func TestURIQueryParamCaseSensitive(t *testing.T) {
 
 	tx = waf.NewTransaction()
 	tx.ProcessURI("/test?test1='SQLI&Test1='SQLI&TEST1='SQLI", "POST", "HTTP/1.1")
+	tx.LastPhase = types.PhaseRequestHeaders
 	_, err = tx.ProcessRequestBody()
 	if err != nil {
 		t.Error(err)
@@ -950,6 +971,9 @@ SecRule REQUEST_URI|ARGS|REQUEST_HEADERS|!REQUEST_HEADERS:Referer|FILES|XML:/* "
 
 	tx := waf.NewTransaction()
 	tx.AddRequestHeader("Content-Type", "multipart/form-data; boundary=----WebKitFormBoundaryABCDEFGIJKLMNOPQ")
+	if it := tx.ProcessRequestHeaders(); it != nil {
+		t.Errorf("Unexpected interruption with status %d at Request Headers phaseus\n", it.Status)
+	}
 
 	body := strings.NewReader(`
 ------WebKitFormBoundaryABCDEFGIJKLMNOPQ