From 4438aebca2ec01d4dbf22287aa651937a381e043 Mon Sep 17 00:00:00 2001 From: Maggie Nolan Date: Mon, 20 Dec 2021 17:19:03 -0800 Subject: [PATCH] fix(profiler): refine regular expression for parsing backoff duration in E2E tests (#5229) --- profiler/proftest/proftest.go | 7 ++++--- profiler/proftest/proftest_test.go | 25 +++++++++++++++++++++++-- 2 files changed, 27 insertions(+), 5 deletions(-) diff --git a/profiler/proftest/proftest.go b/profiler/proftest/proftest.go index e806a8137e9..a4bff522b23 100644 --- a/profiler/proftest/proftest.go +++ b/profiler/proftest/proftest.go @@ -47,7 +47,7 @@ var ( // "ms" must be specified before "m" in the regexp, to ensure "ms" is fully // matched. - backoffTimeRE = regexp.MustCompile(`(\d+(\.\d+)?(ms|h|m|s|us))+`) + backoffTimeRE = regexp.MustCompile(`(?:^|\W)((\d+(\.\d+)?(ms|h|m|s|us))+)(?:$|\W)`) ) // BaseStartupTmpl is the common part of the startup script that @@ -454,10 +454,11 @@ func parseLogTime(line string) (time.Time, error) { // parseBackoffDuration returns the backoff duration associated with a logged // line, or an error if the line does not contain a valid backoff duration. func parseBackoffDuration(line string) (time.Duration, error) { - backoffTimeStr := backoffTimeRE.FindString(line) - if backoffTimeStr == "" { + backoffTimeMatch := backoffTimeRE.FindStringSubmatch(line) + if len(backoffTimeMatch) < 2 || backoffTimeMatch[1] == "" { return 0, fmt.Errorf("log for server-specified backoff %q does not include a backoff time", line) } + backoffTimeStr := backoffTimeMatch[1] backoff, err := time.ParseDuration(backoffTimeStr) if err != nil { return 0, fmt.Errorf("failed to parse backoff duration %q", backoffTimeStr) diff --git a/profiler/proftest/proftest_test.go b/profiler/proftest/proftest_test.go index 9be3894353a..48a071da753 100644 --- a/profiler/proftest/proftest_test.go +++ b/profiler/proftest/proftest_test.go @@ -120,8 +120,24 @@ func TestParseBackoffDuration(t *testing.T) { wantErr bool }{ { - desc: "a valid backoff duration is parsed correctly", - line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s", + desc: "a valid backoff duration is parsed correctly when at the end of the message", + line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: action throttled, backoff for 32m0s", + wantBackoffDur: 32 * time.Minute, + }, + { + desc: "a valid backoff duration is parsed correctly when at the end of a message ending with a period", + line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s.", + wantBackoffDur: 32 * time.Minute, + }, + { + desc: "a valid backoff duration in a structured log statement is parsed correctly", + line: `Mon Dec 20 20:21:40 UTC 2021: benchmark 39: {"timestamp":"2021-12-20T20:21:39.973Z","severity":"DEBUG","logging.googleapis.com/insertId":"..........K231soqV4EIcG8w42yR2.3","message":"Must wait 35m to create profile: Error: generic::aborted: action throttled, backoff for 35m0s","logName":"projects/{{projectId}}/logs/%40google-cloud%2Fprofiler","resource":{"type":"gae_app","labels":{"module_id":"profiler-backoff-test-node12-2021-12-20-12-18-47-077307-0800","zone":"us-east4-b"}}}`, + wantBackoffDur: 35 * time.Minute, + }, + + { + desc: "a valid backoff duration is parsed correctly when in the middle of the message", + line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 32m0s ... more information", wantBackoffDur: 32 * time.Minute, }, { @@ -139,6 +155,11 @@ func TestParseBackoffDuration(t *testing.T) { line: "Fri May 15 22:05:01 UTC 2020: benchmark 0: failed to create profile, will retry: rpc error: code = Aborted desc = generic::aborted: action throttled, backoff for 1h1m1s1ms1us", wantBackoffDur: time.Hour + time.Minute + time.Second + time.Millisecond + time.Microsecond, }, + { + desc: "a backoff duration at the start of the message is parsed correctly", + line: "1h1m1s1ms", + wantBackoffDur: time.Hour + time.Minute + time.Second + time.Millisecond, + }, } { t.Run(tc.desc, func(t *testing.T) { backoffDur, err := parseBackoffDuration(tc.line)