spike filter logging (#106)

Co-authored-by: tomas mccandless <[email protected]>
Workday · Oct 16, 2023 · 0786321 · 0786321
1 parent 1282d71
commit 0786321
Show file tree

Hide file tree

Showing 3 changed files with 28 additions and 10 deletions.
diff --git a/warp-core/src/main/scala/com/workday/warp/arbiters/ArbiterLike.scala b/warp-core/src/main/scala/com/workday/warp/arbiters/ArbiterLike.scala
@@ -52,13 +52,21 @@ trait ArbiterLike extends PersistenceAware with CanReadHistory {
     }
 
     if (spikeFilterEnabled) {
+      logger.trace(s"voting, spike filter is enabled")
       // check the last executions to see if they have a failure tag that matches
       val priorExecutionHasFailureTag: Boolean = priorExecutionsFailed(testExecution, tagName, alertOnNth)
-      if (priorExecutionHasFailureTag) maybeFailure
+      if (priorExecutionHasFailureTag) {
+        logger.trace(s"sufficient prior consecutive failures, vote=${maybeFailure.nonEmpty}")
+        maybeFailure
+      }
       // no failure tag on the last execution, (first time failure), don't vote as a failure
-      else None
+      else {
+        logger.trace(s"last executions did not fail, vote=false")
+        None
+      }
     }
     else {
+      logger.trace(s"spike filter is disabled, vote=${maybeFailure.nonEmpty}")
       maybeFailure
     }
   }
@@ -91,9 +99,16 @@ trait ArbiterLike extends PersistenceAware with CanReadHistory {
     var settings: (Boolean, Int) = this.persistenceUtils.getSpikeFilterSettings(idTestDefinition)
       .map(setting => (setting.spikeFilterEnabled, setting.alertOnNth))
       .getOrElse((false, 1))
+    logger.trace(s"base spike filter settings: $settings")
     // allow individual overrides from properties if they are present
-    Option(WARP_ARBITER_SPIKE_FILTER_ENABLED.value).foreach(f => settings = settings.copy(_1 = f.toBoolean))
-    Option(WARP_ARBITER_SPIKE_FILTER_ALERT_ON_NTH.value).foreach(f => settings = settings.copy(_2 = f.toInt))
+    Option(WARP_ARBITER_SPIKE_FILTER_ENABLED.value).foreach { f =>
+      logger.trace(s"spike filter enabled override: $f")
+      settings = settings.copy(_1 = f.toBoolean)
+    }
+    Option(WARP_ARBITER_SPIKE_FILTER_ALERT_ON_NTH.value).foreach { f =>
+      logger.trace(s"spike filter alert on nth override: $f")
+      settings = settings.copy(_2 = f.toInt)
+    }
     settings
   }
 

diff --git a/warp-core/src/main/scala/com/workday/warp/arbiters/ResponseTimeArbiter.scala b/warp-core/src/main/scala/com/workday/warp/arbiters/ResponseTimeArbiter.scala
@@ -35,8 +35,9 @@ class ResponseTimeArbiter extends ArbiterLike with CorePersistenceAware {
 
     if (threshold.isPositive && responseTime > threshold) {
       Option(new RequirementViolationException(
-        s"$testId violated response time requirement: expected ${threshold.humanReadable} (${threshold.toMillis} ms)" +
-        s", but measured ${responseTime.humanReadable} (${responseTime.toMillis} ms)"
+        s"$testId violated response time requirement (imposed by ${this.getClass.getCanonicalName}): " +
+          s"expected ${threshold.humanReadable} (${threshold.toMillis} ms), " +
+        s"but measured ${responseTime.humanReadable} (${responseTime.toMillis} ms)"
       ))
     }
     else {

diff --git a/warp-core/src/test/scala/com/workday/warp/arbiters/ResponseTimeArbiterSpec.scala b/warp-core/src/test/scala/com/workday/warp/arbiters/ResponseTimeArbiterSpec.scala
@@ -52,8 +52,9 @@ class ResponseTimeArbiterSpec extends WarpJUnitSpec with CorePersistenceAware {
 
     val vote: Option[Throwable] = arbiter.vote(ballot, testExecution)
     vote should not be empty
-    vote.get.getMessage should be (s"$testId violated response time requirement: expected 0:00:03.000 (3000 ms), but " +
-      "measured 0:00:04.000 (4000 ms)")
+    vote.get.getMessage should be (s"$testId violated response time requirement" +
+      " (imposed by com.workday.warp.arbiters.ResponseTimeArbiter):" +
+      " expected 0:00:03.000 (3000 ms), but measured 0:00:04.000 (4000 ms)")
   }
 
 
@@ -68,7 +69,8 @@ class ResponseTimeArbiterSpec extends WarpJUnitSpec with CorePersistenceAware {
 
     val vote: Option[Throwable] = arbiter.vote(ballot, testExecution)
     vote should not be empty
-    vote.get.getMessage should be (s"$testId violated response time requirement: expected 0:00:03.000 (3000 ms), but " +
-      "measured 0:00:04.000 (4000 ms)")
+    vote.get.getMessage should be (s"$testId violated response time requirement" +
+      " (imposed by com.workday.warp.arbiters.ResponseTimeArbiter):" +
+      " expected 0:00:03.000 (3000 ms), but measured 0:00:04.000 (4000 ms)")
   }
 }