Repository: avenga/couper
Pull request #487 (2022-04-19 18:03:44)

Log parse duration errors
Describe your changes!

---
<details>
    <summary>Reviewer checklist</summary>
    <ul>
        <li>Read PR description: a summary about the changes is required</li>
        <li>Changelog updated</li>
        <li>Documentation: docs/{Reference, Cli, ...}, Docker and cli help/usage</li>
        <li>Pulled branch, manually tested</li>
        <li>Verified requirements are met</li>
        <li>Reviewed the code</li>
        <li>Reviewed the related tests</li>
    </ul>
</details>



Patch:
diff --git a/CHANGELOG.md b/CHANGELOG.md
index 2e099d15..9099f9ae 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -9,6 +9,7 @@ Unreleased changes are available as `avenga/couper:edge` container.
     * provided via `-d` command-line flag or `COUPER_FILE_DIRECTORY` environment variable
   * `beta_health`-block to `backend`-block to enable continuous health-checks for defined backends ([#313](https://github.com/avenga/couper/pull/313))
     * `backends.<name>.health` variable to access the current health-check state _(subject to change)_
+  * Log malformed duration settings ([#487](https://github.com/avenga/couper/pull/487))
 
 * **Changed**
   * Permission handling: ([#477](https://github.com/avenga/couper/pull/477))
diff --git a/handler/transport/backend.go b/handler/transport/backend.go
index 0d63cb35..9373978e 100644
--- a/handler/transport/backend.go
+++ b/handler/transport/backend.go
@@ -504,7 +504,7 @@ func (b *Backend) evalTransport(httpCtx *hcl.EvalContext, params hcl.Body, req *
 
 	return b.transportConf.
 		WithTarget(originURL.Scheme, originURL.Host, hostname, proxyURL).
-		WithTimings(connectTimeout, ttfbTimeout, timeout), nil
+		WithTimings(connectTimeout, ttfbTimeout, timeout, log), nil
 }
 
 // setUserAgent sets an empty one if none is present or empty
diff --git a/handler/transport/transport.go b/handler/transport/transport.go
index 87d0c5da..cb6d4fb6 100644
--- a/handler/transport/transport.go
+++ b/handler/transport/transport.go
@@ -152,17 +152,20 @@ func (c *Config) WithTarget(scheme, origin, hostname, proxyURL string) *Config {
 	return &conf
 }
 
-func (c *Config) WithTimings(connect, ttfb, timeout string) *Config {
+func (c *Config) WithTimings(connect, ttfb, timeout string, logger *logrus.Entry) *Config {
 	conf := *c
-	parseDuration(connect, &conf.ConnectTimeout)
-	parseDuration(ttfb, &conf.TTFBTimeout)
-	parseDuration(timeout, &conf.Timeout)
+	parseDuration(connect, &conf.ConnectTimeout, logger)
+	parseDuration(ttfb, &conf.TTFBTimeout, logger)
+	parseDuration(timeout, &conf.Timeout, logger)
 	return &conf
 }
 
 // parseDuration sets the target value if the given duration string is not empty.
-func parseDuration(src string, target *time.Duration) {
+func parseDuration(src string, target *time.Duration, logger *logrus.Entry) {
 	d, err := time.ParseDuration(src)
+	if err != nil {
+		logger.WithError(err).Warning("using default timing of ", target, " because an error occured")
+	}
 	if src != "" && err != nil {
 		return
 	}


Test patch:
diff --git a/handler/transport/transport_test.go b/handler/transport/transport_test.go
index 8ac2072c..e3afed7e 100644
--- a/handler/transport/transport_test.go
+++ b/handler/transport/transport_test.go
@@ -1,13 +1,18 @@
 package transport
 
 import (
+	"context"
 	"testing"
 	"time"
+
+	"github.com/sirupsen/logrus"
 )
 
 func Test_parseDuration(t *testing.T) {
+	log := logrus.New()
+
 	var target time.Duration
-	parseDuration("1ms", &target)
+	parseDuration("1ms", &target, log.WithContext(context.TODO()))
 
 	if target != 1000000 {
 		t.Errorf("Unexpected duration given: %#v", target)
diff --git a/server/http_test.go b/server/http_test.go
index bf93f433..76125d49 100644
--- a/server/http_test.go
+++ b/server/http_test.go
@@ -689,3 +689,24 @@ func TestHTTPServer_RequestID(t *testing.T) {
 		})
 	}
 }
+
+func TestHTTPServer_parseDuration(t *testing.T) {
+	helper := test.New(t)
+	client := newClient()
+
+	shutdown, logHook := newCouper("testdata/integration/config/16_couper.hcl", test.New(t))
+	defer shutdown()
+
+	logHook.Reset()
+	req, err := http.NewRequest(http.MethodGet, "http://anyserver:8080/", nil)
+	helper.Must(err)
+
+	_, err = client.Do(req)
+	helper.Must(err)
+
+	logs := logHook.AllEntries()
+
+	if logs[0].Message != `using default timing of 0s because an error occured: time: invalid duration "xxx"` {
+		t.Errorf("%#v", logs[0].Message)
+	}
+}
diff --git a/server/testdata/integration/config/16_couper.hcl b/server/testdata/integration/config/16_couper.hcl
new file mode 100644
index 00000000..65f5e647
--- /dev/null
+++ b/server/testdata/integration/config/16_couper.hcl
@@ -0,0 +1,10 @@
+server {
+  endpoint "/" {
+    proxy {
+      backend {
+        origin = "${env.COUPER_TEST_BACKEND_ADDR}"
+        timeout = "xxx"
+      }
+    }
+  }
+}