You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@openwhisk.apache.org by ch...@apache.org on 2018/09/25 05:51:29 UTC

[incubator-openwhisk] branch master updated: Put error message as tag into failed trace. (#4000)

This is an automated email from the ASF dual-hosted git repository.

chetanm pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/incubator-openwhisk.git


The following commit(s) were added to refs/heads/master by this push:
     new 77884e5  Put error message as tag into failed trace. (#4000)
77884e5 is described below

commit 77884e542ec0c95d3abfee427dc43cd8044bee0c
Author: Tzu-Chiao Yeh <su...@gmail.com>
AuthorDate: Tue Sep 25 13:51:23 2018 +0800

    Put error message as tag into failed trace. (#4000)
    
    Put error message as tag into failed trace. This is nice to have and useful on trouble shooting within request context via modern UI in Jaegar or Zipkin.
---
 .../main/scala/whisk/common/TransactionId.scala    |  2 +-
 .../whisk/common/tracing/OpenTracingProvider.scala | 17 ++++++++----
 .../core/controller/actions/PrimitiveActions.scala | 13 +++++----
 tests/src/test/scala/common/TestHelpers.scala      |  4 +--
 tests/src/test/scala/common/WskTracingTests.scala  | 32 ++++++++++++++--------
 5 files changed, 42 insertions(+), 26 deletions(-)

diff --git a/common/scala/src/main/scala/whisk/common/TransactionId.scala b/common/scala/src/main/scala/whisk/common/TransactionId.scala
index ae86321..ac9e73c 100644
--- a/common/scala/src/main/scala/whisk/common/TransactionId.scala
+++ b/common/scala/src/main/scala/whisk/common/TransactionId.scala
@@ -154,7 +154,7 @@ case class TransactionId private (meta: TransactionMetadata) extends AnyVal {
     MetricEmitter.emitCounterMetric(endMarker)
 
     //tracing support
-    WhiskTracerProvider.tracer.error(this)
+    WhiskTracerProvider.tracer.error(this, message)
   }
 
   /**
diff --git a/common/scala/src/main/scala/whisk/common/tracing/OpenTracingProvider.scala b/common/scala/src/main/scala/whisk/common/tracing/OpenTracingProvider.scala
index 09c105a..4102532 100644
--- a/common/scala/src/main/scala/whisk/common/tracing/OpenTracingProvider.scala
+++ b/common/scala/src/main/scala/whisk/common/tracing/OpenTracingProvider.scala
@@ -80,7 +80,7 @@ class OpenTracer(val tracer: Tracer, tracingConfig: TracingConfig, ticker: Ticke
    * @param transactionId
    */
   override def finishSpan(transactionId: TransactionId): Unit = {
-    clear(transactionId)
+    clear(transactionId, withErrorMessage = None)
   }
 
   /**
@@ -88,8 +88,8 @@ class OpenTracer(val tracer: Tracer, tracingConfig: TracingConfig, ticker: Ticke
    *
    * @param transactionId
    */
-  override def error(transactionId: TransactionId): Unit = {
-    clear(transactionId)
+  override def error(transactionId: TransactionId, message: => String): Unit = {
+    clear(transactionId, withErrorMessage = Some(message))
   }
 
   /**
@@ -122,19 +122,26 @@ class OpenTracer(val tracer: Tracer, tracingConfig: TracingConfig, ticker: Ticke
     }
   }
 
-  private def clear(transactionId: TransactionId): Unit = {
+  private def clear(transactionId: TransactionId, withErrorMessage: Option[String]): Unit = {
     spanMap.get(transactionId.meta.id).foreach {
       case head :: Nil =>
+        withErrorMessage.foreach(setErrorTags(head, _))
         head.finish()
         spanMap.remove(transactionId.meta.id)
         contextMap.remove(transactionId.meta.id)
       case head :: tail =>
+        withErrorMessage.foreach(setErrorTags(head, _))
         head.finish()
         spanMap.put(transactionId.meta.id, tail)
       case Nil =>
     }
   }
 
+  private def setErrorTags(span: Span, message: => String): Unit = {
+    span.setTag("error", true)
+    span.setTag("message", message)
+  }
+
   private def configureCache[T, R](): collection.concurrent.Map[T, R] =
     Caffeine
       .newBuilder()
@@ -149,7 +156,7 @@ class OpenTracer(val tracer: Tracer, tracingConfig: TracingConfig, ticker: Ticke
 trait WhiskTracer {
   def startSpan(logMarker: LogMarkerToken, transactionId: TransactionId): Unit = {}
   def finishSpan(transactionId: TransactionId): Unit = {}
-  def error(transactionId: TransactionId): Unit = {}
+  def error(transactionId: TransactionId, message: => String): Unit = {}
   def getTraceContext(transactionId: TransactionId): Option[Map[String, String]] = None
   def setTraceContext(transactionId: TransactionId, context: Option[Map[String, String]]): Unit = {}
 }
diff --git a/core/controller/src/main/scala/whisk/core/controller/actions/PrimitiveActions.scala b/core/controller/src/main/scala/whisk/core/controller/actions/PrimitiveActions.scala
index d0d4f60..7bbe071 100644
--- a/core/controller/src/main/scala/whisk/core/controller/actions/PrimitiveActions.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/actions/PrimitiveActions.scala
@@ -174,23 +174,24 @@ protected[actions] trait PrimitiveActions {
 
     val postedFuture = loadBalancer.publish(action, message)
 
-    postedFuture.flatMap { activeAckResponse =>
-      // successfully posted activation request to the message bus
-      transid.finished(this, startLoadbalancer)
-
+    postedFuture andThen {
+      case Success(_) => transid.finished(this, startLoadbalancer)
+      case Failure(e) => transid.failed(this, startLoadbalancer, e.getMessage)
+    } flatMap { activeAckResponse =>
       // is caller waiting for the result of the activation?
       waitForResponse
         .map { timeout =>
           // yes, then wait for the activation response from the message bus
           // (known as the active response or active ack)
           waitForActivationResponse(user, message.activationId, timeout, activeAckResponse)
-            .andThen { case _ => transid.finished(this, startActivation) }
         }
         .getOrElse {
           // no, return the activation id
-          transid.finished(this, startActivation)
           Future.successful(Left(message.activationId))
         }
+    } andThen {
+      case Success(_) => transid.finished(this, startActivation)
+      case Failure(e) => transid.failed(this, startActivation, e.getMessage)
     }
   }
 
diff --git a/tests/src/test/scala/common/TestHelpers.scala b/tests/src/test/scala/common/TestHelpers.scala
index 113e0bc..005468f 100644
--- a/tests/src/test/scala/common/TestHelpers.scala
+++ b/tests/src/test/scala/common/TestHelpers.scala
@@ -23,12 +23,12 @@ import org.scalatest.TestData
 
 trait TestHelpers extends FlatSpec with BeforeAndAfterEachTestData {
 
-  override def beforeEach(td: TestData) {
+  override def beforeEach(td: TestData): Unit = {
     println(s"\nStarting test ${td.name} at ${TestUtils.getDateTime()}")
     super.beforeEach(td)
   }
 
-  override def afterEach(td: TestData) {
+  override def afterEach(td: TestData): Unit = {
     println(s"\nFinished test ${td.name} at ${TestUtils.getDateTime()}")
     super.afterEach(td)
   }
diff --git a/tests/src/test/scala/common/WskTracingTests.scala b/tests/src/test/scala/common/WskTracingTests.scala
index 5a4f9eb..a48c12e 100644
--- a/tests/src/test/scala/common/WskTracingTests.scala
+++ b/tests/src/test/scala/common/WskTracingTests.scala
@@ -28,20 +28,23 @@ import whisk.common.tracing.{OpenTracer, TracingConfig}
 import whisk.core.ConfigKeys
 
 import scala.ref.WeakReference
-import org.scalatest.FlatSpec
-import org.scalatest.Matchers
+import org.scalatest.{Matchers, TestData}
+import scala.collection.JavaConverters._
 
 @RunWith(classOf[JUnitRunner])
-class WskTracingTests extends FlatSpec with TestHelpers with Matchers {
+class WskTracingTests extends TestHelpers with Matchers {
 
   val tracer: MockTracer = new MockTracer()
   val tracingConfig = loadConfigOrThrow[TracingConfig](ConfigKeys.tracing)
   val ticker = new FakeTicker(System.nanoTime())
   val openTracer = new OpenTracer(tracer, tracingConfig, ticker)
 
-  it should "create span and context and invalidate cache after expiry" in {
-    tracer.reset
+  override def beforeEach(td: TestData): Unit = {
+    super.beforeEach(td)
+    tracer.reset()
+  }
 
+  it should "create span and context and invalidate cache after expiry" in {
     val transactionId: TransactionId = TransactionId.testing
     var list: List[WeakReference[Span]] = List.empty
 
@@ -63,17 +66,26 @@ class WskTracingTests extends FlatSpec with TestHelpers with Matchers {
   }
 
   it should "create a finished span" in {
-    tracer.reset
     val transactionId: TransactionId = TransactionId.testing
     openTracer.startSpan(LoggingMarkers.CONTROLLER_ACTIVATION, transactionId)
     openTracer.finishSpan(transactionId)
     val finishedSpans = tracer.finishedSpans()
     finishedSpans should have size 1
+  }
 
+  it should "put error message into span" in {
+    val transactionId = TransactionId.testing
+    val errorMessage = "dummy error message"
+    openTracer.startSpan(LoggingMarkers.CONTROLLER_ACTIVATION, transactionId)
+    openTracer.error(transactionId, errorMessage)
+    val errorSpans = tracer.finishedSpans()
+    errorSpans should have size 1
+    val spanMap = errorSpans.get(0).tags().asScala
+    spanMap.get("error") should be(Some(true))
+    spanMap.get("message") should be(Some(errorMessage))
   }
 
   it should "create a child span" in {
-    tracer.reset
     val transactionId: TransactionId = TransactionId.testing
     openTracer.startSpan(LoggingMarkers.CONTROLLER_ACTIVATION, transactionId)
     openTracer.startSpan(LoggingMarkers.CONTROLLER_KAFKA, transactionId)
@@ -84,11 +96,9 @@ class WskTracingTests extends FlatSpec with TestHelpers with Matchers {
     val parent: MockSpan = finishedSpans.get(1)
     val child: MockSpan = finishedSpans.get(0)
     child.parentId should be(parent.context().spanId)
-
   }
 
   it should "create a span with tag" in {
-    tracer.reset
     val transactionId: TransactionId = TransactionId.testing
     openTracer.startSpan(LoggingMarkers.CONTROLLER_ACTIVATION, transactionId)
     openTracer.finishSpan(transactionId)
@@ -97,16 +107,14 @@ class WskTracingTests extends FlatSpec with TestHelpers with Matchers {
     val mockSpan: MockSpan = finishedSpans.get(0)
     mockSpan.tags should not be null
     mockSpan.tags should have size 1
-
   }
 
   it should "create a valid trace context and use it" in {
-    tracer.reset
     val transactionId: TransactionId = TransactionId.testing
     openTracer.startSpan(LoggingMarkers.CONTROLLER_ACTIVATION, transactionId)
     val context = openTracer.getTraceContext(transactionId)
     openTracer.finishSpan(transactionId)
-    tracer.reset
+    tracer.reset()
     //use context for new span
     openTracer.setTraceContext(transactionId, context)
     openTracer.startSpan(LoggingMarkers.CONTROLLER_KAFKA, transactionId)