+ play: introducing LoggerLikeInstrumentation in order to copy the properties of TraceLocalStorage to MDC

5 files changed, 217 insertions, 23 deletions

diff --git a/kamon-play/src/main/resources/META-INF/aop.xml b/kamon-play/src/main/resources/META-INF/aop.xml
index ca499a33..e24d48d5 100644
--- a/kamon-play/src/main/resources/META-INF/aop.xml
+++ b/kamon-play/src/main/resources/META-INF/aop.xml
@@ -4,6 +4,7 @@
   <aspects>
     <aspect name="kamon.play.instrumentation.RequestInstrumentation"/>
     <aspect name="kamon.play.instrumentation.WSInstrumentation"/>
+    <aspect name="kamon.play.instrumentation.LoggerLikeInstrumentation"/>
   </aspects>
 
    <weaver>
diff --git a/kamon-play/src/main/scala/kamon/play/instrumentation/LoggerLikeInstrumentation.scala b/kamon-play/src/main/scala/kamon/play/instrumentation/LoggerLikeInstrumentation.scala
new file mode 100644
index 00000000..b7afeb76
--- /dev/null
+++ b/kamon-play/src/main/scala/kamon/play/instrumentation/LoggerLikeInstrumentation.scala
@@ -0,0 +1,70 @@
+/* =========================================================================================
+ * Copyright © 2013-2014 the kamon project <http://kamon.io/>
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file
+ * except in compliance with the License. You may obtain a copy of the License at
+ *
+ *   http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software distributed under the
+ * License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND,
+ * either express or implied. See the License for the specific language governing permissions
+ * and limitations under the License.
+ * =========================================================================================
+ */
+
+package kamon.play.instrumentation
+
+import kamon.trace.{ TraceContext, TraceContextAware }
+import org.aspectj.lang.ProceedingJoinPoint
+import org.aspectj.lang.annotation._
+import org.slf4j.MDC
+
+@Aspect
+class LoggerLikeInstrumentation {
+
+  import LoggerLikeInstrumentation._
+
+  @DeclareMixin("play.api.LoggerLike+")
+  def mixinContextAwareToLoggerLike: TraceContextAware = TraceContextAware.default
+
+  @Pointcut("execution(* play.api.LoggerLike+.info(..))")
+  def infoPointcut(): Unit = {}
+
+  @Pointcut("execution(* play.api.LoggerLike+.warn(..))")
+  def warnPointcut(): Unit = {}
+
+  @Pointcut("execution(* play.api.LoggerLike+.error(..))")
+  def errorPointcut(): Unit = {}
+
+  @Pointcut("execution(* play.api.LoggerLike+.trace(..))")
+  def tracePointcut(): Unit = {}
+
+  @Around("(infoPointcut() || warnPointcut() || errorPointcut() || tracePointcut()) && this(logger)")
+  def aroundLog(pjp: ProceedingJoinPoint, logger: TraceContextAware): Any = {
+    withMDC(logger.traceContext) {
+      pjp.proceed()
+    }
+  }
+}
+
+object LoggerLikeInstrumentation {
+  def withMDC[A](currentContext: Option[TraceContext])(block: ⇒ A): A = {
+    val keys = currentContext.map(extractProperties).map(putAndExtractKeys)
+
+    try block finally keys.map(k ⇒ k.foreach(MDC.remove(_)))
+  }
+
+  def putAndExtractKeys(values: Iterable[Map[String, Any]]): Iterable[String] = values.map {
+    value ⇒ value.map { case (key, value) ⇒ MDC.put(key, value.toString); key }
+  }.flatten
+
+  def extractProperties(ctx: TraceContext): Iterable[Map[String, Any]] = ctx.traceLocalStorage.underlyingStorage.values.map {
+    case traceLocalValue @ (p: Product) ⇒ {
+      val properties = p.productIterator
+      traceLocalValue.getClass.getDeclaredFields.filter(field ⇒ field.getName != "$outer").map(_.getName -> properties.next).toMap
+    }
+    case anything ⇒ Map.empty[String, Any]
+  }
+}
+
diff --git a/kamon-play/src/main/scala/kamon/play/instrumentation/RequestInstrumentation.scala b/kamon-play/src/main/scala/kamon/play/instrumentation/RequestInstrumentation.scala
index 00170b1b..db864fb6 100644
--- a/kamon-play/src/main/scala/kamon/play/instrumentation/RequestInstrumentation.scala
+++ b/kamon-play/src/main/scala/kamon/play/instrumentation/RequestInstrumentation.scala
@@ -1,18 +1,17 @@
-/* ===================================================
+/* =========================================================================================
  * Copyright © 2013-2014 the kamon project <http://kamon.io/>
  *
- * Licensed under the Apache License, Version 2.0 (the "License");
- * you may not use this file except in compliance with the License.
- * You may obtain a copy of the License at
+ * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file
+ * except in compliance with the License. You may obtain a copy of the License at
  *
- * http://www.apache.org/licenses/LICENSE-2.0
+ *   http://www.apache.org/licenses/LICENSE-2.0
  *
- * Unless required by applicable law or agreed to in writing, software
- * distributed under the License is distributed on an "AS IS" BASIS,
- * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
- * See the License for the specific language governing permissions and
- * limitations under the License.
- * ========================================================== */
+ * Unless required by applicable law or agreed to in writing, software distributed under the
+ * License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND,
+ * either express or implied. See the License for the specific language governing permissions
+ * and limitations under the License.
+ * =========================================================================================
+ */
 
 package kamon.play.instrumentation
 
@@ -49,7 +48,7 @@ class RequestInstrumentation {
   }
 
   @Around("execution(* play.api.GlobalSettings+.doFilter(*)) && args(next)")
-  def afterDoFilter(pjp: ProceedingJoinPoint, next: EssentialAction): Any = {
+  def aroundDoFilter(pjp: ProceedingJoinPoint, next: EssentialAction): Any = {
     val essentialAction = (requestHeader: RequestHeader) ⇒ {
 
       val incomingContext = TraceRecorder.currentContext
diff --git a/kamon-play/src/test/scala/kamon/play/LoggerLikeInstrumentationSpec.scala b/kamon-play/src/test/scala/kamon/play/LoggerLikeInstrumentationSpec.scala
new file mode 100644
index 00000000..6c90c29f
--- /dev/null
+++ b/kamon-play/src/test/scala/kamon/play/LoggerLikeInstrumentationSpec.scala
@@ -0,0 +1,125 @@
+/* =========================================================================================
+ * Copyright © 2013-2014 the kamon project <http://kamon.io/>
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License") you may not use this file
+ * except in compliance with the License. You may obtain a copy of the License at
+ *
+ *   http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software distributed under the
+ * License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND,
+ * either express or implied. See the License for the specific language governing permissions
+ * and limitations under the License.
+ * =========================================================================================
+ */
+
+package kamon.play
+
+import ch.qos.logback.classic.AsyncAppender
+import ch.qos.logback.classic.spi.ILoggingEvent
+import ch.qos.logback.core.read.ListAppender
+import ch.qos.logback.core.status.NopStatusListener
+import kamon.trace.TraceLocal
+import org.scalatest.BeforeAndAfter
+import org.scalatestplus.play._
+import play.api.Logger
+import play.api.mvc.Results.Ok
+import play.api.mvc._
+import play.api.test.Helpers._
+import play.api.test._
+
+import scala.concurrent.Future
+
+class LoggerLikeInstrumentationSpec extends PlaySpec with OneServerPerSuite with BeforeAndAfter with Logging {
+
+  System.setProperty("config.file", "./kamon-play/src/test/resources/conf/application.conf")
+
+  val executor = scala.concurrent.ExecutionContext.Implicits.global
+
+  val infoMessage = "Info Message"
+
+  val headerValue = "My header value"
+  val otherValue = "My other value"
+
+  case class Test(header: String, other: String)
+
+  object TraceLocalKey extends TraceLocal.TraceLocalKey {
+    type ValueType = Test
+  }
+
+  before {
+    LoggingHandler.startLogging()
+  }
+
+  after {
+    LoggingHandler.stopLogging()
+  }
+
+  implicit override lazy val app = FakeApplication(withRoutes = {
+
+    case ("GET", "/logging") ⇒
+      Action.async {
+        Future {
+          TraceLocal.store(TraceLocalKey)(Test(headerValue, otherValue))
+          logger.info(infoMessage)
+          Ok("OK")
+        }(executor)
+      }
+  })
+
+  "the LoggerLike instrumentation" should {
+    "be put the properties of TraceLocal into the MDC as key -> value in a request" in {
+      LoggingHandler.appenderStart()
+
+      val Some(result) = route(FakeRequest(GET, "/logging"))
+      Thread.sleep(500) // wait to complete the future
+      TraceLocal.retrieve(TraceLocalKey) must be(Some(Test(headerValue, otherValue)))
+
+      LoggingHandler.appenderStop()
+
+      headerValue must be(LoggingHandler.getValueFromMDC("header"))
+      otherValue must be(LoggingHandler.getValueFromMDC("other"))
+    }
+  }
+}
+
+trait Logging {
+  val logger = Logger(this.getClass)
+}
+
+object LoggingHandler {
+
+  val root = play.Logger.of(org.slf4j.Logger.ROOT_LOGGER_NAME)
+  val underlyingLogger = root.underlying().asInstanceOf[ch.qos.logback.classic.Logger]
+  val context = underlyingLogger.getLoggerContext
+  val asyncAppender = new AsyncAppender()
+  val listAppender = new ListAppender[ILoggingEvent]()
+  val onConsoleStatusListener = new NopStatusListener()
+
+  def startLogging(): Unit = {
+    context.getStatusManager().add(onConsoleStatusListener)
+    asyncAppender.setContext(context)
+    listAppender.setContext(context)
+    listAppender.setName("list")
+    listAppender.start()
+  }
+
+  def stopLogging(): Unit = {
+    listAppender.stop()
+  }
+
+  def appenderStart(): Unit = {
+    asyncAppender.addAppender(listAppender)
+    asyncAppender.start()
+    underlyingLogger.addAppender(asyncAppender)
+  }
+
+  def appenderStop(): Unit = {
+    asyncAppender.stop()
+  }
+
+  def getValueFromMDC(key: String): String = {
+    listAppender.list.get(0).getMDCPropertyMap.get(key)
+  }
+}
+
diff --git a/kamon-play/src/test/scala/kamon/play/RequestInstrumentationSpec.scala b/kamon-play/src/test/scala/kamon/play/RequestInstrumentationSpec.scala
index 710c6ed5..3090e60e 100644
--- a/kamon-play/src/test/scala/kamon/play/RequestInstrumentationSpec.scala
+++ b/kamon-play/src/test/scala/kamon/play/RequestInstrumentationSpec.scala
@@ -1,18 +1,17 @@
-/* ===================================================
+/* =========================================================================================
  * Copyright © 2013-2014 the kamon project <http://kamon.io/>
  *
- * Licensed under the Apache License, Version 2.0 (the "License");
- * you may not use this file except in compliance with the License.
- * You may obtain a copy of the License at
+ * Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file
+ * except in compliance with the License. You may obtain a copy of the License at
  *
- * http://www.apache.org/licenses/LICENSE-2.0
+ *   http://www.apache.org/licenses/LICENSE-2.0
  *
- * Unless required by applicable law or agreed to in writing, software
- * distributed under the License is distributed on an "AS IS" BASIS,
- * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
- * See the License for the specific language governing permissions and
- * limitations under the License.
- * ========================================================== */
+ * Unless required by applicable law or agreed to in writing, software distributed under the
+ * License is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND,
+ * either express or implied. See the License for the specific language governing permissions
+ * and limitations under the License.
+ * =========================================================================================
+ */
 
 package kamon.play