1
// Copyright (c) 2017-2024 Cloudflare, Inc.
2
// Licensed under the Apache 2.0 license found in the LICENSE file or at:
3
//     https://opensource.org/licenses/Apache-2.0
4
 
5
#include "duration-exceeded-logger.h"
6
 
7
#include <kj/test.h>
8
#include <kj/timer.h>
9
 
10
namespace workerd::util {
11
namespace {
12
 
13
KJ_TEST("Duration alert triggers when time is exceeded") {
14
  kj::TimerImpl timer(kj::origin<kj::TimePoint>());
15
 
16
  KJ_EXPECT_LOG(WARNING, "durationAlert Test Message; warningDuration = 10s; actualDuration = ");
17
  // we don't check the actual duration emitted to avoid making the test flaky.
18
  // this is OK because KJ_EXPECT_LOG just checks for substring occurrences
19
  {
20
    DurationExceededLogger duration(timer, 10 * kj::SECONDS, "durationAlert Test Message");
21
    timer.advanceTo(timer.now() + 100 * kj::SECONDS);
22
  }
23
}
24
 
25
KJ_TEST("DURATION_EXCEEDED_LOG with extra params triggers when time is exceeded") {
26
  kj::TimerImpl timer(kj::origin<kj::TimePoint>());
27
 
28
  int requestId = 42;
29
  kj::StringPtr operation = "doSomething";
30
 
31
  KJ_EXPECT_LOG(WARNING,
32
      "test message; requestId = 42; operation = doSomething; warningDuration = 10s; "
33
      "actualDuration = ");
34
  {
35
    DURATION_EXCEEDED_LOG(duration, timer, 10 * kj::SECONDS, "test message", requestId, operation);
36
    timer.advanceTo(timer.now() + 100 * kj::SECONDS);
37
  }
38
}
39
 
40
KJ_TEST("DURATION_EXCEEDED_LOG without extra params triggers when time is exceeded") {
41
  kj::TimerImpl timer(kj::origin<kj::TimePoint>());
42
 
43
  KJ_EXPECT_LOG(WARNING, "no extras test; warningDuration = 10s; actualDuration = ");
44
  {
45
    DURATION_EXCEEDED_LOG(duration, timer, 10 * kj::SECONDS, "no extras test");
46
    timer.advanceTo(timer.now() + 100 * kj::SECONDS);
47
  }
48
}
49
 
50
KJ_TEST("DURATION_EXCEEDED_LOG extra params are lazily evaluated") {
51
  kj::TimerImpl timer(kj::origin<kj::TimePoint>());
52
 
53
  // This test verifies that the extra params lambda is NOT called when the duration
54
  // threshold is not exceeded. We use a counter to track whether stringification occurred.
55
  int stringifyCount = 0;
56
  auto makeExpensiveString = [&]() -> kj::StringPtr {
57
    ++stringifyCount;
58
    return "expensive"_kj;
59
  };
60
 
61
  {
62
    DURATION_EXCEEDED_LOG(duration, timer, 10 * kj::SECONDS, "lazy test", makeExpensiveString());
63
    timer.advanceTo(timer.now() + 1 * kj::SECONDS);
64
  }
65
  KJ_EXPECT(stringifyCount == 0, "extra params should not be evaluated when duration not exceeded");
66
}
67
 
68
}  // namespace
69
}  // namespace workerd::util