fix(chore): etags mismatch (#357)

* fix(chore): etags mismatch

* fix: caddy tests

* fix: compute and ETag revalidate detection

* fix(chore): update ETag matcher debug mesage

* fix(chore): update unit tests and patch ETag request to If-None-Match

* fix: ci

* fix(chore): Content-Length compute

* fix(chore): Content-Length set before store

* fix: remove the Content-Length from the Headers property

pkg/middleware/middleware.go

@@ -226,11 +226,15 @@ func (s *SouinBaseHandler) Store(
 		if res.Header.Get("Date") == "" {
 			res.Header.Set("Date", now.Format(http.TimeFormat))
 		}
+		if res.Header.Get("Content-Length") == "" {
+			res.Header.Set("Content-Length", fmt.Sprint(customWriter.Buf.Len()))
+		}
+		res.Header.Set(rfc.StoredLengthHeader, res.Header.Get("Content-Length"))
 		response, err := httputil.DumpResponse(&res, true)
 		if err == nil {
 			variedHeaders := rfc.HeaderAllCommaSepValues(res.Header)
 			cachedKey += rfc.GetVariedCacheKey(rq, variedHeaders)
-			s.Configuration.GetLogger().Sugar().Debugf("Store the response %+v with duration %v", res, ma)
+			s.Configuration.GetLogger().Sugar().Infof("Store the response %+v with duration %v", res, ma)
 			if s.Storer.Set(cachedKey, response, currentMatchedURL, ma) == nil {
 				s.Configuration.GetLogger().Sugar().Debugf("Store the cache key %s into the surrogate keys from the following headers %v", cachedKey, res)
 				go func(rs http.Response, key string) {
@@ -393,18 +397,28 @@ func (s *SouinBaseHandler) ServeHTTP(rw http.ResponseWriter, rq *http.Request, n
 		response := s.Storer.Prefix(cachedKey, rq, validator)
 
 		if response != nil && (!modeContext.Strict || rfc.ValidateCacheControl(response, requestCc)) {
-			if validator.NeedRevalidation {
-				err := s.Revalidate(validator, next, customWriter, rq, requestCc, cachedKey)
+			if validator.ResponseETag != "" && validator.Matched {
+				rfc.SetCacheStatusHeader(response)
+				customWriter.Headers = response.Header
+				if validator.NotModified {
+					customWriter.statusCode = http.StatusNotModified
+					customWriter.Buf.Reset()
+					_, _ = customWriter.Send()
+
+					return nil
+				}
+
+				customWriter.statusCode = response.StatusCode
 				_, _ = io.Copy(customWriter.Buf, response.Body)
 				_, _ = customWriter.Send()
 
-				return err
+				return nil
 			}
 			rfc.SetCacheStatusHeader(response)
 			if !modeContext.Strict || rfc.ValidateMaxAgeCachedResponse(requestCc, response) != nil {
 				customWriter.Headers = response.Header
 				customWriter.statusCode = response.StatusCode
-				s.Configuration.GetLogger().Sugar().Debugf("Serve from cache %+v", rq)
+				s.Configuration.GetLogger().Sugar().Infof("Serve from cache %+v", rq)
 				_, _ = io.Copy(customWriter.Buf, response.Body)
 				_, err := customWriter.Send()
 
@@ -435,6 +449,7 @@ func (s *SouinBaseHandler) ServeHTTP(rw http.ResponseWriter, rq *http.Request, n
 				}
 
 				if responseCc.MustRevalidate || responseCc.NoCachePresent || validator.NeedRevalidation {
+					rq.Header["If-None-Match"] = append(rq.Header["If-None-Match"], validator.ResponseETag)
 					err := s.Revalidate(validator, next, customWriter, rq, requestCc, cachedKey)
 					if err != nil {
 						if responseCc.StaleIfError > -1 || requestCc.StaleIfError > 0 {
@@ -454,22 +469,32 @@ func (s *SouinBaseHandler) ServeHTTP(rw http.ResponseWriter, rq *http.Request, n
 
 						return err
 					}
-					_, _ = io.Copy(customWriter.Buf, response.Body)
+
+					if customWriter.statusCode == http.StatusNotModified {
+						if !validator.Matched {
+							rfc.SetCacheStatusHeader(response)
+							customWriter.statusCode = response.StatusCode
+							customWriter.Headers = response.Header
+							_, _ = io.Copy(customWriter.Buf, response.Body)
+							_, _ = customWriter.Send()
+
+							return err
+						}
+					}
+
+					if customWriter.statusCode != http.StatusNotModified && validator.Matched {
+						customWriter.statusCode = http.StatusNotModified
+						customWriter.Buf.Reset()
+						_, _ = customWriter.Send()
+
+						return err
+					}
+
 					_, _ = customWriter.Send()
 
 					return err
 				}
 
-				// if responseCc.StaleIfError > 0 && s.Upstream(customWriter, rq, next, requestCc, cachedKey) != nil {
-				// 	customWriter.Headers = response.Header
-				// 	customWriter.statusCode = response.StatusCode
-				// 	rfc.HitStaleCache(&response.Header)
-				// 	_, _ = io.Copy(customWriter.Buf, response.Body)
-				// 	_, err := customWriter.Send()
-				//
-				// 	return err
-				// }
-
 				if rfc.ValidateMaxAgeCachedStaleResponse(requestCc, response, int(addTime.Seconds())) != nil {
 					customWriter.Headers = response.Header
 					customWriter.statusCode = response.StatusCode

pkg/middleware/writer.go

@@ -2,7 +2,6 @@ package middleware
 
 import (
 	"bytes"
-	"fmt"
 	"net/http"
 	"strings"
 	"sync"
@@ -68,13 +67,19 @@ func (r *CustomWriter) WriteHeader(code int) {
 func (r *CustomWriter) Write(b []byte) (int, error) {
 	r.Buf.Grow(len(b))
 	_, _ = r.Buf.Write(b)
-	//
+
 	return len(b), nil
 }
 
 // Send delays the response to handle Cache-Status
 func (r *CustomWriter) Send() (int, error) {
 	r.Headers.Del(rfc.StoredTTLHeader)
+	contentLength := r.Headers.Get(rfc.StoredLengthHeader)
+	if contentLength != "" {
+		r.Headers.Del("Content-Length")
+		r.Header().Set("Content-Length", contentLength)
+	}
+	r.Headers.Del(rfc.StoredLengthHeader)
 	defer r.Buf.Reset()
 	b := esi.Parse(r.Buf.Bytes(), r.Req)
 	for h, v := range r.Headers {
@@ -85,7 +90,7 @@ func (r *CustomWriter) Send() (int, error) {
 
 	r.mutex.Lock()
 	if !r.headersSent {
-		r.Rw.Header().Set("Content-Length", fmt.Sprintf("%d", len(b)))
+		// r.Rw.Header().Set("Content-Length", fmt.Sprintf("%d", len(b)))
 		r.Rw.WriteHeader(r.statusCode)
 		r.headersSent = true
 	}

pkg/rfc/cache_status.go

@@ -12,7 +12,10 @@ import (
 	"github.com/pquerna/cachecontrol/cacheobject"
 )
 
-const StoredTTLHeader = "X-Souin-Stored-TTL"
+const (
+	StoredTTLHeader    = "X-Souin-Stored-TTL"
+	StoredLengthHeader = "X-Souin-Stored-Length"
+)
 
 var emptyHeaders = []string{"Expires", "Last-Modified"}
 

pkg/rfc/revalidation.go

@@ -2,6 +2,7 @@ package rfc
 
 import (
 	"net/http"
+	"strings"
 	"time"
 )
 
@@ -13,14 +14,27 @@ type Revalidator struct {
 	IfUnmodifiedSincePresent    bool
 	IfUnmotModifiedSincePresent bool
 	NeedRevalidation            bool
+	NotModified                 bool
 	IfModifiedSince             time.Time
 	IfUnmodifiedSince           time.Time
 	IfNoneMatch                 []string
 	IfMatch                     []string
+	RequestETags                []string
+	ResponseETag                string
 }
 
 func ParseRequest(req *http.Request) *Revalidator {
-	validator := Revalidator{}
+	var rqEtags []string
+	if len(req.Header.Get("If-None-Match")) > 0 {
+		rqEtags = strings.Split(req.Header.Get("If-None-Match"), ",")
+	}
+	for i, tag := range rqEtags {
+		rqEtags[i] = strings.Trim(tag, " ")
+	}
+	validator := Revalidator{
+		NotModified:  len(rqEtags) > 0,
+		RequestETags: rqEtags,
+	}
 	// If-Modified-Since
 	if ifModifiedSince := req.Header.Get("If-Modified-Since"); ifModifiedSince != "" {
 		validator.IfModifiedSincePresent = true
@@ -45,31 +59,37 @@ func ParseRequest(req *http.Request) *Revalidator {
 }
 
 func ValidateETag(res *http.Response, validator *Revalidator) {
-	etag := res.Header.Get("ETag")
-	validator.Matched = etag == ""
+	validator.ResponseETag = res.Header.Get("ETag")
+	validator.NeedRevalidation = validator.NeedRevalidation || validator.ResponseETag != ""
+	validator.Matched = validator.ResponseETag == "" || (validator.ResponseETag != "" && len(validator.RequestETags) == 0)
+
+	if len(validator.RequestETags) == 0 {
+		validator.NotModified = false
+		return
+	}
 
 	// If-None-Match
 	if validator.IfNoneMatchPresent {
 		for _, ifNoneMatch := range validator.IfNoneMatch {
 			// Asrterisk special char to match any of ETag
 			if ifNoneMatch == "*" {
-				validator.Matched = false
+				validator.Matched = true
 				return
 			}
-			if ifNoneMatch == etag {
-				validator.Matched = false
+			if ifNoneMatch == validator.ResponseETag {
+				validator.Matched = true
 				return
 			}
 		}
 
-		validator.Matched = true
+		validator.Matched = false
 		return
 	}
 
 	// If-Match
 	if validator.IfMatchPresent {
 		validator.Matched = false
-		if etag == "" {
+		if validator.ResponseETag == "" {
 			return
 		}
 
@@ -79,7 +99,7 @@ func ValidateETag(res *http.Response, validator *Revalidator) {
 				validator.Matched = true
 				return
 			}
-			if ifMatch == etag {
+			if ifMatch == validator.ResponseETag {
 				validator.Matched = true
 				return
 			}

pkg/storage/badgerProvider.go

@@ -145,10 +145,10 @@ func (provider *Badger) Prefix(key string, req *http.Request, validator *rfc.Rev
 					if res, err := http.ReadResponse(bufio.NewReader(bytes.NewBuffer(val)), req); err == nil {
 						rfc.ValidateETag(res, validator)
 						if validator.Matched {
-							provider.logger.Sugar().Infof("The key %s matched the current iteration key ETag %s", key, it.Item().Key())
+							provider.logger.Sugar().Debugf("The stored key %s matched the current iteration key ETag %+v", it.Item().Key(), validator)
 							result = res
 						} else {
-							provider.logger.Sugar().Infof("The key %s didn't match the current iteration key ETag %s", key, it.Item().Key())
+							provider.logger.Sugar().Debugf("The stored key %s didn't match the current iteration key ETag %+v", it.Item().Key(), validator)
 						}
 					} else {
 						provider.logger.Sugar().Errorf("An error occured while reading response for the key %s: %v", it.Item().Key(), err)

pkg/storage/embeddedOlricProvider.go

@@ -140,11 +140,11 @@ func (provider *EmbeddedOlric) Prefix(key string, req *http.Request, validator *
 				if res, err := http.ReadResponse(bufio.NewReader(bytes.NewBuffer(val)), req); err == nil {
 					rfc.ValidateETag(res, validator)
 					if validator.Matched {
-						provider.logger.Sugar().Infof("The key %s matched the current iteration key ETag %s", key, records.Key())
+						provider.logger.Sugar().Debugf("The stored key %s matched the current iteration key ETag %+v", records.Key(), validator)
 						return res
 					}
 
-					provider.logger.Sugar().Infof("The key %s didn't match the current iteration key ETag %s", key, records.Key())
+					provider.logger.Sugar().Debugf("The stored key %s didn't match the current iteration key ETag %+v", records.Key(), validator)
 				} else {
 					provider.logger.Sugar().Errorf("An error occured while reading response for the key %s: %v", records.Key(), err)
 				}

pkg/storage/etcdProvider.go

@@ -123,11 +123,11 @@ func (provider *Etcd) Prefix(key string, req *http.Request, validator *rfc.Reval
 				if res, err := http.ReadResponse(bufio.NewReader(bytes.NewBuffer(v.Value)), req); err == nil {
 					rfc.ValidateETag(res, validator)
 					if validator.Matched {
-						provider.logger.Sugar().Infof("The key %s matched the current iteration key ETag %s", key, string(v.Key))
+						provider.logger.Sugar().Debugf("The stored key %s matched the current iteration key ETag %+v", string(v.Key), validator)
 						return res
 					}
 
-					provider.logger.Sugar().Infof("The key %s didn't match the current iteration key ETag %s", key, string(v.Key))
+					provider.logger.Sugar().Debugf("The stored key %s didn't match the current iteration key ETag %+v", string(v.Key), validator)
 				} else {
 					provider.logger.Sugar().Errorf("An error occured while reading response for the key %s: %v", string(v.Key), err)
 				}

pkg/storage/nutsProvider.go

@@ -153,12 +153,12 @@ func (provider *Nuts) Prefix(key string, req *http.Request, validator *rfc.Reval
 					if res, err := http.ReadResponse(bufio.NewReader(bytes.NewBuffer(entry.Value)), req); err == nil {
 						rfc.ValidateETag(res, validator)
 						if validator.Matched {
-							provider.logger.Sugar().Infof("The key %s matched the current iteration key ETag %s", key, string(entry.Key))
+							provider.logger.Sugar().Debugf("The stored key %s matched the current iteration key ETag %+v", string(entry.Key), validator)
 							result = res
 							return nil
 						}
 
-						provider.logger.Sugar().Infof("The key %s didn't match the current iteration key ETag %s", key, string(entry.Key))
+						provider.logger.Sugar().Debugf("The stored key %s didn't match the current iteration key ETag %+v", string(entry.Key), validator)
 					} else {
 						provider.logger.Sugar().Errorf("An error occured while reading response for the key %s: %v", string(entry.Key), err)
 					}

pkg/storage/olricProvider.go

@@ -96,11 +96,11 @@ func (provider *Olric) Prefix(key string, req *http.Request, validator *rfc.Reva
 				if res, err := http.ReadResponse(bufio.NewReader(bytes.NewBuffer(val)), req); err == nil {
 					rfc.ValidateETag(res, validator)
 					if validator.Matched {
-						provider.logger.Sugar().Infof("The key %s matched the current iteration key ETag %s", key, records.Key())
+						provider.logger.Sugar().Debugf("The stored key %s matched the current iteration key ETag %+v", records.Key(), validator)
 						return res
 					}
 
-					provider.logger.Sugar().Infof("The key %s didn't match the current iteration key ETag %s", key, records.Key())
+					provider.logger.Sugar().Debugf("The stored key %s didn't match the current iteration key ETag %+v", records.Key(), validator)
 				} else {
 					provider.logger.Sugar().Errorf("An error occured while reading response for the key %s: %v", records.Key(), err)
 				}

pkg/storage/redisProvider.go

@@ -125,11 +125,11 @@ func (provider *Redis) Prefix(key string, req *http.Request, validator *rfc.Reva
 					if res, err := http.ReadResponse(bufio.NewReader(bytes.NewBuffer([]byte(v))), req); err == nil {
 						rfc.ValidateETag(res, validator)
 						if validator.Matched {
-							provider.logger.Sugar().Infof("The key %s matched the current iteration key ETag %s", key, iter.Val())
+							provider.logger.Sugar().Debugf("The stored key %s matched the current iteration key ETag %+v", iter.Val(), validator)
 							in <- res
 							return
 						}
-						provider.logger.Sugar().Errorf("The key %s didn't match the current iteration key ETag %s", key, iter.Val())
+						provider.logger.Sugar().Errorf("The stored key %s didn't match the current iteration key ETag %+v", iter.Val(), validator)
 					}
 				}
 			}

plugins/caddy/README.md

@@ -51,6 +51,7 @@ Here are all the available options for the global options
                 disable_body
                 disable_host
                 disable_method
+                disable_query
                 headers X-Token Authorization
                 hide
             }
@@ -109,14 +110,15 @@ Here are all the available options for the directive options
 ```
 @match path /path
 
-@match {
+handle @match {
     cache {
         cache_name ChangeName
         cache_keys {
             (host1|host2).*\.css {
                 disable_body
                 disable_host
                 disable_method
+                disable_query
                 headers X-Token Authorization
             }
         }
@@ -135,6 +137,7 @@ Here are all the available options for the directive options
             disable_body
             disable_host
             disable_method
+            disable_query
             headers Content-Type Authorization
         }
         log_level debug
@@ -199,7 +202,7 @@ badger-configuration.com {
                 ZSTDCompressionLevel <int>
                 VerifyValueChecksum <bool>
                 EncryptionKey <string>
-                EncryptionKey <Duration>
+                EncryptionKeyRotationDuration <Duration>
                 BypassLockGuard <bool>
                 ChecksumVerificationMode <int>
                 DetectConflicts <bool>
@@ -362,6 +365,7 @@ What does these directives mean?
 | `cache_keys.{your regexp}.disable_body`   | Disable the body part in the key matching the regexp (GraphQL context)                                                                       | `true`<br/><br/>`(default: false)`                                                                                      |
 | `cache_keys.{your regexp}.disable_host`   | Disable the host part in the key matching the regexp                                                                                         | `true`<br/><br/>`(default: false)`                                                                                      |
 | `cache_keys.{your regexp}.disable_method` | Disable the method part in the key matching the regexp                                                                                       | `true`<br/><br/>`(default: false)`                                                                                      |
+| `cache_keys.{your regexp}.disable_query`  | Disable the query string part in the key matching the regexp                                                                                 | `true`<br/><br/>`(default: false)`                                                                                      |
 | `cache_keys.{your regexp}.headers`        | Add headers to the key matching the regexp                                                                                                   | `Authorization Content-Type X-Additional-Header`                                                                        |
 | `cache_keys.{your regexp}.hide`           | Prevent the key from being exposed in the `Cache-Status` HTTP response header                                                                | `true`<br/><br/>`(default: false)`                                                                                      |
 | `cdn`                                     | The CDN management, if you use any cdn to proxy your requests Souin will handle that                                                         |                                                                                                                         |
@@ -379,6 +383,7 @@ What does these directives mean?
 | `key.disable_body`                        | Disable the body part in the key (GraphQL context)                                                                                           | `true`<br/><br/>`(default: false)`                                                                                      |
 | `key.disable_host`                        | Disable the host part in the key                                                                                                             | `true`<br/><br/>`(default: false)`                                                                                      |
 | `key.disable_method`                      | Disable the method part in the key                                                                                                           | `true`<br/><br/>`(default: false)`                                                                                      |
+| `key.disable_query`                       | Disable the query string part in the key                                                                                                     | `true`<br/><br/>`(default: false)`                                                                                      |
 | `key.headers`                             | Add headers to the key matching the regexp                                                                                                   | `Authorization Content-Type X-Additional-Header`                                                                        |
 | `key.hide`                                | Prevent the key from being exposed in the `Cache-Status` HTTP response header                                                                | `true`<br/><br/>`(default: false)`                                                                                      |
 | `mode`                                    | Bypass the RFC respect                                                                                                                       | One of `bypass` `bypass_request` `bypass_response` `strict` (default `strict`)                                          |